Database connection FAULTED (Ignition v8.1.18)

edward.fowler · July 29, 2022, 7:14pm

Our gateway has been running fine, logging data, updating Perspective view, nothing out of the ordinary. Then mid week we started get Modbus timeout, database query timeouts…various odd things. And today we’re getting Database connection Faulted errors.

Also, when changing views on the gateway config or status views, we’re getting “Waiting for cache…” or “Waiting for socket connection…” popups on the bottom left of the Chrome browser tab.

Any ideas?

java.sql.SQLException: Cannot get a connection, pool error Timeout waiting for idle object
at org.apache.commons.dbcp2.PoolingDataSource.getConnection(PoolingDataSource.java:142)
at org.apache.commons.dbcp2.BasicDataSource.getConnection(BasicDataSource.java:734)
at com.inductiveautomation.ignition.gateway.datasource.DatasourceImpl.getConnectionInternal(DatasourceImpl.java:300)
at com.inductiveautomation.ignition.gateway.datasource.DatasourceManagerImpl.getConnectionImpl(DatasourceManagerImpl.java:169)
at com.inductiveautomation.ignition.gateway.datasource.DatasourceImpl.getConnection(DatasourceImpl.java:293)
at com.inductiveautomation.ignition.gateway.datasource.DatasourceManagerImpl.getConnection(DatasourceManagerImpl.java:152)
at com.inductiveautomation.gateway.tags.history.processing.GatewayContextConnectionProvider.getConnection(GatewayContextConnectionProvider.java:31)
at com.inductiveautomation.gateway.tags.history.processing.GatewayContextConnectionProvider.getConnection(GatewayContextConnectionProvider.java:10)
at com.inductiveautomation.gateway.tags.history.query.DatasourceHistoryInterface.getConnection(DatasourceHistoryInterface.java:77)
at com.inductiveautomation.gateway.tags.history.query.DatasourceHistoryInterface.maybeLoadIds(DatasourceHistoryInterface.java:96)
at com.inductiveautomation.gateway.tags.history.query.DatasourceHistoryInterface.getSystemId(DatasourceHistoryInterface.java:159)
at com.inductiveautomation.gateway.tags.history.query.DatasourceQueryExecutor.initialize(DatasourceQueryExecutor.java:544)
at com.inductiveautomation.ignition.gateway.sqltags.history.query.AggregateHistoryQueryExecutor.initialize(AggregateHistoryQueryExecutor.java:78)
at com.inductiveautomation.ignition.gateway.sqltags.history.query.HistoryWriter.initLoader(HistoryWriter.java:141)
at com.inductiveautomation.ignition.gateway.sqltags.history.query.HistoryWriter.execute(HistoryWriter.java:211)
at com.inductiveautomation.ignition.gateway.sqltags.history.TagHistoryManagerImpl.queryHistory(TagHistoryManagerImpl.java:555)
at com.inductiveautomation.ignition.gateway.tags.model.ProjectDefaultTagManagerFacade.queryHistory(ProjectDefaultTagManagerFacade.java:440)
at com.inductiveautomation.perspective.gateway.components.PowerChartModelDelegate$TagHistoryFetch.fetch(PowerChartModelDelegate.java:237)
at com.inductiveautomation.perspective.gateway.comm.FetchableCacheImpl.lambda$fetch$0(FetchableCacheImpl.java:47)
at com.inductiveautomation.perspective.gateway.threading.BlockingWork.invokeBlockingTask(BlockingWork.java:34)
at com.inductiveautomation.perspective.gateway.comm.FetchableCacheImpl.fetch(FetchableCacheImpl.java:47)
at com.inductiveautomation.perspective.gateway.comm.Routes.handleFetch(Routes.java:2233)
at com.inductiveautomation.ignition.gateway.dataroutes.Route.service(Route.java:254)
at com.inductiveautomation.ignition.gateway.dataroutes.RouteGroupImpl.service(RouteGroupImpl.java:61)
at com.inductiveautomation.ignition.gateway.dataroutes.RouteGroupCollectionServlet.serviceInternal(RouteGroupCollectionServlet.java:59)
at com.inductiveautomation.ignition.gateway.dataroutes.AbstractRouteGroupServlet.service(AbstractRouteGroupServlet.java:38)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)

at org.eclipse.jetty.servlet.ServletHolder$NotAsync.service(ServletHolder.java:1450)

at org eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:799)
at org.eclipse.jetty.servlet.ServletHandler$ChainEnd.doFilter(ServletHandler.java:1631)
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:548)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)
at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:600)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:235)
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1624)
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1440)
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:501)
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1594)
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1355)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
at com.inductiveautomation.catapult.handlers.RemoteHostNameLookupHandler.handle(RemoteHostNameLookupHandler.java:121)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
at org.eclipse.jetty.rewrite.handler.RewriteHandler.handle(RewriteHandler.java:322)
at org.eclipse.jetty.server.handler.HandlerList.handle(HandlerList.java:59)
at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:146)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
at org.eclipse.jetty.server.Server.handle(Server.java:516)
at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:487)
at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:732)
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:479)
at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:277)
at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105)
at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:338)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:315)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:173)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:131)
at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:409)
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:883)
at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1034)
at java.base/java.lang.Thread.run(Unknown Source)
Caused by: java.util.NoSuchElementException: Timeout waiting for idle object
at org.apache.commons.pool2.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:321)
at org.apache.commons.pool2.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:428)
at org.apache.commons.pool2.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:232)
at org.apache.commons.dbcp2.PoolingDataSource.getConnection(PoolingDataSource.java:134)
... 66 common frames omitted

pturmel · July 29, 2022, 7:19pm

Looks like DB starvation due to multiple pathological query duration due to excessive time frames on a Power Chart. Do you have someone new trying to mine historical data?

edward.fowler · July 29, 2022, 8:11pm

Hi Phil.
I suspected as such. I have a few users (not Designers) monitoring views with Power Charts…perhaps 4 simultaneous sessions. But they’ve been doing that for a couple of weeks. I don’t know what changed this week but on Wednesday memory usage jumped as well…not sure of the cause of that either.

I’m thinking the active & recent queries are browsers with Power Charts. I’m going to ask all my users to navigate to a view that doesn’t have any power charts and see if there’s a difference. It’s too bad this status page doesn’t tell me where the queries are coming from.

pturmel · July 29, 2022, 8:37pm

Consider setting up an extra database connection that all of your history queries go through. Insertion and operator sparklines stay on the primary connection.

edward.fowler · July 29, 2022, 8:51pm

@pturmel So I checked, It seems that we probably had 7 Power Charts open, each with about 10 pens. I had all of them closed and the database and query errors disappeared. Good to know. Thanks for the advice Phil.

pturmel · July 29, 2022, 9:17pm

Hmm. That doesn’t sound like that big a load. Look for missing indices in your history tables. Or other optimizations. (Via your DB’s equivalent of EXPLAIN.)

MMaynard · July 30, 2022, 3:02pm

Also if it is MS SQL Server make sure you have a weekly maintenance task to at the very least rebuild indexes. Once you start getting into lots of history records the indexes will get extremely fragmented.

I’ve found it best to go down to weekly partition sizes with a weekly index rebuild.