Tomasz Torcz wrote:
On Sat, Jun 18, 2016 at 11:02:23PM -0400, Rob Crittenden wrote:
Most of the functions work, but 5) I cannot get Authentication→Certificates
list:
On okda, going to Certificates list yields ”Certificate operation cannot be
completed: Unable to communicate with CMS (Internal Server Error)”
and error_log contains:
[Sat Jun 18 18:59:10.523796 2016] [wsgi:error] [pid 748083]
<CertSearchRequest><revokedByInUse>false</revokedByInUse><certTypeInUse>false</certTypeInUse><revokedOnInUse>false</revokedOnInUse><validNotAfterInUse>false</validNotAfterInUse><revocationReasonInUse>false</revocationReasonInUse><serialNumberRangeInUse>true</serialNumberRangeInUse><validityLengthInUse>false</validityLengthInUse><subjectInUse>false</subjectInUse><validNotBeforeInUse>false</validNotBeforeInUse><issuedByInUse>false</issuedByInUse><issuedOnInUse>false</issuedOnInUse><matchExactly>false</matchExactly></CertSearchRequest>
[Sat Jun 18 18:59:11.244206 2016] [wsgi:error] [pid 748083] ipa: DEBUG: HTTP
Response code: 500
[Sat Jun 18 18:59:11.248305 2016] [wsgi:error] [pid 748083] ipa: ERROR:
ipaserver.plugins.dogtag.ra.find(): Unable to communicate with CMS (Internal
Server Error)
[Sat Jun 18 18:59:11.336576 2016] [wsgi:error] [pid 748083] ipa: DEBUG: WSGI
wsgi_execute PublicError: Traceback (most recent call last):
[Sat Jun 18 18:59:11.336895 2016] [wsgi:error] [pid 748083] File
"/usr/lib/python2.7/site-packages/ipaserver/rpcserver.py", line 350, in
wsgi_execute
[Sat Jun 18 18:59:11.337011 2016] [wsgi:error] [pid 748083] result =
self.Command[name](*args, **options)
[Sat Jun 18 18:59:11.337086 2016] [wsgi:error] [pid 748083] File
"/usr/lib/python2.7/site-packages/ipalib/frontend.py", line 446, in __call__
[Sat Jun 18 18:59:11.337156 2016] [wsgi:error] [pid 748083] ret =
self.run(*args, **options)
[Sat Jun 18 18:59:11.337241 2016] [wsgi:error] [pid 748083] File
"/usr/lib/python2.7/site-packages/ipalib/frontend.py", line 763, in run
[Sat Jun 18 18:59:11.337311 2016] [wsgi:error] [pid 748083] return
self.execute(*args, **options)
[Sat Jun 18 18:59:11.337373 2016] [wsgi:error] [pid 748083] File
"/usr/lib/python2.7/site-packages/ipalib/plugins/cert.py", line 819, in execute
[Sat Jun 18 18:59:11.337417 2016] [wsgi:error] [pid 748083]
result=self.Backend.ra.find(options)
[Sat Jun 18 18:59:11.337455 2016] [wsgi:error] [pid 748083] File
"/usr/lib/python2.7/site-packages/ipaserver/plugins/dogtag.py", line 1861, in
find
[Sat Jun 18 18:59:11.337493 2016] [wsgi:error] [pid 748083] detail=e.msg)
[Sat Jun 18 18:59:11.337566 2016] [wsgi:error] [pid 748083] File
"/usr/lib/python2.7/site-packages/ipaserver/plugins/dogtag.py", line 1331, in
raise_certificate_operation_error
[Sat Jun 18 18:59:11.337653 2016] [wsgi:error] [pid 748083] raise
errors.CertificateOperationError(error=err_msg)
[Sat Jun 18 18:59:11.337717 2016] [wsgi:error] [pid 748083]
CertificateOperationError: Certificate operation cannot be completed: Unable to
communicate with CMS (Internal Server Error)
[Sat Jun 18 18:59:11.337770 2016] [wsgi:error] [pid 748083]
[Sat Jun 18 18:59:11.338805 2016] [wsgi:error] [pid 748083] ipa: INFO:
[jsonserver_session] [email protected]: cert_find(version=u'2.164'):
CertificateOperationError
How to fix those?
You'll need to look at the dogtag debug log for the reason it threw a 500,
it's in /var/log/pki-tomcat/ca or something close to that.
I've looked into the logs but I'm not wiser. Is there a setting to get
rid of java traceback from logs and get more useful messages? There seem
to be a problem with SSL connection to port 636, maybe because it seems to use
expired certificate?
Not that I know of. The debug log is sure a firehose but you've
identified the problem.
$ echo | openssl s_client -connect okda.pipebreaker.pl:636 | openssl x509
-noout
depth=1 O = PIPEBREAKER.PL, CN = Certificate Authority
verify return:1
depth=0 O = PIPEBREAKER.PL, CN = okda.pipebreaker.pl
verify error:num=10:certificate has expired
notAfter=Nov 17 12:19:28 2015 GMT
verify return:1
depth=0 O = PIPEBREAKER.PL, CN = okda.pipebreaker.pl
notAfter=Nov 17 12:19:28 2015 GMT
verify return:1
DONE
Run getcert list and look at the expiration dates. What you want to do
is kill ntpd, set the date back to say a week before the oldest date,
restart the dirsrv, restart the pki-tomcat/pki-cad service then restart
certmonger. This should force a renewal attempt.
Use getcert and syslog to watch progress. It may require a few restarts
of certmonger to get all the certs renewed.
Ideally that all happens fairly gracefully so then you move forward in
time again, run ipactl restart and things work as usual.
rob
Log from /var/log/pki/pki-tomcat/ca/system:
0.localhost-startStop-1 - [18/Jun/2016:18:54:09 CEST] [8] [3] In Ldap (bound)
connection pool to host okda.pipebreaker.pl port 636, Cannot connect to LDAP
server. Error: netscape.ldap.LDAPException: IO Error creating JSS SSL Socket
(-1)
Log from /var/log/pki/pki-tomcat/ca/debug:
[18/Jun/2016:18:54:03][localhost-startStop-1]:
============================================
[18/Jun/2016:18:54:03][localhost-startStop-1]: ===== DEBUG SUBSYSTEM
INITIALIZED =======
[18/Jun/2016:18:54:03][localhost-startStop-1]:
============================================
[18/Jun/2016:18:54:03][localhost-startStop-1]: CMSEngine: restart at
autoShutdown? false
[18/Jun/2016:18:54:03][localhost-startStop-1]: CMSEngine: autoShutdown crumb
file path? /var/lib/pki/pki-tomcat/logs/autoShutdown.crumb
[18/Jun/2016:18:54:03][localhost-startStop-1]: CMSEngine: about to look for
cert for auto-shutdown support:auditSigningCert cert-pki-ca
[18/Jun/2016:18:54:03][localhost-startStop-1]: CMSEngine: found
cert:auditSigningCert cert-pki-ca
[18/Jun/2016:18:54:03][localhost-startStop-1]: CMSEngine: done init id=debug
[18/Jun/2016:18:54:03][localhost-startStop-1]: CMSEngine: initialized debug
[18/Jun/2016:18:54:03][localhost-startStop-1]: CMSEngine: initSubsystem id=log
[18/Jun/2016:18:54:03][localhost-startStop-1]: CMSEngine: ready to init id=log
[18/Jun/2016:18:54:04][localhost-startStop-1]: Creating
RollingLogFile(/var/lib/pki/pki-tomcat/logs/ca/signedAudit/ca_audit)
[18/Jun/2016:18:54:09][localhost-startStop-1]: Creating
RollingLogFile(/var/lib/pki/pki-tomcat/logs/ca/system)
[18/Jun/2016:18:54:09][localhost-startStop-1]: Creating
RollingLogFile(/var/lib/pki/pki-tomcat/logs/ca/transactions)
[18/Jun/2016:18:54:09][localhost-startStop-1]: CMSEngine: restart at
autoShutdown? false
[18/Jun/2016:18:54:09][localhost-startStop-1]: CMSEngine: autoShutdown crumb
file path? /var/lib/pki/pki-tomcat/logs/autoShutdown.crumb
[18/Jun/2016:18:54:09][localhost-startStop-1]: CMSEngine: about to look for
cert for auto-shutdown support:auditSigningCert cert-pki-ca
[18/Jun/2016:18:54:09][localhost-startStop-1]: CMSEngine: found
cert:auditSigningCert cert-pki-ca
[18/Jun/2016:18:54:09][localhost-startStop-1]: CMSEngine: done init id=log
[18/Jun/2016:18:54:09][localhost-startStop-1]: CMSEngine: initialized log
[18/Jun/2016:18:54:09][localhost-startStop-1]: CMSEngine: initSubsystem id=jss
[18/Jun/2016:18:54:09][localhost-startStop-1]: CMSEngine: ready to init id=jss
[18/Jun/2016:18:54:09][localhost-startStop-1]: CMSEngine: restart at
autoShutdown? false
[18/Jun/2016:18:54:09][localhost-startStop-1]: CMSEngine: autoShutdown crumb
file path? /var/lib/pki/pki-tomcat/logs/autoShutdown.crumb
[18/Jun/2016:18:54:09][localhost-startStop-1]: CMSEngine: about to look for
cert for auto-shutdown support:auditSigningCert cert-pki-ca
[18/Jun/2016:18:54:09][localhost-startStop-1]: CMSEngine: found
cert:auditSigningCert cert-pki-ca
[18/Jun/2016:18:54:09][localhost-startStop-1]: CMSEngine: done init id=jss
[18/Jun/2016:18:54:09][localhost-startStop-1]: CMSEngine: initialized jss
[18/Jun/2016:18:54:09][localhost-startStop-1]: CMSEngine: initSubsystem id=dbs
[18/Jun/2016:18:54:09][localhost-startStop-1]: CMSEngine: ready to init id=dbs
[18/Jun/2016:18:54:09][localhost-startStop-1]: DBSubsystem: init()
mEnableSerialMgmt=true
[18/Jun/2016:18:54:09][localhost-startStop-1]: Creating
LdapBoundConnFactor(DBSubsystem)
[18/Jun/2016:18:54:09][localhost-startStop-1]: LdapBoundConnFactory: init
[18/Jun/2016:18:54:09][localhost-startStop-1]: LdapBoundConnFactory:doCloning
true
[18/Jun/2016:18:54:09][localhost-startStop-1]: LdapAuthInfo: init()
[18/Jun/2016:18:54:09][localhost-startStop-1]: LdapAuthInfo: init begins
[18/Jun/2016:18:54:09][localhost-startStop-1]: LdapAuthInfo: init ends
[18/Jun/2016:18:54:09][localhost-startStop-1]: init: before makeConnection
errorIfDown is true
[18/Jun/2016:18:54:09][localhost-startStop-1]: makeConnection: errorIfDown true
[18/Jun/2016:18:54:09][localhost-startStop-1]: LdapJssSSLSocket set client auth
cert nicknamesubsystemCert cert-pki-ca
Could not connect to LDAP server host okda.pipebreaker.pl port 636 Error
netscape.ldap.LDAPException: IO Error creating JSS SSL Socket (-1)
at
com.netscape.cmscore.ldapconn.LdapBoundConnFactory.makeConnection(LdapBoundConnFactory.java:205)
at
com.netscape.cmscore.ldapconn.LdapBoundConnFactory.init(LdapBoundConnFactory.java:166)
at
com.netscape.cmscore.ldapconn.LdapBoundConnFactory.init(LdapBoundConnFactory.java:130)
at com.netscape.cmscore.dbs.DBSubsystem.init(DBSubsystem.java:654)
at
com.netscape.cmscore.apps.CMSEngine.initSubsystem(CMSEngine.java:1166)
at
com.netscape.cmscore.apps.CMSEngine.initSubsystems(CMSEngine.java:1072)
at com.netscape.cmscore.apps.CMSEngine.init(CMSEngine.java:568)
at com.netscape.certsrv.apps.CMS.init(CMS.java:187)
at com.netscape.certsrv.apps.CMS.start(CMS.java:1616)
at
com.netscape.cms.servlet.base.CMSStartServlet.init(CMSStartServlet.java:114)
at javax.servlet.GenericServlet.init(GenericServlet.java:158)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at
org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:286)
at
org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:283)
at java.security.AccessController.doPrivileged(Native Method)
at javax.security.auth.Subject.doAsPrivileged(Subject.java:549)
at
org.apache.catalina.security.SecurityUtil.execute(SecurityUtil.java:318)
at
org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:173)
at
org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:122)
at
org.apache.catalina.core.StandardWrapper.initServlet(StandardWrapper.java:1226)
at
org.apache.catalina.core.StandardWrapper.loadServlet(StandardWrapper.java:1151)
at
org.apache.catalina.core.StandardWrapper.load(StandardWrapper.java:1038)
at
org.apache.catalina.core.StandardContext.loadOnStartup(StandardContext.java:4997)
at
org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5289)
at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:147)
at
org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:725)
at
org.apache.catalina.core.ContainerBase.access$000(ContainerBase.java:131)
at
org.apache.catalina.core.ContainerBase$PrivilegedAddChild.run(ContainerBase.java:153)
at
org.apache.catalina.core.ContainerBase$PrivilegedAddChild.run(ContainerBase.java:143)
at java.security.AccessController.doPrivileged(Native Method)
at
org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:699)
at
org.apache.catalina.core.StandardHost.addChild(StandardHost.java:717)
at
org.apache.catalina.startup.HostConfig.deployDescriptor(HostConfig.java:585)
at
org.apache.catalina.startup.HostConfig$DeployDescriptor.run(HostConfig.java:1794)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
Internal Database Error encountered: Could not connect to LDAP server host
okda.pipebreaker.pl port 636 Error netscape.ldap.LDAPException: IO Error
creating JSS SSL Socket (-1)
at com.netscape.cmscore.dbs.DBSubsystem.init(DBSubsystem.java:676)
at
com.netscape.cmscore.apps.CMSEngine.initSubsystem(CMSEngine.java:1166)
at
com.netscape.cmscore.apps.CMSEngine.initSubsystems(CMSEngine.java:1072)
at com.netscape.cmscore.apps.CMSEngine.init(CMSEngine.java:568)
at com.netscape.certsrv.apps.CMS.init(CMS.java:187)
at com.netscape.certsrv.apps.CMS.start(CMS.java:1616)
at
com.netscape.cms.servlet.base.CMSStartServlet.init(CMSStartServlet.java:114)
at javax.servlet.GenericServlet.init(GenericServlet.java:158)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at
org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:286)
at
org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:283)
at java.security.AccessController.doPrivileged(Native Method)
at javax.security.auth.Subject.doAsPrivileged(Subject.java:549)
at
org.apache.catalina.security.SecurityUtil.execute(SecurityUtil.java:318)
at
org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:173)
at
org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:122)
at
org.apache.catalina.core.StandardWrapper.initServlet(StandardWrapper.java:1226)
at
org.apache.catalina.core.StandardWrapper.loadServlet(StandardWrapper.java:1151)
at
org.apache.catalina.core.StandardWrapper.load(StandardWrapper.java:1038)
at
org.apache.catalina.core.StandardContext.loadOnStartup(StandardContext.java:4997)
at
org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5289)
at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:147)
at
org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:725)
at
org.apache.catalina.core.ContainerBase.access$000(ContainerBase.java:131)
at
org.apache.catalina.core.ContainerBase$PrivilegedAddChild.run(ContainerBase.java:153)
at
org.apache.catalina.core.ContainerBase$PrivilegedAddChild.run(ContainerBase.java:143)
at java.security.AccessController.doPrivileged(Native Method)
at
org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:699)
at
org.apache.catalina.core.StandardHost.addChild(StandardHost.java:717)
at
org.apache.catalina.startup.HostConfig.deployDescriptor(HostConfig.java:585)
at
org.apache.catalina.startup.HostConfig$DeployDescriptor.run(HostConfig.java:1794)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
[18/Jun/2016:18:54:09][localhost-startStop-1]: CMSEngine.shutdown()
--
Manage your subscription for the Freeipa-users mailing list:
https://www.redhat.com/mailman/listinfo/freeipa-users
Go to http://freeipa.org for more info on the project
