search

openhab / openhab-distro

The binary distribution of openHAB
https://www.openhab.org/
Eclipse Public License 2.0
1.3k stars 394 forks source link

OH3 - Windows - Fresh Install - openhab.log and events.log not generated after installing service wrapper #1227

Open msexton187 opened 3 years ago

msexton187 commented 3 years ago

After doing a fresh install of OH3 on Windows, openhab.log and events.log aren't generated. Prior to installing the service wrapper, all log files are generated as expected, but once the service wrapper is installed only the wrapper.log is created. See below for an excerpt of the wrapper.log file after the service was installed.

Additional Information: openHAB installation dir is set to: set.default.OPENHAB_HOME=C:\openhab This location is valid and exactly what is was for OH2 Windows Version: 10 Java Version: Zulu 11

Full Log:


STATUS | wrapper  | 2020/12/22 07:51:08 | --> Wrapper Started as Service
STATUS | wrapper  | 2020/12/22 07:51:08 | Launching a JVM...
INFO   | jvm 1    | 2020/12/22 07:51:09 | Wrapper (Version 3.2.3) http://wrapper.tanukisoftware.org
INFO   | jvm 1    | 2020/12/22 07:51:09 |   Copyright 1999-2006 Tanuki Software, Inc.  All Rights Reserved.
INFO   | jvm 1    | 2020/12/22 07:51:09 | 
INFO   | jvm 1    | 2020/12/22 07:51:09 | WARNING: An illegal reflective access operation has occurred
INFO   | jvm 1    | 2020/12/22 07:51:09 | WARNING: Illegal reflective access by org.eclipse.osgi.storage.FrameworkExtensionInstaller (file:/C:/openhab/runtime/system/org/eclipse/platform/org.eclipse.osgi/3.12.100/org.eclipse.osgi-3.12.100.jar) to method java.net.URLClassLoader.addURL(java.net.URL)
INFO   | jvm 1    | 2020/12/22 07:51:09 | WARNING: Please consider reporting this to the maintainers of org.eclipse.osgi.storage.FrameworkExtensionInstaller
INFO   | jvm 1    | 2020/12/22 07:51:09 | WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
INFO   | jvm 1    | 2020/12/22 07:51:09 | WARNING: All illegal access operations will be denied in a future release
INFO   | jvm 1    | 2020/12/22 07:51:09 | Dec 22, 2020 7:51:09 AM org.apache.karaf.main.lock.SimpleFileLock lock
INFO   | jvm 1    | 2020/12/22 07:51:09 | INFO: Trying to lock C:\openhab\userdata\tmp\lock
INFO   | jvm 1    | 2020/12/22 07:51:09 | Dec 22, 2020 7:51:09 AM org.apache.karaf.main.lock.SimpleFileLock lock
INFO   | jvm 1    | 2020/12/22 07:51:09 | INFO: Lock acquired
INFO   | jvm 1    | 2020/12/22 07:51:09 | Dec 22, 2020 7:51:09 AM org.apache.karaf.main.Main$KarafLockCallback lockAcquired
INFO   | jvm 1    | 2020/12/22 07:51:09 | INFO: Lock acquired. Setting startlevel to 100
INFO   | jvm 1    | 2020/12/22 07:51:09 | Dec 22, 2020 7:51:09 AM org.apache.karaf.main.ShutdownSocketThread run
INFO   | jvm 1    | 2020/12/22 07:51:09 | INFO: Shutdown socket thread is listening on 127.0.0.1:53451
INFO   | jvm 1    | 2020/12/22 07:51:10 | org.ops4j.pax.logging.pax-logging-api [log4j2] ERROR : Unable to create file ${sys:openhab.logdir}/openhab.log Ignored FQCN: org.apache.logging.log4j.spi.AbstractLogger
INFO   | jvm 1    | 2020/12/22 07:51:10 | java.io.IOException: The filename, directory name, or volume label syntax is incorrect
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at java.base/java.io.WinNTFileSystem.canonicalize0(Native Method)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at java.base/java.io.WinNTFileSystem.canonicalize(WinNTFileSystem.java:438)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at java.base/java.io.File.getCanonicalPath(File.java:620)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at java.base/java.io.File.getCanonicalFile(File.java:645)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.apache.logging.log4j.core.util.FileUtils.makeParentDirs(FileUtils.java:142)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.apache.logging.log4j.core.appender.rolling.RollingFileManager$RollingFileManagerFactory.createManager(RollingFileManager.java:650)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.apache.logging.log4j.core.appender.rolling.RollingFileManager$RollingFileManagerFactory.createManager(RollingFileManager.java:631)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.apache.logging.log4j.core.appender.AbstractManager.getManager(AbstractManager.java:113)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.apache.logging.log4j.core.appender.OutputStreamManager.getManager(OutputStreamManager.java:114)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.apache.logging.log4j.core.appender.rolling.RollingFileManager.getFileManager(RollingFileManager.java:205)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.apache.logging.log4j.core.appender.RollingFileAppender$Builder.build(RollingFileAppender.java:146)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.apache.logging.log4j.core.appender.RollingFileAppender$Builder.build(RollingFileAppender.java:62)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.apache.logging.log4j.core.config.plugins.util.PluginBuilder.build(PluginBuilder.java:122)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.apache.logging.log4j.core.config.AbstractConfiguration.createPluginObject(AbstractConfiguration.java:1002)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:942)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:934)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.apache.logging.log4j.core.config.AbstractConfiguration.doConfigure(AbstractConfiguration.java:552)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.apache.logging.log4j.core.config.AbstractConfiguration.initialize(AbstractConfiguration.java:241)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.apache.logging.log4j.core.config.AbstractConfiguration.start(AbstractConfiguration.java:288)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.apache.logging.log4j.core.LoggerContext.setConfiguration(LoggerContext.java:579)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.apache.logging.log4j.core.LoggerContext.start(LoggerContext.java:285)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.ops4j.pax.logging.log4j2.internal.PaxLoggingServiceImpl.configureLog4J2(PaxLoggingServiceImpl.java:427)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.ops4j.pax.logging.log4j2.internal.PaxLoggingServiceImpl.updated(PaxLoggingServiceImpl.java:269)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.ops4j.pax.logging.log4j2.internal.PaxLoggingServiceImpl$1ManagedPaxLoggingService.updated(PaxLoggingServiceImpl.java:569)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.apache.felix.cm.impl.helper.ManagedServiceTracker.updated(ManagedServiceTracker.java:189)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.apache.felix.cm.impl.helper.ManagedServiceTracker.updateService(ManagedServiceTracker.java:152)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.apache.felix.cm.impl.helper.ManagedServiceTracker.provideConfiguration(ManagedServiceTracker.java:85)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.apache.felix.cm.impl.ConfigurationManager$ManagedServiceUpdate.provide(ConfigurationManager.java:1118)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.apache.felix.cm.impl.ConfigurationManager$ManagedServiceUpdate.run(ConfigurationManager.java:1074)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.apache.felix.cm.impl.UpdateThread.run0(UpdateThread.java:138)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.apache.felix.cm.impl.UpdateThread.run(UpdateThread.java:105)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at java.base/java.lang.Thread.run(Thread.java:834)
INFO   | jvm 1    | 2020/12/22 07:51:10 | org.ops4j.pax.logging.pax-logging-api [log4j2] ERROR : Could not create plugin of type class org.apache.logging.log4j.core.appender.RollingFileAppender for element RollingFile: java.lang.IllegalStateException: ManagerFactory [org.apache.logging.log4j.core.appender.rolling.RollingFileManager$RollingFileManagerFactory@71aabda5] unable to create manager for [${sys:openhab.logdir}/openhab.log] with data [org.apache.logging.log4j.core.appender.rolling.RollingFileManager$FactoryData@95dd3e0[pattern=${sys:openhab.logdir}/openhab.log.%i, append=true, bufferedIO=true, bufferSize=8192, policy=CompositeTriggeringPolicy(policies=[OnStartupTriggeringPolicy, SizeBasedTriggeringPolicy(size=16777216)]), strategy=DefaultRolloverStrategy(min=1, max=7, useMax=true), advertiseURI=null, layout=%d{yyyy-MM-dd HH:mm:ss.SSS} [%-5.5p] [%-36.36c] - %m%n, filePermissions=null, fileOwner=null]] Ignored FQCN: org.apache.logging.log4j.spi.AbstractLogger
INFO   | jvm 1    | 2020/12/22 07:51:10 | java.lang.IllegalStateException: ManagerFactory [org.apache.logging.log4j.core.appender.rolling.RollingFileManager$RollingFileManagerFactory@71aabda5] unable to create manager for [${sys:openhab.logdir}/openhab.log] with data [org.apache.logging.log4j.core.appender.rolling.RollingFileManager$FactoryData@95dd3e0[pattern=${sys:openhab.logdir}/openhab.log.%i, append=true, bufferedIO=true, bufferSize=8192, policy=CompositeTriggeringPolicy(policies=[OnStartupTriggeringPolicy, SizeBasedTriggeringPolicy(size=16777216)]), strategy=DefaultRolloverStrategy(min=1, max=7, useMax=true), advertiseURI=null, layout=%d{yyyy-MM-dd HH:mm:ss.SSS} [%-5.5p] [%-36.36c] - %m%n, filePermissions=null, fileOwner=null]]
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.apache.logging.log4j.core.appender.AbstractManager.getManager(AbstractManager.java:115)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.apache.logging.log4j.core.appender.OutputStreamManager.getManager(OutputStreamManager.java:114)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.apache.logging.log4j.core.appender.rolling.RollingFileManager.getFileManager(RollingFileManager.java:205)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.apache.logging.log4j.core.appender.RollingFileAppender$Builder.build(RollingFileAppender.java:146)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.apache.logging.log4j.core.appender.RollingFileAppender$Builder.build(RollingFileAppender.java:62)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.apache.logging.log4j.core.config.plugins.util.PluginBuilder.build(PluginBuilder.java:122)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.apache.logging.log4j.core.config.AbstractConfiguration.createPluginObject(AbstractConfiguration.java:1002)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:942)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:934)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.apache.logging.log4j.core.config.AbstractConfiguration.doConfigure(AbstractConfiguration.java:552)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.apache.logging.log4j.core.config.AbstractConfiguration.initialize(AbstractConfiguration.java:241)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.apache.logging.log4j.core.config.AbstractConfiguration.start(AbstractConfiguration.java:288)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.apache.logging.log4j.core.LoggerContext.setConfiguration(LoggerContext.java:579)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.apache.logging.log4j.core.LoggerContext.start(LoggerContext.java:285)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.ops4j.pax.logging.log4j2.internal.PaxLoggingServiceImpl.configureLog4J2(PaxLoggingServiceImpl.java:427)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.ops4j.pax.logging.log4j2.internal.PaxLoggingServiceImpl.updated(PaxLoggingServiceImpl.java:269)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.ops4j.pax.logging.log4j2.internal.PaxLoggingServiceImpl$1ManagedPaxLoggingService.updated(PaxLoggingServiceImpl.java:569)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.apache.felix.cm.impl.helper.ManagedServiceTracker.updated(ManagedServiceTracker.java:189)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.apache.felix.cm.impl.helper.ManagedServiceTracker.updateService(ManagedServiceTracker.java:152)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.apache.felix.cm.impl.helper.ManagedServiceTracker.provideConfiguration(ManagedServiceTracker.java:85)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.apache.felix.cm.impl.ConfigurationManager$ManagedServiceUpdate.provide(ConfigurationManager.java:1118)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.apache.felix.cm.impl.ConfigurationManager$ManagedServiceUpdate.run(ConfigurationManager.java:1074)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.apache.felix.cm.impl.UpdateThread.run0(UpdateThread.java:138)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at org.apache.felix.cm.impl.UpdateThread.run(UpdateThread.java:105)
INFO   | jvm 1    | 2020/12/22 07:51:10 |   at java.base/java.lang.Thread.run(Thread.java:834)
fuetti commented 3 years ago

When you start OH with the start.bat file, the log in userdata/logs is used. If you start OP as the service via service wrapper, the files get not created/updated in userdata/logs. But I get the file generated in my c:\ folder then instead.

Fix would be very appreciated. If you need additional info, tell me how I can help.

MHerbst commented 3 years ago

This seems to be same problem that is described here (with solution): https://community.openhab.org/t/solved-when-running-openhab-3-as-a-windows-service-it-takes-wrong-userdata-directory/112110/4?u=mherbst