We recently began using the Edge Historian (Ignition 7.9.12) with a few tags to store high resolution short term history for some real-time charts in addition to the lower resolution long time history we store with a remote historian. It works great until it doesn’t and begins spamming the logs with ResultWriter errors:
ResultWriter error details
java.lang.RuntimeException: java.util.concurrent.TimeoutException: Query took over 30 seconds to produce data.
at com.inductiveautomation.gateway.tsdb.impl.BasicQueryResult.next(BasicQueryResult.java:128)
at com.inductiveautomation.gateway.tsdb.impl.BasicQueryResult.next(BasicQueryResult.java:22)
at com.inductiveautomation.gateway.tags.history.tsdb.HistorianQueryExecutor.moveForward(HistorianQueryExecutor.java:163)
at com.inductiveautomation.gateway.tags.history.tsdb.HistorianQueryExecutor.processData(HistorianQueryExecutor.java:177)
at com.inductiveautomation.ignition.gateway.sqltags.history.query.HistoryWriter.readData(HistoryWriter.java:308)
at com.inductiveautomation.ignition.gateway.sqltags.history.query.HistoryWriter.execute(HistoryWriter.java:230)
at com.inductiveautomation.ignition.gateway.sqltags.SQLTagsManagerImpl.queryHistory(SQLTagsManagerImpl.java:1280)
at com.inductiveautomation.ignition.gateway.sqltags.history.distributed.TagHistoryServiceImpl.lambda$queryTagHistory$3(TagHistoryServiceImpl.java:104)
at java.lang.Thread.run(Unknown Source)
Caused by: java.util.concurrent.TimeoutException: Query took over 30 seconds to produce data.
at com.inductiveautomation.gateway.tsdb.impl.BasicQueryResult.next(BasicQueryResult.java:116)
… 8 common frames omitted
Restarting the tag historian module looks like this in the logs:
After the tag historian module restart, charts in clients display remote historian data again (which was logged all along, but not displayed), but the Edge Historian is still offline (related to 20Nov2019 09:00:46 error above).
20Nov2019 09:00:46 Tags error details
org.sqlite.SQLiteException: [SQLITE_BUSY] The database file is locked (database is locked)
at org.sqlite.core.DB.newSQLException(DB.java:909)
at org.sqlite.core.DB.newSQLException(DB.java:921)
at org.sqlite.core.DB.throwex(DB.java:886)
at org.sqlite.core.NativeDB._exec_utf8(Native Method)
at org.sqlite.core.NativeDB._exec(NativeDB.java:87)
at org.sqlite.jdbc3.JDBC3Statement.executeUpdate(JDBC3Statement.java:116)
at com.inductiveautomation.gateway.tsdb.historians.SQLiteHistorian.runUpdateQuery(SQLiteHistorian.java:433)
at com.inductiveautomation.gateway.tsdb.historians.SQLiteHistorian$Tables.verifyTables(SQLiteHistorian.java:801)
at com.inductiveautomation.gateway.tsdb.historians.SQLiteHistorian.initialize(SQLiteHistorian.java:171)
at com.inductiveautomation.gateway.tags.history.tsdb.HistorianProvider.initialize(HistorianProvider.java:69)
at com.inductiveautomation.gateway.tags.history.edge.EdgeHistorianProviderType$EdgeHistorian.(EdgeHistorianProviderType.java:91)
at com.inductiveautomation.gateway.tags.history.edge.EdgeHistorianProviderType.createHistoryProvider(EdgeHistorianProviderType.java:52)
at com.inductiveautomation.ignition.gateway.sqltags.SQLTagsManagerImpl.instantiateHistoryProvider(SQLTagsManagerImpl.java:408)
at com.inductiveautomation.ignition.gateway.sqltags.SQLTagsManagerImpl.addSQLTagHistoryProviderType(SQLTagsManagerImpl.java:298)
at com.inductiveautomation.gateway.tags.history.module.TagHistorianGatewayHook.registerType(TagHistorianGatewayHook.java:107)
at com.inductiveautomation.gateway.tags.history.module.TagHistorianGatewayHook.setupTagHistorian(TagHistorianGatewayHook.java:115)
at com.inductiveautomation.gateway.tags.history.module.TagHistorianGatewayHook.setup(TagHistorianGatewayHook.java:102)
at com.inductiveautomation.ignition.gateway.modules.ModuleManagerImpl$LoadedModule.setup(ModuleManagerImpl.java:2282)
at com.inductiveautomation.ignition.gateway.modules.ModuleManagerImpl.startupModule(ModuleManagerImpl.java:1122)
at com.inductiveautomation.ignition.gateway.modules.ModuleManagerImpl$4.call(ModuleManagerImpl.java:813)
at com.inductiveautomation.ignition.gateway.modules.ModuleManagerImpl.executeModuleOperation(ModuleManagerImpl.java:860)
at com.inductiveautomation.ignition.gateway.modules.ModuleManagerImpl.restartModuleInternal(ModuleManagerImpl.java:792)
at com.inductiveautomation.ignition.gateway.modules.ModuleManagerImpl.restartModule(ModuleManagerImpl.java:784)
at com.inductiveautomation.ignition.gateway.web.pages.config.ModulePage$RestartAction.execute(ModulePage.java:561)
at com.inductiveautomation.ignition.gateway.web.components.ConfirmationPanel$1.onClick(ConfirmationPanel.java:49)
at org.apache.wicket.markup.html.link.Link.onLinkClicked(Link.java:189)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at org.apache.wicket.RequestListenerInterface.internalInvoke(RequestListenerInterface.java:258)
at org.apache.wicket.RequestListenerInterface.invoke(RequestListenerInterface.java:216)
at org.apache.wicket.core.request.handler.ListenerInterfaceRequestHandler.invokeListener(ListenerInterfaceRequestHandler.java:240)
at org.apache.wicket.core.request.handler.ListenerInterfaceRequestHandler.respond(ListenerInterfaceRequestHandler.java:226)
at org.apache.wicket.request.cycle.RequestCycle$HandlerExecutor.respond(RequestCycle.java:814)
at org.apache.wicket.request.RequestHandlerStack.execute(RequestHandlerStack.java:64)
at org.apache.wicket.request.cycle.RequestCycle.execute(RequestCycle.java:253)
at org.apache.wicket.request.cycle.RequestCycle.processRequest(RequestCycle.java:210)
at org.apache.wicket.request.cycle.RequestCycle.processRequestAndDetach(RequestCycle.java:281)
at org.apache.wicket.protocol.http.WicketFilter.processRequest(WicketFilter.java:188)
at org.apache.wicket.protocol.http.WicketFilter.doFilter(WicketFilter.java:245)
at com.inductiveautomation.ignition.gateway.bootstrap.SRFilter.doFilter(SRFilter.java:80)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1668)
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:581)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)
at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548)
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:226)
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1160)
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:511)
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1092)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
at org.eclipse.jetty.server.handler.HandlerList.handle(HandlerList.java:52)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134)
at org.eclipse.jetty.server.Server.handle(Server.java:518)
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:308)
at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:244)
at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273)
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95)
at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93)
at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceAndRun(ExecuteProduceConsume.java:246)
at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:156)
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:654)
at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572)
at java.lang.Thread.run(Unknown Source)
At this point, the Edge Historian local tag history provider shows as disabled on the gateway status page:
However, if we edit it, it shows as enabled:
After saving it as above (as it was when edit opened), it continues to show disabled. Restarting the gateway via
gwcmd -r
resolves the issue. Edge Historian local tag history begins logging and displaying again as expected… until the next error.
Any suggestions to diagnose/resolve this issue?