Start OMS failed with “javax.xml.stream.XMLStreamException: Premature end of file encountered”

There was one tricky problem at the customers site yesterday – Enteprise Manager was “dead”. I tried to open Enterprise Manager login page, but nothing happened… not even the famous 500 Internal server error displayed! Strange…

Ok, I logged into that server via ssh and checked log file. This is the output I found:

<Feb 19, 2015 6:46:02 PM CET> <Emergency> <Management> <BEA-141151> <The admin server could not be reached at https://example1.com:7101.>
<Feb 19, 2015 6:46:02 PM CET> <Info> <Configuration Management> <BEA-150018> <This server is being started in managed server independence mode in the abse
nce of the admin server.>
<Feb 19, 2015 6:46:02 PM CET> <Notice> <WebLogicServer> <BEA-000365> <Server state changed to STARTING>
<Feb 19, 2015 6:46:02 PM CET> <Info> <WorkManager> <BEA-002900> <Initializing self-tuning thread pool>
<Feb 19, 2015 6:46:02 PM CET> <Notice> <LoggingService> <BEA-320400> <The log file /opt/oracle/gc_inst/user_projects/domains/GCDomain/servers/EMGC_OMS1/lo
gs/EMGC_OMS1.log will be rotated. Reopen the log file if tailing has stopped. This can happen on some platforms like Windows.>
<Feb 19, 2015 6:46:02 PM CET> <Notice> <LoggingService> <BEA-320401> <The log file has been rotated to /opt/oracle/gc_inst/user_projects/domains/GCDomain/
servers/EMGC_OMS1/logs/EMGC_OMS1.log01272. Log messages will continue to be logged in /opt/oracle/gc_inst/user_projects/domains/GCDomain/servers/EMGC_OMS1
/logs/EMGC_OMS1.log.>
<Feb 19, 2015 6:46:03 PM CET> <Notice> <Log Management> <BEA-170019> <The server log file /opt/oracle/gc_inst/user_projects/domains/GCDomain/servers/EMGC_
OMS1/logs/EMGC_OMS1.log is opened. All server side log events will be written to this file.>
<Feb 19, 2015 6:46:05 PM CET> <Error> <Security> <BEA-090892> <The dynamic loading of the OPSS java security policy provider class oracle.security.jps.int
ernal.policystore.JavaPolicyProvider failed due to problem inside OPSS java security policy provider. Exception was thrown when loading or setting the JPS
S policy provider. Enable the debug flag -Djava.security.debug=jpspolicy to get more information. Error message: oracle.security.jps.JpsException: [Policy
Util] Exception while getting default policy Provider>
<Feb 19, 2015 6:46:05 PM CET> <Critical> <WebLogicServer> <BEA-000386> <Server subsystem failed. Reason: weblogic.security.SecurityInitializationException
: The dynamic loading of the OPSS java security policy provider class oracle.security.jps.internal.policystore.JavaPolicyProvider failed due to problem in
side OPSS java security policy provider. Exception was thrown when loading or setting the JPSS policy provider. Enable the debug flag -Djava.security.debu
g=jpspolicy to get more information. Error message: oracle.security.jps.JpsException: [PolicyUtil] Exception while getting default policy Provider
weblogic.security.SecurityInitializationException: The dynamic loading of the OPSS java security policy provider class oracle.security.jps.internal.policy
store.JavaPolicyProvider failed due to problem inside OPSS java security policy provider. Exception was thrown when loading or setting the JPSS policy pro
vider. Enable the debug flag -Djava.security.debug=jpspolicy to get more information. Error message: oracle.security.jps.JpsException: [PolicyUtil] Except
ion while getting default policy Provider
at weblogic.security.service.CommonSecurityServiceManagerDelegateImpl.loadOPSSPolicy(CommonSecurityServiceManagerDelegateImpl.java:1394)
at weblogic.security.service.CommonSecurityServiceManagerDelegateImpl.initialize(CommonSecurityServiceManagerDelegateImpl.java:1018)
at weblogic.security.service.SecurityServiceManager.initialize(SecurityServiceManager.java:875)
at weblogic.security.SecurityService.start(SecurityService.java:141)
at weblogic.t3.srvr.SubsystemRequest.run(SubsystemRequest.java:64)
Truncated. see log file for complete stacktrace

Caused By: oracle.security.jps.JpsRuntimeException: oracle.security.jps.JpsException: [PolicyUtil] Exception while getting default policy Provider
at oracle.security.jps.internal.policystore.PolicyDelegationController.<init>(PolicyDelegationController.java:256)
at oracle.security.jps.internal.policystore.PolicyDelegationController.<init>(PolicyDelegationController.java:248)
at oracle.security.jps.internal.policystore.JavaPolicyProvider.<init>(JavaPolicyProvider.java:130)
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:39)
Truncated. see log file for complete stacktrace

Caused By: oracle.security.jps.JpsException: [PolicyUtil] Exception while getting default policy Provider
at oracle.security.jps.internal.policystore.PolicyUtil.getDefaultPolicyStore(PolicyUtil.java:675)
at oracle.security.jps.internal.policystore.PolicyDelegationController.<init>(PolicyDelegationController.java:254)
at oracle.security.jps.internal.policystore.PolicyDelegationController.<init>(PolicyDelegationController.java:248)
at oracle.security.jps.internal.policystore.JavaPolicyProvider.<init>(JavaPolicyProvider.java:130)
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
Truncated. see log file for complete stacktrace

Caused By: java.security.PrivilegedActionException: oracle.security.jps.JpsException: [PolicyUtil] Unable to obtain default JPS Context!
at java.security.AccessController.doPrivileged(Native Method)
at oracle.security.jps.internal.policystore.PolicyUtil.getDefaultPolicyStore(PolicyUtil.java:622)
at oracle.security.jps.internal.policystore.PolicyDelegationController.<init>(PolicyDelegationController.java:254)
at oracle.security.jps.internal.policystore.PolicyDelegationController.<init>(PolicyDelegationController.java:248)
at oracle.security.jps.internal.policystore.JavaPolicyProvider.<init>(JavaPolicyProvider.java:130)
Truncated. see log file for complete stacktrace

Caused By: oracle.security.jps.JpsException: [PolicyUtil] Unable to obtain default JPS Context!
at oracle.security.jps.internal.policystore.PolicyUtil$1.run(PolicyUtil.java:637)
at oracle.security.jps.internal.policystore.PolicyUtil$1.run(PolicyUtil.java:622)
at java.security.AccessController.doPrivileged(Native Method)
at oracle.security.jps.internal.policystore.PolicyUtil.getDefaultPolicyStore(PolicyUtil.java:622)
at oracle.security.jps.internal.policystore.PolicyDelegationController.<init>(PolicyDelegationController.java:254)
Truncated. see log file for complete stacktrace

Caused By: oracle.security.jps.JpsRuntimeException: Cannot read from policy store.
at oracle.security.jps.internal.policystore.xml.XmlPolicyStore.buildFromFile(XmlPolicyStore.java:286)
at oracle.security.jps.internal.policystore.xml.XmlPolicyStore.<init>(XmlPolicyStore.java:165)
at oracle.security.jps.internal.policystore.xml.XmlPolicyStoreProvider.getInstance(XmlPolicyStoreProvider.java:104)
at oracle.security.jps.internal.policystore.xml.XmlPolicyStoreProvider.getInstance(XmlPolicyStoreProvider.java:74)
at oracle.security.jps.internal.core.runtime.ContextFactoryImpl.findServiceInstance(ContextFactoryImpl.java:139)
Truncated. see log file for complete stacktrace

Caused By: oracle.security.jps.JpsRuntimeException: javax.xml.stream.XMLStreamException: javax.xml.stream.XMLStreamException: Premature end of file encoun
tered
at oracle.security.jps.internal.core.datastore.xml.XmlDataStoreParser.getDataStoreEntryStax(XmlDataStoreParser.java:167)
at oracle.security.jps.internal.core.datastore.xml.XmlDataStoreParser.getDataStoreEntry(XmlDataStoreParser.java:182)
at oracle.security.jps.internal.core.datastore.xml.XmlDataStoreParser.getDataStoreEntry(XmlDataStoreParser.java:226)
at oracle.security.jps.internal.core.datastore.xml.XmlDataStore.loadXmlDataStore(XmlDataStore.java:391)
at oracle.security.jps.internal.core.datastore.xml.XmlDataStore.<init>(XmlDataStore.java:266)
Truncated. see log file for complete stacktrace

Caused By: javax.xml.stream.XMLStreamException: javax.xml.stream.XMLStreamException: Premature end of file encountered
at weblogic.xml.stax.XMLStreamReaderBase.prime(XMLStreamReaderBase.java:80)
at weblogic.xml.stax.XMLStreamReaderBase.setInput(XMLStreamReaderBase.java:99)
at weblogic.xml.stax.XMLStreamInputFactory.createXMLStreamReader(XMLStreamInputFactory.java:316)
at oracle.security.jps.internal.core.datastore.xml.XmlDataStoreParser.getDataStoreEntryStax(XmlDataStoreParser.java:99)
at oracle.security.jps.internal.core.datastore.xml.XmlDataStoreParser.getDataStoreEntry(XmlDataStoreParser.java:182)
Truncated. see log file for complete stacktrace

Caused By: javax.xml.stream.XMLStreamException: Premature end of file encountered
at weblogic.xml.stax.XMLStreamReaderBase.prime(XMLStreamReaderBase.java:69)
at weblogic.xml.stax.XMLStreamReaderBase.setInput(XMLStreamReaderBase.java:99)
at weblogic.xml.stax.XMLStreamInputFactory.createXMLStreamReader(XMLStreamInputFactory.java:316)
at oracle.security.jps.internal.core.datastore.xml.XmlDataStoreParser.getDataStoreEntryStax(XmlDataStoreParser.java:99)
at oracle.security.jps.internal.core.datastore.xml.XmlDataStoreParser.getDataStoreEntry(XmlDataStoreParser.java:182)
Truncated. see log file for complete stacktrace

<Feb 19, 2015 6:46:05 PM CET> <Notice> <WebLogicServer> <BEA-000365> <Server state changed to FAILED>
<Feb 19, 2015 6:46:05 PM CET> <Error> <WebLogicServer> <BEA-000383> <A critical service failed. The server will shut itself down>
<Feb 19, 2015 6:46:05 PM CET> <Notice> <WebLogicServer> <BEA-000365> <Server state changed to FORCE_SHUTTING_DOWN>
<Feb 19, 2015 6:46:05 PM> <FINEST> <NodeManager> <Waiting for the process to die: 30350>
<Feb 19, 2015 6:46:05 PM> <INFO> <NodeManager> <Server failed during startup so will not be restarted>
<Feb 19, 2015 6:46:05 PM> <FINEST> <NodeManager> <runMonitor returned, setting finished=true and notifying waiters>

Quiz question: If you had never seen the error messages like these, and you want to google for some solution, what would be your search keyword or phrase? 😉

The problem was corrupted “system-jazn-data.xml” file under /opt/oracle/gc_inst/user_projects/domains/GCDomain/config/fmwconfig/. The file size was 0 bytes! How could this happen? Frankly – no idea. I had no time to analyze it deeper.

Solution is described in this MOS Note: Start OMS failed with “javax.xml.stream.XMLStreamException: Premature end of file encountered” (Doc ID 1481158.1)

I just copied this file from some other environment and voilà – everything works fine!