Ignition 7.9.5 Internal Error Page

RonB · October 18, 2021, 8:33pm

Running Ignition on Windows Server 2012
Ram 16GB,
64x.

Checked the Ignition config file to make sure the setting wasn’t default 1GB.

Initial Java Heap Size (in MB)

wrapper.java.initmemory=2048

Maximum Java Heap Size (in MB)

wrapper.java.maxmemory=8192

I notice that when I navigate to “configure; OPC-UA Server; Devices” I can add a device without issue, but after it finishes and I’m on the main Device page after a few moments I am redirected in chrome to “internal error: Please return to homepage” In which case, I click the link and off I go to repeat the above. I have left the page up on the Status, logs screen as well and had the same issue.
I’m fairly new to Ignition, but tried to look through the wrapper log file, but didn’t see anything that stood out. There are several connections that are having issues, but with 80+ devices I would expect a few to be having trouble.

If anyone has any tips, I’m all ears. Thank you.

pturmel · October 18, 2021, 8:41pm

There should be log entries for the successful creation of the device. Monitoring its status would be separate. Show us the log from successful device creation until the monitor page faults. Also let us know what drivers are involved. (Please use the preformat button after pasting your log.)

Note that 7.9.5 is now ancient and support will almost certainly ask you to upgrade.

RonB · October 19, 2021, 1:44pm

INFO   | jvm 1    | 2021/10/19 09:33:08 | I [d.CompactLogixDriver          ] [13:33:08]: Processor info: Vendor=1, Product Type=14, Product Code=65, Revision=17.4, Product Name=1769-L35E/A LOGIX5335E device-name=_SFPT_B-Brooks_010161206141_InMotion
INFO   | jvm 1    | 2021/10/19 09:33:08 | I [c.i.x.d.a.t.t.ABControlLogixTagManager] [13:33:08]: Device tags file not found for filePath of=data\drivers\_SFPT_B-Brooks_010161206141_InMotion\_SFPT_B-Brooks_010161206141_InMotion.tags, key=10.161.206.141,0, 
INFO   | jvm 1    | 2021/10/19 09:33:08 | java.io.FileNotFoundException: data\drivers\_SFPT_B-Brooks_010161206141_InMotion\_SFPT_B-Brooks_010161206141_InMotion.tags (The system cannot find the file specified)
INFO   | jvm 1    | 2021/10/19 09:33:08 | 	at java.io.FileInputStream.open0(Native Method)
INFO   | jvm 1    | 2021/10/19 09:33:08 | 	at java.io.FileInputStream.open(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:33:08 | 	at java.io.FileInputStream.<init>(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:33:08 | 	at java.io.FileInputStream.<init>(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:33:08 | 	at com.inductiveautomation.xopc.drivers.allenbradley.transport.tag.ABControlLogixTagManager.loadTagManager(ABControlLogixTagManager.java:65)
INFO   | jvm 1    | 2021/10/19 09:33:08 | 	at com.inductiveautomation.xopc.drivers.allenbradley.ControlLogixDriver.driverNotifyConnectSucceeded(ControlLogixDriver.java:597)
INFO   | jvm 1    | 2021/10/19 09:33:08 | 	at com.inductiveautomation.xopc.drivers.allenbradley.requests.ABControlLogixConnectRequest.receiveMessage(ABControlLogixConnectRequest.java:175)
INFO   | jvm 1    | 2021/10/19 09:33:08 | 	at com.inductiveautomation.xopc.drivers.allenbradley.requests.ABControlLogixConnectRequest.receiveMessage(ABControlLogixConnectRequest.java:21)
INFO   | jvm 1    | 2021/10/19 09:33:08 | 	at com.inductiveautomation.xopc.driver.api.BasicRequestCycle$PendingRequest.receiveMessage(BasicRequestCycle.java:431)
INFO   | jvm 1    | 2021/10/19 09:33:08 | 	at com.inductiveautomation.xopc.driver.api.BasicRequestCycle.deliverMessage(BasicRequestCycle.java:201)
INFO   | jvm 1    | 2021/10/19 09:33:08 | 	at com.inductiveautomation.xopc.driver.api.BasicRequestCycle.messageArrived(BasicRequestCycle.java:183)
INFO   | jvm 1    | 2021/10/19 09:33:08 | 	at com.inductiveautomation.xopc.driver.api.AbstractDriver.messageArrived(AbstractDriver.java:789)
INFO   | jvm 1    | 2021/10/19 09:33:08 | 	at com.inductiveautomation.xopc.driver.api.AbstractSocketDriver.messageArrived(AbstractSocketDriver.java:188)
INFO   | jvm 1    | 2021/10/19 09:33:08 | 	at com.inductiveautomation.xopc.driver.api.AbstractSocketDriver$DriverIOEventHandler$1.run(AbstractSocketDriver.java:250)
INFO   | jvm 1    | 2021/10/19 09:33:08 | 	at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:33:08 | 	at java.util.concurrent.FutureTask.run(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:33:08 | 	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:33:08 | 	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:33:08 | 	at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:33:08 | 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:33:08 | 	at java.lang.Thread.run(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:33:08 | I [c.i.x.d.a.r.ABControlLogixBrowseRequest] [13:33:08]: [_SFPT_B-Brooks_010161206141_InMotion] Creating browse request using HIGH priority. 
INFO   | jvm 1    | 2021/10/19 09:33:13 | 	at java.lang.Thread.run(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:33:26 | E [d.MicroLogixDriver            ] [13:33:26]: Socket connection closed; DriverState was Connected. device-name=_SFPT_P-Louisville_010160173135_InmotionRibRoom
INFO   | jvm 1    | 2021/10/19 09:33:26 | java.net.SocketException: Connection reset
INFO   | jvm 1    | 2021/10/19 09:33:26 | 	at java.net.SocketInputStream.read(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:33:26 | 	at java.net.SocketInputStream.read(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:33:26 | 	at java.net.SocketInputStream.read(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:33:26 | 	at com.inductiveautomation.iosession.socket.AsyncSocketIOSession.run(AsyncSocketIOSession.java:71)
INFO   | jvm 1    | 2021/10/19 09:33:26 | 	at java.lang.Thread.run(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:33:32 | E [d.M.SocketIODelegate          ] [13:33:32]: [hostname=10.160.80.51,port=502] Socket connection closed, DriverState was Connected. device-name=Red Zone 10.160.80.51
INFO   | jvm 1    | 2021/10/19 09:33:32 | java.net.SocketException: Connection reset
INFO   | jvm 1    | 2021/10/19 09:33:32 | 	at java.net.SocketInputStream.read(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:33:32 | 	at java.net.SocketInputStream.read(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:33:32 | 	at java.net.SocketInputStream.read(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:33:32 | 	at com.inductiveautomation.iosession.socket.AsyncSocketIOSession.run(AsyncSocketIOSession.java:71)
INFO   | jvm 1    | 2021/10/19 09:33:32 | 	at java.lang.Thread.run(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:33:42 | E [d.SLCEthernetDriver           ] [13:33:42]: Socket connection closed; DriverState was Connected. device-name=Penthouse Case Ready Refrig
INFO   | jvm 1    | 2021/10/19 09:33:42 | java.net.SocketTimeoutException: Read timed out
INFO   | jvm 1    | 2021/10/19 09:33:42 | 	at java.net.SocketInputStream.socketRead0(Native Method)
INFO   | jvm 1    | 2021/10/19 09:33:42 | 	at java.net.SocketInputStream.socketRead(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:33:42 | 	at java.net.SocketInputStream.read(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:33:42 | 	at java.net.SocketInputStream.read(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:33:42 | 	at java.net.SocketInputStream.read(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:33:42 | 	at com.inductiveautomation.iosession.socket.AsyncSocketIOSession.run(AsyncSocketIOSession.java:71)
INFO   | jvm 1    | 2021/10/19 09:33:42 | 	at java.lang.Thread.run(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:33:47 | I [c.i.x.d.a.r.ABControlLogixBrowseRequest] [13:33:47]: [_SFPT_B-Brooks_010161206141_InMotion] Creating browse nodes. 
INFO   | jvm 1    | 2021/10/19 09:33:47 | I [c.i.x.d.a.r.ABControlLogixBrowseRequest] [13:33:47]: [_SFPT_B-Brooks_010161206141_InMotion] Browse complete. 
INFO   | jvm 1    | 2021/10/19 09:33:47 | I [d.CompactLogixDriver          ] [13:33:47]: [_SFPT_B-Brooks_010161206141_InMotion] Browse complete. device-name=_SFPT_B-Brooks_010161206141_InMotion
INFO   | jvm 1    | 2021/10/19 09:33:47 | I [d.CompactLogixDriver          ] [13:33:47]: [_SFPT_B-Brooks_010161206141_InMotion] Updating tagManager with edit version 3329 with 290 tags device-name=_SFPT_B-Brooks_010161206141_InMotion
INFO   | jvm 1    | 2021/10/19 09:33:51 | E [d.SLCEthernetDriver           ] [13:33:51]: Socket connection closed; DriverState was Connected. device-name=Penthouse Case Ready Refrig
INFO   | jvm 1    | 2021/10/19 09:33:51 | java.net.SocketTimeoutException: Read timed out
INFO   | jvm 1    | 2021/10/19 09:33:51 | 	at java.net.SocketInputStream.socketRead0(Native Method)
INFO   | jvm 1    | 2021/10/19 09:33:51 | 	at java.net.SocketInputStream.socketRead(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:33:51 | 	at java.net.SocketInputStream.read(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:33:51 | 	at java.net.SocketInputStream.read(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:33:51 | 	at java.net.SocketInputStream.read(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:33:51 | 	at com.inductiveautomation.iosession.socket.AsyncSocketIOSession.run(AsyncSocketIOSession.java:71)
INFO   | jvm 1    | 2021/10/19 09:33:51 | 	at java.lang.Thread.run(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:33:55 | E [d.T.TCPConnection[14151]      ] [13:33:55]: Error connecting to 10.160.88.42:14151. Connection timed out: connect 
INFO   | jvm 1    | 2021/10/19 09:34:04 | E [d.T.TCPConnection[14152]      ] [13:34:04]: Error connecting to 10.160.88.43:14152. Connection timed out: connect 
INFO   | jvm 1    | 2021/10/19 09:34:08 | E [d.M.SocketIODelegate          ] [13:34:08]: [hostname=10.160.80.52,port=502] Socket connection closed, DriverState was Connected. device-name=Red Zone 10.160.80.52
INFO   | jvm 1    | 2021/10/19 09:34:08 | java.net.SocketException: Connection reset
INFO   | jvm 1    | 2021/10/19 09:34:08 | 	at java.net.SocketInputStream.read(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:34:08 | 	at java.net.SocketInputStream.read(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:34:08 | 	at java.net.SocketInputStream.read(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:34:08 | 	at com.inductiveautomation.iosession.socket.AsyncSocketIOSession.run(AsyncSocketIOSession.java:71)
INFO   | jvm 1    | 2021/10/19 09:34:08 | 	at java.lang.Thread.run(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:34:10 | I [P.InternalDatabase            ] [13:34:10]: Creating auto-backup of internal database "config.idb"... 
INFO   | jvm 1    | 2021/10/19 09:34:15 | W [d.S.B.TimeoutDaemon           ] [13:34:15]: ScheduledRequest[com.inductiveautomation.xopc.drivers.allenbradley.requests.ABSLCReadRequest@1255e34] request with key "306" failed due to timeout. device-name=Penthouse Case Ready Refrig
INFO   | jvm 1    | 2021/10/19 09:34:15 | W [d.S.ABSLCReadRequest          ] [13:34:15]: Read Request timeout. First item: b26:0/5, Timeout Count: 1, Transaction: 306 device-name=Penthouse Case Ready Refrig
INFO   | jvm 1    | 2021/10/19 09:34:15 | E [d.SLCEthernetDriver           ] [13:34:15]: Socket connection closed; DriverState was Connected. device-name=Penthouse Case Ready Refrig
INFO   | jvm 1    | 2021/10/19 09:34:15 | java.net.SocketTimeoutException: Read timed out
INFO   | jvm 1    | 2021/10/19 09:34:15 | 	at java.net.SocketInputStream.socketRead0(Native Method)
INFO   | jvm 1    | 2021/10/19 09:34:15 | 	at java.net.SocketInputStream.socketRead(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:34:15 | 	at java.net.SocketInputStream.read(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:34:15 | 	at java.net.SocketInputStream.read(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:34:15 | 	at java.net.SocketInputStream.read(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:34:15 | 	at com.inductiveautomation.iosession.socket.AsyncSocketIOSession.run(AsyncSocketIOSession.java:71)
INFO   | jvm 1    | 2021/10/19 09:34:15 | 	at java.lang.Thread.run(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:34:35 | E [d.M.SocketIODelegate          ] [13:34:35]: [hostname=10.160.80.51,port=502] Socket connection closed, DriverState was Connected. device-name=Red Zone 10.160.80.51
INFO   | jvm 1    | 2021/10/19 09:34:35 | java.net.SocketException: Connection reset
INFO   | jvm 1    | 2021/10/19 09:34:35 | 	at java.net.SocketInputStream.read(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:34:35 | 	at java.net.SocketInputStream.read(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:34:35 | 	at java.net.SocketInputStream.read(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:34:35 | 	at com.inductiveautomation.iosession.socket.AsyncSocketIOSession.run(AsyncSocketIOSession.java:71)
INFO   | jvm 1    | 2021/10/19 09:34:35 | 	at java.lang.Thread.run(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:34:42 | E [c.i.i.g.l.s.SingleConnectionDatasource] [13:34:42]: The following stack successfully received a connection. A new attempt was blocked for over 30000 ms 
INFO   | jvm 1    | 2021/10/19 09:34:42 | java.lang.Throwable: null
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at com.inductiveautomation.ignition.gateway.localdb.sqlite.SingleConnectionDatasource.getConnection(SingleConnectionDatasource.java:58)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at com.inductiveautomation.ignition.gateway.localdb.sqlite.SQLiteDBManager$AutoBackupDaemon.run(SQLiteDBManager.java:666)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at com.inductiveautomation.ignition.common.execution.impl.BasicExecutionEngine$TrackedTask.run(BasicExecutionEngine.java:565)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at java.util.concurrent.FutureTask.runAndReset(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at java.lang.Thread.run(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:34:42 | W [ProjectManager                ] [13:34:42]: Unable to prune project change records. 
INFO   | jvm 1    | 2021/10/19 09:34:42 | simpleorm.utils.SException$Jdbc: Opening com.inductiveautomation.ignition.gateway.localdb.CountingDataSource@28a9c566
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at simpleorm.sessionjdbc.SSessionJdbc.innerOpen(SSessionJdbc.java:113)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at com.inductiveautomation.ignition.gateway.localdb.persistence.PersistenceSession.initialize(PersistenceSession.java:31)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at com.inductiveautomation.ignition.gateway.localdb.PersistenceInterfaceImpl.getSession(PersistenceInterfaceImpl.java:62)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at com.inductiveautomation.ignition.gateway.localdb.PersistenceInterfaceImpl.getSession(PersistenceInterfaceImpl.java:44)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at com.inductiveautomation.ignition.gateway.project.ProjectManagerImpl$ProjectCleanupTask.pruneProjectChangeRecords(ProjectManagerImpl.java:2226)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at com.inductiveautomation.ignition.gateway.project.ProjectManagerImpl$ProjectCleanupTask.run(ProjectManagerImpl.java:2211)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at com.inductiveautomation.ignition.common.execution.impl.BasicExecutionEngine$TrackedTask.run(BasicExecutionEngine.java:565)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at java.util.concurrent.FutureTask.runAndReset(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at java.lang.Thread.run(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:34:42 | Caused by: java.sql.SQLException: Connection is locked. Datasource only allows one connection at a time. More information was logged to the gateway console.
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at com.inductiveautomation.ignition.gateway.localdb.sqlite.SingleConnectionDatasource.getConnection(SingleConnectionDatasource.java:75)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at com.inductiveautomation.ignition.gateway.localdb.DelegatingDataSource.getConnection(DelegatingDataSource.java:60)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at simpleorm.sessionjdbc.SSessionJdbc.innerOpen(SSessionJdbc.java:111)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	... 13 common frames omitted
INFO   | jvm 1    | 2021/10/19 09:34:42 | E [c.i.i.g.l.s.SingleConnectionDatasource] [13:34:42]: The following stack successfully received a connection. A new attempt was blocked for over 30000 ms tag-provider=default
INFO   | jvm 1    | 2021/10/19 09:34:42 | java.lang.Throwable: null
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at com.inductiveautomation.ignition.gateway.localdb.sqlite.SingleConnectionDatasource.getConnection(SingleConnectionDatasource.java:58)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at com.inductiveautomation.ignition.gateway.localdb.sqlite.SQLiteDBManager$AutoBackupDaemon.run(SQLiteDBManager.java:666)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at com.inductiveautomation.ignition.common.execution.impl.BasicExecutionEngine$TrackedTask.run(BasicExecutionEngine.java:565)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at java.util.concurrent.FutureTask.runAndReset(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at java.lang.Thread.run(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:34:42 | E [T.P.Config                    ] [13:34:42]: Error storing tag values. tag-provider=default
INFO   | jvm 1    | 2021/10/19 09:34:42 | simpleorm.utils.SException$Jdbc: Opening com.inductiveautomation.ignition.gateway.localdb.sqlite.SingleConnectionDatasource@6ac175dc
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at simpleorm.sessionjdbc.SSessionJdbc.innerOpen(SSessionJdbc.java:113)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at com.inductiveautomation.ignition.gateway.localdb.persistence.PersistenceSession.initialize(PersistenceSession.java:31)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at com.inductiveautomation.ignition.gateway.localdb.PersistenceInterfaceImpl.getSession(PersistenceInterfaceImpl.java:62)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at com.inductiveautomation.ignition.gateway.localdb.PersistenceInterfaceImpl.getSession(PersistenceInterfaceImpl.java:44)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at com.inductiveautomation.ignition.gateway.sqltags.tagproviders.internal.InternalTagStore.openIfNot(InternalTagStore.java:1303)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at com.inductiveautomation.ignition.gateway.sqltags.tagproviders.internal.InternalTagStore.internalStoreTagValues(InternalTagStore.java:1341)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at com.inductiveautomation.ignition.gateway.sqltags.tagproviders.internal.InternalTagStore.storeTagValues(InternalTagStore.java:1250)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at com.inductiveautomation.ignition.gateway.sqltags.providers.AbstractStoreBasedTagProvider.tagValuesChanged(AbstractStoreBasedTagProvider.java:2418)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at com.inductiveautomation.ignition.gateway.sqltags.scanclasses.SimpleExecutableScanClass$ScanClassTagEvaluationContext.processAndReset(SimpleExecutableScanClass.java:1136)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at com.inductiveautomation.ignition.gateway.sqltags.scanclasses.SimpleExecutableScanClass.run(SimpleExecutableScanClass.java:896)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at com.inductiveautomation.ignition.common.execution.impl.BasicExecutionEngine$SelfSchedulingRunner.run(BasicExecutionEngine.java:483)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at com.inductiveautomation.ignition.common.execution.impl.BasicExecutionEngine$TrackedTask.run(BasicExecutionEngine.java:565)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at java.util.concurrent.FutureTask.run(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at java.lang.Thread.run(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:34:42 | Caused by: java.sql.SQLException: Connection is locked. Datasource only allows one connection at a time. More information was logged to the gateway console.
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at com.inductiveautomation.ignition.gateway.localdb.sqlite.SingleConnectionDatasource.getConnection(SingleConnectionDatasource.java:75)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	at simpleorm.sessionjdbc.SSessionJdbc.innerOpen(SSessionJdbc.java:111)
INFO   | jvm 1    | 2021/10/19 09:34:42 | 	... 18 common frames omitted
INFO   | jvm 1    | 2021/10/19 09:34:48 | E [c.i.i.g.l.s.SingleConnectionDatasource] [13:34:48]: The following stack successfully received a connection. A new attempt was blocked for over 30000 ms 
INFO   | jvm 1    | 2021/10/19 09:34:48 | java.lang.Throwable: null
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at com.inductiveautomation.ignition.gateway.localdb.sqlite.SingleConnectionDatasource.getConnection(SingleConnectionDatasource.java:58)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at com.inductiveautomation.ignition.gateway.localdb.sqlite.SQLiteDBManager$AutoBackupDaemon.run(SQLiteDBManager.java:666)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at com.inductiveautomation.ignition.common.execution.impl.BasicExecutionEngine$TrackedTask.run(BasicExecutionEngine.java:565)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at java.util.concurrent.FutureTask.runAndReset(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at java.lang.Thread.run(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:34:48 | E [o.a.w.DefaultExceptionMapper  ] [13:34:48]: Unexpected error occurred 
INFO   | jvm 1    | 2021/10/19 09:34:48 | org.apache.wicket.WicketRuntimeException: Exception in rendering component: [HtmlHeaderContainer [Component id = _header_54]]
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.apache.wicket.Component.internalRenderComponent(Component.java:2562)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.apache.wicket.MarkupContainer.onRender(MarkupContainer.java:1491)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.apache.wicket.Component.internalRender(Component.java:2365)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.apache.wicket.Component.render(Component.java:2293)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.apache.wicket.MarkupContainer.renderNext(MarkupContainer.java:1388)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.apache.wicket.MarkupContainer.renderAll(MarkupContainer.java:1553)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.apache.wicket.Page.onRender(Page.java:884)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.apache.wicket.markup.html.WebPage.onRender(WebPage.java:142)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.apache.wicket.Component.internalRender(Component.java:2365)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.apache.wicket.Component.render(Component.java:2293)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.apache.wicket.Page.renderPage(Page.java:1021)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.apache.wicket.request.handler.render.WebPageRenderer.renderPage(WebPageRenderer.java:116)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.apache.wicket.request.handler.render.WebPageRenderer.respond(WebPageRenderer.java:244)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.apache.wicket.core.request.handler.RenderPageRequestHandler.respond(RenderPageRequestHandler.java:165)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.apache.wicket.request.cycle.RequestCycle$HandlerExecutor.respond(RequestCycle.java:814)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.apache.wicket.request.RequestHandlerStack.execute(RequestHandlerStack.java:64)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.apache.wicket.request.RequestHandlerStack.execute(RequestHandlerStack.java:97)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.apache.wicket.request.cycle.RequestCycle.execute(RequestCycle.java:253)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.apache.wicket.request.cycle.RequestCycle.processRequest(RequestCycle.java:210)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.apache.wicket.request.cycle.RequestCycle.processRequestAndDetach(RequestCycle.java:281)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.apache.wicket.protocol.http.WicketFilter.processRequest(WicketFilter.java:188)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.apache.wicket.protocol.http.WicketFilter.doFilter(WicketFilter.java:245)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1668)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:581)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:226)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1160)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:511)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1092)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.eclipse.jetty.server.handler.HandlerList.handle(HandlerList.java:52)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.eclipse.jetty.server.Server.handle(Server.java:518)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:308)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:244)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceAndRun(ExecuteProduceConsume.java:246)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:156)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:654)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at java.lang.Thread.run(Unknown Source)
INFO   | jvm 1    | 2021/10/19 09:34:48 | Caused by: simpleorm.utils.SException$Jdbc: Opening com.inductiveautomation.ignition.gateway.localdb.CountingDataSource@28a9c566
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at simpleorm.sessionjdbc.SSessionJdbc.innerOpen(SSessionJdbc.java:113)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at com.inductiveautomation.ignition.gateway.localdb.persistence.PersistenceSession.initialize(PersistenceSession.java:31)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at com.inductiveautomation.ignition.gateway.localdb.PersistenceInterfaceImpl.getSession(PersistenceInterfaceImpl.java:62)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at com.inductiveautomation.ignition.gateway.localdb.PersistenceInterfaceImpl.getSession(PersistenceInterfaceImpl.java:44)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at com.inductiveautomation.ignition.gateway.web.pages.FlowstyleMain.getHomepagePanels(FlowstyleMain.java:40)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at com.inductiveautomation.ignition.gateway.web.pages.GatewaySearchData.addHomeItems(GatewaySearchData.java:52)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at com.inductiveautomation.ignition.gateway.web.pages.GatewaySearchData.<init>(GatewaySearchData.java:40)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at com.inductiveautomation.ignition.gateway.web.components.TwoTierMenu.renderHead(TwoTierMenu.java:50)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.apache.wicket.Component.renderHead(Component.java:4428)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.apache.wicket.Component.renderHead(Component.java:2688)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.apache.wicket.markup.renderStrategy.ChildFirstHeaderRenderStrategy$1.component(ChildFirstHeaderRenderStrategy.java:85)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.apache.wicket.markup.renderStrategy.DeepChildFirstVisitor.visit(DeepChildFirstVisitor.java:70)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.apache.wicket.markup.renderStrategy.DeepChildFirstVisitor.visit(DeepChildFirstVisitor.java:87)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.apache.wicket.markup.renderStrategy.DeepChildFirstVisitor.visit(DeepChildFirstVisitor.java:51)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.apache.wicket.markup.renderStrategy.ChildFirstHeaderRenderStrategy.renderChildHeaders(ChildFirstHeaderRenderStrategy.java:78)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.apache.wicket.markup.renderStrategy.ChildFirstHeaderRenderStrategy.renderHeader(ChildFirstHeaderRenderStrategy.java:57)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.apache.wicket.markup.html.internal.HtmlHeaderContainer.onComponentTagBody(HtmlHeaderContainer.java:170)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.apache.wicket.markup.html.panel.DefaultMarkupSourcingStrategy.onComponentTagBody(DefaultMarkupSourcingStrategy.java:71)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	at org.apache.wicket.Component.internalRenderComponent(Component.java:2535)
INFO   | jvm 1    | 2021/10/19 09:34:48 | 	... 44 common frames omitted
INFO   | jvm 1    | 2021/10/19 09:34:48 | Caused by: java.sql.SQLException: Connection is locked.

RonB · October 19, 2021, 1:45pm

Sorry, I had to create two posts as the log was growing pretty quickly. I took a few lines out to get under the limit. The device created is on the first line, drive is compactlogix.

kcollins1 · October 19, 2021, 1:52pm

One thing that jumps out at me is that there seems to be some contention on the internal config DB. It looks like the Creating auto-backup of internal database... kicks off but doesn’t complete. How big is the data/db/config.idb file? Are the auto-backups completing successfully at other times?

pturmel · October 19, 2021, 2:09pm

If auto-backups take longer than 30 seconds, other users of the internal DB begin failing. With cascading consequences all over the gateway. The internal database accumulates old project edits in v7.9.x, which can be alleviated by exporting then re-importing projects. If that isn’t sufficient, consider upgrading the server’s main storage to NVMe or similar super-fast storage.

RonB · October 19, 2021, 2:37pm

Under data; db; the config.idb is 640 MB.
On the 18th at
1:16 it created the backup in 49 seconds.
1:24 42 seconds
1:51 40 seconds
There are more entries than I care to list between yesterday to today. Always between 35-49 seconds with the exception of one entry that started on the 19th at 10:29 and it shows 58 seconds. I searched the log by “p.internaldatabase” for every backup started there looked to be a completion record.

Kevin.Herron · October 19, 2021, 2:38pm

If you get in touch with support they might be able to help you reduce the size of that config.idb.

RonB · October 19, 2021, 2:43pm

@pturmel Not sure how to go about NVMe. It’s a virtual server, so I’ll have to google and see what it entails. For the moment, I’ll get in touch with the sites IT manager and see how big of an ordeal it would be to take everything offline for a moment, or plan for an outage window.

@Kevin.Herron I will try and see what they say. How big would you expect the config file to be?

Kevin.Herron · October 19, 2021, 2:45pm

It can depend on the number of projects and what they contain... but smaller.

Older versions of Ignition (<= 7.9) have a bit of a known issue with the internal DB getting "inflated" over time due to some mismanaged bookkeeping related to project rollback if I'm remembering right.

However... it could also be that you've just made the mistake of saving large DataSets into your project(s) as well. Support should be able to help figure it out.

pturmel · October 19, 2021, 2:47pm

If had gateway backups cut by half or more in a couple cases by doing the project export/re-import dance. Relatively safe to do under production, too, as the disruption is similar to a project edit/save. I’d do this first.