I note that with the latest version of OH2, there’s no longer a logback file, and we’re using logging associated with Karafa. How can we adjust log levels to something more useful for debugging - the default INFO is of little use unfortunately and the Karafa log commands don’t appear to allow changing of the bundle log levels.
Thanks
Chris
See here:
log:set DEBUG org.openhab.binding.sonos: Enables debug logging for a certain binding.
Ok - thanks. I thought when I tried this earlier it only seemed to change the ‘internal’ stuff (lots more output from the web services, but not z-wave).
Cheers
Chris
Hi Kai,
I tried this again, and it doesn’t appear to change the binding log levels which stay at INFO - just lots of DEBUG from Karafa it seems -:
22:11:10.519 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.binding.zwave (174): Starting destruction process
22:11:10.519 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.binding.zwave (174): Not an extended bundle or destruction of extension already finished
22:11:10.519 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.binding.zwave (174): Starting destruction process
22:11:10.519 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.binding.zwave (174): Not an extended bundle or destruction of extension already finished
22:11:10.536 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.binding.zwave (174): Starting destruction process
22:11:10.536 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.binding.zwave (174): Not an extended bundle or destruction of extension already finished
22:11:10.537 [DEBUG] [e.osgi.LoggingCommandSessionListener] - Command: 'stop 174' returned 'null'
22:11:16.638 [DEBUG] [e.osgi.LoggingCommandSessionListener] - Executing command: 'start 174'
22:11:16.642 [DEBUG] [mpl.info.InfoBundleTrackerCustomizer] - Ignore incorrect info null provided by bundle org.openhab.binding.zwave
22:11:16.681 [INFO ] [ng.zwave.internal.ZWaveActiveBinding] - Update config, port = /dev/tty.usbmodem1421
22:11:16.682 [INFO ] [ve.internal.protocol.ZWaveController] - Starting Z-Wave controller
22:11:16.682 [INFO ] [ve.internal.protocol.ZWaveController] - Z-Wave timeout is set to 5000ms. Soft reset is false.
22:11:16.682 [INFO ] [b.core.service.AbstractActiveService] - ZWave Refresh Service has been started
22:11:16.683 [INFO ] [ve.internal.protocol.ZWaveController] - Connecting to serial port /dev/tty.usbmodem1421
22:11:16.698 [INFO ] [ve.internal.protocol.ZWaveController] - Serial port is initialized
22:11:16.702 [DEBUG] [e.osgi.LoggingCommandSessionListener] - Command: 'start 174' returned 'null'
22:11:16.704 [WARN ] [ssage.ApplicationCommandMessageClass] - NODE 13: Not initialized yet, ignoring message.
22:11:16.707 [WARN ] [ssage.ApplicationCommandMessageClass] - NODE 13: Not initialized yet, ignoring message.
22:11:19.257 [ERROR] [l.ZWaveController$ZWaveReceiveThread] - Message is not valid, discarding
22:11:20.078 [DEBUG] [e.osgi.LoggingCommandSessionListener] - Executing command: 'log:display'
22:11:20.138 [DEBUG] [e.osgi.LoggingCommandSessionListener] - Command: 'log:display' returned 'null'
22:11:22.314 [INFO ] [ve.internal.protocol.ZWaveController] - Disconnected from serial port
22:11:22.315 [INFO ] [ve.internal.protocol.ZWaveController] - Stopped Z-Wave controller
22:11:25.729 [DEBUG] [rg.quartz.core.QuartzSchedulerThread] - batch acquisition of 1 triggers
22:11:26.687 [INFO ] [b.core.service.AbstractActiveService] - ZWave Refresh Service has been shut down
22:11:28.356 [DEBUG] [.conn.PoolingClientConnectionManager] - Connection request: [route: {}->http://192.168.2.102:49153][total kept alive: 2; route allocated: 0 of 100; total allocated: 2 of 1024]
22:11:28.356 [DEBUG] [.conn.PoolingClientConnectionManager] - Connection leased: [id: 338][route: {}->http://192.168.2.102:49153][total kept alive: 2; route allocated: 1 of 100; total allocated: 3 of 1024]
22:11:28.356 [DEBUG] [conn.DefaultClientConnectionOperator] - Connecting to 192.168.2.102:49153
22:11:28.683 [DEBUG] [tp.client.protocol.RequestAddCookies] - CookieSpec selected: best-matchWhat does “log:list” show you?
Logger | Level
--------------------------------------------
ROOT | DEBUG
org.eclipse.smarthome | INFO
org.jupnp | ERROR
org.openhab | INFO
smarthome.event | INFO
smarthome.event.ItemStateEvent | ERROR
smarthome.event.ThingStatusInfoEvent | ERRORSorry - the above was with log:set info, the below is with log:set debug -:
Logger | Level
--------------------------------------------
ROOT | DEBUG
org.eclipse.smarthome | INFO
org.jupnp | ERROR
org.openhab | INFO
smarthome.event | INFO
smarthome.event.ItemStateEvent | ERROR
smarthome.event.ThingStatusInfoEvent | ERRORLooks as if you did
log:set DEBUG
instead of
log:set DEBUG org.openhab.binding.zwave
Correct 
. I’m still coming to grips with Karaf - I’ve not used it before today…
FYI, the zwave binding works fine in the IDE, and it nearly works fine if I remote debug, but doesn’t work fine if I let it run, so it’s not the easiest to work out what’s going on… I think it’s a startup timing related issue…
Thanks.
You might also want to try the latest build, since I enabled a compatibility mode that should actually resolve many issues we have seen with beta1 - maybe the ZWave problem is also solved? I doubt it, but have a try 
FYI, when you run the binding in the IDE, it doesn’t run on Karaf. That can explain some of the differences in behaviour.
Ok - thanks. I’ll let you know…
Sadly, you were right 
Interestingly with this version, it doesn’t seem to pick up bundles in the addons folder…
Thanks Davy - yes, Kai mentioned this… I’m sure once I get over the learning curve, I’ll like Karaf - there are certainly some nice features 
Hmmm - now this feature I like - log filtering 
log:display org.openhab.binding.zwave