Re: [Freeipa-users] IPA server having cert issues

Fri, 29 Apr 2016 03:09:27 -0700

The date change was due (I think) to me changing the date back to 4/1 yesterday, though I left it there and haven't updated it again until this morning, when I went back to 4/1 again.
I put the results of the commands you requested at https://pastebin.com/s7cHAh6R. Thanks for your help, Petr. I really appreciate it. 


Bret

On 04/29/2016 04:59 AM, Petr Vobornik wrote:

comments inline

On 04/28/2016 06:30 PM, Bret Wortman wrote:

Look, I'll be honest. When IPA is in this much of a knot, I don't know how to do
the simplest things with its various components. For example, I've no clue how
to search the ldap database for anything. Or even how to authenticate since
Kerberos isn't running. IPA has sheltered me from ldap for so long that it's a
problem at times like this.

That being said, here are the things I /was/ able to handle:

Apr 01 11:02:40 zsipa.private.net server[6896]: Java virtual machine used:
/usr/lib/jvm/jre/bin/java
Apr 01 11:02:40 zsipa.private.net server[6896]: classpath used:
/usr/share/tomcat/bin/bootstrap.jar:/usr/share/tomcat/bin/tomcat-juli.jar:/usr/lib/java/commons-daemon.j
Apr 01 11:02:40 zsipa.private.net server[6896]: main class used:
org.apache.catalina.startup.Bootstrap
Apr 01 11:02:40 zsipa.private.net server[6896]: flags used:
-DRESTEASY_LIB=/usr/share/java/resteasy
Apr 01 11:02:40 zsipa.private.net server[6896]: options used:
-Dcatalina.base=/var/lib/pki/pki-tomcat -Dcatalina.home=/usr/share/tomcat
-Djava.endorsed.dirs= -Djava.io.
Apr 01 11:02:40 zsipa.private.net server[6896]: arguments used: start
Apr 01 11:02:40 zsipa.private.net server[6896]: Apr 01, 2016 11:02:40 AM
org.apache.catalina.startup.ClassLoaderFactory validateFile
Apr 01 11:02:40 zsipa.private.net server[6896]: WARNING: Problem with JAR file
[/var/lib/pki/pki-tomcat/lib/log4j.jar], exists: [false], canRead: [false]
Apr 01 11:02:41 zsipa.private.net server[6896]: Apr 01, 2016 11:02:41 AM
org.apache.catalina.startup.SetAllPropertiesRule begin
Apr 01 11:02:41 zsipa.private.net server[6896]: WARNING:
[SetAllPropertiesRule]{Server/Service/Connector} Setting property 'enableOCSP'
to 'false' did not find a matchi
Apr 01 11:02:41 zsipa.private.net server[6896]: Apr 01, 2016 11:02:41 AM
org.apache.catalina.startup.SetAllPropertiesRule begin
Apr 01 11:02:41 zsipa.private.net server[6896]: WARNING:
[SetAllPropertiesRule]{Server/Service/Connector} Setting property
'ocspResponderURL' to 'http://zsipa.private.net:9
Apr 01 11:02:41 zsipa.private.net server[6896]: Apr 01, 2016 11:02:41 AM
org.apache.catalina.startup.SetAllPropertiesRule begin
Apr 01 11:02:41 zsipa.private.net server[6896]: WARNING:
[SetAllPropertiesRule]{Server/Service/Connector} Setting property
'ocspResponderCertNickname' to 'ocspSigningCe
Apr 01 11:02:41 zsipa.private.net server[6896]: Apr 01, 2016 11:02:41 AM
org.apache.catalina.startup.SetAllPropertiesRule begin
Apr 01 11:02:41 zsipa.private.net server[6896]: WARNING:
[SetAllPropertiesRule]{Server/Service/Connector} Setting property
'ocspCacheSize' to '1000' did not find a matc
Apr 01 11:02:41 zsipa.private.net server[6896]: Apr 01, 2016 11:02:41 AM
org.apache.catalina.startup.SetAllPropertiesRule begin
Apr 01 11:02:41 zsipa.private.net server[6896]: WARNING:
[SetAllPropertiesRule]{Server/Service/Connector} Setting property
'ocspMinCacheEntryDuration' to '60' did not f
Apr 01 11:02:41 zsipa.private.net server[6896]: Apr 01, 2016 11:02:41 AM
org.apache.catalina.startup.SetAllPropertiesRule begin
Apr 01 11:02:41 zsipa.private.net server[6896]: WARNING:
[SetAllPropertiesRule]{Server/Service/Connector} Setting property
'ocspMaxCacheEntryDuration' to '120' did not
Apr 01 11:02:41 zsipa.private.net server[6896]: Apr 01, 2016 11:02:41 AM
org.apache.catalina.startup.SetAllPropertiesRule begin
Apr 01 11:02:41 zsipa.private.net server[6896]: WARNING:
[SetAllPropertiesRule]{Server/Service/Connector} Setting property 'ocspTimeout'
to '10' did not find a matching
Apr 01 11:02:41 zsipa.private.net server[6896]: Apr 01, 2016 11:02:41 AM
org.apache.catalina.startup.SetAllPropertiesRule begin
Apr 01 11:02:41 zsipa.private.net server[6896]: WARNING:
[SetAllPropertiesRule]{Server/Service/Connector} Setting property
'strictCiphers' to 'true' did not find a matc
Apr 01 11:02:41 zsipa.private.net server[6896]: Apr 01, 2016 11:02:41 AM
org.apache.catalina.startup.SetAllPropertiesRule begin
Apr 01 11:02:41 zsipa.private.net server[6896]: WARNING:
[SetAllPropertiesRule]{Server/Service/Connector} Setting property 'sslOptions'
to 'ssl2=true,ssl3=true,tls=true
Apr 01 11:02:41 zsipa.private.net server[6896]: Apr 01, 2016 11:02:41 AM
org.apache.catalina.startup.SetAllPropertiesRule begin
Apr 01 11:02:41 zsipa.private.net server[6896]: WARNING:
[SetAllPropertiesRule]{Server/Service/Connector} Setting property 'ssl2Ciphers'
to '-SSL2_RC4_128_WITH_MD5,-SSL
Apr 01 11:02:41 zsipa.private.net server[6896]: Apr 01, 2016 11:02:41 AM
org.apache.catalina.startup.SetAllPropertiesRule begin
Apr 01 11:02:41 zsipa.private.net server[6896]: WARNING:
[SetAllPropertiesRule]{Server/Service/Connector} Setting property 'ssl3Ciphers'
to '-SSL3_FORTEZZA_DMS_WITH_NUL
Apr 01 11:02:41 zsipa.private.net server[6896]: Apr 01, 2016 11:02:41 AM
org.apache.catalina.startup.SetAllPropertiesRule begin
Apr 01 11:02:41 zsipa.private.net server[6896]: WARNING:
[SetAllPropertiesRule]{Server/Service/Connector} Setting property 'tlsCiphers'
to '-TLS_ECDH_ECDSA_WITH_AES_128
Apr 01 11:02:41 zsipa.private.net server[6896]: Apr 01, 2016 11:02:41 AM
org.apache.catalina.startup.SetAllPropertiesRule begin
Apr 01 11:02:41 zsipa.private.net server[6896]: WARNING:
[SetAllPropertiesRule]{Server/Service/Connector} Setting property
'serverCertNickFile' to '/var/lib/pki/pki-tom
Apr 01 11:02:41 zsipa.private.net server[6896]: Apr 01, 2016 11:02:41 AM
org.apache.catalina.startup.SetAllPropertiesRule begin
Apr 01 11:02:41 zsipa.private.net server[6896]: WARNING:
[SetAllPropertiesRule]{Server/Service/Connector} Setting property 'passwordFile'
to '/var/lib/pki/pki-tomcat/co
Apr 01 11:02:41 zsipa.private.net server[6896]: Apr 01, 2016 11:02:41 AM
org.apache.catalina.startup.SetAllPropertiesRule begin
Apr 01 11:02:41 zsipa.private.net server[6896]: WARNING:
[SetAllPropertiesRule]{Server/Service/Connector} Setting property
'passwordClass' to 'org.apache.tomcat.util.ne
Apr 01 11:02:41 zsipa.private.net server[6896]: Apr 01, 2016 11:02:41 AM
org.apache.catalina.startup.SetAllPropertiesRule begin
Apr 01 11:02:41 zsipa.private.net server[6896]: WARNING:
[SetAllPropertiesRule]{Server/Service/Connector} Setting property 'certdbDir' to
'/var/lib/pki/pki-tomcat/alias
Apr 01 11:02:41 zsipa.private.net server[6896]: Apr 01, 2016 11:02:41 AM
org.apache.catalina.startup.SetAllPropertiesRule begin
Apr 01 11:02:41 zsipa.private.net server[6896]: WARNING:
[SetAllPropertiesRule]{Server/Service/Connector} Setting property
'sslVersionRangeStream' to 'tls1_0:tls1_2' di
Apr 01 11:02:41 zsipa.private.net server[6896]: Apr 01, 2016 11:02:41 AM
org.apache.catalina.startup.SetAllPropertiesRule begin
Apr 01 11:02:41 zsipa.private.net server[6896]: WARNING:
[SetAllPropertiesRule]{Server/Service/Connector} Setting property
'sslVersionRangeDatagram' to 'tls1_1:tls1_2'
Apr 01 11:02:41 zsipa.private.net server[6896]: Apr 01, 2016 11:02:41 AM
org.apache.catalina.startup.SetAllPropertiesRule begin
Apr 01 11:02:41 zsipa.private.net server[6896]: WARNING:
[SetAllPropertiesRule]{Server/Service/Connector} Setting property
'sslRangeCiphers' to '-TLS_ECDH_ECDSA_WITH_AE
Apr 01 11:02:41 zsipa.private.net server[6896]: Apr 01, 2016 11:02:41 AM
org.apache.tomcat.util.digester.SetPropertiesRule begin
Apr 01 11:02:41 zsipa.private.net server[6896]: WARNING:
[SetPropertiesRule]{Server/Service/Engine/Host} Setting property 'xmlValidation'
to 'false' did not find a matc
Apr 01 11:02:41 zsipa.private.net server[6896]: Apr 01, 2016 11:02:41 AM
org.apache.tomcat.util.digester.SetPropertiesRule begin
Apr 01 11:02:41 zsipa.private.net server[6896]: WARNING:
[SetPropertiesRule]{Server/Service/Engine/Host} Setting property
'xmlNamespaceAware' to 'false' did not find a
Apr 01 11:02:42 zsipa.private.net server[6896]: Apr 01, 2016 11:02:41 AM
org.apache.coyote.AbstractProtocol init
Apr 01 11:02:42 zsipa.private.net server[6896]: INFO: Initializing
ProtocolHandler ["http-bio-8080"]
Apr 01 11:02:42 zsipa.private.net server[6896]: Apr 01, 2016 11:02:42 AM
org.apache.coyote.AbstractProtocol init
Apr 01 11:02:42 zsipa.private.net server[6896]: INFO: Initializing
ProtocolHandler ["http-bio-8443"]
Apr 01 11:02:42 zsipa.private.net server[6896]: Error: SSL cipher
"TLS_ECDH_RSA_WITH_3DES_EDE_CBC_SHA" not recognized by tomcatjss
Apr 01 11:02:42 zsipa.private.net server[6896]: Error: SSL cipher
"TLS_ECDH_RSA_WITH_AES_128_CBC_SHA" not recognized by tomcatjss
Apr 01 11:02:42 zsipa.private.net server[6896]: Error: SSL cipher
"TLS_ECDH_RSA_WITH_AES_256_CBC_SHA" not recognized by tomcatjss
Apr 01 11:02:42 zsipa.private.net server[6896]: Error: SSL cipher
"TLS_RSA_WITH_3DES_EDE_CBC_SHA" not recognized by tomcatjss
Apr 01 11:02:42 zsipa.private.net server[6896]: Error: SSL cipher
"TLS_DHE_DSS_WITH_3DES_EDE_CBC_SHA" not recognized by tomcatjss
Apr 01 11:02:42 zsipa.private.net server[6896]: Error: SSL cipher
"TLS_DHE_RSA_WITH_3DES_EDE_CBC_SHA" not recognized by tomcatjss
Apr 01 11:02:42 zsipa.private.net server[6896]: Error: SSL cipher
"TLS_DHE_DSS_WITH_AES_128_GCM_SHA256" unsupported by NSS
Apr 01 11:02:42 zsipa.private.net server[6896]: Error: SSL cipher
"TLS_ECDH_ECDSA_WITH_AES_128_GCM_SHA256" unsupported by NSS
Apr 01 11:02:42 zsipa.private.net server[6896]: Error: SSL cipher
"TLS_ECDH_RSA_WITH_AES_128_GCM_SHA256" unsupported by NSS
Apr 01 11:02:42 zsipa.private.net server[6896]: Apr 01, 2016 11:02:42 AM
org.apache.coyote.AbstractProtocol init
Apr 01 11:02:42 zsipa.private.net server[6896]: INFO: Initializing
ProtocolHandler ["ajp-bio-127.0.0.1-8009"]
Apr 01 11:02:42 zsipa.private.net server[6896]: Apr 01, 2016 11:02:42 AM
org.apache.catalina.startup.Catalina load
Apr 01 11:02:42 zsipa.private.net server[6896]: INFO: Initialization processed
in 988 ms
Apr 01 11:02:42 zsipa.private.net server[6896]: Apr 01, 2016 11:02:42 AM
org.apache.catalina.core.StandardService startInternal
Apr 01 11:02:42 zsipa.private.net server[6896]: INFO: Starting service Catalina
Apr 01 11:02:42 zsipa.private.net server[6896]: Apr 01, 2016 11:02:42 AM
org.apache.catalina.core.StandardEngine startInternal
Apr 01 11:02:42 zsipa.private.net server[6896]: INFO: Starting Servlet Engine:
Apache Tomcat/7.0.59
Apr 01 11:02:42 zsipa.private.net server[6896]: Apr 01, 2016 11:02:42 AM
org.apache.catalina.startup.HostConfig deployDescriptor
Apr 01 11:02:42 zsipa.private.net server[6896]: INFO: Deploying configuration
descriptor /etc/pki/pki-tomcat/Catalina/localhost/ROOT.xml
Apr 01 11:02:43 zsipa.private.net server[6896]: Apr 01, 2016 11:02:43 AM
org.apache.catalina.startup.HostConfig deployDescriptor
Apr 01 11:02:43 zsipa.private.net server[6896]: INFO: Deployment of
configuration descriptor /etc/pki/pki-tomcat/Catalina/localhost/ROOT.xml has
finished in 1,194 ms
Apr 01 11:02:43 zsipa.private.net server[6896]: Apr 01, 2016 11:02:43 AM
org.apache.catalina.startup.HostConfig deployDescriptor
Apr 01 11:02:43 zsipa.private.net server[6896]: INFO: Deploying configuration
descriptor /etc/pki/pki-tomcat/Catalina/localhost/ca.xml
Apr 01 11:02:43 zsipa.private.net server[6896]: SSLAuthenticatorWithFallback:
Creating SSL authenticator with fallback
Apr 01 11:02:43 zsipa.private.net server[6896]: SSLAuthenticatorWithFallback:
Setting container
Apr 01 11:02:45 zsipa.private.net server[6896]: SSLAuthenticatorWithFallback:
Initializing authenticators
Apr 01 11:02:45 zsipa.private.net server[6896]: SSLAuthenticatorWithFallback:
Starting authenticators
Apr 01 11:02:51 zsipa.private.net server[6896]: Server is started.
Apr 01 11:02:51 zsipa.private.net server[6896]: Apr 01, 2016 11:02:51 AM
org.apache.catalina.startup.HostConfig deployDescriptor
Apr 01 11:02:51 zsipa.private.net server[6896]: INFO: Deployment of
configuration descriptor /etc/pki/pki-tomcat/Catalina/localhost/ca.xml has
finished in 7,993 ms
Apr 01 11:02:51 zsipa.private.net server[6896]: Apr 01, 2016 11:02:51 AM
org.apache.catalina.startup.HostConfig deployDescriptor
Apr 01 11:02:51 zsipa.private.net server[6896]: INFO: Deploying configuration
descriptor /etc/pki/pki-tomcat/Catalina/localhost/pki.xml
Apr 01 11:02:52 zsipa.private.net server[6896]: Apr 01, 2016 11:02:52 AM
org.apache.catalina.startup.HostConfig deployDescriptor
Apr 01 11:02:52 zsipa.private.net server[6896]: INFO: Deployment of
configuration descriptor /etc/pki/pki-tomcat/Catalina/localhost/pki.xml has
finished in 661 ms
Apr 01 11:02:52 zsipa.private.net server[6896]: Apr 01, 2016 11:02:52 AM
org.apache.coyote.AbstractProtocol start
Apr 01 11:02:52 zsipa.private.net server[6896]: INFO: Starting ProtocolHandler
["http-bio-8080"]
Apr 01 11:02:52 zsipa.private.net server[6896]: Apr 01, 2016 11:02:52 AM
org.apache.coyote.AbstractProtocol start
Apr 01 11:02:52 zsipa.private.net server[6896]: INFO: Starting ProtocolHandler
["http-bio-8443"]
Apr 01 11:02:52 zsipa.private.net server[6896]: Apr 01, 2016 11:02:52 AM
org.apache.coyote.AbstractProtocol start
Apr 01 11:02:52 zsipa.private.net server[6896]: INFO: Starting ProtocolHandler
["ajp-bio-127.0.0.1-8009"]
Apr 01 11:02:52 zsipa.private.net server[6896]: Apr 01, 2016 11:02:52 AM
org.apache.catalina.startup.Catalina start
Apr 01 11:02:52 zsipa.private.net server[6896]: INFO: Server startup in 9918 ms

Here the PKI server started. And below, 5 minutes later, something
stopped it.



Apr 01 11:07:53 zsipa.private.net server[7974]: Java virtual machine used:
/usr/lib/jvm/jre/bin/java
Apr 01 11:07:53 zsipa.private.net server[7974]: classpath used:
/usr/share/tomcat/bin/bootstrap.jar:/usr/share/tomcat/bin/tomcat-juli.jar:/usr/lib/java/commons-daemon.j
Apr 01 11:07:53 zsipa.private.net server[7974]: main class used:
org.apache.catalina.startup.Bootstrap
Apr 01 11:07:53 zsipa.private.net server[7974]: flags used:
-DRESTEASY_LIB=/usr/share/java/resteasy
Apr 01 11:07:53 zsipa.private.net server[7974]: options used:
-Dcatalina.base=/var/lib/pki/pki-tomcat -Dcatalina.home=/usr/share/tomcat
-Djava.endorsed.dirs= -Djava.io.
Apr 01 11:07:53 zsipa.private.net server[7974]: arguments used: stop
Apr 01 11:07:53 zsipa.private.net server[7974]: Apr 01, 2016 11:07:53 AM
org.apache.catalina.startup.ClassLoaderFactory validateFile
Apr 01 11:07:53 zsipa.private.net server[7974]: WARNING: Problem with JAR file
[/var/lib/pki/pki-tomcat/lib/log4j.jar], exists: [false], canRead: [false]
Apr 01 11:07:54 zsipa.private.net server[6896]: Apr 01, 2016 11:07:54 AM
org.apache.catalina.core.StandardServer await
Apr 01 11:07:54 zsipa.private.net server[6896]: INFO: A valid shutdown command
was received via the shutdown port. Stopping the Server instance.
Apr 01 11:07:54 zsipa.private.net server[6896]: Apr 01, 2016 11:07:54 AM
org.apache.coyote.AbstractProtocol pause
Apr 01 11:07:54 zsipa.private.net server[6896]: INFO: Pausing ProtocolHandler
["http-bio-8080"]
# systemctl status [email protected] -l
● [email protected] - PKI Tomcat Server pki-tomcat
     Loaded: loaded (/usr/lib/systemd/system/[email protected]; enabled)
     Active: inactive (dead)

Apr 28 12:12:53 zsipa.private.net server[8557]: Apr 28, 2016 12:12:53 PM
org.apache.catalina.core.StandardServer await
Apr 28 12:12:53 zsipa.private.net server[8557]: INFO: A valid shutdown command
was received via the shutdown port. Stopping the Server instance.
Apr 28 12:12:53 zsipa.private.net server[8557]: Apr 28, 2016 12:12:53 PM
org.apache.coyote.AbstractProtocol pause
Apr 28 12:12:53 zsipa.private.net server[8557]: INFO: Pausing ProtocolHandler
["http-bio-8080"]
Apr 28 12:12:53 zsipa.private.net server[8557]: Apr 28, 2016 12:12:53 PM
org.apache.coyote.AbstractProtocol pause
Apr 28 12:12:53 zsipa.private.net server[8557]: INFO: Pausing ProtocolHandler
["http-bio-8443"]
Apr 28 12:12:53 zsipa.private.net server[8557]: Apr 28, 2016 12:12:53 PM
org.apache.coyote.AbstractProtocol pause
Apr 28 12:12:53 zsipa.private.net server[8557]: INFO: Pausing ProtocolHandler
["ajp-bio-127.0.0.1-8009"]
Apr 28 12:12:53 zsipa.private.net server[8557]: Apr 28, 2016 12:12:53 PM
org.apache.catalina.core.StandardService stopInternal
Apr 28 12:12:53 zsipa.private.net server[8557]: INFO: Stopping service Catalina

Why is the time different here?


Given that the PKI server seems to start could you:

1. move date to Apr 1
2. # date
3. # ipactl stop
4. # date
5. # ipactl start -d
6. # date
7. # ipactl status
8. # getcert list
9. # journalctl -u [email protected]

paste here output of 1-8. Plus output of 9 since date in 2. Or ideally
attach it as text file so that lines won't be wrapped(hard to read).




# systemctl | grep dirsrv@
[email protected]
                         loaded active running   389 Directory Server 
PRIVATE-NET.

On 04/28/2016 12:04 PM, Petr Vobornik wrote:

On 04/28/2016 05:49 PM, Bret Wortman wrote:

My system shows pki-server is installed and V10.2.1-3.fc21, but I don't
have the pki-server binary itself. Will reinstalling this rpm hurt me in
any way? Without it, I'm not sure how to check my system against the
messages you provided below.

Not sure what you mean. Running doesn't require any additional packages.
It is just to get additional logs.
    systemctl [email protected]
    journalctl [email protected]

And the links below are about checking if CA users have correctly mapped
certificates in LDAP database in ou=people,o=ipaca for that you need
only ldapsearch command and start directory server:

We may skip this part, it might not be needed.


    systemctl [email protected]

Proper name [email protected]  can be found using:
    systemctl | grep dirsrv@



On 04/28/2016 11:07 AM, Petr Vobornik wrote:

On 04/28/2016 04:07 PM, Bret Wortman wrote:

Okay. This morning, I turned back time to 4/1 and started up IPA. It
didn't
work, but I got something new and interesting in the debug log, which
I've
posted tohttp://pastebin.com/M9VGCS8A. Lots of garbled junk came
pouring out
which doesn't happen when I'm set to real time. Is /this/ significant?

Anything in
     systemctl [email protected]
or rather:
     journalctl [email protected]
?

Just to be sure, it might be also worth to check if CA subsystem users
have correct certs assigned:
    *
https://www.redhat.com/archives/freeipa-users/2016-April/msg00138.html
    *
https://www.redhat.com/archives/freeipa-users/2016-April/msg00143.html


On 04/27/2016 02:24 PM, Bret Wortman wrote:

I put excerpts from the ca logs inhttp://pastebin.com/gYgskU79. It
looks
logical to me, but I can't spot anything that looks like a root
cause error.
The selftests are all okay, I think. The debug log might have
something, but
it might also just be complaining about ldap not being up because
it's not.


On 04/27/2016 01:11 PM, Rob Crittenden wrote:

Bret Wortman wrote:

So in lieu of fixing these certs, is there an acceptable way to dump
them all and start over /without losing the contents of the IPA
database/? Or otherwise really screwing ourselves?

I don't believe there is a way.


We have a replica that's still up and running and we've switched
everyone over to talking to it, but we're at risk with just the one.

I'd ignore the two unknown certs for now. They look like someone was
experimenting with issuing a cert and didn't quite get things working.

The CA seems to be throwing an error. I'd check the syslog for
messages from
certmonger and look at the CA debug log and selftest log.

rob


[snip]





--
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




























					Reply via email to