Bug 1536048
Summary: | Unknown Java Time Zone Prevents RHV From Starting. | ||
---|---|---|---|
Product: | Red Hat Enterprise Linux 7 | Reporter: | Bernie Hoefer <bhoefer> |
Component: | java-1.8.0-openjdk | Assignee: | Andrew John Hughes <ahughes> |
Status: | CLOSED NOTABUG | QA Contact: | zzambers |
Severity: | medium | Docs Contact: | |
Priority: | unspecified | ||
Version: | 7.4 | CC: | ahughes, bhoefer, dbhole, jvanek, zzambers |
Target Milestone: | rc | ||
Target Release: | --- | ||
Hardware: | x86_64 | ||
OS: | Linux | ||
Whiteboard: | |||
Fixed In Version: | Doc Type: | If docs needed, set a value | |
Doc Text: | Story Points: | --- | |
Clone Of: | Environment: | ||
Last Closed: | 2021-02-08 14:18:04 UTC | Type: | Bug |
Regression: | --- | Mount Type: | --- |
Documentation: | --- | CRM: | |
Verified Versions: | Category: | --- | |
oVirt Team: | --- | RHEL 7.3 requirements from Atomic Host: | |
Cloudforms Team: | --- | Target Upstream Version: | |
Embargoed: |
Description
Bernie Hoefer
2018-01-18 14:32:57 UTC
I looked at this one a little and I was able to reproduce identical stack trace (icluding line numbers), just by calling: ZoneId.of("EST"); Exception in thread "main" java.time.zone.ZoneRulesException: Unknown time-zone ID: EST at java.time.zone.ZoneRulesProvider.getProvider(ZoneRulesProvider.java:272) at java.time.zone.ZoneRulesProvider.getRules(ZoneRulesProvider.java:227) at java.time.ZoneRegion.ofId(ZoneRegion.java:120) at java.time.ZoneId.of(ZoneId.java:411) at java.time.ZoneId.of(ZoneId.java:359) at ZoneIdTest.main(ZoneIdTest.java:24) However I am not sure this one is actually bug in JDK, since javadoc description of SHORT_IDS field [1] in the ZoneId class says that use of short zone ids have been deprecated. And looks to me, that correct way to use these deprecated SHORT_IDS (such as EST) is by using second form of Zoneid.of method: ZoneId.of("EST", ZoneId.SHORT_IDS); which works, and it is also the form, which is used internally by JDK in Timezone class by toZoneId method [2]. ( I expect, that rest of the stack trace is outside of JDK, when not included. ) Nevertheless adding qa_ack. [1] https://docs.oracle.com/javase/8/docs/api/java/time/ZoneId.html#SHORT_IDS [2] http://hg.openjdk.java.net/jdk8u/jdk8u/jdk/file/f940e7a48b72/src/share/classes/java/util/TimeZone.java#l539 (In reply to zzambers from comment #2) > I looked at this one a little and I was able to reproduce identical stack > trace (icluding line numbers), just by calling: > > ZoneId.of("EST"); I suspected this might be the case when I saw the initial stack trace, but just haven't had time to try it. Thanks for confirming. > > Exception in thread "main" java.time.zone.ZoneRulesException: Unknown > time-zone ID: EST > at java.time.zone.ZoneRulesProvider.getProvider(ZoneRulesProvider.java:272) > at java.time.zone.ZoneRulesProvider.getRules(ZoneRulesProvider.java:227) > at java.time.ZoneRegion.ofId(ZoneRegion.java:120) > at java.time.ZoneId.of(ZoneId.java:411) > at java.time.ZoneId.of(ZoneId.java:359) > at ZoneIdTest.main(ZoneIdTest.java:24) > > > However I am not sure this one is actually bug in JDK, since javadoc > description of SHORT_IDS field [1] in the ZoneId class says that use of > short zone ids have been deprecated. And looks to me, that correct way to > use these deprecated SHORT_IDS (such as EST) is by using second form of > Zoneid.of method: > > ZoneId.of("EST", ZoneId.SHORT_IDS); > > which works, and it is also the form, which is used internally by JDK in > Timezone class by toZoneId method [2]. ( I expect, that rest of the stack > trace is outside of JDK, when not included. ) The interesting bit about [2] is just above that call: public ZoneId toZoneId() { String id = getID(); if (ZoneInfoFile.useOldMapping() && id.length() == 3) { if ("EST".equals(id)) return ZoneId.of("America/New_York"); It could be that useOldMapping has changed value. I'll check this out. But we really need to know the rest of that stack trace to be sure. > > Nevertheless adding qa_ack. > > [1] https://docs.oracle.com/javase/8/docs/api/java/time/ZoneId.html#SHORT_IDS > [2] > http://hg.openjdk.java.net/jdk8u/jdk8u/jdk/file/f940e7a48b72/src/share/ > classes/java/util/TimeZone.java#l539 (In reply to Andrew John Hughes from comment #3) === > But we really need to know the rest of that stack trace to be sure. === Sorry, I'm not familiar with how to get a Java stack trace. Are the lines from /var/log/ovirt-engine/boot.log and /var/log/message, far below, what you want? # ll /etc/localtime lrwxrwxrwx. 1 root root 27 Jan 18 01:44 /etc/localtime -> /usr/share/zoneinfo/EST5EDT # rm -f /etc/localtime; ln -s /usr/share/zoneinfo/EST /etc/localtime # ll /etc/localtime lrwxrwxrwx. 1 root root 23 Apr 9 16:52 /etc/localtime -> /usr/share/zoneinfo/EST # systemctl status ovirt-engine.service ● ovirt-engine.service - oVirt Engine Loaded: loaded (/usr/lib/systemd/system/ovirt-engine.service; enabled; vendor preset: disabled) Active: active (running) since Fri 2018-03-09 16:39:59 EST; 1 months 0 days ago Main PID: 1697 (ovirt-engine.py) CGroup: /system.slice/ovirt-engine.service ├─1697 /usr/bin/python /usr/share/ovirt-engine/services/ovirt-engi... └─3109 ovirt-engine -server -XX:+TieredCompilation -Xms1024M -Xmx1... Mar 09 16:39:55 controller1.localdomain systemd[1]: Starting oVirt Engine... Mar 09 16:39:56 controller1.localdomain ovirt-engine.py[1697]: 2018-03-09 16:39:5... Mar 09 16:39:59 controller1.localdomain ovirt-engine.py[1697]: 2018-03-09 16:39:5... Mar 09 16:39:59 controller1.localdomain systemd[1]: Started oVirt Engine. Hint: Some lines were ellipsized, use -l to show in full. # systemctl restart ovirt-engine.service # systemctl status ovirt-engine.service ● ovirt-engine.service - oVirt Engine Loaded: loaded (/usr/lib/systemd/system/ovirt-engine.service; enabled; vendor preset: disabled) Active: failed (Result: exit-code) since Mon 2018-04-09 16:53:27 EST; 721ms ago Process: 12454 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: 12454 (code=exited, status=1/FAILURE) Apr 09 16:53:22 controller1.localdomain systemd[1]: Starting oVirt Engine... Apr 09 16:53:22 controller1.localdomain ovirt-engine.py[12454]: 2018-04-09 16:53:... Apr 09 16:53:24 controller1.localdomain ovirt-engine.py[12454]: 2018-04-09 16:53:... Apr 09 16:53:24 controller1.localdomain systemd[1]: Started oVirt Engine. Apr 09 16:53:27 controller1.localdomain ovirt-engine.py[12454]: 2018-04-09 16:53:... Apr 09 16:53:27 controller1.localdomain systemd[1]: ovirt-engine.service: main p...E Apr 09 16:53:27 controller1.localdomain systemd[1]: Unit ovirt-engine.service en.... Apr 09 16:53:27 controller1.localdomain systemd[1]: ovirt-engine.service failed. Hint: Some lines were ellipsized, use -l to show in full. # cat /var/log/ovirt-engine/boot.log 16:53:25,619 INFO [org.jboss.modules] JBoss Modules version 1.6.0.Final-redhat-1 16:53:26,333 INFO [org.jboss.msc] JBoss MSC version 1.2.7.SP1-redhat-1 16:53:26,873 INFO [org.jboss.as] WFLYSRV0049: JBoss EAP 7.1.0.GA (WildFly Core 3.0.10.Final-redhat-1) starting 16:53:27,390 ERROR [org.jboss.msc.service.fail] MSC000001: Failed to start service jboss.as.server-controller: org.jboss.msc.service.StartException in service jboss.as.server-controller: Failed to start service at org.jboss.msc.service.ServiceControllerImpl$StartTask.run(ServiceControllerImpl.java:1978) [jboss-msc.jar:1.2.7.SP1-redhat-1] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [rt.jar:1.8.0_161] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [rt.jar:1.8.0_161] at java.lang.Thread.run(Thread.java:748) [rt.jar:1.8.0_161] Caused by: java.lang.ExceptionInInitializerError at org.jboss.as.controller.services.path.PathInfoHandler$Builder.build(PathInfoHandler.java:331) at org.jboss.as.server.ServerEnvironmentResourceDescription.registerOperations(ServerEnvironmentResourceDescription.java:124) [wildfly-server-3.0.10.Final-redhat-1.jar:3.0.10.Final-redhat-1] at org.jboss.as.controller.registry.NodeSubregistry.registerChild(NodeSubregistry.java:109) at org.jboss.as.controller.registry.ConcreteResourceRegistration.registerSubModel(ConcreteResourceRegistration.java:231) at org.jboss.as.server.controller.resources.ServerRootResourceDefinition.registerOperations(ServerRootResourceDefinition.java:355) [wildfly-server-3.0.10.Final-redhat-1.jar:3.0.10.Final-redhat-1] at org.jboss.as.controller.DelegatingResourceDefinition.registerOperations(DelegatingResourceDefinition.java:41) at org.jboss.as.controller.registry.ManagementResourceRegistration$Factory.createRegistration(ManagementResourceRegistration.java:426) at org.jboss.as.controller.AbstractControllerService.start(AbstractControllerService.java:330) at org.jboss.as.server.ServerService.start(ServerService.java:296) [wildfly-server-3.0.10.Final-redhat-1.jar:3.0.10.Final-redhat-1] at org.jboss.msc.service.ServiceControllerImpl$StartTask.startService(ServiceControllerImpl.java:2032) [jboss-msc.jar:1.2.7.SP1-redhat-1] at org.jboss.msc.service.ServiceControllerImpl$StartTask.run(ServiceControllerImpl.java:1955) [jboss-msc.jar:1.2.7.SP1-redhat-1] ... 3 more Caused by: java.time.zone.ZoneRulesException: Unknown time-zone ID: EST at java.time.zone.ZoneRulesProvider.getProvider(ZoneRulesProvider.java:272) [rt.jar:1.8.0_161] at java.time.zone.ZoneRulesProvider.getRules(ZoneRulesProvider.java:227) [rt.jar:1.8.0_161] at java.time.ZoneRegion.ofId(ZoneRegion.java:120) [rt.jar:1.8.0_161] at java.time.ZoneId.of(ZoneId.java:411) [rt.jar:1.8.0_161] at java.time.ZoneId.of(ZoneId.java:359) [rt.jar:1.8.0_161] at org.jboss.as.controller.services.path.PathInfoHandler.<clinit>(PathInfoHandler.java:86) ... 14 more 16:53:27,428 FATAL [org.jboss.as.server] WFLYSRV0239: Aborting with exit code 1 16:53:27,478 INFO [org.jboss.as] WFLYSRV0050: JBoss EAP 7.1.0.GA (WildFly Core 3.0.10.Final-redhat-1) stopped in 34ms # grep -A4 "Starting oVirt Engine" /var/log/messages Apr 9 17:53:22 controller1 systemd: Starting oVirt Engine... Apr 9 17:53:22 controller1 journal: 2018-04-09 16:53:22,816-0500 ovirt-engine: INFO _detectJBossVersion:187 Detecting JBoss version. Running: /usr/lib/jvm/jre/bin/java ['ovirt-engine-version', '-server', '-XX:+TieredCompilation', '-Xms1024M', '-Xmx1024M', '-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=/opt/rh/eap7/root/usr/share/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', '/opt/rh/eap7/root/usr/share/wildfly/jboss-modules.jar', '-mp', '/usr/share/ovirt-engine/modules/common:/usr/share/ovirt-engine-extension-aaa-jdbc/modules:/opt/rh/eap7/root/usr/share/wildfly/modules', '-jaxpmodule', 'javax.xml.jaxp-provider', 'org.jboss.as.standalone', '-v'] Apr 9 17:53:24 controller1 journal: 2018-04-09 16:53:24,127-0500 ovirt-engine: INFO _detectJBossVersion:207 Return code: 0, | stdout: '[u'JBoss EAP 7.1.0.GA (WildFly Core 3.0.10.Final-redhat-1)'], | stderr: '[]' Apr 9 17:53:24 controller1 systemd: Started oVirt Engine. Apr 9 17:53:27 controller1 journal: 2018-04-09 16:53:27,549-0500 ovirt-engine: ERROR run:554 Error: process terminated with status code 1 Great, there is actually one more component of stacktrace in there: Caused by: java.time.zone.ZoneRulesException: Unknown time-zone ID: EST at java.time.zone.ZoneRulesProvider.getProvider(ZoneRulesProvider.java:272) [rt.jar:1.8.0_161] at java.time.zone.ZoneRulesProvider.getRules(ZoneRulesProvider.java:227) [rt.jar:1.8.0_161] at java.time.ZoneRegion.ofId(ZoneRegion.java:120) [rt.jar:1.8.0_161] at java.time.ZoneId.of(ZoneId.java:411) [rt.jar:1.8.0_161] at java.time.ZoneId.of(ZoneId.java:359) [rt.jar:1.8.0_161] at org.jboss.as.controller.services.path.PathInfoHandler.<clinit>(PathInfoHandler.java:86) ... 14 more So it looks like (equivalent of) ZoneId.of("EST") is called here directly by JBossAS/wildfly. After looking to older version of wildfly (3.1.0.Final). It seems, I have found the problematic expression (same class, same line number) [1]. I don't think this is expected to work with "EST", and that 2 argument method ZoneId.of needs to be used to make it work with legacy short locales, as I noted earlier. ( Or alternatively use some alternative mechanism to obtain ZoneId object. ) [1] https://github.com/wildfly/wildfly-core/blob/3.1.0.Final/controller/src/main/java/org/jboss/as/controller/services/path/PathInfoHandler.java#L86 ^^ Or alternatively to use some other mechanism... Any update on this bug? It seems like a JBoss bug, rather than an OpenJDK issue. (In reply to Andrew John Hughes from comment #8) > Any update on this bug? It seems like a JBoss bug, rather than an OpenJDK > issue. Andrew, I apologize. Time got away from me in regards to your 2020-06-09 question. I rebuilt my January 2018 RHV cluster to now be a self-hosted one. Although my (virtual) RHV Manager has the same localtime setup: # ll -d /etc/localtime lrwxrwxrwx. 1 root root 23 Jun 28 2019 /etc/localtime -> /usr/share/zoneinfo/EST ...things seem to be working just fine with it. I am able to stop, start & restart the ovirt-engine.service with no time-zone errors. Come to think of it, I don't remember encountering this problem under this new build. So, whatever/however it got fixed, it has been fixed since I built this self-hosted RHV 4.3.9.4-11.el7 cluster in June 2019. Thanks for following up. Thanks, Bernie. Good to hear it's working for you now. Am I ok to close this bug then? (In reply to Andrew John Hughes from comment #10) > Am I ok to close this bug then? Yes; thank you all for your help and past attention on this. |