Fibaro Switch not responding after 2 weeks

[Gerard]

I'm using RazBerry v2.0.0 with two Fibaro WallPlugs (FGWPE-101) and two Fibaro MultiSensors.
One of the plugs (device with id 4) is used to switch on a light every day at a specific time. This works fine for about two weeks. After this period, the device doesn't respond to (on/off)commands anymore. When I manually switch the device on or off with its hardware button, status is send correctly to the RazBerry, so the device is working and communicating with the RazBerry.

Powering off the device and waiting for about 2 minutes doesn't resolve the problem. The problem is resolved by "Force Interview" using the expert UI.

Below are logs before (when the problem exists) and after (when the problem is resolved after re-interview). Any clue what is going on here?
Kind regards;
Gerard


Before re-interview (Sending Off without success)

Code: Select all

[2015-02-18 21:02:05.717] [I] [zway] Adding job: SwitchBinary Set
[2015-02-18 21:02:05.718] [I] [zway] Adding job: SwitchBinary Get
[2015-02-18 21:02:05.720] [D] [zway] SENDING (cb 0xf9): ( 01 0E 00 13 04 07 56 01 25 01 00 01 CA 25 F9 85 )
[2015-02-18 21:02:05.722] [D] [zway] RECEIVED ACK
[2015-02-18 21:02:05.725] [D] [zway] RECEIVED: ( 01 04 01 13 01 E8 )
[2015-02-18 21:02:05.725] [D] [zway] SENT ACK
[2015-02-18 21:02:05.726] [D] [zway] Delivered to Z-Wave stack
[2015-02-18 21:02:05.739] [D] [zway] RECEIVED: ( 01 05 00 13 F9 00 10 )
[2015-02-18 21:02:05.739] [D] [zway] SENT ACK
[2015-02-18 21:02:05.739] [I] [zway] Job 0x13 (SwitchBinary Set): Delivered
[2015-02-18 21:02:05.739] [D] [zway] SETDATA devices.4.data.lastPacketInfo.delivered = True
[2015-02-18 21:02:05.740] [D] [zway] SETDATA devices.4.data.lastPacketInfo.packetLength = 10 (0x0000000a)
[2015-02-18 21:02:05.740] [D] [zway] SETDATA devices.4.data.lastPacketInfo.deliveryTime = 13 (0x0000000d)
[2015-02-18 21:02:05.740] [D] [zway] SETDATA devices.4.data.lastPacketInfo = **********
[2015-02-18 21:02:05.740] [D] [zway] SendData Response with callback 0xf9 received: received by recipient
[2015-02-18 21:02:05.741] [D] [zway] SETDATA devices.4.data.lastSend = 553481773 (0x20fd762d)
[2015-02-18 21:02:05.741] [D] [zway] Job 0x13 (SwitchBinary Set): success
[2015-02-18 21:02:05.741] [I] [zway] Removing job: SwitchBinary Set
[2015-02-18 21:02:05.813] [D] [zway] SENDING (cb 0xfa): ( 01 0D 00 13 04 06 56 01 25 02 B2 D3 25 FA 2D )
[2015-02-18 21:02:05.815] [D] [zway] RECEIVED ACK
[2015-02-18 21:02:05.818] [D] [zway] RECEIVED: ( 01 04 01 13 01 E8 )
[2015-02-18 21:02:05.819] [D] [zway] SENT ACK
[2015-02-18 21:02:05.819] [D] [zway] Delivered to Z-Wave stack
[2015-02-18 21:02:05.832] [D] [zway] RECEIVED: ( 01 05 00 13 FA 00 13 )
[2015-02-18 21:02:05.832] [D] [zway] SENT ACK
[2015-02-18 21:02:05.832] [I] [zway] Job 0x13 (SwitchBinary Get): Delivered
[2015-02-18 21:02:05.832] [D] [zway] SETDATA devices.4.data.lastPacketInfo.delivered = True
[2015-02-18 21:02:05.833] [D] [zway] SETDATA devices.4.data.lastPacketInfo.packetLength = 9 (0x00000009)
[2015-02-18 21:02:05.833] [D] [zway] SETDATA devices.4.data.lastPacketInfo.deliveryTime = 13 (0x0000000d)
[2015-02-18 21:02:05.833] [D] [zway] SETDATA devices.4.data.lastPacketInfo = **********
[2015-02-18 21:02:05.833] [D] [zway] SendData Response with callback 0xfa received: received by recipient
[2015-02-18 21:02:05.834] [D] [zway] SETDATA devices.4.data.lastSend = 553481781 (0x20fd7635)
[2015-02-18 21:02:05.834] [D] [zway] Job 0x13 (SwitchBinary Get): success
[2015-02-18 21:02:05.834] [I] [zway] Removing job: SwitchBinary Get
[2015-02-18 21:02:25.858] [D] [zway] Job 0x13: deleted from queue
[2015-02-18 21:02:25.940] [D] [zway] Job 0x13: deleted from queue

After re-interview (Sending Off with success)

Code: Select all

[2015-02-18 21:10:53.407] [I] [zway] Adding job: SwitchBinary Set
[2015-02-18 21:10:53.408] [I] [zway] Adding job: SwitchBinary Get
[2015-02-18 21:10:53.409] [D] [zway] SENDING (cb 0x42): ( 01 0A 00 13 04 03 25 01 00 25 42 A2 )
[2015-02-18 21:10:53.410] [D] [zway] RECEIVED ACK
[2015-02-18 21:10:53.413] [D] [zway] RECEIVED: ( 01 04 01 13 01 E8 )
[2015-02-18 21:10:53.414] [D] [zway] SENT ACK
[2015-02-18 21:10:53.414] [D] [zway] Delivered to Z-Wave stack
[2015-02-18 21:10:53.426] [D] [zway] RECEIVED: ( 01 05 00 13 42 00 AB )
[2015-02-18 21:10:53.426] [D] [zway] SENT ACK
[2015-02-18 21:10:53.427] [I] [zway] Job 0x13 (SwitchBinary Set): Delivered
[2015-02-18 21:10:53.427] [D] [zway] SETDATA devices.4.data.lastPacketInfo.delivered = True
[2015-02-18 21:10:53.427] [D] [zway] SETDATA devices.4.data.lastPacketInfo.packetLength = 6 (0x00000006)
[2015-02-18 21:10:53.427] [D] [zway] SETDATA devices.4.data.lastPacketInfo.deliveryTime = 12 (0x0000000c)
[2015-02-18 21:10:53.428] [D] [zway] SETDATA devices.4.data.lastPacketInfo = **********
[2015-02-18 21:10:53.428] [D] [zway] SendData Response with callback 0x42 received: received by recipient
[2015-02-18 21:10:53.428] [D] [zway] SETDATA devices.4.data.lastSend = 553533392 (0x20fe3fd0)
[2015-02-18 21:10:53.428] [D] [zway] Job 0x13 (SwitchBinary Set): success
[2015-02-18 21:10:53.428] [I] [zway] Removing job: SwitchBinary Set
[2015-02-18 21:10:53.500] [D] [zway] SENDING (cb 0x43): ( 01 09 00 13 04 02 25 02 25 43 A2 )
[2015-02-18 21:10:53.502] [D] [zway] RECEIVED ACK
[2015-02-18 21:10:53.505] [D] [zway] RECEIVED: ( 01 04 01 13 01 E8 )
[2015-02-18 21:10:53.506] [D] [zway] SENT ACK
[2015-02-18 21:10:53.506] [D] [zway] Delivered to Z-Wave stack
[2015-02-18 21:10:53.518] [D] [zway] RECEIVED: ( 01 05 00 13 43 00 AA )
[2015-02-18 21:10:53.518] [D] [zway] SENT ACK
[2015-02-18 21:10:53.518] [I] [zway] Job 0x13 (SwitchBinary Get): Delivered
[2015-02-18 21:10:53.518] [D] [zway] SETDATA devices.4.data.lastPacketInfo.delivered = True
[2015-02-18 21:10:53.518] [D] [zway] SETDATA devices.4.data.lastPacketInfo.packetLength = 5 (0x00000005)
[2015-02-18 21:10:53.519] [D] [zway] SETDATA devices.4.data.lastPacketInfo.deliveryTime = 12 (0x0000000c)
[2015-02-18 21:10:53.519] [D] [zway] SETDATA devices.4.data.lastPacketInfo = **********
[2015-02-18 21:10:53.519] [D] [zway] SendData Response with callback 0x43 received: received by recipient
[2015-02-18 21:10:53.519] [D] [zway] SETDATA devices.4.data.lastSend = 553533400 (0x20fe3fd8)
[2015-02-18 21:10:53.520] [D] [zway] Job 0x13 (SwitchBinary Get): success
[2015-02-18 21:10:53.520] [I] [zway] Removing job: SwitchBinary Get
[2015-02-18 21:10:53.525] [D] [zway] RECEIVED: ( 01 09 00 04 00 04 03 25 03 00 D3 )
[2015-02-18 21:10:53.525] [D] [zway] SENT ACK
[2015-02-18 21:10:53.525] [D] [zway] SETDATA devices.4.data.lastReceived = 0 (0x00000000)
[2015-02-18 21:10:53.525] [D] [zway] SETDATA devices.4.instances.0.commandClasses.37.data.level = False
[2015-02-18 21:10:54.160] [D] [zway] RECEIVED: ( 01 0C 00 04 00 04 06 31 05 04 22 00 00 E7 )
[2015-02-18 21:10:54.160] [D] [zway] SENT ACK
[2015-02-18 21:10:54.160] [D] [zway] SETDATA devices.4.data.lastReceived = 0 (0x00000000)
[2015-02-18 21:10:54.161] [D] [zway] SETDATA devices.4.instances.0.commandClasses.49.data.4.deviceScale = 0 (0x00000000)
[2015-02-18 21:10:54.161] [D] [zway] SETDATA devices.4.instances.0.commandClasses.49.data.4.scale = 0 (0x00000000)
[2015-02-18 21:10:54.161] [D] [zway] SETDATA devices.4.instances.0.commandClasses.49.data.4.val = 0.000000
[2015-02-18 21:10:54.164] [D] [zway] SETDATA devices.4.instances.0.commandClasses.49.data.4.scaleString = "W"
[2015-02-18 21:10:54.165] [D] [zway] SETDATA devices.4.instances.0.commandClasses.49.data.4 = Empty

[dolpheen]

From the log it looks like you have MultiCmd problem (before interview commands are sent in MultiCmd format, after in normal format)
The same is in the next topics:
viewtopic.php?f=3422&t=21231
viewtopic.php?f=3422&t=21250

I think only developers can help on that

[pofs]

From the log it looks like you have MultiCmd problem

It is not actually MultiCmd, but CRC16.
It should be fixed in 2.0.1 release candidates. Now we check NIF before rendering command classes like MultiCmd and CRC16 on arrival.

[dolpheen]

It is not actually MultiCmd, but CRC16.
It should be fixed in 2.0.1 release candidates. Now we check NIF before rendering command classes like MultiCmd and CRC16 on arrival.

Not clear still, how the device began to behave like this after some time?(that commands are wrapped in CRC)