Since it starts directly as root perhaps check for SELinux AVCs? Maybe a
relabel would help (or try permissive to catch the full set).
rob
Natxo Asenjo wrote:
hi,
yes, there was something wrong with another file :-):
# grep -r "11.5.0" /etc/pki/
/etc/pki/pki-tomcat/tomcat.conf: PKI_VERSION="11.5.0"
So I modified that to
PKI_VERSION=11.4.2
And now I have another error :-), it fails to start because of this (I
know I should not start this from systemctl, but from ipactl restart,
debugging, it takes longer to run ipactl restart):
May 29 14:23:01 kdc.sub.domain.tld systemd[1]: Starting PKI Tomcat
Server pki-tomcat...
░░ Subject: A start job for unit pki-tomcatd(a)pki-tomcat.service has
begun execution
░░ Defined-By: systemd
░░ Support:
https://access.redhat.com/support
░░
░░ A start job for unit pki-tomcatd(a)pki-tomcat.service has begun execution.
░░
░░ The job identifier is 35769.
May 29 14:23:03 kdc.sub.domain.tld pki-server[43389]: NOTE: Picked up
JDK_JAVA_OPTIONS: --add-opens=j>
May 29 14:23:03 kdc.sub.domain.tld pki-server[43371]: AJP connector
requiredSecret: None
May 29 14:23:03 kdc.sub.domain.tld pki-server[43371]: AJP connector
requiredSecret: None
May 29 14:23:03 kdc.sub.domain.tld server[43423]: Java virtual machine
used: /usr/lib/jvm/jre-17-openj>
May 29 14:23:03 kdc.sub.domain.tld server[43423]: classpath used:
/usr/share/tomcat/bin/bootstrap.jar:>
May 29 14:23:03 kdc.sub.domain.tld server[43423]: main class used:
org.apache.catalina.startup.Bootstr>
May 29 14:23:03 kdc.sub.domain.tld server[43423]: flags used:
-Dcom.redhat.fips=false
May 29 14:23:03 kdc.sub.domain.tld server[43423]: options used:
-Dcatalina.base=/var/lib/pki/pki-tomca>
May 29 14:23:03 kdc.sub.domain.tld server[43423]: arguments used: start
May 29 14:23:03 kdc.sub.domain.tld server[43423]: NOTE: Picked up
JDK_JAVA_OPTIONS: --add-opens=java.>
May 29 14:23:03 kdc.sub.domain.tld server[43423]: WARNING: A command
line option has enabled the Secur>
May 29 14:23:03 kdc.sub.domain.tld server[43423]: WARNING: The Security
Manager is deprecated and will>
May 29 14:23:04 kdc.sub.domain.tld ipa-pki-wait-running[43424]:
pki.client: /usr/libexec/ipa/ipa-pki-w>
May 29 14:23:04 kdc.sub.domain.tld ipa-pki-wait-running[43424]:
ipa-pki-wait-running: Created connecti>
May 29 14:23:04 kdc.sub.domain.tld ipa-pki-wait-running[43424]:
ipa-pki-wait-running: Connection faile>
May 29 14:23:05 kdc.sub.domain.tld server[43423]: SEVERE: Protocol
handler instantiation failed
May 29 14:23:05 kdc.sub.domain.tld server[43423]:
java.lang.ClassNotFoundException: org.dogtagpki.jss.>
May 29 14:23:05 kdc.sub.domain.tld server[43423]: at
java.base/java.net.URLClassLoader.findCla>
May 29 14:23:05 kdc.sub.domain.tld server[43423]: at
java.base/java.lang.ClassLoader.loadClass>
lines 1094-1145/1353 80%
░░ Defined-By: systemd
░░ Support:
https://access.redhat.com/support
░░
░░ A start job for unit pki-tomcatd(a)pki-tomcat.service has begun execution.
░░
░░ The job identifier is 35665.
May 29 14:19:36 kdc.sub.domain.tld pki-server[43128]: NOTE: Picked up
JDK_JAVA_OPTIONS: --add-opens=java.base/java.lang=ALL-UNNAMED
--add-opens=java.base/java.io <
http://java.io>=ALL-UNNAMED
--add-opens=java.base/java.util=>
May 29 14:19:36 kdc.sub.domain.tld pki-server[43109]: AJP connector
requiredSecret: None
May 29 14:19:36 kdc.sub.domain.tld pki-server[43109]: AJP connector
requiredSecret: None
May 29 14:19:36 kdc.sub.domain.tld server[43162]: Java virtual machine
used: /usr/lib/jvm/jre-17-openjdk/bin/java
May 29 14:19:36 kdc.sub.domain.tld server[43162]: classpath used:
/usr/share/tomcat/bin/bootstrap.jar:/usr/share/tomcat/bin/tomcat-juli.jar:
May 29 14:19:36 kdc.sub.domain.tld server[43162]: main class used:
org.apache.catalina.startup.Bootstrap
May 29 14:19:36 kdc.sub.domain.tld server[43162]: flags used:
-Dcom.redhat.fips=false
May 29 14:19:36 kdc.sub.domain.tld server[43162]: options used:
-Dcatalina.base=/var/lib/pki/pki-tomcat
-Dcatalina.home=/usr/share/tomcat -Djava.endorsed.dirs=
-Djava.io.tmpdir=/var/lib/pki/pki-tomcat/temp ->
May 29 14:19:36 kdc.sub.domain.tld server[43162]: arguments used: start
May 29 14:19:36 kdc.sub.domain.tld server[43162]: NOTE: Picked up
JDK_JAVA_OPTIONS: --add-opens=java.base/java.lang=ALL-UNNAMED
--add-opens=java.base/java.io <
http://java.io>=ALL-UNNAMED
--add-opens=java.base/java.util=ALL->
May 29 14:19:36 kdc.sub.domain.tld server[43162]: WARNING: A command
line option has enabled the Security Manager
May 29 14:19:36 kdc.sub.domain.tld server[43162]: WARNING: The Security
Manager is deprecated and will be removed in a future release
May 29 14:19:37 kdc.sub.domain.tld ipa-pki-wait-running[43163]:
pki.client: /usr/libexec/ipa/ipa-pki-wait-running:61: The subsystem in
PKIConnection.__init__() has been deprecated (
https://github.com/dogtagp>
May 29 14:19:37 kdc.sub.domain.tld ipa-pki-wait-running[43163]:
ipa-pki-wait-running: Created connection
http://kdc.sub.domain.tld:8080/ca
May 29 14:19:37 kdc.sub.domain.tld ipa-pki-wait-running[43163]:
ipa-pki-wait-running: Connection failed:
HTTPConnectionPool(host='kdc.sub.domain.tld', port=8080): Max retries
exceeded with url: /ca/admin/ca>
May 29 14:19:37 kdc.sub.domain.tld server[43162]: SEVERE: Protocol
handler instantiation failed
May 29 14:19:37 kdc.sub.domain.tld server[43162]:
java.lang.ClassNotFoundException: org.dogtagpki.jss.tomcat.Http11NioProtocol
May 29 14:19:37 kdc.sub.domain.tld server[43162]: at
java.base/java.net.URLClassLoader.findClass(URLClassLoader.java:445)
May 29 14:19:37 kdc.sub.domain.tld server[43162]: at
java.base/java.lang.ClassLoader.loadClass(ClassLoader.java:592)
May 29 14:19:37 kdc.sub.domain.tld server[43162]: at
java.base/java.lang.ClassLoader.loadClass(ClassLoader.java:525)
May 29 14:19:37 kdc.sub.domain.tld server[43162]: at
java.base/java.lang.Class.forName0(Native Method)
May 29 14:19:37 kdc.sub.domain.tld server[43162]: at
java.base/java.lang.Class.forName(Class.java:375)
May 29 14:19:37 kdc.sub.domain.tld server[43162]: at
org.apache.coyote.ProtocolHandler.create(ProtocolHandler.java:254)
May 29 14:19:37 kdc.sub.domain.tld server[43162]: at
org.apache.catalina.connector.Connector.<init>(Connector.java:88)
May 29 14:19:37 kdc.sub.domain.tld server[43162]: at
org.apache.catalina.startup.ConnectorCreateRule.begin(ConnectorCreateRule.java:65)
May 29 14:19:37 kdc.sub.domain.tld server[43162]: at
org.apache.tomcat.util.digester.Digester.startElement(Digester.java:1293)
May 29 14:19:37 kdc.sub.domain.tld server[43162]: at
java.xml/com.sun.org.apache.xerces.internal.parsers.AbstractSAXParser.startElement(AbstractSAXParser.java:518)
May 29 14:19:37 kdc.sub.domain.tld server[43162]: at
java.xml/com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl.scanStartElement(XMLDocumentFragmentScannerImpl.java:1407)
May 29 14:19:37 kdc.sub.domain.tld server[43162]: at
java.xml/com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl$FragmentContentDriver.next(XMLDocumentFragmentScannerImpl.java:272>
May 29 14:19:37 kdc.sub.domain.tld server[43162]: at
java.xml/com.sun.org.apache.xerces.internal.impl.XMLDocumentScannerImpl.next(XMLDocumentScannerImpl.java:605)
May 29 14:19:37 kdc.sub.domain.tld server[43162]: at
java.xml/com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl.scanDocument(XMLDocumentFragmentScannerImpl.java:542)
May 29 14:19:37 kdc.sub.domain.tld server[43162]: at
java.xml/com.sun.org.apache.xerces.internal.parsers.XML11Configuration.parse(XML11Configuration.java:889)
May 29 14:19:37 kdc.sub.domain.tld server[43162]: at
java.xml/com.sun.org.apache.xerces.internal.parsers.XML11Configuration.parse(XML11Configuration.java:825)
May 29 14:19:37 kdc.sub.domain.tld server[43162]: at
java.xml/com.sun.org.apache.xerces.internal.parsers.XMLParser.parse(XMLParser.java:141)
May 29 14:19:37 kdc.sub.domain.tld server[43162]: at
java.xml/com.sun.org.apache.xerces.internal.parsers.AbstractSAXParser.parse(AbstractSAXParser.java:1224)
May 29 14:19:37 kdc.sub.domain.tld server[43162]: at
java.xml/com.sun.org.apache.xerces.internal.jaxp.SAXParserImpl$JAXPSAXParser.parse(SAXParserImpl.java:637)
May 29 14:19:37 kdc.sub.domain.tld server[43162]: at
org.apache.tomcat.util.digester.Digester.p
arse(Digester.java:1551)
May 29 14:19:37 kdc.sub.domain.tld server[43162]: at
org.apache.catalina.startup.Catalina.parseServerXml(Catalina.java:617)
May 29 14:19:37 kdc.sub.domain.tld server[43162]: at
org.apache.catalina.startup.Catalina.load(Catalina.java:709)
lish a new connection: [Errno 111] Connection refused'))
May 29 14:24:22 kdc1 ipa-pki-wait-running[43424]: ipa-pki-wait-running:
Connection failed: HTTPConnectionPool(host='kdc.sub.domain.tld',
port=8080): Max retries exceeded with url: /ca/admin/ca/getStatus
(Caused by NewConnectionError('<urllib3.connection.HTTPConnection object
at 0x7f6ddd7fcee0>: Failed to establish a new connection: [Errno 111]
Connection refused'))
May 29 14:24:23 kdc1 ipa-pki-wait-running[43424]: ipa-pki-wait-running:
Connection failed: HTTPConnectionPool(host='kdc.sub.domain.tld',
port=8080): Max retries exceeded with url: /ca/admin/ca/getStatus
(Caused by NewConnectionError('<urllib3.connection.HTTPConnection object
at 0x7f6ddd80dbe0>: Failed to establish a new connection: [Errno 111]
Connection refused'))
May 29 14:24:24 kdc1 ipa-pki-wait-running[43424]: ipa-pki-wait-running:
Connection failed: HTTPConnectionPool(host='kdc.sub.domain.tld',
port=8080): Max retries exceeded with url: /ca/admin/ca/getStatus
(Caused by NewConnectionError('<urllib3.connection.HTTPConnection object
at 0x7f6ddd80d640>: Failed to establish a new connection: [Errno 111]
Connection refused'))
May 29 14:24:25 kdc1 ipa-pki-wait-running[43424]: ipa-pki-wait-running:
Connection failed: HTTPConnectionPool(host='kdc.sub.domain.tld',
port=8080): Max retries exceeded with url: /ca/admin/ca/getStatus
(Caused by NewConnectionError('<urllib3.connection.HTTPConnection object
at 0x7f6ddd80da00>: Failed to establish a new connection: [Errno 111]
Connection refused'))
May 29 14:24:26 kdc1 ipa-pki-wait-running[43424]: ipa-pki-wait-running:
Connection failed: HTTPConnectionPool(host='kdc.sub.domain.tld',
port=8080): Max retries exceeded with url: /ca/admin/ca/getStatus
(Caused by NewConnectionError('<urllib3.connection.HTTPConnection object
at 0x7f6ddd80d310>: Failed to establish a new connection: [Errno 111]
Connection refused'))
May 29 14:24:27 kdc1 ipa-pki-wait-running[43424]: ipa-pki-wait-running:
Connection failed: HTTPConnectionPool(host='kdc.sub.domain.tld',
port=8080): Max retries exceeded with url: /ca/admin/ca/getStatus
(Caused by NewConnectionError('<urllib3.connection.HTTPConnection object
at 0x7f6ddd7a9310>: Failed to establish a new connection: [Errno 111]
Connection refused'))
May 29 14:24:28 kdc1 ipa-pki-wait-running[43424]: ipa-pki-wait-running:
Connection failed: HTTPConnectionPool(host='kdc.sub.domain.tld',
port=8080): Max retries exceeded with url: /ca/admin/ca/getStatus
(Caused by NewConnectionError('<urllib3.connection.HTTPConnection object
at 0x7f6ddd80d880>: Failed to establish a new connection: [Errno 111]
Connection refused'))
May 29 14:24:29 kdc1 ipa-pki-wait-running[43424]: ipa-pki-wait-running:
Connection failed: HTTPConnectionPool(host='kdc.sub.domain.tld',
port=8080): Max retries exceeded with url: /ca/admin/ca/getStatus
(Caused by NewConnectionError('<urllib3.connection.HTTPConnection object
at 0x7f6ddd80dee0>: Failed to establish a new connection: [Errno 111]
Connection refused'))
May 29 14:24:30 kdc1 ipa-pki-wait-running[43424]: ipa-pki-wait-running:
Connection failed: HTTPConnectionPool(host='kdc.sub.domain.tld',
port=8080): Max retries exceeded with url: /ca/admin/ca/getStatus
(Caused by NewConnectionError('<urllib3.connection.HTTPConnection object
at 0x7f6ddd80d640>: Failed to establish a new connection: [Errno 111]
Connection refused'))
May 29 14:24:31 kdc1 ipa-pki-wait-running[43424]: ipa-pki-wait-running:
Connection failed: HTTPConnectionPool(host='kdc.sub.domain.tld',
port=8080): Max retries exceeded with url: /ca/admin/ca/getStatus
(Caused by NewConnectionError('<urllib3.connection.HTTPConnection object
at 0x7f6ddd80d1c0>: Failed to establish a new connection: [Errno 111]
Connection refused'))
May 29 14:24:32 kdc1 ipa-pki-wait-running[43424]: ipa-pki-wait-running:
Connection failed: HTTPConnectionPool(host='kdc.sub.domain.tld',
port=8080): Max retries exceeded with url: /ca/admin/ca/getStatus
(Caused by NewConnectionError('<urllib3.connection.HTTPConnection object
at 0x7f6ddd7fcee0>: Failed to establish a new connection: [Errno 111]
Connection refused'))
May 29 14:24:33 kdc1 systemd[1]: pki-tomcatd(a)pki-tomcat.service:
start-post operation timed out. Terminating.
May 29 14:24:33 kdc1 systemd[1]: pki-tomcatd(a)pki-tomcat.service: Control
process exited, code=killed, status=15/TERM
May 29 14:24:33 kdc1 systemd[1]: pki-tomcatd(a)pki-tomcat.service: Failed
with result 'exit-code'.
May 29 14:24:33 kdc1 systemd[1]: Failed to start PKI Tomcat Server
pki-tomcat.
May 29 14:24:33 kdc1 systemd[1]: pki-tomcatd(a)pki-tomcat.service:
Consumed 3.677s CPU time.
What is interesting is that if I run the commands on the unit file, as
root, it does start:
[root@kdc ~]# systemctl cat pki-tomcatd@pki-tomcat
# /usr/lib/systemd/system/pki-tomcatd@.service
[Unit]
Description=PKI Tomcat Server %i
PartOf=pki-tomcatd.target
[Service]
Type=simple
EnvironmentFile=/usr/share/pki/etc/tomcat.conf
EnvironmentFile=/etc/tomcat/tomcat.conf
Environment="NAME=%i"
EnvironmentFile=-/etc/sysconfig/%i
EnvironmentFile=/usr/share/pki/etc/pki.conf
EnvironmentFile=/etc/pki/pki.conf
ExecStartPre=/usr/sbin/pki-server upgrade %i
ExecStartPre=/usr/sbin/pki-server migrate %i
ExecStartPre=/usr/bin/pkidaemon start %i
ExecStart=/usr/libexec/tomcat/server start
ExecStop=/usr/libexec/tomcat/server stop
SuccessExitStatus=143
User=pkiuser
Group=pkiuser
[Install]
WantedBy=pki-tomcatd.target
# /etc/systemd/system/pki-tomcatd(a)pki-tomcat.service.d/ipa.conf
[Service]
Environment=LC_ALL=C.UTF-8
ExecStartPost=/usr/libexec/ipa/ipa-pki-wait-running
[root@kdc ~]# su - pkiuser
This account is currently not available.
[root@kdc ~]# source /usr/share/pki/etc/tomcat.conf
[root@kdc ~]# source /etc/tomcat/tomcat.conf
[root@kdc ~]# NAME=pki-tomcat
[root@kdc ~]# source /etc/sysconfig/pki-tomcat
[root@kdc ~]# source /usr/share/pki/etc/pki.conf
[root@kdc ~]# source /etc/pki/pki.conf
[root@kdc ~]# /usr/sbin/pki-server upgrade pki-tomcat
[root@kdc ~]# /usr/sbin/pki-server migrate pki-tomcat
NOTE: Picked up JDK_JAVA_OPTIONS:
--add-opens=java.base/java.lang=ALL-UNNAMED
--add-opens=java.base/java.io <
http://java.io>=ALL-UNNAMED
--add-opens=java.base/java.util=ALL-UNNAMED
--add-opens=java.base/java.util.concurrent=ALL-UNNAMED
--add-opens=java.rmi/sun.rmi.transport=ALL-UNNAMED
AJP connector requiredSecret: None
AJP connector requiredSecret: None
[root@kdc ~]# /usr/bin/pkidaemon start pki-tomcat
[root@kdc ~]# /usr/libexec/tomcat/server start
Java virtual machine used: /usr/lib/jvm/jre/bin/java
classpath used:
/usr/share/tomcat/bin/bootstrap.jar:/usr/share/tomcat/bin/tomcat-juli.jar:
main class used: org.apache.catalina.startup.Bootstrap
flags used:
-Djavax.sql.DataSource.Factory=org.apache.commons.dbcp.BasicDataSourceFactory
options used: -Dcatalina.base=/usr/share/tomcat
-Dcatalina.home=/usr/share/tomcat -Djava.endorsed.dirs=
-Djava.io.tmpdir=/var/cache/tomcat/temp
-Djava.util.logging.config.file=/usr/share/tomcat/conf/logging.properties
-Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
arguments used: start
NOTE: Picked up JDK_JAVA_OPTIONS:
--add-opens=java.base/java.lang=ALL-UNNAMED
--add-opens=java.base/java.io <
http://java.io>=ALL-UNNAMED
--add-opens=java.base/java.util=ALL-UNNAMED
--add-opens=java.base/java.util.concurrent=ALL-UNNAMED
--add-opens=java.rmi/sun.rmi.transport=ALL-UNNAMED
29-May-2024 14:36:36.689 INFO [main]
org.apache.catalina.startup.VersionLoggerListener.log Server version
name: Apache Tomcat/9.0.62
29-May-2024 14:36:36.697 INFO [main]
org.apache.catalina.startup.VersionLoggerListener.log Server
built: Dec 30 1969 17:35:50 UTC
29-May-2024 14:36:36.698 INFO [main]
org.apache.catalina.startup.VersionLoggerListener.log Server version
number: 9.0.62.0
29-May-2024 14:36:36.699 INFO [main]
org.apache.catalina.startup.VersionLoggerListener.log OS
Name: Linux
29-May-2024 14:36:36.699 INFO [main]
org.apache.catalina.startup.VersionLoggerListener.log OS
Version: 5.14.0-427.16.1.el9_4.x86_64
29-May-2024 14:36:36.699 INFO [main]
org.apache.catalina.startup.VersionLoggerListener.log
Architecture: amd64
29-May-2024 14:36:36.699 INFO [main]
org.apache.catalina.startup.VersionLoggerListener.log Java
Home: /usr/lib/jvm/java-11-openjdk-11.0.22.0.7-2.el9.x86_64
29-May-2024 14:36:36.700 INFO [main]
org.apache.catalina.startup.VersionLoggerListener.log JVM
Version: 11.0.22+7-LTS
29-May-2024 14:36:36.700 INFO [main]
org.apache.catalina.startup.VersionLoggerListener.log JVM
Vendor: Red Hat, Inc.
29-May-2024 14:36:36.700 INFO [main]
org.apache.catalina.startup.VersionLoggerListener.log
CATALINA_BASE: /usr/share/tomcat
29-May-2024 14:36:36.701 INFO [main]
org.apache.catalina.startup.VersionLoggerListener.log
CATALINA_HOME: /usr/share/tomcat
29-May-2024 14:36:36.727 INFO [main]
org.apache.catalina.startup.VersionLoggerListener.log Command line
argument: --add-opens=java.base/java.lang=ALL-UNNAMED
29-May-2024 14:36:36.728 INFO [main]
org.apache.catalina.startup.VersionLoggerListener.log Command line
argument: --add-opens=java.base/java.io <
http://java.io>=ALL-UNNAMED
29-May-2024 14:36:36.728 INFO [main]
org.apache.catalina.startup.VersionLoggerListener.log Command line
argument: --add-opens=java.base/java.util=ALL-UNNAMED
29-May-2024 14:36:36.728 INFO [main]
org.apache.catalina.startup.VersionLoggerListener.log Command line
argument: --add-opens=java.base/java.util.concurrent=ALL-UNNAMED
29-May-2024 14:36:36.728 INFO [main]
org.apache.catalina.startup.VersionLoggerListener.log Command line
argument: --add-opens=java.rmi/sun.rmi.transport=ALL-UNNAMED
29-May-2024 14:36:36.729 INFO [main]
org.apache.catalina.startup.VersionLoggerListener.log Command line
argument:
-Djavax.sql.DataSource.Factory=org.apache.commons.dbcp.BasicDataSourceFactory
29-May-2024 14:36:36.730 INFO [main]
org.apache.catalina.startup.VersionLoggerListener.log Command line
argument: -Dcatalina.base=/usr/share/tomcat
29-May-2024 14:36:36.730 INFO [main]
org.apache.catalina.startup.VersionLoggerListener.log Command line
argument: -Dcatalina.home=/usr/share/tomcat
29-May-2024 14:36:36.733 INFO [main]
org.apache.catalina.startup.VersionLoggerListener.log Command line
argument: -Djava.endorsed.dirs=
29-May-2024 14:36:36.733 INFO [main]
org.apache.catalina.startup.VersionLoggerListener.log Command line
argument: -Djava.io.tmpdir=/var/cache/tomcat/temp
29-May-2024 14:36:36.733 INFO [main]
org.apache.catalina.startup.VersionLoggerListener.log Command line
argument:
-Djava.util.logging.config.file=/usr/share/tomcat/conf/logging.properties
29-May-2024 14:36:36.733 INFO [main]
org.apache.catalina.startup.VersionLoggerListener.log Command line
argument: -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
29-May-2024 14:36:36.735 INFO [main]
org.apache.catalina.core.AprLifecycleListener.lifecycleEvent The Apache
Tomcat Native library which allows using OpenSSL was not found on the
java.library.path: [/usr/java/packages/lib:/usr/lib64:/lib64:/lib:/usr/lib]
29-May-2024 14:36:37.550 INFO [main]
org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler
["http-nio-8080"]
29-May-2024 14:36:37.613 INFO [main]
org.apache.catalina.startup.Catalina.load Server initialization in
[1379] milliseconds
29-May-2024 14:36:37.739 INFO [main]
org.apache.catalina.core.StandardService.startInternal Starting service
[Catalina]
29-May-2024 14:36:37.740 INFO [main]
org.apache.catalina.core.StandardEngine.startInternal Starting Servlet
engine: [Apache Tomcat/9.0.62]
29-May-2024 14:36:37.756 INFO [main]
org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler
["http-nio-8080"]
29-May-2024 14:36:37.823 INFO [main]
org.apache.catalina.startup.Catalina.start Server startup in [209]
milliseconds
I will try rebooting later, although I do not think this will fix the
problem.
On Wed, May 29, 2024 at 12:41 PM Alexander Bokovoy <abokovoy(a)redhat.com
<mailto:abokovoy@redhat.com>> wrote:
On Срд, 29 мая 2024, Natxo Asenjo wrote:
>hi,
>
>indeed, sorry.
>
># cat
>/etc/pki/pki.version
>│
>Configuration-Version: 11.5.0
>
># ipactl restart
>Restarting Directory Service
>Restarting krb5kdc Service
>Restarting kadmin Service
>Restarting named Service
>Restarting httpd Service
>Restarting ipa-custodia Service
>Restarting pki-tomcatd Service
>Restarting smb Service
>Restarting winbind Service
>Restarting ipa-otpd Service
>Restarting ipa-dnskeysyncd Service
>ipa: INFO: The ipactl command was successful
>
>]# ipactl status
>Directory Service: RUNNING
>krb5kdc Service: RUNNING
>kadmin Service: RUNNING
>named Service: RUNNING
>httpd Service: RUNNING
>ipa-custodia Service: RUNNING
>pki-tomcatd Service: STOPPED
>smb Service: RUNNING
>winbind Service: RUNNING
>ipa-otpd Service: RUNNING
>ipa-dnskeysyncd Service: RUNNING
>1 service(s) are not running
>
>May 29 12:12:34 kdc.sub.domain.tld systemd[1]: Starting PKI Tomcat
Server
>pki-tomcat...
>May 29 12:12:35 kdc.sub.domain.tld pki-server[36733]: ERROR: Unable to
>parse version number: "11.5.0"
>May 29 12:12:35 kdc.sub.domain.tld pki-server[36733]: Traceback (most
>recent call last):
>May 29 12:12:35 kdc.sub.domain.tld pki-server[36733]: File
>"/usr/lib/python3.9/site-packages/pki/server/pkiserver.py", line 41,
in
><module>
>May 29 12:12:35 kdc.sub.domain.tld pki-server[36733]:
>cli.execute(sys.argv)
>May 29 12:12:35 kdc.sub.domain.tld pki-server[36733]: File
>"/usr/lib/python3.9/site-packages/pki/server/cli/__init__.py", line
145, in
>execute
>May 29 12:12:35 kdc.sub.domain.tld pki-server[36733]:
>super().execute(args)
>May 29 12:12:35 kdc.sub.domain.tld pki-server[36733]: File
>"/usr/lib/python3.9/site-packages/pki/cli/__init__.py", line 217,
in execute
>May 29 12:12:35 kdc.sub.domain.tld pki-server[36733]:
>module.execute(module_args)
>May 29 12:12:35 kdc.sub.domain.tld pki-server[36733]: File
>"/usr/lib/python3.9/site-packages/pki/server/cli/upgrade.py", line
144, in
>execute
>May 29 12:12:35 kdc.sub.domain.tld pki-server[36733]: self.upgrade(
>May 29 12:12:35 kdc.sub.domain.tld pki-server[36733]: File
>"/usr/lib/python3.9/site-packages/pki/server/cli/upgrade.py", line
178, in
>upgrade
>May 29 12:12:35 kdc.sub.domain.tld pki-server[36733]:
upgrader.upgrade()
>May 29 12:12:35 kdc.sub.domain.tld pki-server[36733]: File
>"/usr/lib/python3.9/site-packages/pki/upgrade.py", line 481, in
upgrade
>May 29 12:12:35 kdc.sub.domain.tld pki-server[36733]: versions =
>self.versions()
>May 29 12:12:35 kdc.sub.domain.tld pki-server[36733]: File
>"/usr/lib/python3.9/site-packages/pki/upgrade.py", line 238, in
versions
>May 29 12:12:35 kdc.sub.domain.tld pki-server[36733]:
current_version =
>self.get_current_version()
>May 29 12:12:35 kdc.sub.domain.tld pki-server[36733]: File
>"/usr/lib/python3.9/site-packages/pki/upgrade.py", line 341, in
>get_current_version
>May 29 12:12:35 kdc.sub.domain.tld pki-server[36733]:
current_version =
>self.get_tracker().get_version()
>May 29 12:12:35 kdc.sub.domain.tld pki-server[36733]: File
>"/usr/lib/python3.9/site-packages/pki/upgrade.py", line 141, in
get_version
>May 29 12:12:35 kdc.sub.domain.tld pki-server[36733]: return
>pki.util.Version(version)
>May 29 12:12:35 kdc.sub.domain.tld pki-server[36733]: File
>"/usr/lib/python3.9/site-packages/pki/util.py", line 613, in __init__
>May 29 12:12:35 kdc.sub.domain.tld pki-server[36733]: raise
>Exception('Unable to parse version number: %s' % obj)
>May 29 12:12:35 kdc.sub.domain.tld pki-server[36733]: Exception:
Unable to
>parse version number: "11.5.0"
The only way to get this string in double quotes is if it was in double
quotes in the original file:
-----------------------------------------------------------------
>>> obj = "11.5.0"
>>> m = re.match(r'^(\d+)\.(\d+)\.(\d+)', obj)
>>> m.group(2)
'5'
>>> raise Exception('Unable to parse version number: %s' % obj)
Traceback (most recent call last):
File "<stdin>", line 1, in <module>
Exception: Unable to parse version number: 11.5.0
>>> obj = '"11.5.0"'
>>> m = re.match(r'^(\d+)\.(\d+)\.(\d+)', obj)
>>> m.group(2)
Traceback (most recent call last):
File "<stdin>", line 1, in <module>
AttributeError: 'NoneType' object has no attribute 'group'
>>> raise Exception('Unable to parse version number: %s' % obj)
Traceback (most recent call last):
File "<stdin>", line 1, in <module>
Exception: Unable to parse version number: "11.5.0"
-----------------------------------------------------------------
So I still think there is something wrong with the file it reads...
>
>If I revert it to 11.4.2, so it looks as though it is not reading
this file
>for getting this information.
>
># cat /etc/pki/pki.version
>Configuration-Version: 11.4.2
>
># ipactl restart
>Restarting Directory Service
>Restarting krb5kdc Service
>Restarting kadmin Service
>Restarting named Service
>Restarting httpd Service
>Restarting ipa-custodia Service
>Restarting pki-tomcatd Service
>Restarting smb Service
>Restarting winbind Service
>Restarting ipa-otpd Service
>Restarting ipa-dnskeysyncd Service
>ipa: INFO: The ipactl command was successful
>
># ipactl status
>Directory Service: RUNNING
>krb5kdc Service: RUNNING
>kadmin Service: RUNNING
>named Service: RUNNING
>httpd Service: RUNNING
>ipa-custodia Service: RUNNING
>pki-tomcatd Service: STOPPED
>smb Service: RUNNING
>winbind Service: RUNNING
>ipa-otpd Service: RUNNING
>ipa-dnskeysyncd Service: RUNNING
>1 service(s) are not running
>
>May 29 12:17:08 kdc.sub.domain.tld systemd[1]: Starting PKI Tomcat
Server
>pki-tomcat...
>May 29 12:17:08 kdc.sub.domain.tld pki-server[37297]: ERROR: Unable to
>parse version number: "11.5.0"
>
>Strange.
>
>
>On Tue, May 28, 2024 at 7:35 PM Rob Crittenden <rcritten(a)redhat.com
<mailto:rcritten@redhat.com>> wrote:
>
>> Natxo Asenjo via FreeIPA-users wrote:
>> > hi,
>> >
>> > no, it's without quotes but the rolledback version:
>> >
>> > Configuration-Version: 11.4.2
>> >
>> > I tried modifiying it to 11.5.0 and ipactl restart, but it does
not help
>> > (reset it to the proper value 11.4.2 now)
>>
>> Did the error change when you switched to 11.4.2? You didn't
include a
>> new traceback.
>>
>> rob
>>
>> >
>> >
>> >
>> > On Fri, May 24, 2024 at 5:14 PM Alexander Bokovoy
<abokovoy(a)redhat.com <mailto:abokovoy@redhat.com>
>> > <mailto:abokovoy@redhat.com
<mailto:abokovoy@redhat.com>>> wrote:
>> >
>> > On Fri, 24 May 2024, Natxo Asenjo via FreeIPA-users wrote:
>> > >hi,
>> > >
>> > >after a botched update
>> > (https://access.redhat.com/solutions/7065748) and
>> > >rolling back the changes, this service will not start:
>> > >
>> > ># ipactl status
>> > >Directory Service: RUNNING
>> > >krb5kdc Service: RUNNING
>> > >kadmin Service: RUNNING
>> > >named Service: RUNNING
>> > >httpd Service: RUNNING
>> > >ipa-custodia Service: RUNNING
>> > >pki-tomcatd Service: STOPPED
>> > >smb Service: RUNNING
>> > >winbind Service: RUNNING
>> > >ipa-otpd Service: RUNNING
>> > >ipa-dnskeysyncd Service: RUNNING
>> > >1 service(s) are not running
>> > >
>> > >in journalctl I found this stdout/stderr messages:
>> > >
>> > >
>> > >May 24 11:40:35 kdc1.sub.domain.tld named[27437]: zone
>> > sub.domain.tld/IN:
>> > >sending notifies (serial 1716543629)
>> > >May 24 11:40:35 kdc1.sub.domain.tld pki-server[27758]: ERROR:
>> Unable to
>> > >parse version number: "11.5.0"
>> > >May 24 11:40:35 kdc1.sub.domain.tld pki-server[27758]:
Traceback
>> (most
>> > >recent call last):
>> > >May 24 11:40:35 kdc1.sub.domain.tld pki-server[27758]: File
>> >
>"/usr/lib/python3.9/site-packages/pki/server/pkiserver.py", line
>> 41, in
>> > ><module>
>> > >May 24 11:40:35 kdc1.sub.domain.tld pki-server[27758]:
>> > >cli.execute(sys.argv)
>> > >May 24 11:40:35 kdc1.sub.domain.tld pki-server[27758]: File
>> >
>"/usr/lib/python3.9/site-packages/pki/server/cli/__init__.py", line
>> > 145, in
>> > >execute
>> > >May 24 11:40:35 kdc1.sub.domain.tld pki-server[27758]:
>> > >super().execute(args)
>> > >May 24 11:40:35 kdc1.sub.domain.tld pki-server[27758]: File
>> >
>"/usr/lib/python3.9/site-packages/pki/cli/__init__.py",
line 217,
>> > in execute
>> > >May 24 11:40:35 kdc1.sub.domain.tld pki-server[27758]:
>> > >module.execute(module_args)
>> > >May 24 11:40:35 kdc1.sub.domain.tld pki-server[27758]: File
>> >
>"/usr/lib/python3.9/site-packages/pki/server/cli/upgrade.py", line
>> > 144, in
>> > >execute
>> > >May 24 11:40:35 kdc1.sub.domain.tld pki-server[27758]:
>> > self.upgrade(
>> > >May 24 11:40:35 kdc1.sub.domain.tld pki-server[27758]: File
>> >
>"/usr/lib/python3.9/site-packages/pki/server/cli/upgrade.py", line
>> > 178, in
>> > >upgrade
>> > >May 24 11:40:35 kdc1.sub.domain.tld pki-server[27758]:
>> > >upgrader.upgrade()
>> > >May 24 11:40:35 kdc1.sub.domain.tld pki-server[27758]: File
>> > >"/usr/lib/python3.9/site-packages/pki/upgrade.py",
line
481, in
>> upgrade
>> > >May 24 11:40:35 kdc1.sub.domain.tld pki-server[27758]:
versions
>> =
>> > >self.versions()
>> > >May 24 11:40:35 kdc1.sub.domain.tld pki-server[27758]: File
>> > >"/usr/lib/python3.9/site-packages/pki/upgrade.py",
line
238, in
>> > versions
>> > >May 24 11:40:35 kdc1.sub.domain.tld pki-server[27758]:
>> > current_version
>> > >= self.get_current_version()
>> > >May 24 11:40:35 kdc1.sub.domain.tld pki-server[27758]: File
>> > >"/usr/lib/python3.9/site-packages/pki/upgrade.py",
line
341, in
>> > >get_current_version
>> > >May 24 11:40:35 kdc1.sub.domain.tld pki-server[27758]:
>> > current_version
>> > >= self.get_tracker().get_version()
>> > >May 24 11:40:35 kdc1.sub.domain.tld pki-server[27758]: File
>> > >"/usr/lib/python3.9/site-packages/pki/upgrade.py",
line
141, in
>> > get_version
>> > >May 24 11:40:35 kdc1.sub.domain.tld pki-server[27758]:
return
>> > >pki.util.Version(version)
>> > >May 24 11:40:35 kdc1.sub.domain.tld pki-server[27758]: File
>> > >"/usr/lib/python3.9/site-packages/pki/util.py", line
613, in
>> __init__
>> > >May 24 11:40:35 kdc1.sub.domain.tld pki-server[27758]:
raise
>> > >Exception('Unable to parse version number: %s' % obj)
>> > >May 24 11:40:35 kdc1.sub.domain.tld pki-server[27758]:
Exception:
>> > Unable to
>> > >parse version number: "11.5.0"
>> >
>> > What do you have in /etc/pki/pki.version file? Is it literally
>> >
>> > # cat /etc/pki/pki.version
>> > Configuration-Version: "11.5.0"
>> >
>> > ? If so, then remove quotes around 11.5.0, they are not
expected.
>> >
>> > >May 24 11:40:35 kdc1.sub.domain.tld systemd[1]:
>> > >pki-tomcatd(a)pki-tomcat.service: Control process exited,
>> code=exited,
>> > >status=1/FAILURE
>> > >May 24 11:40:35 kdc1.sub.domain.tld systemd[1]:
>> > >pki-tomcatd(a)pki-tomcat.service: Failed with result
'exit-code'.
>> > >May 24 11:40:35 kdc1.sub.domain.tld systemd[1]: Failed to
start PKI
>> > Tomcat
>> > >Server pki-tomcat.
>> > >
>> > >So it seems something is broken on this upgrade script.
This is in
>> in
>> > >almalinux 9.3
>> > >ipa-server-4.10.2-5.el9_3.alma.1.x86_64
>> > >
>> > >I cannot upgrade because I get bitten by the named ldap
thing, even
>> > though
>> > >the versions are newer.
>> > >
>> > >I will create a replicat to a rhel host but first I need
to get the
>> > CA up
>> > >and running obviously :-).
>> > >
>> > >Any ideas?
>> > >
>> > >Thanks!
>> > >
>> > >--
>> > >regards,
>> > >
>> > >natxo
>> > >
>> > >--
>> > >--
>> > >Groeten,
>> > >natxo
>> >
>> >
>> >
>> >
>> > --
>> > / Alexander Bokovoy
>> > Sr. Principal Software Engineer
>> > Security / Identity Management Engineering
>> > Red Hat Limited, Finland
>> >
>> >
>> >
>> > --
>> > --
>> > Groeten,
>> > natxo
>> >
>> > --
>> > _______________________________________________
>> > FreeIPA-users mailing list --
freeipa-users(a)lists.fedorahosted.org
<mailto:freeipa-users@lists.fedorahosted.org>
>> > To unsubscribe send an email to
>> freeipa-users-leave(a)lists.fedorahosted.org
<mailto:freeipa-users-leave@lists.fedorahosted.org>
>> > Fedora Code of Conduct:
>>
https://docs.fedoraproject.org/en-US/project/code-of-conduct/
>> > List Guidelines:
https://fedoraproject.org/wiki/Mailing_list_guidelines
>> > List Archives:
>>
https://lists.fedorahosted.org/archives/list/freeipa-users@lists.fedoraho...
>> > Do not reply to spam, report it:
>>
https://pagure.io/fedora-infrastructure/new_issue
>> >
>>
>>
>
>--
>--
>Groeten,
>natxo
--
/ Alexander Bokovoy
Sr. Principal Software Engineer
Security / Identity Management Engineering
Red Hat Limited, Finland
--
--
Groeten,
natxo