Item Debugging Techniques

gduprey · January 29, 2015, 5:40pm

Howdy,

So getting into the item setup. Thanks to @guessed for his item creator, this is going to be a lot easier. There is still a fair amount of expected editing, but it is a great bootstrap.

That said, is there some way to ‘dump’ all the current items and their current values in openhab or, if not, for the mios binding?

I have about 950 items after the generator is run. I suspect there are a lot of them I can just cull as not being something I expect to use (i.e the ID entries) or ones that need to have the format/name changed to better match the data (i.e. some ‘string’ items that are really likely numbers).

Being able to ‘read in’ the generated items file and then dump out the items with their current values would be a huge help to fine tuning what items to keep, which to rename and what formats/descriptions to tweak.

Not looking for anything formatted and a log file output or text file would be just ducky too.

Gerry

guessed · January 29, 2015, 5:56pm

Hey Gerry,
In the openHAB MiOS Item Generator’s transformation file (miosTransform.xslt), find the line that looks like this:

</xsl:choose>{mios="unit:<xsl:value-of select="$MIOS_UNIT"/>,device:<xsl:value-of select="../../@id"/>/service/<xsl:value-of select="$ServiceAlias"/>/<xsl:value-of select="@variable"/>"}

and make look like this (stuff appended to the end):

</xsl:choose>{mios="unit:<xsl:value-of select="$MIOS_UNIT"/>,device:<xsl:value-of select="../../@id"/>/service/<xsl:value-of select="$ServiceAlias"/>/<xsl:value-of select="@variable"/>"} // <xsl:value-of select="@value"/> //

That will make it emit lines like:

DateTime BellBoxZone14LastUpdate "..." <calendar> {mios="..."} // 1362361040 //

with the “current value” at the end of the line. The file won’t have valid Item syntax anymore, but it’ll give you an idea of what value is in there.

guessed · January 29, 2015, 6:57pm

If you find any patterns that are broadly useful for others, let me know the specifics and I’ll work to add them to the generator.

It already has a lot of DataType rules, but I know that list could be more comprehensive - especially for the more common Plugins.

I’m not too worried if there are one-or-two extra Items declared that aren’t needed, but I’m very interested in [common] cases where the DataType should be refined, or where the Item should be [widely] skipped from generation.

@lolodomo: In particular I’m interested in stuff for Sonos and DLNA, since they have a wide user-base that could benefit from improvements to the auto-generation process. I already need to add a swath of stuff for the Weather Service Variables.

gduprey · January 29, 2015, 7:35pm

Again, perfect reply!

I’ll take notes on what I change and post back.

A few things right off is that there are places (mostly in thermostats) where items that should be numeric are define as string. I’ll confirm that more once I make the changes you suggested to get a set of reference values.

Also, temperatures and humidity might be nice to have their value set with F/C formats and/or %RH formats. Right now, all my temp sensors just have %d formats.

Gerry

gduprey · January 30, 2015, 3:27am

Howdy,

So this was incredibly helpful to diagnose and know what sort of data I could have available in my rules. Actually helped shed some light on some of the more subtle aspects of some complex vera/zwave devices.

I modified what you suggested a little bit. Instead of appending

// <xsl:value-of select="@value"/> //

I appended

/** SAMPLE=[<xsl:value-of select="@value"/>] **/

That solved 3 things for me :

I could leave the sample values in the item file, allowing me to work my way through things and still have both the value and a working item.
By putting the VALUE=[] stuff in, I could more easily see when a value had a space or other white space characters.
The expression is unique enough that it will be pretty easy to write a sed script to strip those sample values off the items (if I decide to later)

Question though: When I install the items, pretty raw from the transformation (for testing), I get a lot of ‘NOT BOUND’ messages (I’m in trace mode). These are for devices that do have items defined. For example, this one is coming from a power meter:

2015-01-29 22:22:47.422 [DEBUG] [b.m.internal.MiosUnitConnector] - processResponse: success! loadTime=1422584506, dataVersion=584508144 devices(1) scenes(0) rooms(0) sections(0)
2015-01-29 22:22:47.422 [TRACE] [.o.b.mios.internal.MiosBinding] - internalPropertyUpdate: NOT BOUND {mios="unit:nightmare,device:71/id"}, value=71
2015-01-29 22:22:47.422 [TRACE] [.o.b.mios.internal.MiosBinding] - internalPropertyUpdate: NOT BOUND {mios="unit:nightmare,device:71/status"}, value=-1
2015-01-29 22:22:47.422 [TRACE] [.o.b.mios.internal.MiosBinding] - internalPropertyUpdate: NOT BOUND {mios="unit:nightmare,device:71/service/urn:micasaverde-com:serviceId:EnergyMetering1/KWHReading"}, value=1422588167
2015-01-29 22:22:47.423 [TRACE] [.o.b.mios.internal.MiosBinding] - internalPropertyUpdate: NOT BOUND {mios="unit:nightmare,system:/LoadTime"}, value=2015-01-29T21:21:46
2015-01-29 22:22:47.423 [TRACE] [.o.b.mios.internal.MiosBinding] - internalPropertyUpdate: NOT BOUND {mios="unit:nightmare,system:/DataVersion"}, value=584508144
2015-01-29 22:22:47.423 [TRACE] [.o.b.mios.internal.MiosBinding] - internalPropertyUpdate: NOT BOUND {mios="unit:nightmare,system:/UserData_DataVersion"}, value=584506016
2015-01-29 22:22:47.423 [TRACE] [.o.b.mios.internal.MiosBinding] - internalPropertyUpdate: NOT BOUND {mios="unit:nightmare,system:/TimeStamp"}, value=2015-01-29T22:22:47
2015-01-29 22:22:47.424 [TRACE] [.o.b.mios.internal.MiosBinding] - internalPropertyUpdate: NOT BOUND {mios="unit:nightmare,system:/ZWaveStatus"}, value=1
2015-01-29 22:22:47.424 [TRACE] [.o.b.mios.internal.MiosBinding] - internalPropertyUpdate: NOT BOUND {mios="unit:nightmare,system:/Mode"}, value=1
2015-01-29 22:22:47.424 [TRACE] [.o.b.mios.internal.MiosBinding] - internalPropertyUpdate: NOT BOUND {mios="unit:nightmare,system:/LocalTime"}, value=2015-01-29 22:22:47 N
2015-01-29 22:22:47.424 [DEBUG] [b.m.internal.MiosUnitConnector] - run: URI Built was 'http://vera:3480/data_request?id=status2&LoadTime=1422584506&DataVersion=584508144&Timeout=40&MinimumDelay=0' loop '18'

and here is the related section of items:

/* Device - Panel 2 Master */
Number   Panel2MasterId "ID [%d]" (GDevice) {mios="unit:nightmare,device:71/id"}
String   Panel2MasterDeviceStatus "Panel 2 Master Device Status [%s]" (GDevice) {mios="unit:nightmare,device:71/status"}
String   Panel2MasterDocumentation "Panel 2 Master FIXME Documentation [%s]" {mios="unit:nightmare,device:71/service/HaDevice1/Documentation"} /** SAMPLE=[http://wiki.mios.com/index.php/AeonHEM] **/ 
String   Panel2MasterConfigured "Panel 2 Master FIXME Configured [%s]" {mios="unit:nightmare,device:71/service/HaDevice1/Configured"} /** SAMPLE=[1] **/ 
DateTime Panel2MasterLastUpdate "Panel 2 Master FIXME LastUpdate [%1$ta, %1$tm/%1$te %1$tR]" <calendar> {mios="unit:nightmare,device:71/service/HaDevice1/LastUpdate"} /** SAMPLE=[1420318140] **/ 
DateTime Panel2MasterFirstConfigured "Panel 2 Master FIXME FirstConfigured [%1$ta, %1$tm/%1$te %1$tR]" <calendar> {mios="unit:nightmare,device:71/service/HaDevice1/FirstConfigured"} /** SAMPLE=[1409487481] **/ 
String   Panel2MasterKWH "Panel 2 Master FIXME KWH [%s]" {mios="unit:nightmare,device:71/service/EnergyMetering1/KWH"} /** SAMPLE=[3035.0210] **/ 
String   Panel2MasterKWHReading "Panel 2 Master FIXME KWHReading [%s]" {mios="unit:nightmare,device:71/service/EnergyMetering1/KWHReading"} /** SAMPLE=[1422586817] **/ 
String   Panel2MasterChildrenSameRoom "Panel 2 Master FIXME ChildrenSameRoom [%s]" {mios="unit:nightmare,device:71/service/HaDevice1/ChildrenSameRoom"} /** SAMPLE=[1] **/ 
Number   Panel2MasterWatts "Panel 2 Master FIXME Watts [%d]" {mios="unit:nightmare,device:71/service/EnergyMetering1/Watts"} /** SAMPLE=[383] **/ 
String   Panel2MasterLog "Panel 2 Master FIXME Log [%s]" {mios="unit:nightmare,device:71/service/EnergyMetering1/Log"} /** SAMPLE=[383,747,1220,1422586816,1817] **/ 
String   Panel2MasterActualUsage "Panel 2 Master FIXME ActualUsage [%s]" {mios="unit:nightmare,device:71/service/EnergyMetering1/ActualUsage"} /** SAMPLE=[1] **/ 
Number   Panel2MasterCommFailure "Panel 2 Master FIXME CommFailure [%d]" {mios="unit:nightmare,device:71/service/HaDevice1/CommFailure"} /** SAMPLE=[0] **/ 
String   Panel2MasterCommFailureTime "Panel 2 Master FIXME CommFailureTime [%s]" {mios="unit:nightmare,device:71/service/HaDevice1/CommFailureTime"} /** SAMPLE=[0] **/ 
String   Panel2MasterCurrentLevel "Panel 2 Master FIXME CurrentLevel [%s]" {mios="unit:nightmare,device:71/service/urn:micasaverde-com:serviceId:GenericSensor1/CurrentLevel"} /** SAMPLE=[721] **/ 
Switch   Panel2MasterStatus "Panel 2 Master FIXME Status" {mios="unit:nightmare,device:71/service/SwitchPower1/Status"} /** SAMPLE=[1] **/

What does the NOT BOUND trace messages mean? Is there a problem where OH/MiOS is not connecting the Item definition with data coming from Vera?

Thanks!

Gerry

P.S. And yes, my ‘house’ is ‘nightmare’ for reasons involving a bad joke and property location

guessed · January 30, 2015, 3:51pm

Your Items file looks good, and the NOT BOUND messages indicate that the system doesn’t know about your Items so it’s likely something prevented them from being loaded in the earlier phases.

You’ll need to look earlier in the logs to see what prevented the Items file from being loaded.

In these cases, I manually rotated the [tt]OH/logs/openhab.log[/tt] file and then restart openHAB in order to get a clean log of all initial activity. I’ve had cases where a simple syntax error up front prevents later stuff from loading.

gduprey · January 30, 2015, 4:38pm

I did clean out all logs and restart. Looking at the logs (openhab.log and mios.log), I’m not seeing any errors or exceptions for anything.

I’m still learning to parse these logs, but from what I can see here, it looks like after parsing items for device id 2, it just stops, thinks it’s done and gets on with talking to vera. Can I assume that last line means it’s done parsing the item file?


2015-01-30 11:28:55.963 [TRACE] [.b.m.i.MiosBindingProviderImpl] - parseBindingConfig: unit 'nightmare' thing 'device:2/service/SwitchPower1/Status' inTrans 'null' outTrans 'null'
2015-01-30 11:28:55.964 [TRACE] [.b.m.i.MiosBindingProviderImpl] - parseBindingConfig: in: (Type 'device' id '2' Stuff 'service/SwitchPower1/Status'), command: ('null')
2015-01-30 11:28:55.964 [TRACE] [b.m.i.config.MiosBindingConfig] - Device ParameterDefaults FOUND 'SceneControllerStatus' for 'service/urn:upnp-org:serviceId:SwitchPower1/Status', 'command:ON|OFF,in:MAP(miosSwitchIn.map),out:MAP(miosSwitchOut.map)'
2015-01-30 11:28:55.964 [TRACE] [b.m.i.config.MiosBindingConfig] - Device ParameterDefaults 'SceneControllerStatus' defaulted command: to 'ON|OFF'
2015-01-30 11:28:55.964 [TRACE] [b.m.i.config.MiosBindingConfig] - Device ParameterDefaults 'SceneControllerStatus' defaulted in: to 'MAP(miosSwitchIn.map)'
2015-01-30 11:28:55.964 [TRACE] [b.m.i.config.MiosBindingConfig] - Device ParameterDefaults 'SceneControllerStatus' defaulted out: to 'MAP(miosSwitchOut.map)'
2015-01-30 11:28:55.964 [TRACE] [b.m.i.config.MiosBindingConfig] - newInStuff 'service/urn:upnp-org:serviceId:SwitchPower1/Status', iName 'urn:upnp-org:serviceId:SwitchPower1', iVar 'Status'
2015-01-30 11:28:55.964 [TRACE] [b.m.i.config.MiosBindingConfig] - start: IN 'MAP', 'miosSwitchIn.map'
2015-01-30 11:28:55.964 [TRACE] [b.m.i.config.MiosBindingConfig] - start: OUT 'MAP', 'miosSwitchOut.map'
2015-01-30 11:28:55.965 [DEBUG] [.b.m.i.MiosBindingProviderImpl] - processBindingConfiguration: Adding Item 'SceneControllerStatus' Binding 'unit:nightmare,device:2/service/urn:upnp-org:serviceId:SwitchPower1/Status,command:ON|OFF,in:MAP(miosSwitchIn.map),out:MAP(miosSwitchOut.
map)', from 'nightmare.items'
2015-01-30 11:28:55.970 [DEBUG] [.o.b.mios.internal.MiosBinding] - allBindingsChanged: start provider 'org.openhab.binding.mios.internal.MiosBindingProviderImpl@d0e4ce'

This is an excerpt from the items file showing the end of device id 2 (and you can see that in the above log) and the start of the next device. id 4.

/* Device - _Scene Controller */
Number   SceneControllerId "ID [%d]" (GDevice) {mios="unit:nightmare,device:2/id"}
String   SceneControllerDeviceStatus "_Scene Controller Device Status [%s]" (GDevice) {mios="unit:nightmare,device:2/status"}
String   SceneControllerScenes "_Scene Controller FIXME Scenes [%s]" {mios="unit:nightmare,device:2/service/SceneController1/Scenes"} 
String   SceneControllerIgnoreRoom "_Scene Controller FIXME IgnoreRoom [%s]" {mios="unit:nightmare,device:2/service/HaDevice1/IgnoreRoom"} 
Contact  SceneControllerTripped "_Scene Controller FIXME Tripped [%s]" <contact> {mios="unit:nightmare,device:2/service/SecuritySensor1/Tripped"} 
String   SceneControllerArmedTripped "_Scene Controller FIXME ArmedTripped [%s]" {mios="unit:nightmare,device:2/service/SecuritySensor1/ArmedTripped"} 
DateTime SceneControllerLastTrip "_Scene Controller FIXME LastTrip [%1$ta, %1$tm/%1$te %1$tR]" <calendar> {mios="unit:nightmare,device:2/service/SecuritySensor1/LastTrip"} 
Number   SceneControllerCommFailure "_Scene Controller FIXME CommFailure [%d]" {mios="unit:nightmare,device:2/service/HaDevice1/CommFailure"} 
String   SceneControllerCommFailureTime "_Scene Controller FIXME CommFailureTime [%s]" {mios="unit:nightmare,device:2/service/HaDevice1/CommFailureTime"} 
Switch   SceneControllerStatus "_Scene Controller FIXME Status" {mios="unit:nightmare,device:2/service/SwitchPower1/Status"} 

/* Device - Unused Lamp/Repeater */
Number   UnusedLamp/RepeaterId "ID [%d]" (GDevice) {mios="unit:nightmare,device:4/id"}
String   UnusedLamp/RepeaterDeviceStatus "Unused Lamp/Repeater Device Status [%s]" (GDevice) {mios="unit:nightmare,device:4/status"}
String   UnusedLamp/RepeaterConfigured "Unused Lamp/Repeater FIXME Configured [%s]" {mios="unit:nightmare,device:4/service/HaDevice1/Configured"} 
String   UnusedLamp/RepeaterModeSetting "Unused Lamp/Repeater FIXME ModeSetting [%s]" {mios="unit:nightmare,device:4/service/HaDevice1/ModeSetting"} 
DateTime UnusedLamp/RepeaterLastUpdate "Unused Lamp/Repeater FIXME LastUpdate [%1$ta, %1$tm/%1$te %1$tR]" <calendar> {mios="unit:nightmare,device:4/service/HaDevice1/LastUpdate"} 
DateTime UnusedLamp/RepeaterFirstConfigured "Unused Lamp/Repeater FIXME FirstConfigured [%1$ta, %1$tm/%1$te %1$tR]" <calendar> {mios="unit:nightmare,device:4/service/HaDevice1/FirstConfigured"} 
Switch   UnusedLamp/RepeaterStatus "Unused Lamp/Repeater FIXME Status" {mios="unit:nightmare,device:4/service/SwitchPower1/Status"} 
Dimmer   UnusedLamp/RepeaterLoadLevelStatus "Unused Lamp/Repeater FIXME LoadLevelStatus [%d] %" {mios="unit:nightmare,device:4/service/Dimming1/LoadLevelStatus"} 
Number   UnusedLamp/RepeaterLoadLevelTarget "Unused Lamp/Repeater FIXME LoadLevelTarget [%d]" {mios="unit:nightmare,device:4/service/Dimming1/LoadLevelTarget"} 
Number   UnusedLamp/RepeaterCommFailure "Unused Lamp/Repeater FIXME CommFailure [%d]" {mios="unit:nightmare,device:4/service/HaDevice1/CommFailure"} 
String   UnusedLamp/RepeaterCommFailureTime "Unused Lamp/Repeater FIXME CommFailureTime [%s]" {mios="unit:nightmare,device:4/service/HaDevice1/CommFailureTime"}

Later in the log file, anything about device id 4 shows as NOT BOUND, so it appears that immediately after parsing device 2, something is making it stop/give up/etc.

Any thoughts on what to look at next?

Gerry

guessed · January 30, 2015, 4:52pm

I need to eliminate ALL non-AlphaNumeric characters from Item names in the generator, because it’s generating invalid Item names with the “/” in them.

For a quick-fix, look for this string "#.() " throughout the miosTransform.xslt file, and add “/” to it so it looks like "#.()/ ".

I’ll see if I can do it more generically. Unfortunately, XSLT 1.x doesn’t have support for regex, so we’ll see how I go.

d55m14 · January 30, 2015, 6:06pm

I guessed,

i noticed in my items name a ‘-’ char too that is invalid .

Tnks donato

guessed · January 30, 2015, 6:08pm

That’s fixed in the latest version, along with a bunch of others.

gduprey · January 30, 2015, 8:09pm

Great! Downloaded your updated script and ran it through. Only getting a few NOT BOUND and they are things I’d expect.

Now to some serious tailoring time!

Thanks for such a great tool!

Gerry