how did you perform the cleaning of /var/lib/openhab2/cache & /var/lib/openhab2/tmp directories?
It seems that some specific method (on openHABian that I haven’t been able to identify until now) results in modified permissions after the cleaning of these 2 subdirs, and as a result, OH2 service (using username openhab) will not be able to write into them afterwards.
first check current permissions:
ls -al /var/lib/openhab2/cache /var/lib/openhab2/tmp
this is not a problem since these files have a read permission for all, so you are fine with that.
OH2 process (running as the openhab user) simply reads them (no need to write and/or execute).
The OH2 process needs to be able to write into other dirs (e.g. log, tmp, cache, jsondb, etc). Mainly in $OPENHAB_USERDATA (/var/lib/openhab2/) space.
How did you clear the tmp & cache in the first place and what permissions did you have on tmp & cache?
not exactly the same… I don’t see any permission denied errors.
what does openhab.log say?
try clearing tmp & cache again and make sure that the permissions are ok within /var/lib/openhab2/
I cleared it with the above guide first by using the clean command then after that did not work I deleted them with the second guide. They did have root root permissions until I changed them like you said. I will check log again now and check permissions
you mean: openhab-cli clean-cache ?
did you run it as root or as openhabian user?
I am trying to reproduce the steps because I have seen this problem several times but I can’t identify the exact steps that were taken.
what do you mean: “did not work” ? the dirs were not removed with openhab-cli clean-cache ?
which is the second guide ? (link to it plz)
Yes I used openhab-cli clean-cache,
No I mean the problem wasn’t resolved to intrude the second option. I used the sudo command at the start logged in as openhabian user.
The permissions are as follows
`[22:20:17] openhabian@openHABianPi:/$ ls -l /var/lib/openhab2/
total 16332
drwxrwxr-x+ 4 openhab openhab 4096 Dec 21 18:53 cache
drwxrwxr-x+ 5 openhab openhab 4096 Dec 21 18:53 config
-rw-rw-r-- 1 root root 7248681 Dec 21 17:58 dump-2018-12-21_175738-883.zip
-rw-rw-r-- 1 root root 9432921 Dec 21 18:56 dump-2018-12-21_185623-990.zip
drwxrwxr-x+ 3 openhab openhabian 12288 Dec 21 18:43 etc
drwxrwxr-x+ 3 openhab openhab 4096 Dec 21 17:41 jsondb
drwxrwxr-x+ 2 openhab openhab 4096 May 28 2018 openhabcloud
drwxrwxr-x+ 5 openhab openhabian 4096 May 28 2018 persistence
drwxrwxr-x+ 8 openhab openhab 4096 Dec 21 21:29 tmp
-rw-rw-r-- 1 openhab openhab 37 May 28 2018 uuid`
`[22:44:23] openhabian@openHABianPi:~$ tail -f /var/log/openhab2/openhab.log
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1317) ~[?:?]
at org.ops4j.pax.web.service.jetty.internal.HttpServiceContext.doHandle(HttpServiceContext.java:293) ~[?:?]
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203) ~[?:?]
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:473) ~[?:?]
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1564) ~[?:?]
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201) ~[?:?]
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1219) ~[?:?]
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144) ~[?:?]
at org.ops4j.pax.web.service.jetty.internal.JettyServerHandlerCollection.handle(JettyServerHandlerCollection.java:80) ~[?:?]
... 15 more`
2018-12-21 23:02:52.408 [SEVERE] [org.apache.karaf.main.Main] - Could not launch fram
ework
java.lang.RuntimeException: Error initializing storage.
at org.eclipse.osgi.internal.framework.EquinoxContainer.(EquinoxContain
er.java:70)
at org.eclipse.osgi.launch.Equinox.(Equinox.java:31)
at org.eclipse.osgi.launch.EquinoxFactory.newFramework(EquinoxFactory.java:24
)
at org.apache.karaf.main.Main.launch(Main.java:256)
at org.apache.karaf.main.Main.main(Main.java:178)
Caused by: java.io.FileNotFoundException: /var/lib/openhab2/cache/org.eclipse.osgi/.m
anager/.fileTableLock (Permission denied)
at java.io.RandomAccessFile.open0(Native Method)
at java.io.RandomAccessFile.open(RandomAccessFile.java:316)
at java.io.RandomAccessFile.(RandomAccessFile.java:243)
at org.eclipse.osgi.internal.location.Locker_JavaNio.lock(Locker_JavaNio.java
:36)
at org.eclipse.osgi.storagemanager.StorageManager.lock(StorageManager.java:38
8)
at org.eclipse.osgi.storagemanager.StorageManager.open(StorageManager.java:70
1)
at org.eclipse.osgi.storage.Storage.getChildStorageManager(Storage.java:1776)
at org.eclipse.osgi.storage.Storage.getInfoInputStream(Storage.java:1793)
at org.eclipse.osgi.storage.Storage.(Storage.java:132)
at org.eclipse.osgi.storage.Storage.createStorage(Storage.java:85)
at org.eclipse.osgi.internal.framework.EquinoxContainer.(EquinoxContain
er.java:68)
… 4 more
2018-12-21 23:03:03.560 [SEVERE] [org.apache.karaf.main.Main] - Could not launch fram
ework
java.lang.RuntimeException: Error initializing storage.
at org.eclipse.osgi.internal.framework.EquinoxContainer.(EquinoxContain
er.java:70)
at org.eclipse.osgi.launch.Equinox.(Equinox.java:31)
at org.eclipse.osgi.launch.EquinoxFactory.newFramework(EquinoxFactory.java:24
)
at org.apache.karaf.main.Main.launch(Main.java:256)
at org.apache.karaf.main.Main.main(Main.java:178)
Caused by: java.io.FileNotFoundException: /var/lib/openhab2/cache/org.eclipse.osgi/.m
anager/.fileTableLock (Permission denied)
at java.io.RandomAccessFile.open0(Native Method)
at java.io.RandomAccessFile.open(RandomAccessFile.java:316)
at java.io.RandomAccessFile.(RandomAccessFile.java:243)
at org.eclipse.osgi.internal.location.Locker_JavaNio.lock(Locker_JavaNio.java
:36)
at org.eclipse.osgi.storagemanager.StorageManager.lock(StorageManager.java:38
8)
at org.eclipse.osgi.storagemanager.StorageManager.open(StorageManager.java:70
–More–(86%)
no need to change the permissions openhab-cli clean-cache will remove both tmp and cache subdirs
OH2 will recreate them with the proper permissions when it starts
just execute the commands as listed
i still don’t understand how you ended up with files being owned by root:root within these 2 subfolders…
I have seen this before and I don’t know which steps are done to end up with this situation…
(maybe you shouldn’t sudo openhab-cli but simply openhab-cli ? but this should not be the problem)
`2018-12-21 23:20:40.078 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Location set to '53.68352473443406,-2.91215297395416'.
2018-12-21 23:20:54.047 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘home.rules’
2018-12-21 23:20:54.134 [WARN ] [el.core.internal.ModelRepositoryImpl] - Configuration model ‘home.rules’ is either empty or cannot be parsed correctly!2018-12-21 23:21:00.243 [INFO ] [.dashboard.internal.DashboardService] - Started Dashboard at http://192.168.1.113:8080
2018-12-21 23:21:00.248 [INFO ] [.dashboard.internal.DashboardService] - Started Dashboard at https://192.168.1.113:8443
2018-12-21 23:21:05.956 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘home.things’
2018-12-21 23:21:05.973 [WARN ] [el.core.internal.ModelRepositoryImpl] - Configuration model ‘home.things’ is either empty or cannot be parsed correctly!
2018-12-21 23:21:08.905 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘home.items’
2018-12-21 23:21:13.136 [INFO ] [thome.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007
2018-12-21 23:21:14.418 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘home.sitemap’
2018-12-21 23:22:10.258 [INFO ] [ebuilder.internal.HomeBuilderServlet] - Started Home Builder at /homebuilder
2018-12-21 23:22:10.552 [INFO ] [panel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel
2018-12-21 23:22:11.358 [INFO ] [etvisu.internal.servlet.CometVisuApp] - Started CometVisu UI at /cometvisu serving …/…/…/CometVisu/src/
2018-12-21 23:22:15.793 [INFO ] [io.openhabcloud.internal.CloudClient] - Connected to the openHAB Cloud service (UUID = 75d6ab02-7c9a-47d7-9dd9-d8b6e57f6cf2, base URL = http://localhost:8080)
2018-12-21 23:22:22.077 [INFO ] [ui.habmin.internal.servlet.HABminApp] - Started HABmin servlet at /habmin
2018-12-21 23:22:24.295 [ERROR] [ipse.smarthome.io.mqttembeddedbroker] - bundle org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240 (213)[org.eclipse.smarthome.io.mqttembeddedbroker.internal.EmbeddedBrokerServiceImpl(299)] : The activate method has thrown an exception
java.net.BindException: Address already in use
at sun.nio.ch.Net.bind0(Native Method) ~[?:?]
at sun.nio.ch.Net.bind(Net.java:433) ~[?:?]
at sun.nio.ch.Net.bind(Net.java:425) ~[?:?]
at sun.nio.ch.ServerSocketChannelImpl.bind(ServerSocketChannelImpl.java:223) ~[?:?]
at io.netty.channel.socket.nio.NioServerSocketChannel.doBind(NioServerSocketChannel.java:128) ~[?:?]
at io.netty.channel.AbstractChannel$AbstractUnsafe.bind(AbstractChannel.java:558) ~[?:?]
at io.netty.channel.DefaultChannelPipeline$HeadContext.bind(DefaultChannelPipeline.java:1283) ~[?:?]
at io.netty.channel.AbstractChannelHandlerContext.invokeBind(AbstractChannelHandlerContext.java:501) ~[?:?]
at io.netty.channel.AbstractChannelHandlerContext.bind(AbstractChannelHandlerContext.java:486) ~[?:?]
at io.netty.channel.DefaultChannelPipeline.bind(DefaultChannelPipeline.java:989) ~[?:?]
at io.netty.channel.AbstractChannel.bind(AbstractChannel.java:254) ~[?:?]
at io.netty.bootstrap.AbstractBootstrap$2.run(AbstractBootstrap.java:364) ~[?:?]
at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:163) ~[?:?]
at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:404) ~[?:?]
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:463) ~[?:?]
at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:886) ~[?:?]
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) ~[?:?]
at java.lang.Thread.run(Thread.java:748) [?:?]
2018-12-21 23:22:24.394 [WARN ] [ipse.smarthome.io.mqttembeddedbroker] - FrameworkEvent WARNING - org.eclipse.smarthome.io.mqttembeddedbroker
org.osgi.framework.ServiceException: org.apache.felix.scr.impl.manager.SingleComponentManager.getService() returned a null service object
at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.factoryGetService(ServiceFactoryUse.java:232) ~[?:?]
at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.getService(ServiceFactoryUse.java:111) ~[?:?]
at org.eclipse.osgi.internal.serviceregistry.ServiceConsumer$2.getService(ServiceConsumer.java:45) ~[?:?]
at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.getService(ServiceRegistrationImpl.java:508) ~[?:?]
at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.getService(ServiceRegistry.java:461) ~[?:?]
at org.eclipse.osgi.internal.framework.BundleContextImpl.getService(BundleContextImpl.java:624) ~[?:?]
at com.eclipsesource.jaxrs.publisher.internal.ResourceTracker.addingService(ResourceTracker.java:39) ~[?:?]
at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:941) ~[?:?]
at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:870) ~[?:?]
at org.osgi.util.tracker.AbstractTracked.trackAdding(AbstractTracked.java:256) ~[?:?]
at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:229) ~[?:?]
at org.osgi.util.tracker.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:901) ~[?:?]
at org.eclipse.osgi.internal.serviceregistry.FilteredServiceListener.serviceChanged(FilteredServiceListener.java:109) ~[?:?]
at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:920) ~[?:?]
at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) ~[?:?]
at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148) ~[?:?]
at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEventPrivileged(ServiceRegistry.java:862) ~[?:?]
at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry$1.run(ServiceRegistry.java:805) ~[?:?]
at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry$1.run(ServiceRegistry.java:1) ~[?:?]
at java.security.AccessController.doPrivileged(Native Method) ~[?:?]
at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEvent(ServiceRegistry.java:803) ~[?:?]
at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.register(ServiceRegistrationImpl.java:127) ~[?:?]
at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.registerService(ServiceRegistry.java:225) ~[?:?]
at org.eclipse.osgi.internal.framework.BundleContextImpl.registerService(BundleContextImpl.java:469) ~[?:?]
at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:891) ~[?:?]
at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:877) ~[?:?]
at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:128) ~[?:?]
at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:944) ~[?:?]
at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:727) ~[?:?]
at org.apache.felix.scr.impl.manager.AbstractComponentManager.enableInternal(AbstractComponentManager.java:661) ~[?:?]
at org.apache.felix.scr.impl.manager.AbstractComponentManager.enable(AbstractComponentManager.java:427) ~[?:?]
at org.apache.felix.scr.impl.manager.ConfigurableComponentHolder.enableComponents(ConfigurableComponentHolder.java:665) ~[?:?]
at org.apache.felix.scr.impl.BundleComponentActivator.initialEnable(BundleComponentActivator.java:339) ~[?:?]
at org.apache.felix.scr.impl.Activator.loadComponents(Activator.java:381) ~[?:?]
at org.apache.felix.scr.impl.Activator.access$200(Activator.java:49) ~[?:?]
at org.apache.felix.scr.impl.Activator$ScrExtension.start(Activator.java:263) ~[?:?]
at org.apache.felix.scr.impl.AbstractExtender.createExtension(AbstractExtender.java:196) ~[?:?]
at org.apache.felix.scr.impl.AbstractExtender.modifiedBundle(AbstractExtender.java:169) ~[?:?]
at org.apache.felix.scr.impl.AbstractExtender.modifiedBundle(AbstractExtender.java:49) ~[?:?]
at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:482) ~[?:?]
at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:415) ~[?:?]
at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:232) ~[?:?]
at org.osgi.util.tracker.BundleTracker$Tracked.bundleChanged(BundleTracker.java:444) ~[?:?]
at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:908) ~[?:?]
at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) ~[?:?]
at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148) ~[?:?]
at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEventPrivileged(EquinoxEventPublisher.java:213) ~[?:?]
at org.eclipse.osgi.internal.framework.EquinoxEventPublisher$1.run(EquinoxEventPublisher.java:124) ~[?:?]
at org.eclipse.osgi.internal.framework.EquinoxEventPublisher$1.run(EquinoxEventPublisher.java:1) ~[?:?]
at java.security.AccessController.doPrivileged(Native Method) ~[?:?]
at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:122) ~[?:?]
at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:112) ~[?:?]
at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor.publishModuleEvent(EquinoxContainerAdaptor.java:168) ~[?:?]
at org.eclipse.osgi.container.Module.publishEvent(Module.java:476) ~[?:?]
at org.eclipse.osgi.container.Module.start(Module.java:467) ~[?:?]
at org.eclipse.osgi.internal.framework.EquinoxBundle.start(EquinoxBundle.java:383) ~[?:?]
at org.eclipse.osgi.internal.framework.EquinoxBundle.start(EquinoxBundle.java:402) ~[?:?]
at org.apache.karaf.features.internal.service.BundleInstallSupportImpl.startBundle(BundleInstallSupportImpl.java:161) ~[?:?]
at org.apache.karaf.features.internal.service.FeaturesServiceImpl.startBundle(FeaturesServiceImpl.java:1116) ~[?:?]
at org.apache.karaf.features.internal.service.Deployer.deploy(Deployer.java:997) ~[?:?]
at org.apache.karaf.features.internal.service.FeaturesServiceImpl.doProvision(FeaturesServiceImpl.java:1025) ~[?:?]
at org.apache.karaf.features.internal.service.FeaturesServiceImpl.lambda$doProvisionInThread$13(FeaturesServiceImpl.java:964) ~[?:?]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[?:?]
at java.lang.Thread.run(Thread.java:748) ~[?:?]
2018-12-21 23:22:24.428 [ERROR] [ipse.smarthome.io.mqttembeddedbroker] - bundle org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240 (213)[org.eclipse.smarthome.io.mqttembeddedbroker.internal.EmbeddedBrokerServiceImpl(299)] : The activate method has thrown an exception
java.net.BindException: Address already in use
at sun.nio.ch.Net.bind0(Native Method) ~[?:?]
at sun.nio.ch.Net.bind(Net.java:433) ~[?:?]
at sun.nio.ch.Net.bind(Net.java:425) ~[?:?]
at sun.nio.ch.ServerSocketChannelImpl.bind(ServerSocketChannelImpl.java:223) ~[?:?]
at io.netty.channel.socket.nio.NioServerSocketChannel.doBind(NioServerSocketChannel.java:128) ~[?:?]
at io.netty.channel.AbstractChannel$AbstractUnsafe.bind(AbstractChannel.java:558) ~[?:?]
at io.netty.channel.DefaultChannelPipeline$HeadContext.bind(DefaultChannelPipeline.java:1283) ~[?:?]
at io.netty.channel.AbstractChannelHandlerContext.invokeBind(AbstractChannelHandlerContext.java:501) ~[?:?]
at io.netty.channel.AbstractChannelHandlerContext.bind(AbstractChannelHandlerContext.java:486) ~[?:?]
at io.netty.channel.DefaultChannelPipeline.bind(DefaultChannelPipeline.java:989) ~[?:?]
at io.netty.channel.AbstractChannel.bind(AbstractChannel.java:254) ~[?:?]
at io.netty.bootstrap.AbstractBootstrap$2.run(AbstractBootstrap.java:364) ~[?:?]
at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:163) ~[?:?]
at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:404) ~[?:?]
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:463) ~[?:?]
at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:886) ~[?:?]
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) ~[?:?]
at java.lang.Thread.run(Thread.java:748) [?:?]
2018-12-21 23:22:24.923 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /paperui
`
do you need the embedded MQTT Broker?
looks like you are using already another Broker on your system (maybe Mosquitto?) that is conflicting with the embedded.
If you are using an external broker, uninstall the embedded broker addon
Ps: When starting code fences, use: ``` in one line, paste the stuff in the next line and at the end close the code with another ``` in a new line
like this:
```
code/log…
code/log…
code/log…
code/log…
code/log…
code/log…
```