zwave.me ZME / UZB1 (Sigma) with Fibaro FGMS-001 Motion Sensors

[GoogleCodeExporter]

What steps will reproduce the problem?
1. Using Domoticz when adding Fibaro FGMS-001 I have been able to include but 
then the device fails to report motion, lux or temperature - my two TKB energy 
power switches appear to work ok with this controller but OZW_log.txt has a 
number of warnings/errors - see below.  I have re-included, deleted and still 
not working so I turned to OZW_log.txt and now I need help :-).
2. I apologise in advance if I am missing something fundamental and feel free 
to refer me to the manual :-).
3.

What is the expected output? What do you see instead?
I would like to see motion, temperature, lux levels reported and on waking up 
the device manually (pressing button b three times) the configuration doesn't 
appear to update correctly.
The controller doesn't appear to be properly recognised in Domoticz (v2.2182) - 
it shows as 
Z-Wave.Me Unknown: type=0400, id=0001 - which is odd as the description is 
present in both ozw and domoticz manufacturer_specific.xml (I have re-run make 
of Domoticz recently)
<Product type="0400" id="0001" name="ZME_UZB1 USB Stick"/>

These warnings/errors:
2015-01-01 17:38:15.777 Warning, WARNING: Out of frame flow! (0x07).  Sending 
NAK.
2015-01-01 17:38:15.778 Warning, WARNING: Out of frame flow! (0x00).  Sending 
NAK.
2015-01-01 17:38:15.779 Warning, WARNING: Out of frame flow! (0x13).  Sending 
NAK.
…
2015-01-01 17:39:34.124 Warning, Exception: Manager.cpp:1477 - 101 - Invalid 
ValueID passed to GetValueLabel
...
2015-01-01 17:39:43.884 Info, Node004, ApplicationCommandHandler - Unhandled 
Command Class 0x32
…

2015-01-01 17:40:15.808 Error, Node001, ERROR: Dropping command, expected 
response not received after 3 attempt(s)

What version of the product are you using? On what operating system?

Ubuntu 14.04
Domoticz v2.2182
OZW 1.3

What branch of the code were you using? 
trunk

Please include the file OZW_Log.txt from your program. Make sure the file
zwcfg*.xml is NOT present.

Please provide any additional information below.
I renamed my zwave*.xml file and let it recreate but this hasn't addressed the 
problem.   
Node003/004 are the TKB
Node006 is the Fibaro FGMS
The gaps are due to multiple remove/re-includes

Thanks a lot!

Original issue reported on code.google.com by whiteduc...@gmail.com on 1 Jan 2015 at 6:12

Attachments:

• OZW_Log.txt

[GoogleCodeExporter]

A few more warnings I spotted:
2015-01-01 17:38:43.958 Info, Node004, ApplicationCommandHandler - Unhandled 
Command Class 0x32
2015-01-01 17:38:56.600 Info, Node006, ApplicationCommandHandler - Unhandled 
Command Class 0x9c
2015-01-01 17:38:56.624 Info, Node006, ApplicationCommandHandler - Unhandled 
Command Class 0x9c
2015-01-01 17:39:43.884 Info, Node004, ApplicationCommandHandler - Unhandled 
Command Class 0x32

Original comment by whiteduc...@gmail.com on 1 Jan 2015 at 6:31

[GoogleCodeExporter]

Just an update: A second restart of domoticz has fixed the problem where the 
controller was not being recognised and I am not seeing those cpp warnings or 
the Unhandled ones.

Things look better (not sure why) but I still see lots of these throughout the 
log file:

2015-01-01 18:54:44.683 Warning, WARNING: Out of frame flow! (0x21).  Sending 
NAK.
2015-01-01 18:54:44.685 Warning, WARNING: Out of frame flow! (0x34).  Sending 
NAK.
2015-01-01 18:54:44.687 Warning, WARNING: Out of frame flow! (0x00).  Sending 
NAK.

Original comment by whiteduc...@gmail.com on 1 Jan 2015 at 7:03

[GoogleCodeExporter]

The out of frame flow: indicates the serial data from the controller is getting 
corrupted. Make sure no other app etc is also opening the serial port. Worst 
case, you have a faulty controller. 

No reports of motion etc. check the associations and the device is configured 
to send the correct reports on motion ( not basic - see here 
https://code.google.com/p/open-zwave/wiki/Basic_Command_Class) 

The invalid ValueID message is caused by Domoticz. Please report to them. 

Original comment by jus...@dynam.ac on 1 Jan 2015 at 7:14

• Changed title: zwave.me ZME / UZB1 (Sigma) with Fibaro FGMS-001 Motion Sensors

[GoogleCodeExporter]

Sorry to add lots of comments - when I say better - i still have the issue with 
the PIR not reliably being seen...

Original comment by whiteduc...@gmail.com on 1 Jan 2015 at 7:32

[GoogleCodeExporter]

Bit more info - I have been playing with the on / off of the TKB devices to see 
if there are other issues - sometimes the commands are immediate - other times 
it can take a while before anything appears in OZW_Log.txt - perhaps that is 
Domoticz but the server is not CPU bound…  in the example below the command 
is accepted immediate by OZW but queued for 25 seconds - is this normal?

2015-01-01 19:46:36.994 Info, Node003, Value::Set - COMMAND_CLASS_SWITCH_BINARY 
- Switch - 0 - 1 - True
2015-01-01 19:46:36.994 Info, Node003, SwitchBinary::Set - Setting node 3 to On
2015-01-01 19:46:36.994 Detail, Node003, Queuing (Send) SwitchBinaryCmd_Set 
(Node=3): 0x01, 0x0a, 0x00, 0x13, 0x03, 0x03, 0x25, 0x01, 0xff, 0x25, 0xbc, 0xa4
2015-01-01 19:46:36.994 Detail, Node003, Queuing (Send) SwitchBinaryCmd_Get 
(Node=3): 0x01, 0x09, 0x00, 0x13, 0x03, 0x02, 0x25, 0x02, 0x25, 0xbd, 0x5b
2015-01-01 19:46:44.142 Detail, Node004,   Received: 0x01, 0x14, 0x00, 0x04, 
0x00, 0x04, 0x0e, 0x32, 0x02, 0x21, 0x34, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 
0x00, 0x00, 0x00, 0x00, 0xc0
2015-01-01 19:46:44.143 Detail, 
2015-01-01 19:46:44.143 Detail, Node004, Refreshed Value: old value=false, new 
value=false, type=bool
2015-01-01 19:46:44.143 Detail, Node004, Changes to this value are not verified
2015-01-01 19:46:44.143 Info, Node004, Received Meter report from node 4: 
Power=0.0W
2015-01-01 19:46:44.143 Detail, Node004, Refreshed Value: old value=0.0, new 
value=0.0, type=string
2015-01-01 19:46:44.143 Detail, Node004, Changes to this value are not verified
2015-01-01 19:47:01.106 Detail, 
2015-01-01 19:47:01.106 Info, Node003, Sending (Send) message (Attempt 2, 
Callback ID=0xbe, Expected Reply=0x13) - SwitchBinaryCmd_Set (Node=3): 0x01, 
0x0a, 0x00, 0x13, 0x03, 0x03, 0x25, 0x01, 0x00, 0x25, 0xbe, 0x59
2015-01-01 19:47:01.208 Detail, Node003,   Received: 0x01, 0x04, 0x01, 0x13, 
0x01, 0xe8
2015-01-01 19:47:01.208 Detail, Node003,   ZW_SEND_DATA delivered to Z-Wave 
stack
2015-01-01 19:47:01.229 Detail, Node003,   Received: 0x01, 0x07, 0x00, 0x13, 
0xbe, 0x00, 0x00, 0x02, 0x57
2015-01-01 19:47:01.229 Detail, Node003,   ZW_SEND_DATA Request with callback 
ID 0xbe received (expected 0xbe)
2015-01-01 19:47:01.229 Info, Node003, Request RTT 122 Average Request RTT 153
2015-01-01 19:47:01.229 Detail, Node003,   Expected reply was received
2015-01-01 19:47:01.229 Detail, Node003,   Message transaction complete
2015-01-01 19:47:01.229 Detail, 
2015-01-01 19:47:01.229 Detail, Node003, Removing current message
2015-01-01 19:47:01.229 Detail, 
2015-01-01 19:47:01.229 Info, Node003, Sending (Send) message (Callback 
ID=0xbb, Expected Reply=0x04) - SwitchBinaryCmd_Get (Node=3): 0x01, 0x09, 0x00, 
0x13, 0x03, 0x02, 0x25, 0x02, 0x25, 0xbb, 0x5d
2015-01-01 19:47:01.246 Detail, Node003,   Received: 0x01, 0x04, 0x01, 0x13, 
0x01, 0xe8
2015-01-01 19:47:01.246 Detail, Node003,   ZW_SEND_DATA delivered to Z-Wave 
stack
2015-01-01 19:47:01.264 Detail, Node003,   Received: 0x01, 0x07, 0x00, 0x13, 
0xbb, 0x00, 0x00, 0x02, 0x52
2015-01-01 19:47:01.264 Detail, Node003,   ZW_SEND_DATA Request with callback 
ID 0xbb received (expected 0xbb)
2015-01-01 19:47:01.264 Info, Node003, Request RTT 34 Average Request RTT 93
2015-01-01 19:47:01.282 Detail, Node003,   Received: 0x01, 0x09, 0x00, 0x04, 
0x00, 0x03, 0x03, 0x25, 0x03, 0x00, 0xd4
2015-01-01 19:47:01.283 Detail, 
2015-01-01 19:47:01.283 Info, Node003, Response RTT 53 Average Response RTT 54
2015-01-01 19:47:01.283 Info, Node003, Received SwitchBinary report from node 
3: level=Off
2015-01-01 19:47:01.283 Detail, Node003, Refreshed Value: old value=false, new 
value=false, type=bool
2015-01-01 19:47:01.283 Detail, Node003, Changes to this value are not verified
2015-01-01 19:47:01.283 Detail, Node003,   Expected reply and command class was 
received
2015-01-01 19:47:01.283 Detail, Node003,   Message transaction complete
2015-01-01 19:47:01.283 Detail, 
2015-01-01 19:47:01.283 Detail, Node003, Removing current message
2015-01-01 19:47:01.288 Detail, 
2015-01-01 19:47:01.288 Info, Node003, Sending (Send) message (Callback 
ID=0xbc, Expected Reply=0x13) - SwitchBinaryCmd_Set (Node=3): 0x01, 0x0a, 0x00, 
0x13, 0x03, 0x03, 0x25, 0x01, 0xff, 0x25, 0xbc, 0xa4
2015-01-01 19:47:01.305 Detail, Node003,   Received: 0x01, 0x04, 0x01, 0x13, 
0x01, 0xe8
2015-01-01 19:47:01.305 Detail, Node003,   ZW_SEND_DATA delivered to Z-Wave 
stack
2015-01-01 19:47:01.325 Detail, Node003,   Received: 0x01, 0x07, 0x00, 0x13, 
0xbc, 0x00, 0x00, 0x02, 0x55
2015-01-01 19:47:01.325 Detail, Node003,   ZW_SEND_DATA Request with callback 
ID 0xbc received (expected 0xbc)
2015-01-01 19:47:01.325 Info, Node003, Request RTT 37 Average Request RTT 65
2015-01-01 19:47:01.326 Detail, Node003,   Expected reply was received
2015-01-01 19:47:01.326 Detail, Node003,   Message transaction complete
2015-01-01 19:47:01.326 Detail, 
2015-01-01 19:47:01.326 Detail, Node003, Removing current message
2015-01-01 19:47:01.326 Detail, 
2015-01-01 19:47:01.326 Info, Node003, Sending (Send) message (Callback 
ID=0xbd, Expected Reply=0x04) - SwitchBinaryCmd_Get (Node=3): 0x01, 0x09, 0x00, 
0x13, 0x03, 0x02, 0x25, 0x02, 0x25, 0xbd, 0x5b
2015-01-01 19:47:01.342 Detail, Node003,   Received: 0x01, 0x04, 0x01, 0x13, 
0x01, 0xe8
2015-01-01 19:47:01.342 Detail, Node003,   ZW_SEND_DATA delivered to Z-Wave 
stack
2015-01-01 19:47:01.364 Detail, Node003,   Received: 0x01, 0x07, 0x00, 0x13, 
0xbd, 0x00, 0x00, 0x02, 0x54
2015-01-01 19:47:01.365 Detail, Node003,   ZW_SEND_DATA Request with callback 
ID 0xbd received (expected 0xbd)
2015-01-01 19:47:01.365 Info, Node003, Request RTT 38 Average Request RTT 51
2015-01-01 19:47:01.381 Detail, Node003,   Received: 0x01, 0x09, 0x00, 0x04, 
0x00, 0x03, 0x03, 0x25, 0x03, 0xff, 0x2b
2015-01-01 19:47:01.381 Detail, 
2015-01-01 19:47:01.381 Info, Node003, Response RTT 54 Average Response RTT 54
2015-01-01 19:47:01.381 Info, Node003, Received SwitchBinary report from node 
3: level=On
2015-01-01 19:47:01.382 Detail, Node003, Refreshed Value: old value=false, new 
value=true, type=bool
2015-01-01 19:47:01.382 Detail, Node003, Changes to this value are not verified
2015-01-01 19:47:01.382 Detail, Node003,   Expected reply and command class was 
received
2015-01-01 19:47:01.383 Detail, Node003,   Message transaction complete
2015-01-01 19:47:01.383 Detail, 
2015-01-01 19:47:01.383 Detail, Node003, Removing current message
2015-01-01 19:47:02.936 Detail, Node003,   Received: 0x01, 0x09, 0x00, 0x04, 
0x00, 0x03, 0x03, 0x25, 0x03, 0xff, 0x2b
2015-01-01 19:47:02.936 Detail, 
2015-01-01 19:47:02.936 Info, Node003, Received SwitchBinary report from node 
3: level=On
2015-01-01 19:47:02.936 Detail, Node003, Refreshed Value: old value=true, new 
value=true, type=bool
2015-01-01 19:47:02.936 Detail, Node003, Changes to this value are not verified
2015-01-01 19:47:04.027 Detail, Node003,   Received: 0x01, 0x14, 0x00, 0x04, 
0x00, 0x03, 0x0e, 0x32, 0x02, 0x21, 0x34, 0x00, 0x00, 0x04, 0x64, 0x00, 0x00, 
0x00, 0x00, 0x00, 0x00, 0xa7
2015-01-01 19:47:04.027 Detail, 
2015-01-01 19:47:04.027 Detail, Node003, Refreshed Value: old value=false, new 
value=false, type=bool
2015-01-01 19:47:04.027 Detail, Node003, Changes to this value are not verified
2015-01-01 19:47:04.027 Info, Node003, Received Meter report from node 3: 
Power=112.4W
2015-01-01 19:47:04.027 Detail, Node003, Refreshed Value: old value=0.0, new 
value=112.4, type=string
2015-01-01 19:47:04.027 Detail, Node003, Changes to this value are not verified

Do these problems indicate an rf issue?

Original comment by whiteduc...@gmail.com on 1 Jan 2015 at 7:49

[GoogleCodeExporter]

Thank you jus…@dynam.ac - I have a Aeon Labs stick on order also as a 
fallback so I'll try that and if the problems vanish put it down to the UZB!

Original comment by whiteduc...@gmail.com on 1 Jan 2015 at 10:10

[GoogleCodeExporter]

Another possible jus…@dynamic.ac - I am using a VM on top of VMware ESXi so 
the USB is connected to the Hypervisor - but I've seen no issues with other USB 
devices e.g. USB Sound, RFXCom etc.

Original comment by whiteduc...@gmail.com on 1 Jan 2015 at 10:21

[GoogleCodeExporter]

I set the speed to 9600 with stty before running which may have made it more 
stable but I still get the out of frame errors.   An lsof on /dev/ttyACM0 shows 
Domoticz only.

Original comment by whiteduc...@gmail.com on 1 Jan 2015 at 11:14

[GoogleCodeExporter]

[deleted comment]

[GoogleCodeExporter]

I added a timeout to the controller to reset it which may help…  but I think 
there is something wrong with this device…  and I can't use z-way as it's not 
supported yet…   the following shows the level of errors...

23:17:03.254 Always, 
***************************************************************************
2015-01-01 23:17:03.254 Always, *********************  Cumulative Network 
Statistics  *********************
2015-01-01 23:17:03.254 Always, *** General
2015-01-01 23:17:03.254 Always, Driver run time: . .  . 0 days, 0 hours, 9 
minutes
2015-01-01 23:17:03.254 Always, Frames processed: . . . . . . . . . . . . . . . 
. . . . . 146
2015-01-01 23:17:03.255 Always, Total messages successfully received: . . . . . 
. . . . . 132
2015-01-01 23:17:03.255 Always, Total Messages successfully sent: . . . . . . . 
. . . . . 46
2015-01-01 23:17:03.255 Always, ACKs received from controller:  . . . . . . . . 
. . . . . 50
2015-01-01 23:17:03.255 Always, *** Errors
2015-01-01 23:17:03.255 Always, Unsolicited messages received while waiting for 
ACK:  . . 0
2015-01-01 23:17:03.255 Always, Reads aborted due to timeouts:  . . . . . . . . 
. . . . . 14
2015-01-01 23:17:03.255 Always, Bad checksum errors:  . . . . . . . . . . . . . 
. . . . . 0
2015-01-01 23:17:03.255 Always, CANs received from controller:  . . . . . . . . 
. . . . . 0
2015-01-01 23:17:03.256 Always, NAKs received from controller:  . . . . . . . . 
. . . . . 0
2015-01-01 23:17:03.256 Always, Out of frame data flow errors:  . . . . . . . . 
. . . . . 141
2015-01-01 23:17:03.256 Always, Messages retransmitted: . . . . . . . . . . . . 
. . . . . 3
2015-01-01 23:17:03.256 Always, Messages dropped and not delivered: . . . . . . 
. . . . . 1
2015-01-01 23:17:03.256 Always, 
***************************************************************************

Original comment by whiteduc...@gmail.com on 1 Jan 2015 at 11:25

[GoogleCodeExporter]

Update - replaced the USB UZB stick with Aeon Labs V2, fresh install of 
Domoticz and OZW  and all of the problems have been solved - no more errors and 
solid reliable comms with the devices…   so the question is VMware USB 
passthrough, the stick,  a faulty stick or an incompatibility…  if I had more 
time I would connect to a physical server instead of a VM and find out...

Original comment by whiteduc...@gmail.com on 3 Jan 2015 at 10:26

[GoogleCodeExporter]

Closing this

Original comment by jus...@dynam.ac on 6 Jan 2015 at 5:47

• Changed state: Invalid