Difficult day with ubuntu today - gateway does not start

hewking32 · March 6, 2023, 6:08pm

I just gave up an idea to use Demo VM in hyperV and revered to the original demo Vm in VMware.
It run ok first time but i noticed that there is no valid loopbackup OPC connection so removed security in the OPC gateway settings selecting none in security polices and then restarted VM.
After the restart VM the gateway is failing to start.
Any chance you help me to do the basic diagnostic before deleting this VM and starting with the new one?
Where do i find wrapper file in ubuntu?

In general i did see many times that loopback connection failed which most of the time was simply by restarting - i wonder if more people experienced this? could it be antivirus or firewall issues by any chance?

jcoffman · March 6, 2023, 6:21pm

It looks like this gateway might have been upgraded as part of an EAM Agent Upgrade and something failed. I would check the controller logs and grab the wrapper.log file. Depending on the situation here it is probably appropriate to reach out to support.

Typically the install location is usr/local/bin/ignition for linux

Hope that gets you pointed in the right direction

hewking32 · March 6, 2023, 6:31pm

"""
23/03/06 10:18:39 | --> Wrapper Started as Daemon
STATUS | wrapper | 2023/03/06 10:18:39 | Java Service Wrapper Standard Edition 64-bit 3.5.35
STATUS | wrapper | 2023/03/06 10:18:39 | Copyright (C) 1999-2018 Tanuki Software, Ltd. All Rights Reserved.
STATUS | wrapper | 2023/03/06 10:18:39 | http://wrapper.tanukisoftware.com
STATUS | wrapper | 2023/03/06 10:18:39 | Licensed to Inductive Automation for Inductive Automation
STATUS | wrapper | 2023/03/06 10:18:39 |
WARN | wrapper | 2023/03/06 10:18:39 | ---------------------------------------------------------------------
WARN | wrapper | 2023/03/06 10:18:39 | The JVM is being launched with a debugger enabled and could possibly
WARN | wrapper | 2023/03/06 10:18:39 | be suspended. To avoid unwanted shutdowns, timeouts will be
WARN | wrapper | 2023/03/06 10:18:39 | disabled, removing the ability to detect and restart frozen JVMs.
WARN | wrapper | 2023/03/06 10:18:39 | ---------------------------------------------------------------------
STATUS | wrapper | 2023/03/06 10:18:39 | Launching a JVM...
INFO | jvm 1 | 2023/03/06 10:18:40 | Listening for transport dt_socket at address: 8000
INFO | jvm 1 | 2023/03/06 10:18:40 | WrapperManager: Initializing...
INFO | jvm 1 | 2023/03/06 10:18:41 | 10:18:40,884 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [/var/lib/ignition/data//logback.xml] at [file:/var/lib/ignition/data/logback.xml]
INFO | jvm 1 | 2023/03/06 10:18:41 | 10:18:40,981 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
INFO | jvm 1 | 2023/03/06 10:18:41 | 10:18:40,983 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [SysoutAppender]
INFO | jvm 1 | 2023/03/06 10:18:41 | 10:18:40,988 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
INFO | jvm 1 | 2023/03/06 10:18:41 | 10:18:41,008 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [com.inductiveautomation.logging.SQLiteAppender]
INFO | jvm 1 | 2023/03/06 10:18:41 | 10:18:41,017 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [DB]
INFO | jvm 1 | 2023/03/06 10:18:41 | 10:18:41,142 |-INFO in ch.qos.logback.core.db.DataSourceConnectionSource@68a1798f - Driver name=SQLite JDBC
INFO | jvm 1 | 2023/03/06 10:18:41 | 10:18:41,142 |-INFO in ch.qos.logback.core.db.DataSourceConnectionSource@68a1798f - Driver version=3.23.1
INFO | jvm 1 | 2023/03/06 10:18:41 | 10:18:41,142 |-INFO in ch.qos.logback.core.db.DataSourceConnectionSource@68a1798f - supportsGetGeneratedKeys=true
INFO | jvm 1 | 2023/03/06 10:18:41 | 10:18:41,155 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.classic.AsyncAppender]
INFO | jvm 1 | 2023/03/06 10:18:41 | 10:18:41,163 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [SysoutAsync]
INFO | jvm 1 | 2023/03/06 10:18:41 | 10:18:41,163 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [SysoutAppender] to ch.qos.logback.classic.AsyncAppender[SysoutAsync]
INFO | jvm 1 | 2023/03/06 10:18:41 | 10:18:41,163 |-INFO in ch.qos.logback.classic.AsyncAppender[SysoutAsync] - Attaching appender named [SysoutAppender] to AsyncAppender.
INFO | jvm 1 | 2023/03/06 10:18:41 | 10:18:41,164 |-INFO in ch.qos.logback.classic.AsyncAppender[SysoutAsync] - Setting discardingThreshold to 51
INFO | jvm 1 | 2023/03/06 10:18:41 | 10:18:41,167 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.classic.AsyncAppender]
INFO | jvm 1 | 2023/03/06 10:18:41 | 10:18:41,178 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [DBAsync]
INFO | jvm 1 | 2023/03/06 10:18:41 | 10:18:41,179 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [DB] to ch.qos.logback.classic.AsyncAppender[DBAsync]
INFO | jvm 1 | 2023/03/06 10:18:41 | 10:18:41,179 |-INFO in ch.qos.logback.classic.AsyncAppender[DBAsync] - Attaching appender named [DB] to AsyncAppender.
INFO | jvm 1 | 2023/03/06 10:18:41 | 10:18:41,179 |-INFO in ch.qos.logback.classic.AsyncAppender[DBAsync] - Setting discardingThreshold to 51
INFO | jvm 1 | 2023/03/06 10:18:41 | 10:18:41,180 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT logger to INFO
INFO | jvm 1 | 2023/03/06 10:18:41 | 10:18:41,180 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [SysoutAsync] to Logger[ROOT]
INFO | jvm 1 | 2023/03/06 10:18:41 | 10:18:41,180 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [DBAsync] to Logger[ROOT]
INFO | jvm 1 | 2023/03/06 10:18:41 | 10:18:41,180 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration.
INFO | jvm 1 | 2023/03/06 10:18:41 | 10:18:41,181 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@1b6e7b0c - Registering current configuration as safe fallback point
INFO | jvm 1 | 2023/03/06 10:18:41 | W [WebResourceManagerImpl ] [18:18:41]: Unable to read "gateway.metroKeystoreAlias" gateway.xml property. Assuming metro keystore alias is: metro-key
INFO | jvm 1 | 2023/03/06 10:18:41 | I [o.e.j.u.log ] [18:18:41]: Logging initialized @1586ms to org.eclipse.jetty.util.log.Slf4jLog
INFO | jvm 1 | 2023/03/06 10:18:41 | I [g.WebServerManager ] [18:18:41]: Starting setup
INFO | jvm 1 | 2023/03/06 10:18:41 | I [g.WebServerManager ] [18:18:41]: Setup complete
INFO | jvm 1 | 2023/03/06 10:18:42 | I [g.WebServerManager ] [18:18:42]: Starting up
INFO | jvm 1 | 2023/03/06 10:18:42 | W [g.CertificateValidationUtil ] [18:18:42]: Cert with subject 'CN=Ignition, OU=Ignition, O=Inductive Automation, L=Folsom, ST=California, C=US' has no basic constraints.
INFO | jvm 1 | 2023/03/06 10:18:42 | W [g.CertificateValidationUtil ] [18:18:42]: Cert with subject 'CN=Ignition, OU=Ignition, O=Inductive Automation, L=Folsom, ST=California, C=US' has no basic constraints.
INFO | jvm 1 | 2023/03/06 10:18:42 | I [g.SslManager ] [18:18:42]: State refreshed state=LEGACY_SELF_SIGNED_CERTIFICATE
INFO | jvm 1 | 2023/03/06 10:18:43 | I [o.e.j.s.Server ] [18:18:42]: jetty-9.4.24.v20191120; built: 2019-11-20T21:37:49.771Z; git: 363d5f2df3a8a28de40604320230664b9c793c16; jvm 11.0.6+10-LTS
INFO | jvm 1 | 2023/03/06 10:18:43 | I [o.e.j.w.StandardDescriptorProcessor] [18:18:43]: NO JSP Support for /idp, did not find org.apache.jasper.servlet.JspServlet
INFO | jvm 1 | 2023/03/06 10:18:43 | I [o.e.j.s.session ] [18:18:43]: DefaultSessionIdManager workerName=node0
INFO | jvm 1 | 2023/03/06 10:18:43 | I [o.e.j.s.session ] [18:18:43]: No SessionScavenger set, using defaults
INFO | jvm 1 | 2023/03/06 10:18:43 | I [o.e.j.s.session ] [18:18:43]: node0 Scavenging every 600000ms
INFO | jvm 1 | 2023/03/06 10:18:43 | I [g.IgnitionIdentityProvider ] [18:18:43]: Initializing
INFO | jvm 1 | 2023/03/06 10:18:43 | I [o.e.j.s.h.ContextHandler ] [18:18:43]: Started c.i.c.IdpWebAppContext@7453e5d2{Ignition Identity Provider,/idp,file:///usr/local/bin/ignition/webserver/webapps/idp/,AVAILABLE}
INFO | jvm 1 | 2023/03/06 10:18:43 | I [o.e.j.w.StandardDescriptorProcessor] [18:18:43]: NO JSP Support for /, did not find org.apache.jasper.servlet.JspServlet
INFO | jvm 1 | 2023/03/06 10:18:43 | I [o.a.w.Application ] [18:18:43]: [WicketFilter] init: Wicket core library initializer
INFO | jvm 1 | 2023/03/06 10:18:43 | I [o.a.w.RequestListenerInterface] [18:18:43]: registered listener interface [RequestListenerInterface name=IBehaviorListener, method=public abstract void org.apache.wicket.behavior.IBehaviorListener.onRequest()]
INFO | jvm 1 | 2023/03/06 10:18:43 | I [o.a.w.RequestListenerInterface] [18:18:43]: registered listener interface [RequestListenerInterface name=IFormSubmitListener, method=public abstract void org.apache.wicket.markup.html.form.IFormSubmitListener.onFormSubmitted()]
INFO | jvm 1 | 2023/03/06 10:18:43 | I [o.a.w.RequestListenerInterface] [18:18:43]: registered listener interface [RequestListenerInterface name=ILinkListener, method=public abstract void org.apache.wicket.markup.html.link.ILinkListener.onLinkClicked()]
INFO | jvm 1 | 2023/03/06 10:18:43 | I [o.a.w.RequestListenerInterface] [18:18:43]: registered listener interface [RequestListenerInterface name=IOnChangeListener, method=public abstract void org.apache.wicket.markup.html.form.IOnChangeListener.onSelectionChanged()]
INFO | jvm 1 | 2023/03/06 10:18:43 | I [o.a.w.RequestListenerInterface] [18:18:43]: registered listener interface [RequestListenerInterface name=IRedirectListener, method=public abstract void org.apache.wicket.IRedirectListener.onRedirect()]
INFO | jvm 1 | 2023/03/06 10:18:43 | I [o.a.w.RequestListenerInterface] [18:18:43]: registered listener interface [RequestListenerInterface name=IResourceListener, method=public abstract void org.apache.wicket.IResourceListener.onResourceRequested()]
INFO | jvm 1 | 2023/03/06 10:18:43 | I [o.a.w.Application ] [18:18:43]: [WicketFilter] init: Wicket extensions initializer
INFO | jvm 1 | 2023/03/06 10:18:43 | I [g.IgnitionIdentityProvider ] [18:18:43]: Setting Ignition Gateway
INFO | jvm 1 | 2023/03/06 10:18:43 | I [IgnitionGateway ] [18:18:43]: Ignition[state=STOPPED] ContextState = STARTING
INFO | jvm 1 | 2023/03/06 10:18:43 | I [o.a.w.p.h.WebApplication ] [18:18:43]: [WicketFilter] Started Wicket version 6.1.1 in DEPLOYMENT mode
INFO | jvm 1 | 2023/03/06 10:18:43 | I [IgnitionGateway ] [18:18:43]: Starting Ignition 8.0.10 (b2020031912)
INFO | jvm 1 | 2023/03/06 10:18:43 | I [IgnitionGateway ] [18:18:43]: Reloading JDBC classloader.
INFO | jvm 1 | 2023/03/06 10:18:43 | I [C.SecureRandomProvider ] [18:18:43]: Secure random seed generated in 2ms
INFO | jvm 1 | 2023/03/06 10:18:43 | I [o.e.j.s.h.ContextHandler ] [18:18:43]: Started c.i.c.MainWebAppContext@5d5b2d2{Ignition,/,file:///usr/local/bin/ignition/webserver/webapps/main/,AVAILABLE}
INFO | jvm 1 | 2023/03/06 10:18:43 | I [R.S.S.InternalDb ] [18:18:43]: Internal db synchronizer disk cache initialized. State id=e0879693-46a9-4fb8-b9c2-d81d71085ae0
INFO | jvm 1 | 2023/03/06 10:18:43 | I [R.StateMonitoring ] [18:18:43]: Redundancy state changed: Role=Independent, Activity level=Active, Project state=Good, History level=Full
INFO | jvm 1 | 2023/03/06 10:18:44 | I [g.InternalDatabaseManager ] [18:18:43]: Starting up...
INFO | jvm 1 | 2023/03/06 10:18:44 | I [P.InternalDatabase ] [18:18:43]: Looking for existing internal database "config.idb"...
INFO | jvm 1 | 2023/03/06 10:18:44 | I [P.InternalDatabase ] [18:18:43]: ... found existing.
INFO | jvm 1 | 2023/03/06 10:18:44 | I [P.InternalDatabase ] [18:18:44]: internal database "config.idb" started up successfully.
INFO | jvm 1 | 2023/03/06 10:18:44 | I [P.InternalDatabase ] [18:18:44]: Registering autobackup task [owner=Internal DB Autobackup, name=internal database "config.idb"]
INFO | jvm 1 | 2023/03/06 10:18:44 | WARNING: An illegal reflective access operation has occurred
INFO | jvm 1 | 2023/03/06 10:18:44 | WARNING: Illegal reflective access by com.inductiveautomation.ignition.gateway.modules.ModuleManagerImpl (file:/usr/local/bin/ignition/lib/core/gateway/gateway-8.0.10.jar) to field java.lang.ClassLoader.usr_paths
INFO | jvm 1 | 2023/03/06 10:18:44 | WARNING: Please consider reporting this to the maintainers of com.inductiveautomation.ignition.gateway.modules.ModuleManagerImpl
INFO | jvm 1 | 2023/03/06 10:18:44 | WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
INFO | jvm 1 | 2023/03/06 10:18:44 | WARNING: All illegal access operations will be denied in a future release
INFO | jvm 1 | 2023/03/06 10:18:44 | I [g.ModuleManager ] [18:18:44]: Loading modules....
INFO | jvm 1 | 2023/03/06 10:18:44 | I [o.e.j.s.AbstractConnector ] [18:18:44]: Started ServerConnector@b519bfc{SSL,[ssl, http/1.1]}{0.0.0.0:8060}
INFO | jvm 1 | 2023/03/06 10:18:44 | I [o.e.j.s.AbstractConnector ] [18:18:44]: Started ServerConnector@7de42c77{HTTP/1.1,[http/1.1]}{0.0.0.0:8088}
INFO | jvm 1 | 2023/03/06 10:18:44 | I [o.e.j.s.AbstractConnector ] [18:18:44]: Started ServerConnector@3bb9c33b{SSL,[ssl, http/1.1]}{0.0.0.0:8043}
INFO | jvm 1 | 2023/03/06 10:18:44 | I [o.e.j.s.Server ] [18:18:44]: Started @4616ms
INFO | jvm 1 | 2023/03/06 10:18:47 | I [A.Notification ] [18:18:47]: Alert notification system created.
INFO | jvm 1 | 2023/03/06 10:18:47 | I [g.PersistentRecordSecurityLevelConfigService] [18:18:47]: Set up in 4 ms
INFO | jvm 1 | 2023/03/06 10:18:47 | I [g.PersistentRecordIdpAdapterConfigService] [18:18:47]: Set up in 12 ms
INFO | jvm 1 | 2023/03/06 10:18:47 | I [g.PersistentRecordIdpAdapterMetricsService] [18:18:47]: Set up in 9 ms
INFO | jvm 1 | 2023/03/06 10:18:48 | I [c.i.i.g.p.r.ProjectRecordConverter] [18:18:48]: Conversion finished. Elapsed time: 17 ms
INFO | jvm 1 | 2023/03/06 10:18:50 | I [g.ModuleManager ] [18:18:50]: Setting up modules
INFO | jvm 1 | 2023/03/06 10:18:51 | I [G.L.A.AlarmNotificationService] [18:18:50]: Remote Alarm Notification Manager initialized successfully.
INFO | jvm 1 | 2023/03/06 10:18:51 | I [c.i.i.g.o.KeyStoreManager ] [18:18:51]: Loading KeyStore at /var/lib/ignition/data/opcua/client/security/certificates.pfx
INFO | jvm 1 | 2023/03/06 10:18:51 | I [c.i.i.g.o.KeyStoreManager ] [18:18:51]: Loading KeyStore at /var/lib/ignition/data/opcua/server/security/certificates.pfx
INFO | jvm 1 | 2023/03/06 10:18:51 | I [o.e.m.o.s.s.OpcUaServer ] [18:18:51]: Eclipse Milo OPC UA Stack version: 0.3.7
INFO | jvm 1 | 2023/03/06 10:18:51 | I [o.e.m.o.s.s.OpcUaServer ] [18:18:51]: Eclipse Milo OPC UA Server SDK version: 0.3.7
INFO | jvm 1 | 2023/03/06 10:18:53 | I [o.e.m.o.s.s.n.OpcUaNamespace ] [18:18:53]: Loaded nodes in 984ms.
INFO | jvm 1 | 2023/03/06 10:18:58 | I [g.PersistentRecordSecurityLevelConfigService] [18:18:58]: Started up in 0 ms
INFO | jvm 1 | 2023/03/06 10:18:58 | I [g.SecurityLevelManager ] [18:18:58]: Started up in 4 ms
INFO | jvm 1 | 2023/03/06 10:18:58 | I [g.PersistentRecordIdpAdapterConfigService] [18:18:58]: Started up in 19 ms
INFO | jvm 1 | 2023/03/06 10:18:58 | I [g.PersistentRecordIdpAdapterMetricsService] [18:18:58]: Started up in 0 ms
INFO | jvm 1 | 2023/03/06 10:18:58 | I [g.IdpAdapterManager ] [18:18:58]: Started up in 1 ms
"""

hewking32 · March 6, 2023, 6:33pm

is there anything obvious which prevents gateway from starting?
all i did is changed security policy to none in opc server settings - then restarted and gateway does not start. Trying to learn and understand what got broken so badly...

hewking32 · March 6, 2023, 6:36pm

is there a way to write manually security policy as it was originally or reset to the default settings?

hewking32 · March 7, 2023, 7:22am

maybe i can i copy ubuntu internal database to my host machine, then modify opc server security from none to default settings (i assume this broke demo vm and prevents gateway from starting) using kindling internal database viewer
@PGriffith does kindling allow modifications of all gateway settings? might try to copy internal db from the gateway backup to fix it - restoring gateway backup would not work as gateway does not start

PGriffith · March 7, 2023, 3:15pm

No, Kindling does not currently allow updates back. There are lots of options to manipulate SQLite files available, though.

I would recommend contacting support at this point, personally.

hewking32 · March 7, 2023, 4:04pm

@PGriffith
thanks for reply - i had issue with Demo VM so i would not bother support and just unzip fresh VM but before i do i will be tempted to find a tool to write back to the SQL lite to have last attempt to fix that VM

regarding latest version of the kindling - it triggered some false antivirus alarm and does not allow me to run installer to the end due to my laptop policies,

I tried to install it on the test server 2019 with no antivirus policies but the installer does not even start or trigger anything - do you know if kindling is compatible with windows server 2019?

PGriffith · March 7, 2023, 4:20pm

As far as I know it should, but there's no testing infrastructure to check compatibility.

Which download/install are you using? The MSI/EXE downloads directly on the release are self-signed and more likely to trigger AV.

The jdeploy builds: Download Kindling should be properly signed (and offer auto-updates) which is likely more palatable to your environment.

hewking32 · March 7, 2023, 6:13pm

@PGriffith massive thanks for help
I gave up installing kindling on my laptop with sensitive antivirus (your latest link was also creating alarms same as github version) but i did download it to the linux demo VM and managed to run it ok.

Updating internal database to the original opc ua security policy did not help so I fixed broken VM by reinstalling ignition on it.

Thanks for putting me in the right direction - i am starting to like linux