[Freeipa-users] ipa fails to start hangs on pki-tomcatd
Rob Verduijn
rob.verduijn at gmail.com
Fri Dec 2 13:42:43 UTC 2016
2016-12-01 19:44 GMT+01:00 Rob Verduijn <rob.verduijn at gmail.com>:
>
>
> 2016-12-01 17:20 GMT+01:00 Rob Crittenden <rcritten at redhat.com>:
>
>> Rob Verduijn wrote:
>> >
>> >
>> > 2016-12-01 15:41 GMT+01:00 Rob Crittenden <rcritten at redhat.com
>> > <mailto:rcritten at redhat.com>>:
>> >
>> > Rob Verduijn wrote:
>> > > Hello,
>> > >
>> > > For some reason my ipa server no longer boots.
>> > > It keeps trying to start pki-tomcat service.
>> > >
>> > > Does anybody know where I should start looking to get this fixed ?
>> > >
>> > > Rob Verduijn
>> > >
>> > > ipactl -d start gives this output:
>> > > ipa: DEBUG: The CA status is: check interrupted due to error:
>> Command
>> > > ''/usr/bin/wget' '-S' '-O' '-' '--timeout=30'
>> '--no-check-certificate'
>> > > 'https://freeipa02.tjako.thuis:8443/ca/admin/ca/getStatus
>> > <https://freeipa02.tjako.thuis:8443/ca/admin/ca/getStatus>''
>> returned
>> > > non-zero exit status 8
>> > > ipa: DEBUG: Waiting for CA to start...
>> > > ipa: DEBUG: Starting external process
>> > > ipa: DEBUG: args='/usr/bin/wget' '-S' '-O' '-' '--timeout=30'
>> > > '--no-check-certificate'
>> > > 'https://freeipa02.tjako.thuis:8443/ca/admin/ca/getStatus
>> > <https://freeipa02.tjako.thuis:8443/ca/admin/ca/getStatus>'
>> > > ipa: DEBUG: Process finished, return code=8
>> > > ipa: DEBUG: stdout=
>> > > ipa: DEBUG: stderr=--2016-12-01 11:06:12--
>> > > https://freeipa02.tjako.thuis:8443/ca/admin/ca/getStatus
>> > <https://freeipa02.tjako.thuis:8443/ca/admin/ca/getStatus>
>> > > Resolving freeipa02.tjako.thuis (freeipa02.tjako.thuis)...
>> 172.16.1.13
>> > > Connecting to freeipa02.tjako.thuis
>> > > (freeipa02.tjako.thuis)|172.16.1.13|:8443... connected.
>> > > HTTP request sent, awaiting response...
>> > > HTTP/1.1 500 Internal Server Error
>> > > Server: Apache-Coyote/1.1
>> > > Content-Type: text/html;charset=utf-8
>> > > Content-Language: en
>> > > Content-Length: 2134
>> > > Date: Thu, 01 Dec 2016 10:06:13 GMT
>> > > Connection: close
>> > > 2016-12-01 11:06:13 ERROR 500: Internal Server Error.
>> > >
>> > > There are also some java warnings in the logs, but its java and I
>> can
>> > > never tell if its a serious error when java gives a warning.
>> > > Dec 1 09:53:59 freeipa02 server: Dec 01, 2016 9:53:59 AM
>> > > org.apache.catalina.startup.SetAllPropertiesRule begin
>> > > Dec 1 09:53:59 freeipa02 server: WARNING:
>> > > [SetAllPropertiesRule]{Server/Service/Connector} Setting property
>> > > 'serverCertNickFile' to
>> > > '/var/lib/pki/pki-tomcat/conf/serverCertNick.conf' did not find a
>> > > matching property.
>> > > Dec 1 09:53:59 freeipa02 server: Dec 01, 2016 9:53:59 AM
>> > > org.apache.catalina.startup.SetAllPropertiesRule begin
>> > > Dec 1 09:53:59 freeipa02 server: WARNING:
>> > > [SetAllPropertiesRule]{Server/Service/Connector} Setting property
>> > > 'passwordFile' to '/var/lib/pki/pki-tomcat/conf/password.conf'
>> did not
>> > > find a matching property.
>> > > Dec 1 09:53:59 freeipa02 server: Dec 01, 2016 9:53:59 AM
>> > > org.apache.catalina.startup.SetAllPropertiesRule begin
>> > > Dec 1 09:53:59 freeipa02 server: WARNING:
>> > > [SetAllPropertiesRule]{Server/Service/Connector} Setting property
>> > > 'passwordClass' to 'org.apache.tomcat.util.net
>> > <http://org.apache.tomcat.util.net>.jss.PlainPasswordFile'
>> > > did not find a matching property.
>> > > Dec 1 09:53:59 freeipa02 server: Dec 01, 2016 9:53:59 AM
>> > > org.apache.catalina.startup.SetAllPropertiesRule begin
>> > > Dec 1 09:53:59 freeipa02 server: WARNING:
>> > > [SetAllPropertiesRule]{Server/Service/Connector} Setting property
>> > > 'certdbDir' to '/var/lib/pki/pki-tomcat/alias' did not find a
>> matching
>> > > property.
>> > > Dec 1 09:53:59 freeipa02 server: Dec 01, 2016 9:53:59 AM
>> > > org.apache.tomcat.util.digester.SetPropertiesRule begin
>> > > Dec 1 09:53:59 freeipa02 server: WARNING:
>> > > [SetPropertiesRule]{Server/Service/Engine/Host} Setting property
>> > > 'xmlValidation' to 'false' did not find a matching property.
>> > > Dec 1 09:53:59 freeipa02 server: Dec 01, 2016 9:53:59 AM
>> > > org.apache.tomcat.util.digester.SetPropertiesRule begin
>> > > Dec 1 09:53:59 freeipa02 server: WARNING:
>> > > [SetPropertiesRule]{Server/Service/Engine/Host} Setting property
>> > > 'xmlNamespaceAware' to 'false' did not find a matching property.
>> > >
>> > >
>> > > I'm running centos7.2 x86_64 with the latest patches applied.
>> > > some package versions below
>> > > rpm -qa|egrep "ipa|tomcat"|sort
>> > > ipa-admintools-4.2.0-15.0.1.el7.centos.19.x86_64
>> > > ipa-client-4.2.0-15.0.1.el7.centos.19.x86_64
>> > > ipa-python-4.2.0-15.0.1.el7.centos.19.x86_64
>> > > ipa-server-4.2.0-15.0.1.el7.centos.19.x86_64
>> > > ipa-server-dns-4.2.0-15.0.1.el7.centos.19.x86_64
>> > > libipa_hbac-1.13.0-40.el7_2.12.x86_64
>> > > python-iniparse-0.4-9.el7.noarch
>> > > python-libipa_hbac-1.13.0-40.el7_2.12.x86_64
>> > > sssd-ipa-1.13.0-40.el7_2.12.x86_64
>> > > tomcat-7.0.54-8.el7_2.noarch
>> > > tomcat-el-2.2-api-7.0.54-8.el7_2.noarch
>> > > tomcat-jsp-2.2-api-7.0.54-8.el7_2.noarch
>> > > tomcatjss-7.1.2-1.el7.noarch
>> > > tomcat-lib-7.0.54-8.el7_2.noarch
>> > > tomcat-servlet-3.0-api-7.0.54-8.el7_2.noarch
>> >
>> > The debug log is quite verbose. I find it helpful to note where the
>> > previous log ended, starting and pulling the difference and going
>> line
>> > by line. It sometimes fails in one place which cascades to others
>> this
>> > generally makes it hard to grok.
>> >
>> > I'd also run `getcert list` and check to ensure that the CA
>> subsystem
>> > certificates are still valid.
>> >
>> > rob
>> >
>> >
>> >
>> > Hi,
>> >
>> > My certs where indeed expired.
>> > I did what was said in here
>> > http://www.freeipa.org/page/Howto/CA_Certificate_Renewal
>> > And now they are all valid again.
>> >
>> > However it is still stuck at the same spot.
>> > It keeps waiting for the ca to start and gets an internal error.
>> >
>> > In the pki-cataline logs this keeps repeating :
>> > Dec 01, 2016 4:22:44 PM org.apache.catalina.core.ContainerBase
>> > backgroundProcess
>> > WARNING: Exception processing realm
>> > com.netscape.cms.tomcat.ProxyRealm at 6934e456 background process
>> > java.lang.NullPointerException
>> > at
>> > com.netscape.cms.tomcat.ProxyRealm.backgroundProcess(ProxyRe
>> alm.java:108)
>> > at
>> > org.apache.catalina.core.ContainerBase.backgroundProcess(Con
>> tainerBase.java:1360)
>> > at
>> > org.apache.catalina.core.ContainerBase$ContainerBackgroundPr
>> ocessor.processChildren(ContainerBase.java:1530)
>> > at
>> > org.apache.catalina.core.ContainerBase$ContainerBackgroundPr
>> ocessor.processChildren(ContainerBase.java:1540)
>> > at
>> > org.apache.catalina.core.ContainerBase$ContainerBackgroundPr
>> ocessor.processChildren(ContainerBase.java:1540)
>> > at
>> > org.apache.catalina.core.ContainerBase$ContainerBackgroundPr
>> ocessor.run(ContainerBase.java:1519)
>> > at java.lang.Thread.run(Thread.java:745)
>> >
>> > I keep digging through the logs, but they are rather overwhelming.
>> >
>> > Have you got any pointers for me ?
>>
>> My only recommendation is to read top-down instead of bottom up as one
>> would normally do. Look for the selftest and see if it was successful.
>> If it wasn't then nothing will work.
>>
>> rob
>>
>
>
>
> in the pki-catalina log I find a lot of warnings are these real warnings
> or just noise from tomcat ?
> Dec 01, 2016 6:18:40 PM org.apache.catalina.startup.SetAllPropertiesRule
> begin
> WARNING: [SetAllPropertiesRule]{Server/Service/Connector} Setting
> property 'enableOCSP' to 'false' did not find a matching property.
> Dec 01, 2016 6:18:40 PM org.apache.catalina.startup.SetAllPropertiesRule
> begin
> WARNING: [SetAllPropertiesRule]{Server/Service/Connector} Setting
> property 'ocspResponderURL' to 'http://freeipa02.tjako.thuis:9080/ca/ocsp'
> did not find a matching property.
> Dec 01, 2016 6:18:40 PM org.apache.catalina.startup.SetAllPropertiesRule
> begin
> WARNING: [SetAllPropertiesRule]{Server/Service/Connector} Setting
> property 'ocspResponderCertNickname' to 'ocspSigningCert cert-pki-ca' did
> not find a matching property.
> Dec 01, 2016 6:18:40 PM org.apache.catalina.startup.SetAllPropertiesRule
> begin
> WARNING: [SetAllPropertiesRule]{Server/Service/Connector} Setting
> property 'ocspCacheSize' to '1000' did not find a matching property.
> Dec 01, 2016 6:18:40 PM org.apache.catalina.startup.SetAllPropertiesRule
> begin
> WARNING: [SetAllPropertiesRule]{Server/Service/Connector} Setting
> property 'ocspMinCacheEntryDuration' to '60' did not find a matching
> property.
> Dec 01, 2016 6:18:40 PM org.apache.catalina.startup.SetAllPropertiesRule
> begin
> WARNING: [SetAllPropertiesRule]{Server/Service/Connector} Setting
> property 'ocspMaxCacheEntryDuration' to '120' did not find a matching
> property.
> Dec 01, 2016 6:18:40 PM org.apache.catalina.startup.SetAllPropertiesRule
> begin
> WARNING: [SetAllPropertiesRule]{Server/Service/Connector} Setting
> property 'ocspTimeout' to '10' did not find a matching property.
> Dec 01, 2016 6:18:40 PM org.apache.catalina.startup.SetAllPropertiesRule
> begin
> WARNING: [SetAllPropertiesRule]{Server/Service/Connector} Setting
> property 'strictCiphers' to 'true' did not find a matching property.
> Dec 01, 2016 6:18:40 PM org.apache.catalina.startup.SetAllPropertiesRule
> begin
> WARNING: [SetAllPropertiesRule]{Server/Service/Connector} Setting
> property 'sslOptions' to 'ssl2=false,ssl3=false,tls=true' did not find a
> matching property.
>
> Rob Verduijn
>
> --
> 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
>
Hi again,
After some serious digging, I found something in the catalina log which
happens at the same time in the slapd errors log
==> /var/log/pki/pki-tomcat/catalina.2016-11-23.log <==
INFO: Deploying configuration descriptor
/etc/pki/pki-tomcat/Catalina/localhost/ca.xml
==> /var/log/dirsrv/slapd-TJAKO-THUIS/errors <==
[23/Nov/2016:14:38:19 +0100] slapd_ldap_sasl_interactive_bind - Error:
could not perform interactive bind for id [] mech [GSSAPI]: LDAP error -1
(Can't contact LDAP server) ((null)) errno 107 (Transport endpoint is not
connected)
[23/Nov/2016:14:38:19 +0100] slapi_ldap_bind - Error: could not perform
interactive bind for id [] authentication mechanism [GSSAPI]: error -1
(Can't contact LDAP server)
[23/Nov/2016:14:38:19 +0100] slapi_ldap_bind - Error: could not send
startTLS request: error -1 (Can't contact LDAP server) errno 107 (Transport
endpoint is not connected)
Those are the first errors after which many follow.
Manual binding to the ldap works ofcourse.
What could be causing this ?
Rob verduijn
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://listman.redhat.com/archives/freeipa-users/attachments/20161202/1444ecc5/attachment.htm>
More information about the Freeipa-users
mailing list