chris
(Chris Jackson)
January 17, 2016, 10:01pm
1
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
1 Like
chris
(Chris Jackson)
January 17, 2016, 10:09pm
3
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
chris
(Chris Jackson)
January 17, 2016, 10:16pm
4
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-match
Kai
(Kai Kreuzer)
January 17, 2016, 10:23pm
5
What does “log:list” show you?
chris
(Chris Jackson)
January 17, 2016, 10:24pm
6
Logger | Level
--------------------------------------------
ROOT | DEBUG
org.eclipse.smarthome | INFO
org.jupnp | ERROR
org.openhab | INFO
smarthome.event | INFO
smarthome.event.ItemStateEvent | ERROR
smarthome.event.ThingStatusInfoEvent | ERROR
chris
(Chris Jackson)
January 17, 2016, 10:25pm
7
Sorry - 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 | ERROR
1 Like
Kai
(Kai Kreuzer)
January 17, 2016, 10:25pm
8
Looks as if you did
log:set DEBUG
instead of
log:set DEBUG org.openhab.binding.zwave
2 Likes
chris
(Chris Jackson)
January 17, 2016, 10:29pm
9
Kai:
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.
Kai
(Kai Kreuzer)
January 17, 2016, 10:33pm
10
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
davy
(Davy Vanherbergen)
January 17, 2016, 10:35pm
11
chris:
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…
FYI, when you run the binding in the IDE, it doesn’t run on Karaf. That can explain some of the differences in behaviour.
chris
(Chris Jackson)
January 17, 2016, 10:35pm
12
Ok - thanks. I’ll let you know…
chris
(Chris Jackson)
January 17, 2016, 11:16pm
13
Kai:
maybe the ZWave problem is also solved? I doubt it, but have a try
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
chris
(Chris Jackson)
January 17, 2016, 11:18pm
14
Hmmm - now this feature I like - log filtering
log:display org.openhab.binding.zwave
3 Likes