[GEODE-9988] Log full exception when JNDI binding fails during cache creation

• Type: Improvement
• Status: Closed
• Priority: Major
• Resolution: Fixed
• Affects Version/s: 1.15.0
• Fix Version/s: 1.15.0
• Component/s: core
• Labels: pull-request-available
• Assignee: Jens Deppe
• Reporter: Jens Deppe
• Created: 25/Jan/22 21:47
• Updated: 22/Jun/22 20:46
• Resolved: 02/Feb/22 17:17

Description

When a cache.xml is configured with a jndi-binding construct it may fail to bind but the log does not contain a useful error message, only something like:

[warn 2022/01/25 13:26:41.286 PST  <main> tid=0x1] jndi-binding creation of SimpleDataSource failed with: org.apache.geode.internal.datasource.DataSourceCreateException: Failed to connect to "SimpleDataSource". See log for details 

The full exception stack would contain a the real cause of the problem. In this case:

java.sql.SQLNonTransientConnectionException: java.net.ConnectException : Error connecting to server localhost on port 1,528 with message Connection refused (Connection refused).
    at org.apache.derby.client.am.SQLExceptionFactory.getSQLException(Unknown Source)
    at org.apache.derby.client.am.SqlException.getSQLException(Unknown Source)
    at org.apache.derby.jdbc.ClientDriver.connect(Unknown Source)
    at org.apache.geode.internal.datasource.GemFireBasicDataSource.getConnection(GemFireBasicDataSource.java:111)
    at org.apache.geode.internal.jndi.JNDIInvoker.getConnection(JNDIInvoker.java:429)
    at org.apache.geode.internal.jndi.JNDIInvoker.validateAndBindDataSource(JNDIInvoker.java:413)
    at org.apache.geode.internal.jndi.JNDIInvoker.mapDatasource(JNDIInvoker.java:392)
    at org.apache.geode.internal.jndi.JNDIInvoker.mapDatasource(JNDIInvoker.java:366)
    at org.apache.geode.internal.cache.xmlcache.CacheXmlParser.endElement(CacheXmlParser.java:3064)
    at org.apache.geode.internal.cache.xmlcache.CacheXmlParser$DefaultHandlerDelegate.endElement(CacheXmlParser.java:3485)
    at com.sun.org.apache.xerces.internal.parsers.AbstractSAXParser.endElement(AbstractSAXParser.java:610)
    at com.sun.org.apache.xerces.internal.impl.dtd.XMLNSDTDValidator.endNamespaceScope(XMLNSDTDValidator.java:226)
    at com.sun.org.apache.xerces.internal.impl.dtd.XMLDTDValidator.handleEndElement(XMLDTDValidator.java:2007)
    at com.sun.org.apache.xerces.internal.impl.dtd.XMLDTDValidator.endElement(XMLDTDValidator.java:881)
    at com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl.scanEndElement(XMLDocumentFragmentScannerImpl.java:1784)
    at com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl$FragmentContentDriver.next(XMLDocumentFragmentScannerImpl.java:2969)
    at com.sun.org.apache.xerces.internal.impl.XMLDocumentScannerImpl.next(XMLDocumentScannerImpl.java:605)
    at com.sun.org.apache.xerces.internal.impl.XMLNSDocumentScannerImpl.next(XMLNSDocumentScannerImpl.java:113)
    at com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl.scanDocument(XMLDocumentFragmentScannerImpl.java:507)
    at com.sun.org.apache.xerces.internal.parsers.XML11Configuration.parse(XML11Configuration.java:867)
    at com.sun.org.apache.xerces.internal.parsers.XML11Configuration.parse(XML11Configuration.java:796)
    at com.sun.org.apache.xerces.internal.parsers.XMLParser.parse(XMLParser.java:142)
    at com.sun.org.apache.xerces.internal.parsers.AbstractSAXParser.parse(AbstractSAXParser.java:1216)
    at com.sun.org.apache.xerces.internal.jaxp.SAXParserImpl$JAXPSAXParser.parse(SAXParserImpl.java:644)
    at com.sun.org.apache.xerces.internal.jaxp.SAXParserImpl.parse(SAXParserImpl.java:328)
    at javax.xml.parsers.SAXParser.parse(SAXParser.java:196)
    at org.apache.geode.internal.cache.xmlcache.CacheXmlParser.parse(CacheXmlParser.java:233)
    at org.apache.geode.internal.cache.GemFireCacheImpl.loadCacheXml(GemFireCacheImpl.java:4203)
    at org.apache.geode.internal.cache.GemFireCacheImpl.initializeDeclarativeCache(GemFireCacheImpl.java:1625)
    at org.apache.geode.internal.cache.GemFireCacheImpl.initialize(GemFireCacheImpl.java:1451)
    at org.apache.geode.internal.cache.InternalCacheBuilder.create(InternalCacheBuilder.java:191)
    at org.apache.geode.internal.cache.InternalCacheBuilder.create(InternalCacheBuilder.java:158)
    at org.apache.geode.cache.CacheFactory.create(CacheFactory.java:142)
    at org.apache.geode.JtaDebug.insanity(JtaDebug.java:47)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:59)
    at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
    at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:56)
    at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
    at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
    at org.junit.runners.BlockJUnit4ClassRunner$1.evaluate(BlockJUnit4ClassRunner.java:100)
    at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:366)
    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:103)
    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:63)
    at org.junit.runners.ParentRunner$4.run(ParentRunner.java:331)
    at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:79)
    at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:329)
    at org.junit.runners.ParentRunner.access$100(ParentRunner.java:66)
    at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:293)
    at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
    at org.junit.runners.ParentRunner.run(ParentRunner.java:413)
    at org.junit.runner.JUnitCore.run(JUnitCore.java:137)
    at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:69)
    at com.intellij.rt.junit.IdeaTestRunner$Repeater$1.execute(IdeaTestRunner.java:38)
    at com.intellij.rt.execution.junit.TestsRepeater.repeat(TestsRepeater.java:11)
    at com.intellij.rt.junit.IdeaTestRunner$Repeater.startRunnerWithArgs(IdeaTestRunner.java:35)
    at com.intellij.rt.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:235)
    at com.intellij.rt.junit.JUnitStarter.main(JUnitStarter.java:54)
Caused by: ERROR 08001: java.net.ConnectException : Error connecting to server localhost on port 1,528 with message Connection refused (Connection refused).
    at org.apache.derby.client.net.NetAgent.<init>(Unknown Source)
    at org.apache.derby.client.net.NetConnection.newAgent_(Unknown Source)
    at org.apache.derby.client.am.ClientConnection.<init>(Unknown Source)
    at org.apache.derby.client.net.NetConnection.<init>(Unknown Source)
    at org.apache.derby.client.net.ClientJDBCObjectFactoryImpl.newNetConnection(Unknown Source)
    ... 59 more
Caused by: java.net.ConnectException: Connection refused (Connection refused)
    at java.net.PlainSocketImpl.socketConnect(Native Method)
    at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:476)
    at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:218)
    at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:200)
    at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:394)
    at java.net.Socket.connect(Socket.java:606)
    at java.net.Socket.connect(Socket.java:555)
    at java.net.Socket.<init>(Socket.java:451)
    at java.net.Socket.<init>(Socket.java:228)
    at javax.net.DefaultSocketFactory.createSocket(SocketFactory.java:271)
    at org.apache.derby.client.net.OpenSocketAction.run(Unknown Source)
    at org.apache.derby.client.net.OpenSocketAction.run(Unknown Source)
    at java.security.AccessController.doPrivileged(Native Method)
    ... 64 more 

Issue Links

• links to: GitHub Pull Request #7304