8 Abandoned Clients Opened On 5 client License

I came across an issue on December 29th where one of our customers could not log in to a limited vision (5 client) system due to there being too many clients opened. The system is set up with two machines to auto login with the admin login, one of these machines is the gateway itself.
When I logged into the gateway webpage I saw there were 8 clients opened, unfortunately I did not record the details of all clients, however I noticed that at least 3 of them were opened on 127.0.0.1 even though there were no clients running on the machine. The webpage gave the option to “Prune Abandoned Client”, so I did this and the customer was then able to login.
Something seems to have happened on December 28th at 14:52 whereby the gateway restarted and security audit log records > 1000 logins from then until I logged into the webpage.

Our customer is looking for a reason to why/how this could have happened and a preventative measure on how to stop it happening again.
Below is a wrapper extract, any ideas would be much appreciated.

[01:15:02,609]: dataFileCache commit start
INFO | jvm 2 | 2013/12/26 01:15:02 | INFO [ENGINE ] [01:15:02,734]: Initiating backup of instance ‘settings’
INFO | jvm 2 | 2013/12/26 01:15:02 | 1 / 4 settings.properties…
INFO | jvm 2 | 2013/12/26 01:15:02 | 2 / 4 settings.script…
INFO | jvm 2 | 2013/12/26 01:15:02 | 3 / 4 settings.data…
INFO | jvm 2 | 2013/12/26 01:15:03 |
INFO | jvm 2 | 2013/12/26 01:15:03 | 4 / 4 settings.lobs…
INFO | jvm 2 | 2013/12/26 01:15:08 |
INFO | jvm 2 | 2013/12/26 01:15:08 | INFO [ENGINE ] [01:15:08,312]: Successfully backed up instance ‘settings’ to ‘C:\WINDOWS\Temp\tempdir3087035670437526349416382025968554\db_backup.tar.gz’
INFO | jvm 2 | 2013/12/26 01:15:18 | INFO [ScheduledBackupManager ] [01:15:18,250]: Created scheduled backup successfully.
INFO | jvm 2 | 2013/12/26 01:15:18 | INFO [ScheduledBackupManager ] [01:15:18,265]: Removed 1 old autobackup(s).
INFO | jvm 2 | 2013/12/27 01:15:00 | INFO [ENGINE ] [01:15:00,015]: Checkpoint start
INFO | jvm 2 | 2013/12/27 01:15:00 | INFO [ENGINE ] [01:15:00,015]: defrag start
INFO | jvm 2 | 2013/12/27 01:15:02 | INFO [ENGINE ] [01:15:02,140]: dataFileCache commit start
INFO | jvm 2 | 2013/12/27 01:15:02 | INFO [ENGINE ] [01:15:02,406]: open start
INFO | jvm 2 | 2013/12/27 01:15:02 | INFO [ENGINE ] [01:15:02,406]: open end
INFO | jvm 2 | 2013/12/27 01:15:02 | INFO [ENGINE ] [01:15:02,453]: defrag end
INFO | jvm 2 | 2013/12/27 01:15:02 | INFO [ENGINE ] [01:15:02,453]: Checkpoint end
INFO | jvm 2 | 2013/12/27 01:15:02 | INFO [ENGINE ] [01:15:02,546]: dataFileCache commit start
INFO | jvm 2 | 2013/12/27 01:15:02 | INFO [ENGINE ] [01:15:02,703]: Initiating backup of instance ‘settings’
INFO | jvm 2 | 2013/12/27 01:15:02 | 1 / 4 settings.properties…
INFO | jvm 2 | 2013/12/27 01:15:02 | 2 / 4 settings.script…
INFO | jvm 2 | 2013/12/27 01:15:02 | 3 / 4 settings.data…
INFO | jvm 2 | 2013/12/27 01:15:03 |
INFO | jvm 2 | 2013/12/27 01:15:03 | 4 / 4 settings.lobs…
INFO | jvm 2 | 2013/12/27 01:15:08 |
INFO | jvm 2 | 2013/12/27 01:15:08 | INFO [ENGINE ] [01:15:08,406]: Successfully backed up instance ‘settings’ to ‘C:\WINDOWS\Temp\tempdir13938236537698511459502775396760314\db_backup.tar.gz’
INFO | jvm 2 | 2013/12/27 01:15:21 | INFO [ScheduledBackupManager ] [01:15:21,031]: Created scheduled backup successfully.
INFO | jvm 2 | 2013/12/27 01:15:21 | INFO [ScheduledBackupManager ] [01:15:21,093]: Removed 1 old autobackup(s).
INFO | jvm 2 | 2013/12/28 01:15:00 | INFO [ENGINE ] [01:15:00,000]: Checkpoint start
INFO | jvm 2 | 2013/12/28 01:15:00 | INFO [ENGINE ] [01:15:00,000]: defrag start
INFO | jvm 2 | 2013/12/28 01:15:02 | INFO [ENGINE ] [01:15:02,421]: dataFileCache commit start
INFO | jvm 2 | 2013/12/28 01:15:02 | INFO [ENGINE ] [01:15:02,828]: open start
INFO | jvm 2 | 2013/12/28 01:15:02 | INFO [ENGINE ] [01:15:02,843]: open end
INFO | jvm 2 | 2013/12/28 01:15:02 | INFO [ENGINE ] [01:15:02,906]: defrag end
INFO | jvm 2 | 2013/12/28 01:15:02 | INFO [ENGINE ] [01:15:02,906]: Checkpoint end
INFO | jvm 2 | 2013/12/28 01:15:03 | INFO [ENGINE ] [01:15:03,062]: dataFileCache commit start
INFO | jvm 2 | 2013/12/28 01:15:03 | INFO [ENGINE ] [01:15:03,218]: Initiating backup of instance ‘settings’
INFO | jvm 2 | 2013/12/28 01:15:03 | 1 / 4 settings.properties…
INFO | jvm 2 | 2013/12/28 01:15:03 | 2 / 4 settings.script…
INFO | jvm 2 | 2013/12/28 01:15:03 | 3 / 4 settings.data…
INFO | jvm 2 | 2013/12/28 01:15:03 |
INFO | jvm 2 | 2013/12/28 01:15:03 | 4 / 4 settings.lobs…
INFO | jvm 2 | 2013/12/28 01:15:14 | WARN [TimeoutDaemon ] [01:15:14,015]: com.inductiveautomation.xopc.drivers.modbus2.requests.WriteSingleRegisterRequest@ad4faa request with key “5348” failed due to timeout.
INFO | jvm 2 | 2013/12/28 01:15:14 | WARN [WriteSingleRegisterRequest ] [01:15:14,015]: Request failed due to TIMEOUT
INFO | jvm 2 | 2013/12/28 01:15:14 | WARN [BasicRequestCycle ] [01:15:14,031]: Message arrived for key “5348” but no request found.
INFO | jvm 2 | 2013/12/28 01:15:14 | ERROR [Provider[default] ] [01:15:14,031]: [[default]PLC/PC_Minute] Error writing to OPC address [[Ignition OPC-UA Server][MainPLC]HR7862]. Result code: Unknown
INFO | jvm 2 | 2013/12/28 01:15:14 |
INFO | jvm 2 | 2013/12/28 01:15:14 | INFO [ENGINE ] [01:15:14,765]: Successfully backed up instance ‘settings’ to ‘C:\WINDOWS\Temp\tempdir61921107407189214949589169099024118\db_backup.tar.gz’
INFO | jvm 2 | 2013/12/28 01:15:22 | INFO [ScheduledBackupManager ] [01:15:22,000]: Created scheduled backup successfully.
INFO | jvm 2 | 2013/12/28 01:15:22 | INFO [ScheduledBackupManager ] [01:15:22,000]: Removed 1 old autobackup(s).
INFO | jvm 2 | 2013/12/28 01:16:35 | INFO [HSQLDataStore ] [01:16:35,265]: Creating auto-backup of store and forward datacache “SCADA”…
INFO | jvm 2 | 2013/12/28 01:16:35 | INFO [ENGINE ] [01:16:35,375]: dataFileCache commit start
INFO | jvm 2 | 2013/12/28 01:16:35 | INFO [ENGINE ] [01:16:35,671]: Initiating backup of instance ‘SCADA’
INFO | jvm 2 | 2013/12/28 01:16:35 | 1 / 3 SCADA.properties…
INFO | jvm 2 | 2013/12/28 01:16:35 | 2 / 3 SCADA.script…
INFO | jvm 2 | 2013/12/28 01:16:35 | 3 / 3 SCADA.data…
INFO | jvm 2 | 2013/12/28 01:16:35 | INFO [ENGINE ] [01:16:35,718]: Successfully backed up instance ‘SCADA’ to ‘C:\Program Files\Inductive Automation\Ignition\data\datacache\SCADA\autobackup\db_20131228_011635.tar.gz’
INFO | jvm 2 | 2013/12/28 01:16:35 | INFO [HSQLDataStore ] [01:16:35,796]: Created auto-backup of store and forward datacache “SCADA” in 531 ms
ERROR | wrapper | 2013/12/28 14:51:43 | JVM appears hung: Timed out waiting for signal from JVM.
ERROR | wrapper | 2013/12/28 14:51:43 | JVM did not exit on request, terminated
STATUS | wrapper | 2013/12/28 14:51:49 | Launching a JVM…
INFO | jvm 3 | 2013/12/28 14:51:55 | WrapperManager: Initializing…
INFO | jvm 3 | 2013/12/28 14:52:14 | Dec 28, 2013 2:52:14 PM org.apache.catalina.startup.Embedded start
INFO | jvm 3 | 2013/12/28 14:52:14 | INFO: Starting tomcat server
INFO | jvm 3 | 2013/12/28 14:52:15 | Dec 28, 2013 2:52:15 PM org.apache.catalina.core.StandardEngine start
INFO | jvm 3 | 2013/12/28 14:52:15 | INFO: Starting Servlet Engine: Apache Tomcat/6.0.18
INFO | jvm 3 | 2013/12/28 14:52:15 | Dec 28, 2013 2:52:15 PM org.apache.catalina.startup.DigesterFactory register
INFO | jvm 3 | 2013/12/28 14:52:15 | WARNING: Could not get url for /javax/servlet/jsp/resources/jsp_2_0.xsd
INFO | jvm 3 | 2013/12/28 14:52:15 | Dec 28, 2013 2:52:15 PM org.apache.catalina.startup.DigesterFactory register
INFO | jvm 3 | 2013/12/28 14:52:15 | WARNING: Could not get url for /javax/servlet/jsp/resources/jsp_2_1.xsd
INFO | jvm 3 | 2013/12/28 14:52:15 | Dec 28, 2013 2:52:15 PM org.apache.catalina.startup.DigesterFactory register
INFO | jvm 3 | 2013/12/28 14:52:15 | WARNING: Could not get url for /javax/servlet/jsp/resources/web-jsptaglibrary_1_1.dtd
INFO | jvm 3 | 2013/12/28 14:52:15 | Dec 28, 2013 2:52:15 PM org.apache.catalina.startup.DigesterFactory register
INFO | jvm 3 | 2013/12/28 14:52:15 | WARNING: Could not get url for /javax/servlet/jsp/resources/web-jsptaglibrary_1_2.dtd
INFO | jvm 3 | 2013/12/28 14:52:15 | Dec 28, 2013 2:52:15 PM org.apache.catalina.startup.DigesterFactory register
INFO | jvm 3 | 2013/12/28 14:52:15 | WARNING: Could not get url for /javax/servlet/jsp/resources/web-jsptaglibrary_2_0.xsd
INFO | jvm 3 | 2013/12/28 14:52:15 | Dec 28, 2013 2:52:15 PM org.apache.catalina.startup.DigesterFactory register
INFO | jvm 3 | 2013/12/28 14:52:15 | WARNING: Could not get url for /javax/servlet/jsp/resources/web-jsptaglibrary_2_1.xsd
INFO | jvm 3 | 2013/12/28 14:52:18 | INFO [SRClassLoader ] [14:52:18,781]: SRClassLoader init
INFO | jvm 3 | 2013/12/28 14:52:24 | INFO [SRContext ] [14:52:24,484]: Ignition["/main", state=STOPPED] ContextState = STARTING
INFO | jvm 3 | 2013/12/28 14:52:24 | INFO [SRContext ] [14:52:24,562]: Starting Ignition 7.3.2 (b533)
INFO | jvm 3 | 2013/12/28 14:52:24 | INFO [SRContext ] [14:52:24,578]: Reloading JDBC classloader.
INFO | jvm 3 | 2013/12/28 14:52:26 | INFO [SecureRandomProvider ] [14:52:26,671]: Creating SecureRandom object…
INFO | jvm 3 | 2013/12/28 14:52:26 | INFO [SecureRandomProvider ] [14:52:26,687]: Generating seed…
INFO | jvm 3 | 2013/12/28 14:52:26 | INFO [SecureRandomProvider ] [14:52:26,734]: … Seed Created.
INFO | jvm 3 | 2013/12/28 14:52:26 | INFO [SecureRandomProvider ] [14:52:26,734]: … SecureRandom Created.
INFO | jvm 3 | 2013/12/28 14:52:27 | INFO [Application ] [14:52:27,796]: [SRContext] init: Wicket core library initializer
INFO | jvm 3 | 2013/12/28 14:52:27 | INFO [RequestListenerInterface ] [14:52:27,796]: registered listener interface [RequestListenerInterface name=IBehaviorListener, method=public abstract void org.apache.wicket.behavior.IBehaviorListener.onRequest()]
INFO | jvm 3 | 2013/12/28 14:52:27 | INFO [RequestListenerInterface ] [14:52:27,796]: registered listener interface [RequestListenerInterface name=IBehaviorListener, method=public abstract void org.apache.wicket.behavior.IBehaviorListener.onRequest()]
INFO | jvm 3 | 2013/12/28 14:52:27 | INFO [RequestListenerInterface ] [14:52:27,812]: registered listener interface [RequestListenerInterface name=IFormSubmitListener, method=public abstract void org.apache.wicket.markup.html.form.IFormSubmitListener.onFormSubmitted()]
INFO | jvm 3 | 2013/12/28 14:52:27 | INFO [RequestListenerInterface ] [14:52:27,812]: registered listener interface [RequestListenerInterface name=IFormSubmitListener, method=public abstract void org.apache.wicket.markup.html.form.IFormSubmitListener.onFormSubmitted()]
INFO | jvm 3 | 2013/12/28 14:52:27 | INFO [RequestListenerInterface ] [14:52:27,812]: registered listener interface [RequestListenerInterface name=ILinkListener, method=public abstract void org.apache.wicket.markup.html.link.ILinkListener.onLinkClicked()]
INFO | jvm 3 | 2013/12/28 14:52:27 | INFO [RequestListenerInterface ] [14:52:27,812]: registered listener interface [RequestListenerInterface name=ILinkListener, method=public abstract void org.apache.wicket.markup.html.link.ILinkListener.onLinkClicked()]
INFO | jvm 3 | 2013/12/28 14:52:27 | INFO [RequestListenerInterface ] [14:52:27,828]: registered listener interface [RequestListenerInterface name=IOnChangeListener, method=public abstract void org.apache.wicket.markup.html.form.IOnChangeListener.onSelectionChanged()]
INFO | jvm 3 | 2013/12/28 14:52:27 | INFO [RequestListenerInterface ] [14:52:27,828]: registered listener interface [RequestListenerInterface name=IOnChangeListener, method=public abstract void org.apache.wicket.markup.html.form.IOnChangeListener.onSelectionChanged()]
INFO | jvm 3 | 2013/12/28 14:52:27 | INFO [RequestListenerInterface ] [14:52:27,828]: registered listener interface [RequestListenerInterface name=IRedirectListener, method=public abstract void org.apache.wicket.IRedirectListener.onRedirect()]
INFO | jvm 3 | 2013/12/28 14:52:27 | INFO [RequestListenerInterface ] [14:52:27,828]: registered listener interface [RequestListenerInterface name=IRedirectListener, method=public abstract void org.apache.wicket.IRedirectListener.onRedirect()]
INFO | jvm 3 | 2013/12/28 14:52:27 | INFO [RequestListenerInterface ] [14:52:27,828]: registered listener interface [RequestListenerInterface name=IResourceListener, method=public abstract void org.apache.wicket.IResourceListener.onResourceRequested()]
INFO | jvm 3 | 2013/12/28 14:52:27 | INFO [RequestListenerInterface ] [14:52:27,828]: registered listener interface [RequestListenerInterface name=IResourceListener, method=public abstract void org.apache.wicket.IResourceListener.onResourceRequested()]
INFO | jvm 3 | 2013/12/28 14:52:27 | INFO [RequestListenerInterface ] [14:52:27,828]: registered listener interface [RequestListenerInterface name=IActivePageBehaviorListener, method=public abstract void org.apache.wicket.behavior.IBehaviorListener.onRequest()]
INFO | jvm 3 | 2013/12/28 14:52:27 | INFO [RequestListenerInterface ] [14:52:27,843]: registered listener interface [RequestListenerInterface name=IActivePageBehaviorListener, method=public abstract void org.apache.wicket.behavior.IBehaviorListener.onRequest()]
INFO | jvm 3 | 2013/12/28 14:52:27 | INFO [Application ] [14:52:27,843]: [SRContext] init: Wicket extensions initializer
INFO | jvm 3 | 2013/12/28 14:52:27 | INFO [StateMonitoring ] [14:52:27,843]: The cluster node state has changed. Current state: [RedundancyState[role=Independent, activity level=Active, project state=Good, history level=Full]
INFO | jvm 3 | 2013/12/28 14:52:28 | INFO [WebApplication ] [14:52:28,000]: [SRContext] Started Wicket version 1.4.5 in deployment mode
INFO | jvm 3 | 2013/12/28 14:52:28 | Dec 28, 2013 2:52:28 PM org.apache.coyote.http11.Http11Protocol init
INFO | jvm 3 | 2013/12/28 14:52:28 | INFO: Initializing Coyote HTTP/1.1 on http-8088
INFO | jvm 3 | 2013/12/28 14:52:28 | Dec 28, 2013 2:52:28 PM org.apache.coyote.http11.Http11Protocol start
INFO | jvm 3 | 2013/12/28 14:52:28 | INFO: Starting Coyote HTTP/1.1 on http-8088
INFO | jvm 3 | 2013/12/28 14:52:30 | Dec 28, 2013 2:52:30 PM org.apache.coyote.http11.Http11Protocol init
INFO | jvm 3 | 2013/12/28 14:52:30 | INFO: Initializing Coyote HTTP/1.1 on http-8043
INFO | jvm 3 | 2013/12/28 14:52:30 | Dec 28, 2013 2:52:30 PM org.apache.coyote.http11.Http11Protocol start
INFO | jvm 3 | 2013/12/28 14:52:30 | INFO: Starting Coyote HTTP/1.1 on http-8043
INFO | jvm 3 | 2013/12/28 14:52:33 | WARN [ModuleManager ] [14:52:32,968]: Could not read license from HASP key.
INFO | jvm 3 | 2013/12/28 14:52:33 | INFO [SystemInfo ] [14:52:33,156]: os.name=“windows xp”, os.arch=“x86”.
INFO | jvm 3 | 2013/12/28 14:52:33 | INFO [SystemInfo ] [14:52:33,171]: Validating native library “ignition32”…
INFO | jvm 3 | 2013/12/28 14:52:33 | INFO [SystemInfo ] [14:52:33,250]: Validated ignition32 (ignition32.dll)
INFO | jvm 3 | 2013/12/28 14:52:33 | INFO [SystemInfo ] [14:52:33,250]: Loading native library “ignition32”…
INFO | jvm 3 | 2013/12/28 14:52:47 | INFO [LocalDBManagerImpl ] [14:52:47,750]: Starting up…
INFO | jvm 3 | 2013/12/28 14:52:47 | INFO [LocalDBManagerImpl ] [14:52:47,828]: Looking for existing internal database “settings”…
INFO | jvm 3 | 2013/12/28 14:52:50 | INFO [ENGINE ] [14:52:50,203]: open start
INFO | jvm 3 | 2013/12/28 14:52:50 | INFO [ENGINE ] [14:52:50,312]: open end
INFO | jvm 3 | 2013/12/28 14:52:51 | INFO [ENGINE ] [14:52:51,109]: dataFileCache commit start
INFO | jvm 3 | 2013/12/28 14:52:51 | INFO [LocalDBManagerImpl ] [14:52:51,296]: … found existing.
INFO | jvm 3 | 2013/12/28 14:52:52 | INFO [ENGINE ] [14:52:52,093]: Checkpoint start
INFO | jvm 3 | 2013/12/28 14:52:52 | INFO [ENGINE ] [14:52:52,218]: dataFileCache commit start
INFO | jvm 3 | 2013/12/28 14:52:52 | INFO [ENGINE ] [14:52:52,359]: Checkpoint end
INFO | jvm 3 | 2013/12/28 14:52:52 | INFO [LocalDBManagerImpl ] [14:52:52,375]: internal database “settings” started up successfully.
INFO | jvm 3 | 2013/12/28 14:52:52 | INFO [LocalDBManagerImpl ] [14:52:52,375]: Registering autobackup task [owner=Internal DB Autobackup, name=internal database “settings”]
INFO | jvm 3 | 2013/12/28 14:52:52 | INFO [Notification ] [14:52:52,859]: Alert notification system created.
INFO | jvm 3 | 2013/12/28 14:52:56 | INFO [HSQLDataStore ] [14:52:56,546]: Looking for existing store and forward datacache “SCADA”…
INFO | jvm 3 | 2013/12/28 14:52:56 | INFO [ENGINE ] [14:52:56,625]: open start
INFO | jvm 3 | 2013/12/28 14:52:56 | INFO [ENGINE ] [14:52:56,671]: open end
INFO | jvm 3 | 2013/12/28 14:52:56 | INFO [ENGINE ] [14:52:56,734]: dataFileCache commit start
INFO | jvm 3 | 2013/12/28 14:52:57 | INFO [HSQLDataStore ] [14:52:56,953]: … found existing.
INFO | jvm 3 | 2013/12/28 14:52:57 | INFO [ENGINE ] [14:52:56,953]: Checkpoint start
INFO | jvm 3 | 2013/12/28 14:52:57 | INFO [ENGINE ] [14:52:57,000]: dataFileCache commit start
INFO | jvm 3 | 2013/12/28 14:52:57 | INFO [ENGINE ] [14:52:57,328]: Checkpoint end
INFO | jvm 3 | 2013/12/28 14:52:57 | INFO [HSQLDataStore ] [14:52:57,328]: store and forward datacache “SCADA” started up successfully.
INFO | jvm 3 | 2013/12/28 14:52:57 | INFO [HSQLDataStore ] [14:52:57,328]: Registering autobackup task [owner=Internal DB Autobackup, name=store and forward datacache “SCADA”]
INFO | jvm 3 | 2013/12/28 14:52:57 | INFO [SCADA ] [14:52:57,562]: History sink started successfully.
INFO | jvm 3 | 2013/12/28 14:52:57 | INFO [HSQLDataStore ] [14:52:57,562]: Looking for existing store and forward datacache “Logs”…
INFO | jvm 3 | 2013/12/28 14:52:57 | INFO [ENGINE ] [14:52:57,671]: open start
INFO | jvm 3 | 2013/12/28 14:52:57 | INFO [ENGINE ] [14:52:57,687]: open end
INFO | jvm 3 | 2013/12/28 14:52:57 | INFO [ENGINE ] [14:52:57,734]: dataFileCache commit start
INFO | jvm 3 | 2013/12/28 14:52:58 | INFO [HSQLDataStore ] [14:52:57,921]: … found existing.
INFO | jvm 3 | 2013/12/28 14:52:58 | INFO [ENGINE ] [14:52:57,937]: Checkpoint start
INFO | jvm 3 | 2013/12/28 14:52:58 | INFO [ENGINE ] [14:52:57,968]: dataFileCache commit start
INFO | jvm 3 | 2013/12/28 14:52:58 | INFO [ENGINE ] [14:52:58,250]: Checkpoint end
INFO | jvm 3 | 2013/12/28 14:52:58 | INFO [HSQLDataStore ] [14:52:58,250]: store and forward datacache “Logs” started up successfully.
INFO | jvm 3 | 2013/12/28 14:52:58 | INFO [HSQLDataStore ] [14:52:58,250]: Registering autobackup task [owner=Internal DB Autobackup, name=store and forward datacache “Logs”]
INFO | jvm 3 | 2013/12/28 14:52:58 | INFO [Logs ] [14:52:58,421]: History sink started successfully.
INFO | jvm 3 | 2013/12/28 14:52:59 | INFO [ModuleManager ] [14:52:59,375]: Trial time reset. Time remaining = 0. Notify modules = false.
INFO | jvm 3 | 2013/12/28 14:52:59 | INFO [ModuleManager ] [14:52:59,375]: Setting up modules
INFO | jvm 3 | 2013/12/28 14:53:00 | INFO [AuthenticationManager ] [14:53:00,546]: Starting up…
INFO | jvm 3 | 2013/12/28 14:53:01 | INFO [AuditManager ] [14:53:01,031]: AuditManager starting up…
INFO | jvm 3 | 2013/12/28 14:53:01 | WARN [InternalProviderSettingsRecord] [14:53:01,343]: Default datasource not found for internal tag provider “default”
INFO | jvm 3 | 2013/12/28 14:53:01 | INFO [Provider[default] ] [14:53:01,546]: Starting tag provider ‘default’.
INFO | jvm 3 | 2013/12/28 14:53:04 | INFO [StorageManager ] [14:53:04,890]: Starting up…
INFO | jvm 3 | 2013/12/28 14:53:05 | INFO [NotificationManager ] [14:53:05,046]: Starting up…
INFO | jvm 3 | 2013/12/28 14:53:05 | INFO [ImageManager ] [14:53:05,234]: Starting up…
INFO | jvm 3 | 2013/12/28 14:53:05 | INFO [ProjectManager ] [14:53:05,234]: ProjectManager starting up…
INFO | jvm 3 | 2013/12/28 14:53:06 | INFO [Project[CastlemoyleWTW] ] [14:53:06,093]: Project [CastlemoyleWTW] starting up…
INFO | jvm 3 | 2013/12/28 14:53:06 | INFO [SessionManager ] [14:53:06,187]: Starting up…
INFO | jvm 3 | 2013/12/28 14:53:06 | INFO [ScheduledBackupManager ] [14:53:06,234]: Registered scheduled backups for cron schedule: 15 1 * * *
INFO | jvm 3 | 2013/12/28 14:53:07 | ERROR [Provider[default] ] [14:53:06,906]: [WxCastlPM_kvarhTotal] Error occurred in tag: Error evaluating tag: null
INFO | jvm 3 | 2013/12/28 14:53:07 | java.lang.NullPointerException
INFO | jvm 3 | 2013/12/28 14:53:07 | at com.inductiveautomation.ignition.common.expressions.ArithmeticExpression.multOp(ArithmeticExpression.java:100)
INFO | jvm 3 | 2013/12/28 14:53:07 | at com.inductiveautomation.ignition.common.expressions.ArithmeticExpression.execute(ArithmeticExpression.java:76)
INFO | jvm 3 | 2013/12/28 14:53:07 | at com.inductiveautomation.ignition.common.expressions.ArithmeticExpression.execute(ArithmeticExpression.java:58)
INFO | jvm 3 | 2013/12/28 14:53:07 | at com.inductiveautomation.ignition.gateway.sqltags.execution.tags.ExpressionTag$ELExecutor.internalExecute(ExpressionTag.java:356)
INFO | jvm 3 | 2013/12/28 14:53:07 | at com.inductiveautomation.ignition.gateway.sqltags.execution.tags.ExpressionTag$Executor.execute(ExpressionTag.java:267)
INFO | jvm 3 | 2013/12/28 14:53:07 | at com.inductiveautomation.ignition.gateway.sqltags.execution.tags.ExpressionTag.internalEvaluate(ExpressionTag.java:203)
INFO | jvm 3 | 2013/12/28 14:53:07 | at com.inductiveautomation.ignition.gateway.sqltags.execution.tags.AbstractExecutableTag.evaluate(AbstractExecutableTag.java:470)
INFO | jvm 3 | 2013/12/28 14:53:07 | at com.inductiveautomation.ignition.gateway.sqltags.scanclasses.BasicScanClassInstance.evaluateTags(BasicScanClassInstance.java:177)
INFO | jvm 3 | 2013/12/28 14:53:07 | at com.inductiveautomation.ignition.gateway.sqltags.scanclasses.BasicScanClassInstance.runTagEvaluation(BasicScanClassInstance.java:164)
INFO | jvm 3 | 2013/12/28 14:53:07 | at com.inductiveautomation.ignition.gateway.sqltags.scanclasses.SimpleExecutableScanClass.runTagEvaluation(SimpleExecutableScanClass.java:698)
INFO | jvm 3 | 2013/12/28 14:53:07 | at com.inductiveautomation.ignition.gateway.sqltags.scanclasses.SimpleExecutableScanClass.run(SimpleExecutableScanClass.java:816)
INFO | jvm 3 | 2013/12/28 14:53:07 | at com.inductiveautomation.ignition.common.execution.impl.BasicExecutionEngine$TrackedTask.run(BasicExecutionEngine.java:573)
INFO | jvm 3 | 2013/12/28 14:53:07 | at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)
INFO | jvm 3 | 2013/12/28 14:53:07 | at java.util.concurrent.FutureTask$Sync.innerRunAndReset(Unknown Source)
INFO | jvm 3 | 2013/12/28 14:53:07 | at java.util.concurrent.FutureTask.runAndReset(Unknown Source)
INFO | jvm 3 | 2013/12/28 14:53:07 | at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(Unknown Source)
INFO | jvm 3 | 2013/12/28 14:53:07 | at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(Unknown Source)
INFO | jvm 3 | 2013/12/28 14:53:07 | at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source)
INFO | jvm 3 | 2013/12/28 14:53:07 | at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
INFO | jvm 3 | 2013/12/28 14:53:07 | at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
INFO | jvm 3 | 2013/12/28 14:53:07 | at java.lang.Thread.run(Unknown Source)
INFO | jvm 3 | 2013/12/28 14:53:07 | ERROR [Provider[default] ] [14:53:07,093]: [WxCastlPM_kVAhTotal] Error occurred in tag: Error evaluating tag: null
INFO | jvm 3 | 2013/12/28 14:53:07 | java.lang.NullPointerException
INFO | jvm 3 | 2013/12/28 14:53:07 | at com.inductiveautomation.ignition.common.expressions.ArithmeticExpression.multOp(ArithmeticExpression.java:100)
INFO | jvm 3 | 2013/12/28 14:53:07 | at com.inductiveautomation.ignition.common.expressions.ArithmeticExpression.execute(ArithmeticExpression.java:76)
INFO | jvm 3 | 2013/12/28 14:53:07 | at com.inductiveautomation.ignition.common.expressions.ArithmeticExpression.execute(ArithmeticExpression.java:58)
INFO | jvm 3 | 2013/12/28 14:53:07 | at com.inductiveautomation.ignition.gateway.sqltags.execution.tags.ExpressionTag$ELExecutor.internalExecute(ExpressionTag.java:356)
INFO | jvm 3 | 2013/12/28 14:53:07 | at com.inductiveautomation.ignition.gateway.sqltags.execution.tags.ExpressionTag$Executor.execute(ExpressionTag.java:267)
INFO | jvm 3 | 2013/12/28 14:53:07 | at com.inductiveautomation.ignition.gateway.sqltags.execution.tags.ExpressionTag.internalEvaluate(ExpressionTag.java:203)
INFO | jvm 3 | 2013/12/28 14:53:07 | at com.inductiveautomation.ignition.gateway.sqltags.execution.tags.AbstractExecutableTag.evaluate(AbstractExecutableTag.java:470)
INFO | jvm 3 | 2013/12/28 14:53:07 | at com.inductiveautomation.ignition.gateway.sqltags.scanclasses.BasicScanClassInstance.evaluateTags(BasicScanClassInstance.java:177)
INFO | jvm 3 | 2013/12/28 14:53:07 | at com.inductiveautomation.ignition.gateway.sqltags.scanclasses.BasicScanClassInstance.runTagEvaluation(BasicScanClassInstance.java:164)
INFO | jvm 3 | 2013/12/28 14:53:07 | at com.inductiveautomation.ignition.gateway.sqltags.scanclasses.SimpleExecutableScanClass.runTagEvaluation(SimpleExecutableScanClass.java:698)
INFO | jvm 3 | 2013/12/28 14:53:07 | at com.inductiveautomation.ignition.gateway.sqltags.scanclasses.SimpleExecutableScanClass.run(SimpleExecutableScanClass.java:816)
INFO | jvm 3 | 2013/12/28 14:53:07 | at com.inductiveautomation.ignition.common.execution.impl.BasicExecutionEngine$TrackedTask.run(BasicExecutionEngine.java:573)
INFO | jvm 3 | 2013/12/28 14:53:07 | at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)
INFO | jvm 3 | 2013/12/28 14:53:07 | at java.util.concurrent.FutureTask$Sync.innerRunAndReset(Unknown Source)
INFO | jvm 3 | 2013/12/28 14:53:07 | at java.util.concurrent.FutureTask.runAndReset(Unknown Source)
INFO | jvm 3 | 2013/12/28 14:53:07 | at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(Unknown Source)
INFO | jvm 3 | 2013/12/28 14:53:07 | at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(Unknown Source)
INFO | jvm 3 | 2013/12/28 14:53:07 | at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source)
INFO | jvm 3 | 2013/12/28 14:53:07 | at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
INFO | jvm 3 | 2013/12/28 14:53:07 | at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
INFO | jvm 3 | 2013/12/28 14:53:07 | at java.lang.Thread.run(Unknown Source)
INFO | jvm 3 | 2013/12/28 14:53:07 | ERROR [Provider[default] ] [14:53:07,093]: [WxCastlPM_kWhTotal] Error occurred in tag: Error evaluating tag: null
INFO | jvm 3 | 2013/12/28 14:53:07 | java.lang.NullPointerException
INFO | jvm 3 | 2013/12/28 14:53:07 | at com.inductiveautomation.ignition.common.expressions.ArithmeticExpression.multOp(ArithmeticExpression.java:100)
INFO | jvm 3 | 2013/12/28 14:53:07 | at com.inductiveautomation.ignition.common.expressions.ArithmeticExpression.execute(ArithmeticExpression.java:76)
INFO | jvm 3 | 2013/12/28 14:53:07 | at com.inductiveautomation.ignition.common.expressions.ArithmeticExpression.execute(ArithmeticExpression.java:58)
INFO | jvm 3 | 2013/12/28 14:53:07 | at com.inductiveautomation.ignition.gateway.sqltags.execution.tags.ExpressionTag$ELExecutor.internalExecute(ExpressionTag.java:356)
INFO | jvm 3 | 2013/12/28 14:53:07 | at com.inductiveautomation.ignition.gateway.sqltags.execution.tags.ExpressionTag$Executor.execute(ExpressionTag.java:267)
INFO | jvm 3 | 2013/12/28 14:53:07 | at com.inductiveautomation.ignition.gateway.sqltags.execution.tags.ExpressionTag.internalEvaluate(ExpressionTag.java:203)
INFO | jvm 3 | 2013/12/28 14:53:07 | at com.inductiveautomation.ignition.gateway.sqltags.execution.tags.AbstractExecutableTag.evaluate(AbstractExecutableTag.java:470)
INFO | jvm 3 | 2013/12/28 14:53:07 | at com.inductiveautomation.ignition.gateway.sqltags.scanclasses.BasicScanClassInstance.evaluateTags(BasicScanClassInstance.java:177)
INFO | jvm 3 | 2013/12/28 14:53:07 | at com.inductiveautomation.ignition.gateway.sqltags.scanclasses.BasicScanClassInstance.runTagEvaluation(BasicScanClassInstance.java:164)
INFO | jvm 3 | 2013/12/28 14:53:07 | at com.inductiveautomation.ignition.gateway.sqltags.scanclasses.SimpleExecutableScanClass.runTagEvaluation(SimpleExecutableScanClass.java:698)
INFO | jvm 3 | 2013/12/28 14:53:07 | at com.inductiveautomation.ignition.gateway.sqltags.scanclasses.SimpleExecutableScanClass.run(SimpleExecutableScanClass.java:816)
INFO | jvm 3 | 2013/12/28 14:53:07 | at com.inductiveautomation.ignition.common.execution.impl.BasicExecutionEngine$TrackedTask.run(BasicExecutionEngine.java:573)
INFO | jvm 3 | 2013/12/28 14:53:07 | at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)
INFO | jvm 3 | 2013/12/28 14:53:07 | at java.util.concurrent.FutureTask$Sync.innerRunAndReset(Unknown Source)
INFO | jvm 3 | 2013/12/28 14:53:07 | at java.util.concurrent.FutureTask.runAndReset(Unknown Source)
INFO | jvm 3 | 2013/12/28 14:53:07 | at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(Unknown Source)
INFO | jvm 3 | 2013/12/28 14:53:07 | at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(Unknown Source)
INFO | jvm 3 | 2013/12/28 14:53:07 | at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source)
INFO | jvm 3 | 2013/12/28 14:53:07 | at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
INFO | jvm 3 | 2013/12/28 14:53:07 | at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
INFO | jvm 3 | 2013/12/28 14:53:07 | at java.lang.Thread.run(Unknown Source)
INFO | jvm 3 | 2013/12/28 14:53:07 | INFO [ModuleManager ] [14:53:07,781]: Starting up…
INFO | jvm 3 | 2013/12/28 14:53:07 | INFO [ModuleManager ] [14:53:07,796]: Starting up module fsql
INFO | jvm 3 | 2013/12/28 14:53:21 | INFO [TagHistoryDatasourceSink ] [14:53:21,828]: SQLTags history tables verified successfully.
INFO | jvm 3 | 2013/12/28 14:53:24 | INFO [SQL Bridge-CastlemoyleWTW ] [14:53:24,765]: Project started.
INFO | jvm 3 | 2013/12/28 14:53:24 | INFO [ModuleManager ] [14:53:24,765]: Starting up module xopc
INFO | jvm 3 | 2013/12/28 14:53:24 | INFO [XOPCGatewayHook ] [14:53:24,765]: OPC-UA module starting up.
INFO | jvm 3 | 2013/12/28 14:53:29 | WARN [XOPCModule ] [14:53:29,468]: java.lang.Exception: Could not find Inet4Address “192.168.1.103”.
INFO | jvm 3 | 2013/12/28 14:53:33 | INFO [ModuleManager ] [14:53:33,468]: Starting up module fpmi
INFO | jvm 3 | 2013/12/28 14:53:33 | INFO [ModuleManager ] [14:53:33,468]: Starting up module help
INFO | jvm 3 | 2013/12/28 14:53:33 | INFO [ModuleManager ] [14:53:33,468]: Starting up module rept
INFO | jvm 3 | 2013/12/28 14:53:33 | INFO [ModuleManager ] [14:53:33,468]: Starting up module symfact
INFO | jvm 3 | 2013/12/28 14:53:33 | INFO [ModuleManager ] [14:53:33,468]: Starting up module siemens-drivers
INFO | jvm 3 | 2013/12/28 14:53:33 | INFO [ModuleManager ] [14:53:33,609]: Starting up module xopc-drivers
INFO | jvm 3 | 2013/12/28 14:53:33 | INFO [ModuleManager ] [14:53:33,703]: Starting up module modbus-driver2
INFO | jvm 3 | 2013/12/28 14:53:34 | INFO [ModuleManager ] [14:53:34,234]: Starting up module udp-driver
INFO | jvm 3 | 2013/12/28 14:53:34 | INFO [ModuleManager ] [14:53:34,281]: Starting up module mobile
INFO | jvm 3 | 2013/12/28 14:53:34 | INFO [VMManager ] [14:53:34,343]: Starting Mobile VM Manager. JavaPath=“java”, Interface=“localhost”, Port=“45900”
INFO | jvm 3 | 2013/12/28 14:53:36 | INFO [ActivateSessionService ] [14:53:36,515]: User “opcuauser ([ReadWrite])” connected.
INFO | jvm 3 | 2013/12/28 14:53:36 | INFO [Projects$ProjectChangeMonitor ] [14:53:36,562]: Starting up client project monitor. project=CastlemoyleWTW, uuid=18c50d1c-6e2d-c94f-bff5-8d64aedae79a, editCount=1464, scope=4, version=Published
INFO | jvm 3 | 2013/12/28 14:53:36 | INFO [Projects$ProjectChangeMonitor ] [14:53:36,625]: Starting up client project monitor. project=CastlemoyleWTW, uuid=18c50d1c-6e2d-c94f-bff5-8d64aedae79a, editCount=1464, scope=4, version=Published
INFO | jvm 3 | 2013/12/28 14:53:36 | INFO [SRContext ] [14:53:36,640]: Ignition["/main", state=STARTING] ContextState = RUNNING
INFO | jvm 3 | 2013/12/28 14:56:39 | WARN [Updates ] [14:56:39,250]: Slow query “UPDATE “ALERT_LOG” SET “ACK_USER” = ?, “ACK_TIMESTAMP” = ? WHERE “SYSTEM” = ? AND “PATH” = ? AND “STATE_NAME” = ? AND “ACK_TIMESTAMP” IS NULL” took 1 minutes, 1 seconds
INFO | jvm 3 | 2013/12/28 14:56:39 | WARN [Updates ] [14:56:39,265]: Slow query “UPDATE “ALERT_LOG” SET “ACK_USER” = ?, “ACK_TIMESTAMP” = ? WHERE “SYSTEM” = ? AND “PATH” = ? AND “STATE_NAME” = ? AND “ACK_TIMESTAMP” IS NULL” took 1 minutes, 1 seconds
INFO | jvm 3 | 2013/12/28 14:57:57 | INFO [HSQLDataStore ] [14:57:57,390]: Creating auto-backup of store and forward datacache “SCADA”…
INFO | jvm 3 | 2013/12/28 14:57:57 | INFO [ENGINE ] [14:57:57,500]: dataFileCache commit start
INFO | jvm 3 | 2013/12/28 14:57:57 | INFO [ENGINE ] [14:57:57,609]: Initiating backup of instance ‘SCADA’
INFO | jvm 3 | 2013/12/28 14:57:57 | 1 / 3 SCADA.properties…
INFO | jvm 3 | 2013/12/28 14:57:57 | 2 / 3 SCADA.script…
INFO | jvm 3 | 2013/12/28 14:57:57 | 3 / 3 SCADA.data…
INFO | jvm 3 | 2013/12/28 14:57:57 | INFO [ENGINE ] [14:57:57,812]: Successfully backed up instance ‘SCADA’ to ‘C:\Program Files\Inductive Automation\Ignition\data\datacache\SCADA\autobackup\db_20131228_145757.tar.gz’
INFO | jvm 3 | 2013/12/28 14:57:57 | INFO [HSQLDataStore ] [14:57:57,890]: Created auto-backup of store and forward datacache “SCADA” in 500 ms
INFO | jvm 3 | 2013/12/29 01:15:00 | INFO [ENGINE ] [01:15:00,468]: Checkpoint start
INFO | jvm 3 | 2013/12/29 01:15:00 | INFO [ENGINE ] [01:15:00,500]: defrag start
INFO | jvm 3 | 2013/12/29 01:15:03 | INFO [ENGINE ] [01:15:03,218]: dataFileCache commit start
INFO | jvm 3 | 2013/12/29 01:15:03 | INFO [ENGINE ] [01:15:03,750]: open start
INFO | jvm 3 | 2013/12/29 01:15:03 | INFO [ENGINE ] [01:15:03,765]: open end
INFO | jvm 3 | 2013/12/29 01:15:03 | INFO [ENGINE ] [01:15:03,843]: defrag end
INFO | jvm 3 | 2013/12/29 01:15:03 | INFO [ENGINE ] [01:15:03,843]: Checkpoint end
INFO | jvm 3 | 2013/12/29 01:15:04 | INFO [ENGINE ] [01:15:04,203]: dataFileCache commit start
INFO | jvm 3 | 2013/12/29 01:15:04 | INFO [ENGINE ] [01:15:04,390]: Initiating backup of instance ‘settings’
INFO | jvm 3 | 2013/12/29 01:15:04 | 1 / 4 settings.properties…
INFO | jvm 3 | 2013/12/29 01:15:04 | 2 / 4 settings.script…
INFO | jvm 3 | 2013/12/29 01:15:04 | 3 / 4 settings.data…
INFO | jvm 3 | 2013/12/29 01:15:04 |
INFO | jvm 3 | 2013/12/29 01:15:05 | 4 / 4 settings.lobs…
INFO | jvm 3 | 2013/12/29 01:15:12 |
INFO | jvm 3 | 2013/12/29 01:15:12 | INFO [ENGINE ] [01:15:12,375]: Successfully backed up instance ‘settings’ to ‘C:\WINDOWS\Temp\tempdir17665216339273104859675563295057700\db_backup.tar.gz’
INFO | jvm 3 | 2013/12/29 01:15:20 | INFO [ScheduledBackupManager ] [01:15:20,453]: Created scheduled backup successfully.
INFO | jvm 3 | 2013/12/29 01:15:20 | INFO [ScheduledBackupManager ] [01:15:20,640]: Removed 1 old autobackup(s).
INFO | jvm 3 | 2013/12/29 09:23:17 | INFO [RequestListenerInterface ] [09:23:17,187]: registered listener interface [RequestListenerInterface name=INewBrowserWindowListener, method=public abstract void org.apache.wicket.markup.html.INewBrowserWindowListener.onNewBrowserWindow()]
INFO | jvm 3 | 2013/12/29 10:04:12 | ERROR [Gateway ] [10:04:12,640]: ERROR(302): Login failed.
INFO | jvm 3 | 2013/12/29 10:56:40 | INFO [PropertiesFactory ] [10:56:40,796]: Loading properties files from jar:file:/C:/WINDOWS/TEMP/ignition_main_tmp/gateway8705688410185293637.jar!/com/inductiveautomation/ignition/gateway/web/pages/config/SystemStatus.properties
INFO | jvm 3 | 2013/12/29 10:57:34 | INFO [Projects$ProjectChangeMonitor ] [10:57:34,562]: Starting up client project monitor. project=CastlemoyleWTW, uuid=18c50d1c-6e2d-c94f-bff5-8d64aedae79a, editCount=1578, scope=4, version=Published
INFO | jvm 3 | 2013/12/29 10:58:23 | INFO [Projects$ProjectChangeMonitor ] [10:58:23,734]: Starting up client project monitor. project=CastlemoyleWTW, uuid=18c50d1c-6e2d-c94f-bff5-8d64aedae79a, editCount=1578, scope=4, version=Published
INFO | jvm 3 | 2013/12/29 11:43:12 | INFO [Projects$ProjectChangeMonitor ] [11:43:12,640]: Starting up client project monitor. project=CastlemoyleWTW, uuid=18c50d1c-6e2d-c94f-bff5-8d64aedae79a, editCount=1578, scope=4, version=Published
INFO | jvm 3 | 2013/12/30 01:15:00 | INFO [ENGINE ] [01:15:00,046]: Checkpoint start
INFO | jvm 3 | 2013/12/30 01:15:00 | INFO [ENGINE ] [01:15:00,046]: defrag start
INFO | jvm 3 | 2013/12/30 01:15:02 | INFO [ENGINE ] [01:15:02,359]: dataFileCache commit start
INFO | jvm 3 | 2013/12/30 01:15:02 | INFO [ENGINE ] [01:15:02,640]: open start
INFO | jvm 3 | 2013/12/30 01:15:02 | INFO [ENGINE ] [01:15:02,640]: open end
INFO | jvm 3 | 2013/12/30 01:15:02 | INFO [ENGINE ] [01:15:02,703]: defrag end
INFO | jvm 3 | 2013/12/30 01:15:02 | INFO [ENGINE ] [01:15:02,703]: Checkpoint end
INFO | jvm 3 | 2013/12/30 01:15:02 | INFO [ENGINE ] [01:15:02,828]: dataFileCache commit start
INFO | jvm 3 | 2013/12/30 01:15:03 | INFO [ENGINE ] [01:15:02,953]: Initiating backup of instance ‘settings’
INFO | jvm 3 | 2013/12/30 01:15:03 | 1 / 4 settings.properties…
INFO | jvm 3 | 2013/12/30 01:15:03 | 2 / 4 settings.script…
INFO | jvm 3 | 2013/12/30 01:15:03 | 3 / 4 settings.data…
INFO | jvm 3 | 2013/12/30 01:15:03 |
INFO | jvm 3 | 2013/12/30 01:15:03 | 4 / 4 settings.lobs…
INFO | jvm 3 | 2013/12/30 01:15:09 |
INFO | jvm 3 | 2013/12/30 01:15:09 | INFO [ENGINE ] [01:15:09,296]: Successfully backed up instance ‘settings’ to ‘C:\WINDOWS\Temp\tempdir44724134804502250419761955342987490\db_backup.tar.gz’
INFO | jvm 3 | 2013/12/30 01:15:16 | INFO [ScheduledBackupManager ] [01:15:16,203]: Created scheduled backup successfully.
INFO | jvm 3 | 2013/12/30 01:15:16 | INFO [ScheduledBackupManager ] [01:15:16,218]: Removed 1 old autobackup(s).
INFO | jvm 3 | 2013/12/31 01:15:00 | INFO [ENGINE ] [01:15:00,000]: Checkpoint start
INFO | jvm 3 | 2013/12/31 01:15:00 | INFO [ENGINE ] [01:15:00,000]: defrag start
INFO | jvm 3 | 2013/12/31 01:15:02 | INFO [ENGINE ] [01:15:02,046]: dataFileCache commit start
INFO | jvm 3 | 2013/12/31 01:15:02 | INFO [ENGINE ] [01:15:02,296]: open start
INFO | jvm 3 | 2013/12/31 01:15:02 | INFO [ENGINE ] [01:15:02,296]: open end
INFO | jvm 3 | 2013/12/31 01:15:02 | INFO [ENGINE ] [01:15:02,375]: defrag end
INFO | jvm 3 | 2013/12/31 01:15:02 | INFO [ENGINE ] [01:15:02,375]: Checkpoint end
INFO | jvm 3 | 2013/12/31 01:15:02 | INFO [ENGINE ] [01:15:02,484]: dataFileCache commit start
INFO | jvm 3 | 2013/12/31 01:15:02 | INFO [ENGINE ] [01:15:02,625]: Initiating backup of instance ‘settings’
INFO | jvm 3 | 2013/12/31 01:15:02 | 1 / 4 settings.properties…
INFO | jvm 3 | 2013/12/31 01:15:02 | 2 / 4 settings.script…
INFO | jvm 3 | 2013/12/31 01:15:02 | 3 / 4 settings.data…
INFO | jvm 3 | 2013/12/31 01:15:03 |
INFO | jvm 3 | 2013/12/31 01:15:03 | 4 / 4 settings.lobs…
INFO | jvm 3 | 2013/12/31 01:15:09 |
INFO | jvm 3 | 2013/12/31 01:15:09 | INFO [ENGINE ] [01:15:09,296]: Successfully backed up instance ‘settings’ to ‘C:\WINDOWS\Temp\tempdir49635955525314684569848348268401592\db_backup.tar.gz’
INFO | jvm 3 | 2013/12/31 01:15:16 | INFO [ScheduledBackupManager ] [01:15:16,093]: Created scheduled backup successfully.
INFO | jvm 3 | 2013/12/31 01:15:16 | INFO [ScheduledBackupManager ] [01:15:16,093]: Removed 1 old autobackup(s).
INFO | jvm 3 | 2014/01/01 00:00:06 | INFO [SCADA_PMgr ] [00:00:06,671]: Created SQLTags history partition sqlt_data_1_2014_01
INFO | jvm 3 | 2014/01/01 01:15:00 | INFO [ENGINE ] [01:15:00,015]: Checkpoint start
INFO | jvm 3 | 2014/01/01 01:15:00 | INFO [ENGINE ] [01:15:00,015]: defrag start
INFO | jvm 3 | 2014/01/01 01:15:02 | INFO [ENGINE ] [01:15:01,937]: dataFileCache commit start
INFO | jvm 3 | 2014/01/01 01:15:02 | INFO [ENGINE ] [01:15:02,218]: open start
INFO | jvm 3 | 2014/01/01 01:15:02 | INFO [ENGINE ] [01:15:02,218]: open end
INFO | jvm 3 | 2014/01/01 01:15:02 | INFO [ENGINE ] [01:15:02,250]: defrag end
INFO | jvm 3 | 2014/01/01 01:15:02 | INFO [ENGINE ] [01:15:02,250]: Checkpoint end
INFO | jvm 3 | 2014/01/01 01:15:02 | INFO [ENGINE ] [01:15:02,375]: dataFileCache commit start
INFO | jvm 3 | 2014/01/01 01:15:02 | INFO [ENGINE ] [01:15:02,500]: Initiating backup of instance ‘settings’
INFO | jvm 3 | 2014/01/01 01:15:02 | 1 / 4 settings.properties…
INFO | jvm 3 | 2014/01/01 01:15:02 | 2 / 4 settings.script…
INFO | jvm 3 | 2014/01/01 01:15:02 | 3 / 4 settings.data…
INFO | jvm 3 | 2014/01/01 01:15:02 |
INFO | jvm 3 | 2014/01/01 01:15:03 | 4 / 4 settings.lobs…
INFO | jvm 3 | 2014/01/01 01:15:08 |
INFO | jvm 3 | 2014/01/01 01:15:09 | INFO [ENGINE ] [01:15:08,953]: Successfully backed up instance ‘settings’ to ‘C:\WINDOWS\Temp\tempdir34076226745614181759934741429408270\db_backup.tar.gz’
INFO | jvm 3 | 2014/01/01 01:15:15 | INFO [ScheduledBackupManager ] [01:15:15,734]: Created scheduled backup successfully.
INFO | jvm 3 | 2014/01/01 01:15:15 | INFO [ScheduledBackupManager ] [01:15:15,750]: Removed 1 old autobackup(s).
INFO | jvm 3 | 2014/01/02 01:15:00 | INFO [ENGINE ] [01:15:00,000]: Checkpoint start
INFO | jvm 3 | 2014/01/02 01:15:00 | INFO [ENGINE ] [01:15:00,000]: defrag start
INFO | jvm 3 | 2014/01/02 01:15:01 | INFO [ENGINE ] [01:15:01,937]: dataFileCache commit start
INFO | jvm 3 | 2014/01/02 01:15:02 | INFO [ENGINE ] [01:15:02,171]: open start
INFO | jvm 3 | 2014/01/02 01:15:02 | INFO [ENGINE ] [01:15:02,171]: open end
INFO | jvm 3 | 2014/01/02 01:15:02 | INFO [ENGINE ] [01:15:02,265]: defrag end
INFO | jvm 3 | 2014/01/02 01:15:02 | INFO [ENGINE ] [01:15:02,265]: Checkpoint end
INFO | jvm 3 | 2014/01/02 01:15:02 | INFO [ENGINE ] [01:15:02,359]: dataFileCache commit start
INFO | jvm 3 | 2014/01/02 01:15:02 | INFO [ENGINE ] [01:15:02,468]: Initiating backup of instance ‘settings’
INFO | jvm 3 | 2014/01/02 01:15:02 | 1 / 4 settings.properties…
INFO | jvm 3 | 2014/01/02 01:15:02 | 2 / 4 settings.script…
INFO | jvm 3 | 2014/01/02 01:15:02 | 3 / 4 settings.data…
INFO | jvm 3 | 2014/01/02 01:15:02 |
INFO | jvm 3 | 2014/01/02 01:15:02 | 4 / 4 settings.lobs…
INFO | jvm 3 | 2014/01/02 01:15:09 |
INFO | jvm 3 | 2014/01/02 01:15:09 | INFO [ENGINE ] [01:15:09,062]: Successfully backed up instance ‘settings’ to ‘C:\WINDOWS\Temp\tempdir60672119659828017610021134766219822\db_backup.tar.gz’
INFO | jvm 3 | 2014/01/02 01:15:16 | INFO [ScheduledBackupManager ] [01:15:16,000]: Created scheduled backup successfully.
INFO | jvm 3 | 2014/01/02 01:15:16 | INFO [ScheduledBackupManager ] [01:15:16,031]: Removed 1 old autobackup(s).
INFO | jvm 3 | 2014/01/02 09:18:22 | INFO [Projects$ProjectChangeMonitor ] [09:18:22,000]: Starting up client project monitor. project=CastlemoyleWTW, uuid=18c50d1c-6e2d-c94f-bff5-8d64aedae79a, editCount=1578, scope=4, version=Published
INFO | jvm 3 | 2014/01/02 09:18:33 | INFO [Projects$ProjectChangeMonitor ] [09:18:33,562]: Starting up client project monitor. project=CastlemoyleWTW, uuid=18c50d1c-6e2d-c94f-bff5-8d64aedae79a, editCount=1578, scope=4, version=Published
INFO | jvm 3 | 2014/01/02 09:18:47 | ERROR [Gateway ] [09:18:47,578]: ERROR(302): Login failed.
INFO | jvm 3 | 2014/01/02 09:19:15 | INFO [Projects$ProjectChangeMonitor ] [09:19:15,140]: Starting up client project monitor. project=CastlemoyleWTW, uuid=18c50d1c-6e2d-c94f-bff5-8d64aedae79a, editCount=1578, scope=4, version=Published

What version of Ignition is this?
Under Configure / Mobile / Settings in the Gateway, what is the setting for “Idle VMs”? for “Session Timeout”?

It is version 7.3.2 (b533).

The Idle VMs are set to 0 ( see attached screen shot ).

There have been several changes and fixes to the mobile module since the version you are running. One of these issues had to do with idle vm’s staying open when they shouldn’t. Currently the LTS (long term support) version of Ignition is 7.5 and bug fixes are being made to this branch and will continue to be made for several more years. I would suggest upgrading to the latest 7.5.11 if your license allows because it is very likely that this issue has been resolved.