Error while parsing to ZpiObject 'Error: CommandID '159' from subsystem '5' not found

[lolorc]

Hi

I've just upgraded my cc2652 firmware (20200328) and z2m to latest dev.
it looks like it's working ok, but I had errors:

Apr 14 18:33:19 zigbee2mqtt:info  2020-04-14 18:33:19: Starting zigbee2mqtt version 1.12.2-dev (commit #838cb6e)                           

Apr 14 18:33:40   zigbee-herdsman:adapter:zStack:znp:SREQ --> AF - dataRequest - {"dstaddr":31826,"destendpoint":1,"srcendpoint":1,"clusterid":6,"transid":3,"options":0,"radius":30,"len":5,"data":{"type":"Buffer","data":[24,102,11,10,0]}} +1sman:adapter:zStack:unpi:writer --> frame [254,15,36,1,82,124,1,1,6,0,3,0,30,5,24,102,11,10,0,101] +1s
Apr 14 18:33:40   zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +43ms
Apr 14 18:33:40   zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,1,100,1,0,100] +8ms
Apr 14 18:33:40   zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,1,100,1,0,100] +0ms
Apr 14 18:33:40   zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 1 - 3 - 4 - 1 - [0] - 100 +1ms
Apr 14 18:33:40   zigbee-herdsman:adapter:zStack:znp:SRSP <-- AF - dataRequest - {"status":0} +1s
Apr 14 18:33:40   zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +1ms
Apr 14 18:33:40   zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,3,68,128,0,1,3,197] +2ms
Apr 14 18:33:40   zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,3,68,128,0,1,3,197] +0ms
Apr 14 18:33:40   zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 3 - 2 - 4 - 128 - [0,1,3] - 197 +0ms
Apr 14 18:33:40   zigbee-herdsman:adapter:zStack:znp:AREQ <-- AF - dataConfirm - {"status":0,"endpoint":1,"transid":3} +55ms
Apr 14 18:33:40   zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +1ms
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,5,69,159,247,57,132,10,235,116] +2s
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,5,69,159,247,57,132,10,235,116] +1ms
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 5 - 2 - 5 - 159 - [247,57,132,10,235] - 116 +1ms
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error Error while parsing to ZpiObject 'Error: CommandID '159' from subsystem '5' not found
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at Function.fromUnpiFrame (/home/pi/zigbee2mqtt.dev/node_modules/zigbee-herdsman/dist/adapter/z-stack/znp/zpiObject.js:44:19)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at Znp.onUnpiParsed (/home/pi/zigbee2mqtt.dev/node_modules/zigbee-herdsman/dist/adapter/z-stack/znp/znp.js:76:48)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at Parser.emit (events.js:198:13)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at Parser.parseNext (/home/pi/zigbee2mqtt.dev/node_modules/zigbee-herdsman/dist/adapter/z-stack/unpi/parser.js:47:26)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at Parser._transform (/home/pi/zigbee2mqtt.dev/node_modules/zigbee-herdsman/dist/adapter/z-stack/unpi/parser.js:26:14)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at Parser.Transform._read (_stream_transform.js:190:10)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at Parser.Transform._write (_stream_transform.js:178:12)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at doWrite (_stream_writable.js:415:12)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at writeOrBuffer (_stream_writable.js:399:5)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at Parser.Writable.write (_stream_writable.js:299:11)' +0ms
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +4ms
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,5,69,159,228,174,132,10] +16ms
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,5,69,159,228,174,132,10] +0ms
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:unpi:parser <-- [235,240,254,5,69,159,143,89,132,10,235,108] +2ms
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,5,69,159,228,174,132,10,235,240,254,5,69,159,143,89,132,10,235,108] +1ms
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 5 - 2 - 5 - 159 - [228,174,132,10,235] - 240 +1ms
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error Error while parsing to ZpiObject 'Error: CommandID '159' from subsystem '5' not found
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at Function.fromUnpiFrame (/home/pi/zigbee2mqtt.dev/node_modules/zigbee-herdsman/dist/adapter/z-stack/znp/zpiObject.js:44:19)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at Znp.onUnpiParsed (/home/pi/zigbee2mqtt.dev/node_modules/zigbee-herdsman/dist/adapter/z-stack/znp/znp.js:76:48)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at Parser.emit (events.js:198:13)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at Parser.parseNext (/home/pi/zigbee2mqtt.dev/node_modules/zigbee-herdsman/dist/adapter/z-stack/unpi/parser.js:47:26)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at Parser._transform (/home/pi/zigbee2mqtt.dev/node_modules/zigbee-herdsman/dist/adapter/z-stack/unpi/parser.js:26:14)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at Parser.Transform._read (_stream_transform.js:190:10)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at Parser.Transform._write (_stream_transform.js:178:12)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at doWrite (_stream_writable.js:415:12)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at writeOrBuffer (_stream_writable.js:399:5)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at Parser.Writable.write (_stream_writable.js:299:11)' +23ms
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,5,69,159,143,89,132,10,235,108] +3ms
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 5 - 2 - 5 - 159 - [143,89,132,10,235] - 108 +1ms
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error Error while parsing to ZpiObject 'Error: CommandID '159' from subsystem '5' not found
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at Function.fromUnpiFrame (/home/pi/zigbee2mqtt.dev/node_modules/zigbee-herdsman/dist/adapter/z-stack/znp/zpiObject.js:44:19)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at Znp.onUnpiParsed (/home/pi/zigbee2mqtt.dev/node_modules/zigbee-herdsman/dist/adapter/z-stack/znp/znp.js:76:48)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at Parser.emit (events.js:198:13)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at Parser.parseNext (/home/pi/zigbee2mqtt.dev/node_modules/zigbee-herdsman/dist/adapter/z-stack/unpi/parser.js:47:26)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at Parser.parseNext (/home/pi/zigbee2mqtt.dev/node_modules/zigbee-herdsman/dist/adapter/z-stack/unpi/parser.js:53:22)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at Parser._transform (/home/pi/zigbee2mqtt.dev/node_modules/zigbee-herdsman/dist/adapter/z-stack/unpi/parser.js:26:14)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at Parser.Transform._read (_stream_transform.js:190:10)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at Parser.Transform._write (_stream_transform.js:178:12)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at doWrite (_stream_writable.js:415:12)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at writeOrBuffer (_stream_writable.js:399:5)' +4ms
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +3ms
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,5,69,159,62,56,132,10,235,188,254,5,69,159,182,85] +3ms
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,5,69,159,62,56,132,10,235,188,254,5,69,159,182,85] +1ms
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 5 - 2 - 5 - 159 - [62,56,132,10,235] - 188 +1ms
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error Error while parsing to ZpiObject 'Error: CommandID '159' from subsystem '5' not found
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at Function.fromUnpiFrame (/home/pi/zigbee2mqtt.dev/node_modules/zigbee-herdsman/dist/adapter/z-stack/znp/zpiObject.js:44:19)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at Znp.onUnpiParsed (/home/pi/zigbee2mqtt.dev/node_modules/zigbee-herdsman/dist/adapter/z-stack/znp/znp.js:76:48)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at Parser.emit (events.js:198:13)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at Parser.parseNext (/home/pi/zigbee2mqtt.dev/node_modules/zigbee-herdsman/dist/adapter/z-stack/unpi/parser.js:47:26)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at Parser._transform (/home/pi/zigbee2mqtt.dev/node_modules/zigbee-herdsman/dist/adapter/z-stack/unpi/parser.js:26:14)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at Parser.Transform._read (_stream_transform.js:190:10)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at Parser.Transform._write (_stream_transform.js:178:12)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at doWrite (_stream_writable.js:415:12)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at writeOrBuffer (_stream_writable.js:399:5)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at Parser.Writable.write (_stream_writable.js:299:11)' +8ms
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,5,69,159,182,85] +3ms
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:unpi:parser <-- [132,10,235,89] +2ms
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,5,69,159,182,85,132,10,235,89] +1ms
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 5 - 2 - 5 - 159 - [182,85,132,10,235] - 89 +1ms
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error Error while parsing to ZpiObject 'Error: CommandID '159' from subsystem '5' not found
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at Function.fromUnpiFrame (/home/pi/zigbee2mqtt.dev/node_modules/zigbee-herdsman/dist/adapter/z-stack/znp/zpiObject.js:44:19)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at Znp.onUnpiParsed (/home/pi/zigbee2mqtt.dev/node_modules/zigbee-herdsman/dist/adapter/z-stack/znp/znp.js:76:48)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at Parser.emit (events.js:198:13)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at Parser.parseNext (/home/pi/zigbee2mqtt.dev/node_modules/zigbee-herdsman/dist/adapter/z-stack/unpi/parser.js:47:26)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at Parser._transform (/home/pi/zigbee2mqtt.dev/node_modules/zigbee-herdsman/dist/adapter/z-stack/unpi/parser.js:26:14)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at Parser.Transform._read (_stream_transform.js:190:10)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at Parser.Transform._write (_stream_transform.js:178:12)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at doWrite (_stream_writable.js:415:12)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at writeOrBuffer (_stream_writable.js:399:5)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at Parser.Writable.write (_stream_writable.js:299:11)' +6ms
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [] +3ms
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,12,69,159,239,223,0,1] +356ms
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,12,69,159,239,223,0,1] +1ms
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:unpi:parser <-- [4,189,144,254,255,204,204,204,3] +1ms
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,12,69,159,239,223,0,1,4,189,144,254,255,204,204,204,3] +0ms
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 12 - 2 - 5 - 159 - [239,223,0,1,4,189,144,254,255,204,204,204] - 3 +0ms
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error Error while parsing to ZpiObject 'Error: CommandID '159' from subsystem '5' not found
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at Function.fromUnpiFrame (/home/pi/zigbee2mqtt.dev/node_modules/zigbee-herdsman/dist/adapter/z-stack/znp/zpiObject.js:44:19)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at Znp.onUnpiParsed (/home/pi/zigbee2mqtt.dev/node_modules/zigbee-herdsman/dist/adapter/z-stack/znp/znp.js:76:48)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at Parser.emit (events.js:198:13)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at Parser.parseNext (/home/pi/zigbee2mqtt.dev/node_modules/zigbee-herdsman/dist/adapter/z-stack/unpi/parser.js:47:26)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at Parser._transform (/home/pi/zigbee2mqtt.dev/node_modules/zigbee-herdsman/dist/adapter/z-stack/unpi/parser.js:26:14)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at Parser.Transform._read (_stream_transform.js:190:10)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at Parser.Transform._write (_stream_transform.js:178:12)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at doWrite (_stream_writable.js:415:12)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at writeOrBuffer (_stream_writable.js:399:5)
Apr 14 18:33:42   zigbee-herdsman:adapter:zStack:znp:error     at Parser.Writable.write (_stream_writable.js:299:11)' +361ms

                    

[Koenkk]

Interesting, this command is not specified in the zstack documentation, nor can I found anything about it in the source code. Did you also have this when running the 20191106 firmware?

[lolorc]

I don't remember so. It's quite new, as far as I know it started happening with the the latest firmware and only when starting after flashing.
IOW, it just happened now with 20200417, I will restart z2m a bit later on, pretty sure it won't happen, might be related to the restore stuff.

[lolorc]

yep, only happens after a firmware update.

[Koenkk]

@lolorc TI released a new version of their SDK, can you check if the issue is still present: https://github.com/Koenkk/Z-Stack-firmware/tree/develop/coordinator/Z-Stack_3.x.0/bin ?

[lolorc]

@Koenkk you want me to flash 20200417 again ? this is already the firmware I'm running

[Koenkk]

No, I've asked TI what this command is as it's not documented nor I can find it in the source code: https://e2e.ti.com/support/wireless-connectivity/zigbee-and-thread/f/158/t/898525

[Koenkk]

It seems that TI also doesn't know.

• Did you make sure to flash the firmware using: https://www.zigbee2mqtt.io/information/flashing_via_uniflash.html and also executed step 5?
• When do you get this error? (how often? As I havent' seen it yet in my case).

[lolorc]

oh my mistake then, I did not, just flashed over without erasing anything.
the error only occured on the next start just after flashing the firmware. It then happens just after restoring the backup it seems. After that the error doesn't occur anymore.
Shall I try to reflash the same firmware again without erasing, then with erasing to check ?
(otherwise I'll wait for the next firmware)

[Koenkk]

@lolorc yes please try that. So the error only happens a few times right after startup?

[lolorc]

@Koenkk confimed,

did a simple flash without erasing => few seconds after restore, the error occurs.
did a full erase/check/flash => no error.