Bug 1730428

Created attachment 1591125 [details]
This error is generated in both ovirt-engine and ovirt-engine-dwhd

Description of problem:

ovirt-engine crashes during service start
ovirt-engine-dwhd crashes during service start


Version-Release number of selected component (if applicable):

4.3.4.3

How reproducible:

systemctl start ovirt-engine
systemctl start ovirt-engine-dwhd

Steps to Reproduce:

1) Updated self hosted engine.
2) Restarted VM after update
3) VM is up but ovirt-engine related services would not start.

Actual results:

systemctl status ovirt-engine

● ovirt-engine.service - oVirt Engine
   Loaded: loaded (/usr/lib/systemd/system/ovirt-engine.service; enabled; vendor preset: disabled)
   Active: failed (Result: exit-code) since Tue 2019-07-16 10:33:17 MDT; 8s ago
  Process: 3603 ExecStart=/usr/share/ovirt-engine/services/ovirt-engine/ovirt-engine.py --redirect-output --systemd=notify $EXTRA_ARGS start (code=exited, status=1/FAILURE)
 Main PID: 3603 (code=exited, status=1/FAILURE)

Jul 16 10:33:12 ovirt systemd[1]: Starting oVirt Engine...
Jul 16 10:33:13 ovirt ovirt-engine.py[3603]: 2019-07-16 10:33:13,034-0600 ovirt-engine: INFO _detectJBossVersion:195 Detecting JBoss version. Running: /usr/lib/jvm/jre/bin/java ['ovirt-engine-version', '-server', '-XX:+TieredCompilation', '-Xms1024M', '-Xmx1024M', '-Xss1M', '-Dj...gc.client.gcInterval=36
Jul 16 10:33:14 ovirt ovirt-engine.py[3603]: 2019-07-16 10:33:14,506-0600 ovirt-engine: INFO _detectJBossVersion:215 Return code: 0,  | stdout: '[u'WildFly Full 15.0.1.Final (WildFly Core 7.0.0.Final)'],  | stderr: '[u'Failed to invoke setter setPattern with value %d{HH:mm:ss,SS...eflect.InvocationTarget
Jul 16 10:33:14 ovirt systemd[1]: Started oVirt Engine.
Jul 16 10:33:17 ovirt ovirt-engine.py[3603]: 2019-07-16 10:33:17,976-0600 ovirt-engine: ERROR run:554 Error: process terminated with status code 1
Jul 16 10:33:17 ovirt systemd[1]: ovirt-engine.service: main process exited, code=exited, status=1/FAILURE
Jul 16 10:33:17 ovirt systemd[1]: Unit ovirt-engine.service entered failed state.
Jul 16 10:33:17 ovirt systemd[1]: ovirt-engine.service failed.


Expected results:

systemctl status ovirt-engine
Output will indicate that engine successfully stated and running.

Additional info:

Both services fail when starting jboss with following error:

Failed to invoke setter setPattern with value %d{HH:mm:ss,SSS} %-5p [%c] %s%E%n

ovirt-engine: INFO _detectJBossVersion:195 
Detecting JBoss version. Running: /usr/lib/jvm/jre/bin/java 
['ovirt-engine-version', 
'-server', 
'-XX:+TieredCompilation', 
'-Xms1024M', 
'-Xmx1024M', 
'-Xss1M', 
'-Djava.awt.headless=true', 
'-Dsun.rmi.dgc.client.gcInterval=3600000', 
'-Dsun.rmi.dgc.server.gcInterval=3600000', 
'-Djsse.enableSNIExtension=false', 
'-XX:+HeapDumpOnOutOfMemoryError', 
'-XX:HeapDumpPath=/var/log/ovirt-engine/dump', 
'-Djava.util.logging.manager=org.jboss.logmanager', 
'-Dlogging.configuration=file:///var/lib/ovirt-engine/jboss_runtime/config/ovirt-engine-logging.properties', 
'-Dorg.jboss.resolver.warning=true', 
'-Djboss.modules.system.pkgs=org.jboss.byteman', 
'-Djboss.server.default.config=ovirt-engine', 
'-Djboss.home.dir=/usr/share/ovirt-engine-wildfly', 
'-Djboss.server.base.dir=/usr/share/ovirt-engine', 
'-Djboss.server.data.dir=/var/lib/ovirt-engine', 
'-Djboss.server.log.dir=/var/log/ovirt-engine', 
'-Djboss.server.config.dir=/var/lib/ovirt-engine/jboss_runtime/config', 
'-Djboss.server.temp.dir=/var/lib/ovirt-engine/jboss_runtime/tmp', 
'-Djboss.controller.temp.dir=/var/lib/ovirt-engine/jboss_runtime/tmp', 
'-jar', '/usr/share/ovirt-engine-wildfly/jboss-modules.jar', 
'-mp', '/usr/share/ovirt-engine-wildfly-overlay/modules:/usr/share/ovirt-engine/modules/common:/usr/share/ovirt-engine-extension-aaa-jdbc/modules:/usr/share/ovirt-engine-extension-aaa-ldap/modules:/usr/share/ovirt-engine-wildfly/modules', 
'-jaxpmodule', 'javax.xml.jaxp-provider', 'org.jboss.as.standalone', '-v']

Jul 16 07:22:03 ovirt ovirt-engine.py[3345]: 2019-07-16 07:22:03,697-0600 ovirt-engine: INFO _detectJBossVersion:215 Return code: 0,  | stdout: '[u'WildFly Full 15.0.1.Final (WildFly Core 7.0.0.Final)'],  | stderr: '[
u'Failed to invoke setter setPattern with value %d{HH:mm:ss,SSS} %-5p [%c] %s%E%n', 
u'.java.lang.reflect.InvocationTargetException', 
u'\tat sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)', 
u'\tat sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)', 
u'\tat sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)', 
u'\tat java.lang.reflect.Method.invoke(Method.java:498)', 
u'\tat org.jboss.logmanager.config.AbstractPropertyConfiguration$1.applyPostCreate(AbstractPropertyConfiguration.java:217)', 
u'\tat org.jboss.logmanager.config.AbstractPropertyConfiguration$1.applyPostCreate(AbstractPropertyConfiguration.java:197)', 
u'\tat org.jboss.logmanager.config.LogContextConfigurationImpl.doApplyPostCreate(LogContextConfigurationImpl.java:313)', 
u'\tat org.jboss.logmanager.config.LogContextConfigurationImpl.doPrepare(LogContextConfigurationImpl.java:345)', 
u'\tat org.jboss.logmanager.config.LogContextConfigurationImpl.prepare(LogContextConfigurationImpl.java:289)', 
u'\tat org.jboss.logmanager.config.LogContextConfigurationImpl.commit(LogContextConfigurationImpl.java:298)', 
u'\tat org.jboss.logmanager.PropertyConfigurator.configure(PropertyConfigurator.java:546)', 
u'\tat org.jboss.logmanager.PropertyConfigurator.configure(PropertyConfigurator.java:97)', 
u'\tat org.jboss.logmanager.LogManager.readConfiguration(LogManager.java:170)', 
u'\tat org.jboss.logmanager.LogManager.readConfiguration(LogManager.java:132)', 
u'\tat java.util.logging.LogManager$3.run(LogManager.java:399)', 
u'\tat java.util.logging.LogManager$3.run(LogManager.java:396)', 
u'\tat java.security.AccessController.doPrivileged(Native Method)', 
u'\tat java.util.logging.LogManager.readPrimordialConfiguration(LogManager.java:396)', 
u'\tat java.util.logging.LogManager.access$800(LogManager.java:145)', 
u'\tat java.util.logging.LogManager$2.run(LogManager.java:345)', 
u'\tat java.security.AccessController.doPrivileged(Native Method)', 
u'\tat java.util.logging.LogManager.ensureLogManagerInitialized(LogManager.java:338)', 
u'\tat java.util.logging.LogManager.getLogManager(LogManager.java:378)', 
u'\tat org.jboss.modules.Main.main(Main.java:523)', 
u'Caused by: java.lang.Error: java.io.EOFException', 
u'\tat sun.util.calendar.ZoneInfoFile$1.run(ZoneInfoFile.java:261)', 
u'\tat java.security.AccessController.doPrivileged(Native Method)', 
u'\tat sun.util.calendar.ZoneInfoFile.<clinit>(ZoneInfoFile.java:251)', 
u'\tat sun.util.calendar.ZoneInfo.getTimeZone(ZoneInfo.java:589)', 
u'\tat java.util.TimeZone.getTimeZone(TimeZone.java:560)', 
u'\tat java.util.TimeZone.setDefaultZone(TimeZone.java:666)', 
u'\tat java.util.TimeZone.getDefaultRef(TimeZone.java:636)', 
u'\tat java.util.TimeZone.getDefault(TimeZone.java:625)', 
u'\tat org.jboss.logmanager.formatters.FormatStringParser.getSteps(FormatStringParser.java:65)', 
u'\tat org.jboss.logmanager.formatters.PatternFormatter.setPattern(PatternFormatter.java:79)', 
u'\t... 24 more', u'Caused by: java.io.EOFException', 
u'\tat java.io.DataInputStream.readByte(DataInputStream.java:267)', 
u'\tat sun.util.calendar.ZoneInfoFile.load(ZoneInfoFile.java:294)', 
u'\tat sun.util.calendar.ZoneInfoFile.access$000(ZoneInfoFile.java:61)', 
u'\tat sun.util.calendar.ZoneInfoFile$1.run(ZoneInfoFile.java:258)', 
u'\t... 33 more']'


I suspect it is a java problem or some sort of the conflict between
installed java components.
The failing component is a org.jboss.logmanager. 
But I think it is a symptom not a cause.
---------------------------------------
Start occurring after an update.
---------------------------------------

Regards.