Created attachment 349597 [details] screenshot of error Description of problem: Attempting to publish to a remote LDAP server fails when using Basic Auth over SSL connection. During configuration, pkiconsole hangs and returns error message "SERVER_NORESPONSE-java.util.MissingResourceException: Can't find resource for bundle com.netscape.admin.certserv.CMSAdminResources, key SERVER_NORESPONSE". All trust-chains have been installed and verified. Publishing succeeds when using Basic Auth over non-SSL port/protocol (389/LDAP). Version-Release number of selected component (if applicable): CS8.0 Beta 2 How reproducible: Always Steps to Reproduce: 1. start CA and launch pkiconsole 2. enable publishing for LDAP, to a remote host, using Basic Authentication. 3. save settings and verify that publishing works 4. change settings to "Use SSL" and port=636. 5. Console hangs for some time, eventually generates error (attached). 6. From terminal of CA, telnet to remote publishing directory host, port 636 to verify route is intact and host is listening. Actual results: Publishing over SSL using Basic Auth, to remote host, is not a possible configuration. Expected results: Publishing over SSL using Basic Auth, to remote host, is a possible configuration. Additional info: Publishing Directory Server has a 2048-bit SSL certificate signed by a different CA, but the trust chains are installed and trusted in the NSS stores.
Created attachment 349942 [details] CA debug log when publishing over ssl is enabled
- Tried on RHEL5.3(x86)-updated - Generated a cert for directory server, enrolled it and installed it in the DS console. - Installed the CA cert in the Directory "CA certificates" console - Enabled SSL in directory configuration - Restarted DS and CA I modified the dnpattern for the (existing default) mappers as below(as Andrew suggested earlier) dnPattern for LdapCaCertMap - UID=$subj.cn,OU=people,dc=pnq,dc=redhat,dc=com dnPattern for LdapUserCertMap - UID=$subj.UID,OU=people,dc=pnq,dc=redhat,dc=com dnPattern for LdapCrlMap - UID=$subj.cn,OU=people,dc=pnq,dc=redhat,dc=com ================= ldap publishing over non ssl(389 port) - successfully published both CA & CRL certificates (with mentioned above dnPattern) ================= ldap publishing over ssl(636) - unsuccessful - Fails with "Connect to directory server dirve.pnq.redhat.com tat port 636.........Failure exception: netscape.ldap.LDAPException: IO Error creating JSS SSL Socket (-1) ============ "ldapsearch" over ssl was successful [root@el3pki ~]# /usr/lib/mozldap/ldapsearch -p 636 -P /etc/dirsrv/slapd-pki/ -D "cn=Directory Manager" -w Secret123 -x -b "dc=pnq,dc=redhat,dc=com" objectclass=* -s base version: 1 dn: dc=pnq,dc=redhat,dc=com objectClass: top objectClass: domain dc: pnq [root@el3pki ~]# ============= In slapd access log, I see error (for ssl publishing)- "SSL peer cannot verify your certificate" ->http://fpaste.org/paste/16892 => I'm not sure why it cannot verify certificate(despite I installed the trust chains(CA certificate) ============================================================= [root@el3pki ~]# tail -90 /var/log/dirsrv/slapd-pki/access [30/Jun/2009:16:39:49 +051800] conn=7 op=317 RESULT err=0 tag=101 nentries=1 etime=0 [30/Jun/2009:16:39:49 +051800] conn=7 op=318 SRCH base="ou=People,dc=el3pki.pnq.redhat.com-pki-ca" scope=2 filter="(uid=admin)" attrs=ALL [30/Jun/2009:16:39:49 +051800] conn=7 op=318 RESULT err=0 tag=101 nentries=1 etime=0 [30/Jun/2009:16:39:49 +051800] conn=7 op=319 SRCH base="cn=Administrators,ou=groups,dc=el3pki.pnq.redhat.com-pki-ca" scope=0 filter="(uniqueMember=uid=admin,ou=People,dc=el3pki.pnq.redhat.com-pki-ca)" attrs="cn" [30/Jun/2009:16:39:49 +051800] conn=7 op=319 RESULT err=0 tag=101 nentries=1 etime=0 [30/Jun/2009:16:39:49 +051800] conn=7 op=320 SRCH base="ou=Groups,dc=el3pki.pnq.redhat.com-pki-ca" scope=2 filter="(&(objectClass=groupofuniquenames)(cn=*))" attrs=ALL [30/Jun/2009:16:39:49 +051800] conn=7 op=320 RESULT err=0 tag=101 nentries=14 etime=0 [30/Jun/2009:16:39:49 +051800] conn=22 fd=101 slot=101 SSL connection from 127.0.0.1 to 127.0.0.1 [30/Jun/2009:16:39:49 +051800] conn=22 op=-1 fd=101 closed - SSL peer cannot verify your certificate. ==================================================================== ============================================= [root@el3pki ~]# certutil -L -d /etc/dirsrv/slapd-pki/ Certificate Nickname Trust Attributes SSL,S/MIME,JAR/XPI server-cert u,u,u Certificate Authority CT,, [root@el3pki ~]# ============== log publishing with ssl(636 port) - see attachment ===============
In step-4(from description)with just giving the value-636 (and not checking the box "use ssl communication" has resulted in the same behaviour mentioned in description: " pkiconsole hangs for long time and returns error message "SERVER_NORESPONSE-java.util.MissingResourceException: Can't find resource for bundle com.netscape.admin.certserv.CMSAdminResources, key SERVER_NORESPONSE"."
With the CN component of DS SSL server cert distinguished name=FQDN of the server, I saw the SSL Handshake happened(in the CA debug log) when LDAP publishing is enabled over SSL...but still it hangs for eternity, and now the error message in the CA debug log says "[02/Jul/2009:09:20:32][CertStatusUpdateThread]: Serial Management not enabled. Returning .. " Any pointers?? ========================= <snip of CA debug log afer the SSL handshake , but still hung> [02/Jul/2009:09:20:32][CertStatusUpdateThread]: getEntries returning 0 [02/Jul/2009:09:20:32][CertStatusUpdateThread]: mTop 0 [02/Jul/2009:09:20:32][CertStatusUpdateThread]: Getting Virtual List size: 0 [02/Jul/2009:09:20:32][CertStatusUpdateThread]: index may be empty [02/Jul/2009:09:20:32][CertStatusUpdateThread]: updateCertStatus done [02/Jul/2009:09:20:32][CertStatusUpdateThread]: Starting cert checkRanges [02/Jul/2009:09:20:32][CertStatusUpdateThread]: Serial Management not enabled. Returning .. [02/Jul/2009:09:20:32][CertStatusUpdateThread]: cert checkRanges done [02/Jul/2009:09:20:32][CertStatusUpdateThread]: Starting request checkRanges [02/Jul/2009:09:20:32][CertStatusUpdateThread]: Serial Management not enabled. Returning .. [02/Jul/2009:09:20:32][CertStatusUpdateThread]: request checkRanges done ================================================ <snip of CA debug log showing the SSL handshake> 02/Jul/2009:09:05:20][http-9445-Processor23]: DirAclAuthz: authorization passed [02/Jul/2009:09:05:20][http-9445-Processor23]: authorization succeeded for servlet: capublisher [02/Jul/2009:09:05:20][http-9445-Processor23]: SignedAuditEventFactory: create() message=[AuditEvent=AUTHZ_SUCCESS][SubjectID=admin][Outcome=Success][aclResource=certServer.publisher.configuration][Op=modify] authorization success [02/Jul/2009:09:05:20][http-9445-Processor23]: getConn: mNumConns now 2 [02/Jul/2009:09:05:20][http-9445-Processor23]: returnConn: mNumConns now 3 [02/Jul/2009:09:05:20][http-9445-Processor23]: SignedAuditEventFactory: create() message=[AuditEvent=ROLE_ASSUME][SubjectID=admin][Outcome=Success][Role=Certificate Manager Agents, Administrators, Security Domain Administrators, Enterprise CA Administrators, Enterprise KRA Administrators, Enterprise OCSP Administrators, Enterprise TKS Administrators, Enterprise RA Administrators, Enterprise TPS Administrators] assume privileged role [02/Jul/2009:09:05:20][http-9445-Processor23]: PublisherAdmineServlet: in testSetLDAPDest [02/Jul/2009:09:05:20][http-9445-Processor23]: SSL handshake happened [02/Jul/2009:09:05:20][http-9445-Processor23]: CMSEngine: getPasswordStore(): password store initialized before. [02/Jul/2009:09:05:20][http-9445-Processor23]: CMSEngine: getPasswordStore(): password store initialized. [02/Jul/2009:09:05:20][http-9445-Processor23]: PublisherAdminServlet: testSetLDAPDest(): saving password for CA LDAP Publishing to password file [02/Jul/2009:09:05:20][http-9445-Processor23]: PublisherAdminServlet: testSetLDAPDest(): password saved [02/Jul/2009:09:05:20][http-9445-Processor23]: Shuting down publishing. [02/Jul/2009:09:05:20][http-9445-Processor23]: PublisherProcessor: startup() [02/Jul/2009:09:05:20][http-9445-Processor23]: PublisherProcessor: about to initLdapConn [02/Jul/2009:09:05:20][http-9445-Processor23]: LdapConnModule: init called [02/Jul/2009:09:05:20][http-9445-Processor23]: LdapConnModule: init begins [02/Jul/2009:09:05:20][http-9445-Processor23]: LdapAuthInfo: init() [02/Jul/2009:09:05:20][http-9445-Processor23]: LdapAuthInfo: init begins [02/Jul/2009:09:05:20][http-9445-Processor23]: LdapAuthInfo: init: prompt is CA LDAP Publishing [02/Jul/2009:09:05:20][http-9445-Processor23]: LdapAuthInfo: init: try getting from memory cache [02/Jul/2009:09:05:20][http-9445-Processor23]: LdapAuthInfo: init: got password from memory [02/Jul/2009:09:05:20][http-9445-Processor23]: LdapAuthInfo: init: password found for prompt. [02/Jul/2009:09:10:32][CertStatusUpdateThread]: About to start updateCertStatus [02/Jul/2009:09:10:32][CertStatusUpdateThread]: Starting updateCertStatus (entered lock) [02/Jul/2009:09:10:3 ===========================================
Created attachment 350226 [details] proposed fix
Attachment (id=350226) +jmagne .
svn commit pki/dogtag/common/pki-common.spec Sending pki/dogtag/common/pki-common.spec Transmitting file data . Committed revision 668. svn commit pki/base/common/src/com/netscape/cmscore/ldap/LdapConnModule.java Sending pki/base/common/src/com/netscape/cmscore/ldap/LdapConnModule.java Transmitting file data . Committed revision 669.
Verified(with CS RC2). LDAP publishing over SSL was successful ================================ [05/Jul/2009:18:47:15][http-9445-Processor24]: AdminServlet::service() param name='ldapauth.bindPWPrompt' value='CA LDAP Publishing' [05/Jul/2009:18:47:15][http-9445-Processor24]: AdminServlet::service() param name='ldapconn.host' value='madrid.pnq.redhat.com' [05/Jul/2009:18:47:15][http-9445-Processor24]: AdminServlet::service() param name='ldapconn.version' value='3' [05/Jul/2009:18:47:15][http-9445-Processor24]: AdminServlet::service() param name='ldapauth.authtype' value='BasicAuth' [05/Jul/2009:18:47:15][http-9445-Processor24]: AdminServlet::service() param name='ldapconn.port' value='636' [05/Jul/2009:18:47:15][http-9445-Processor24]: AdminServlet::service() param name='enable' value='true' [05/Jul/2009:18:47:15][http-9445-Processor24]: AdminServlet::service() param name='RS_ID' value='RS_ID_CONFIG' [05/Jul/2009:18:47:15][http-9445-Processor24]: AdminServlet::service() param name='publishingEnable' value='true' [05/Jul/2009:18:47:15][http-9445-Processor24]: AdminServlet::service() param name='OP_TYPE' value='OP_PROCESS' [05/Jul/2009:18:47:15][http-9445-Processor24]: AdminServlet::service() param name='ldapconn.secureConn' value='true' [05/Jul/2009:18:47:15][http-9445-Processor24]: AdminServlet::service() param name='ldapauth.bindDN' value='cn=Directory Manager' [05/Jul/2009:18:47:15][http-9445-Processor24]: AdminServlet::service() param name='OP_SCOPE' value='ldap' [05/Jul/2009:18:47:15][http-9445-Processor24]: PublisherAdminServlet: in service [05/Jul/2009:18:47:15][http-9445-Processor24]: Authentication: UID=admin [05/Jul/2009:18:47:15][http-9445-Processor24]: getConn: mNumConns now 2 [05/Jul/2009:18:47:15][http-9445-Processor24]: getConn(): num avail conns now 2 [05/Jul/2009:18:47:15][http-9445-Processor24]: returnConn: mNumConns now 3 [05/Jul/2009:18:47:15][http-9445-Processor24]: returnConn: mNumConns now 2 [05/Jul/2009:18:47:15][http-9445-Processor24]: getConn: mNumConns now 2 [05/Jul/2009:18:47:15][http-9445-Processor24]: returnConn: mNumConns now 3 [05/Jul/2009:18:47:15][http-9445-Processor24]: AdminServlet: authenticated for servlet: capublisher. [05/Jul/2009:18:47:15][http-9445-Processor24]: getConn: mNumConns now 2 [05/Jul/2009:18:47:15][http-9445-Processor24]: returnConn: mNumConns now 3 [05/Jul/2009:18:47:15][http-9445-Processor24]: SignedAuditEventFactory: create() message=[AuditEvent=AUTH_SUCCESS][SubjectID=admin][Outcome=Success][AuthMgr=passwdUserDBAuthMgr] authentication success [05/Jul/2009:18:47:15][http-9445-Processor24]: AdminServlet: About to check AuthzSubsystem authorization for servlet: capublisher. [05/Jul/2009:18:47:15][http-9445-Processor24]: checkACLS(): ACLEntry expressions= group="Administrators" [05/Jul/2009:18:47:15][http-9445-Processor24]: evaluating expressions: group="Administrators" [05/Jul/2009:18:47:15][http-9445-Processor24]: GroupAccessEvaluator: evaluate: uid=admin value="Administrators" [05/Jul/2009:18:47:15][http-9445-Processor24]: GroupAccessEvaluator: evaluate: no gid in authToken [05/Jul/2009:18:47:15][http-9445-Processor24]: getConn: mNumConns now 2 [05/Jul/2009:18:47:15][http-9445-Processor24]: returnConn: mNumConns now 3 [05/Jul/2009:18:47:15][http-9445-Processor24]: UGSubsystem.isMemberOf() using new lookup code [05/Jul/2009:18:47:15][http-9445-Processor24]: getConn: mNumConns now 2 [05/Jul/2009:18:47:15][http-9445-Processor24]: authorization search base: cn=Administrators,ou=groups,dc=madrid.pnq.redhat.com-pki-ca [05/Jul/2009:18:47:15][http-9445-Processor24]: authorization search filter: (uniquemember=uid=admin,ou=People,dc=madrid.pnq.redhat.com-pki-ca) [05/Jul/2009:18:47:15][http-9445-Processor24]: authorization result: true [05/Jul/2009:18:47:15][http-9445-Processor24]: returnConn: mNumConns now 3 [05/Jul/2009:18:47:15][http-9445-Processor24]: evaluated expression: group="Administrators" to be true [05/Jul/2009:18:47:15][http-9445-Processor24]: DirAclAuthz: authorization passed [05/Jul/2009:18:47:15][http-9445-Processor24]: authorization succeeded for servlet: capublisher [05/Jul/2009:18:47:15][http-9445-Processor24]: SignedAuditEventFactory: create() message=[AuditEvent=AUTHZ_SUCCESS][SubjectID=admin][Outcome=Success][aclResource=certServer.publisher.configuration][Op=modify] authorization success [05/Jul/2009:18:47:15][http-9445-Processor24]: getConn: mNumConns now 2 [05/Jul/2009:18:47:15][http-9445-Processor24]: returnConn: mNumConns now 3 [05/Jul/2009:18:47:15][http-9445-Processor24]: SignedAuditEventFactory: create() message=[AuditEvent=ROLE_ASSUME][SubjectID=admin][Outcome=Success][Role=Certificate Manager Agents, Administrators, Security Domain Administrators, Enterprise CA Administrators, Enterprise KRA Administrators, Enterprise OCSP Administrators, Enterprise TKS Administrators, Enterprise RA Administrators, Enterprise TPS Administrators] assume privileged role [05/Jul/2009:18:47:15][http-9445-Processor24]: PublisherAdmineServlet: in testSetLDAPDest [05/Jul/2009:18:47:15][http-9445-Processor24]: SSL handshake happened [05/Jul/2009:18:47:15][http-9445-Processor24]: CMSEngine: getPasswordStore(): password store initialized before. [05/Jul/2009:18:47:15][http-9445-Processor24]: CMSEngine: getPasswordStore(): password store initialized. [05/Jul/2009:18:47:15][http-9445-Processor24]: PublisherAdminServlet: testSetLDAPDest(): saving password for CA LDAP Publishing to password file [05/Jul/2009:18:47:15][http-9445-Processor24]: PublisherAdminServlet: testSetLDAPDest(): password saved [05/Jul/2009:18:47:15][http-9445-Processor24]: Shuting down publishing. [05/Jul/2009:18:47:15][http-9445-Processor24]: PublisherProcessor: startup() [05/Jul/2009:18:47:15][http-9445-Processor24]: PublisherProcessor: about to initLdapConn [05/Jul/2009:18:47:15][http-9445-Processor24]: LdapConnModule: init called [05/Jul/2009:18:47:15][http-9445-Processor24]: LdapConnModule: init begins [05/Jul/2009:18:47:15][http-9445-Processor24]: LdapAuthInfo: init() [05/Jul/2009:18:47:15][http-9445-Processor24]: LdapAuthInfo: init begins [05/Jul/2009:18:47:15][http-9445-Processor24]: LdapAuthInfo: init: prompt is CA LDAP Publishing [05/Jul/2009:18:47:15][http-9445-Processor24]: LdapAuthInfo: init: try getting from memory cache [05/Jul/2009:18:47:15][http-9445-Processor24]: LdapAuthInfo: init: got password from memory [05/Jul/2009:18:47:15][http-9445-Processor24]: LdapAuthInfo: init: password found for prompt. [05/Jul/2009:18:47:15][http-9445-Processor24]: LdapAuthInfo: password ok: store in memory cache [05/Jul/2009:18:47:15][http-9445-Processor24]: LdapAuthInfo: init ends [05/Jul/2009:18:47:15][http-9445-Processor24]: init: before makeConnection errorIfDown is false [05/Jul/2009:18:47:15][http-9445-Processor24]: makeConnection: errorIfDown false [05/Jul/2009:18:47:15][http-9445-Processor24]: SSL handshake happened [05/Jul/2009:18:47:15][http-9445-Processor24]: Established LDAP connection using basic authentication to host madrid.pnq.redhat.com port 636 as cn=Directory Manager [05/Jul/2009:18:47:15][http-9445-Processor24]: initializing with mininum 3 and maximum 15 connections to host madrid.pnq.redhat.com port 636, secure connection, true, authentication type 1 [05/Jul/2009:18:47:15][http-9445-Processor24]: increasing minimum connections by 3 [05/Jul/2009:18:47:15][http-9445-Processor24]: new total available connections 3 [05/Jul/2009:18:47:15][http-9445-Processor24]: new number of connections 3 [05/Jul/2009:18:47:15][http-9445-Processor24]: LdapConnModule: init ends [05/Jul/2009:18:47:15][http-9445-Processor24]: LdapPublishing connection inited [05/Jul/2009:18:47:15][http-9445-Processor24]: PublisherProcessor: in publishNow() [05/Jul/2009:18:47:15][http-9445-Processor24]: getConn: mNumConns now 2 [05/Jul/2009:18:47:15][http-9445-Processor24]: LdapCaSimpleMap: cert subject dn:CN=Certificate Authority,O=PnqRedhat Domain [05/Jul/2009:18:47:15][http-9445-Processor24]: returnConn: mNumConns now 3 [05/Jul/2009:18:47:15][http-9445-Processor24]: getConn: mNumConns now 2 [05/Jul/2009:18:47:15][http-9445-Processor24]: returnConn: mNumConns now 3 [05/Jul/2009:18:47:15][http-9445-Processor24]: getConn: mNumConns now 2 [05/Jul/2009:18:47:15][http-9445-Processor24]: returnConn: mNumConns now 3 [05/Jul/2009:18:47:15][http-9445-Processor24]: PublisherAdminServlet: Published CA cert. [05/Jul/2009:18:47:15][http-9445-Processor24]: PublisherAdminServlet: about to update CRL [05/Jul/2009:18:47:15][http-9445-Processor24]: Publish CRL [05/Jul/2009:18:47:15][http-9445-Processor24]: getConn: mNumConns now 2 [05/Jul/2009:18:47:15][http-9445-Processor24]: returnConn: mNumConns now 3 [05/Jul/2009:18:47:15][http-9445-Processor24]: getConn: mNumConns now 2 [05/Jul/2009:18:47:15][http-9445-Processor24]: OCSPPublisher: Host='madrid.pnq.redhat.com' Port='11444' URL='/ocsp/ee/ocsp/addCRL' [05/Jul/2009:18:47:15][http-9445-Processor24]: OCSPPublisher: start CRL sending startTime=1246799835964 [05/Jul/2009:18:47:15][http-9445-Processor24]: OCSPPublisher: done CRL sending endTime=1246799835974 diff=10 [05/Jul/2009:18:47:16][http-9445-Processor24]: LdapCaSimpleMap: crl issuer dn: CN=Certificate Authority,O=PnqRedhat Domain [05/Jul/2009:18:47:16][http-9445-Processor24]: returnConn: mNumConns now 3 [05/Jul/2009:18:47:16][http-9445-Processor24]: CRL published. [05/Jul/2009:18:47:16][http-9445-Processor24]: published CRL ==================================================