Job queue gets stuck

Discussions about RaZberry - Z-Wave board for Raspberry computer
Post Reply
knightruby
Posts: 2
Joined: 27 Oct 2021 13:00

Job queue gets stuck

Post by knightruby »

Hi all,

I am using a Razberry setup for 7+ years now. Since the start of this week suddenly the job queue started to overload and nothing seems to react.
If I restart z-way server things work for a few minutes until the queue loads up again. The problem starts at a specific command which has the timeout being increased continously, the node differs each time.

I already upgraded the razberry to the latest version without any problems, but the overloading of the queue persists.
Also the batteries of my Fibaro Motion sensors died the day the problem started to occur. I replaced the batteries.
The fibaro motion sensors function correctly, until the job queue overloads again. Then even the eye-flashing (when detecting movement) is stopped. Is this all related?

Code: Select all

n	U	W	S	E	D	Ack	Resp	Cbk	Repl	Timeout	NodeId	Description	Progress	Buffer
0		W				-	-	-		0.20	4	Wakeup Sleep		4 2 84 8 5
0		W				-	-	-		0.20	26	Wakeup Sleep		1a 2 84 8 5
0		W				-	-	-		0.20	65	Wakeup Sleep		41 2 84 8 5
2		W				-	-	-	-	0.20	53	Nonce Get	Not delivered to recipient	35 2 98 40 5
0		W				-		-		0.20	4	Request node neighbours update		4
0		W				-		-		0.20	26	Request node neighbours update		1a
0		W				-		-		0.20	53	Request node neighbours update		35
0			S	E		-	-	-	-	0.20	56	Meter Get (v2/3)		38 3 32 1 10 25
1			S	E		-	-	-	-	0.20	60	Alarm Get (v3)		3c 9 60 d 0 1 71 4 0 9 0 25
0						-	-	-		0.20	57	Security S2 Nonce Get		39 3 9f 1 d 25
0						-	-	-		0.20	59	Security S2 Nonce Get		3b 3 9f 1 8a 25
0						-	-	-		0.20	56	Security S2 Encapsulation (S2 Unauthenticated), Meter Get (v2/3)		38 f 9f 3 7 0 a 41 3e a 39 ec a8 b5 16 59 b6 25
0						-	-	-	-	0.20	61	Nonce Get		3d 2 98 40 25
0						-	-	-	-	0.20	55	Nonce Get		37 2 98 40 25
1						-	-	-		567.89	60	Security, Alarm Get (v3)		3c 1d 98 81 27 a3 fe c2 8f 87 74 a8 86 fd 9 26 83 b8 45 7b 79 65 da 29 32 95 e2 28 21 3e 28 25          <==== HERE THE PROBLEM STARTED
0			S			-	-	-		0.20	60	SwitchMultilevel Set		3c 4 26 1 0 ff 25
0			S			-	-	-	-	0.20	60	SwitchMultilevel Get		3c 2 26 2 25
0						-	-	-		0.20	25	NoOperation		19 1 0 5
0						-	-	-		0.20	25	Wakeup Sleep		19 2 84 8 5
0						-	-	-	-	0.20	13	Meter Get (v2/3)		d 3 32 1 10 25
0						-	-	-	-	0.20	13	Meter Get (v2/3)		d 3 32 1 28 25
0						-	-	-	-	0.20	13	Meter Get (v2/3)		d 7 60 d 0 1 32 1 10 25
0						-	-	-	-	0.20	13	Meter Get (v2/3)		d 7 60 d 0 1 32 1 30 25
0						-	-	-	-	0.20	13	Meter Get (v2/3)		d 7 60 d 0 2 32 1 0 25
0						-	-	-	-	0.20	13	Meter Get (v2/3)		d 7 60 d 0 2 32 1 10 25
0						-	-	-	-	0.20	13	Meter Get (v2/3)		d 7 60 d 0 2 32 1 20 25
0						-	-	-	-	0.20	13	Meter Get (v2/3)		d 7 60 d 0 2 32 1 28 25
0						-	-	-	-	0.20	13	Meter Get (v2/3)		d 7 60 d 0 2 32 1 30 25
0						-	-	-	-	0.20	13	Meter Get (v2/3)		d 7 60 d 0 3 32 1 0 25
0						-	-	-	-	0.20	13	Meter Get (v2/3)		d 7 60 d 0 3 32 1 10 25
0						-	-	-	-	0.20	13	Meter Get (v2/3)		d 7 60 d 0 3 32 1 20 25
0						-	-	-	-	0.20	13	Meter Get (v2/3)		d 7 60 d 0 3 32 1 28 25
0						-	-	-	-	0.20	13	Meter Get (v2/3)		d 7 60 d 0 3 32 1 30 25
0						-	-	-	-	0.20	15	SensorMultilevel V1-4 Get		f 2 31 4 25
0						-	-	-	-	0.20	15	SensorMultilevel V1-4 Get		f 6 60 d 0 3 31 4 25
0						-	-	-	-	0.20	15	Alarm Get (v3)		f 9 60 d 0 2 71 4 0 7 0 25
0			S			-	-	-	-	0.20	51	Meter Get (v2/3)		33 3 32 1 0 25
0			S			-	-	-	-	0.20	51	Meter Get (v2/3)		33 3 32 1 10 25
0			S			-	-	-	-	0.20	51	Alarm Get (v3)		33 5 71 4 0 8 0 25
0			S			-	-	-	-	0.20	51	Alarm Get (v3)		33 5 71 4 0 9 0 25
1			S			-	-	-	-	0.20	52	SensorMultilevel V5 Get	Security S2 failed to prepare S2 packet	34 4 31 4 f 0 25
0			S			-	-	-	-	0.20	52	Meter Get (v2/3)		34 3 32 1 0 25
0			S			-	-	-	-	0.20	52	Meter Get (v2/3)		34 3 32 1 10 25
0			S			-	-	-	-	0.20	52	Alarm Get (v3)		34 5 71 4 0 8 0 25
0			S			-	-	-	-	0.20	52	Alarm Get (v3)		34 5 71 4 0 9 0 25
0			S			-	-	-	-	0.20	52	Meter Get (v2/3)		34 7 60 d 0 1 32 1 0 25
0			S			-	-	-	-	0.20	52	Meter Get (v2/3)		34 7 60 d 0 1 32 1 10 25
0			S			-	-	-	-	0.20	52	Alarm Get (v3)		34 9 60 d 0 1 71 4 0 8 0 25
0			S			-	-	-	-	0.20	52	Alarm Get (v3)		34 9 60 d 0 1 71 4 0 9 0 25
0			S			-	-	-	-	0.20	52	SensorMultilevel V5 Get		34 8 60 d 0 6 31 4 f 0 25
0			S			-	-	-	-	0.20	52	SensorMultilevel V5 Get		34 8 60 d 0 7 31 4 f 0 25
0			S			-	-	-	-	0.20	52	SensorMultilevel V5 Get		34 8 60 d 0 8 31 4 f 0 25
0			S			-	-	-	-	0.20	52	SensorMultilevel V5 Get		34 8 60 d 0 9 31 4 f 0 25
0			S			-	-	-	-	0.20	55	SensorMultilevel V1-4 Get		37 6 60 d 0 1 31 4 25
0			S			-	-	-	-	0.20	55	Meter Get (v2/3)		37 7 60 d 0 1 32 1 0 25
0			S			-	-	-	-	0.20	55	Alarm Get (v3)		37 9 60 d 0 1 71 4 0 4 0 25
0			S			-	-	-	-	0.20	55	Alarm Get (v3)		37 9 60 d 0 1 71 4 0 8 0 25
0			S			-	-	-	-	0.20	55	Alarm Get (v3)		37 9 60 d 0 1 71 4 0 9 0 25
0			S			-	-	-	-	0.20	56	Meter Get (v2/3)		38 3 32 1 10 25
0			S			-	-	-	-	0.20	56	Alarm Get (v3)		38 5 71 4 0 8 0 25
0			S			-	-	-	-	0.20	56	Alarm Get (v3)		38 5 71 4 0 9 0 25
0			S			-	-	-	-	0.20	56	Meter Get (v2/3)		38 7 60 d 0 1 32 1 0 25
0			S			-	-	-	-	0.20	56	Meter Get (v2/3)		38 7 60 d 0 1 32 1 10 25
0			S			-	-	-	-	0.20	56	Alarm Get (v3)		38 9 60 d 0 1 71 4 0 8 0 25
0			S			-	-	-	-	0.20	56	Alarm Get (v3)		38 9 60 d 0 1 71 4 0 9 0 25
1			S			-	-	-	-	0.20	57	Meter Get (v2/3)	Security S2 failed to prepare S2 packet	39 3 32 1 0 25
0			S			-	-	-	-	0.20	57	Meter Get (v2/3)		39 3 32 1 10 25
0			S			-	-	-	-	0.20	57	Alarm Get (v3)		39 5 71 4 0 8 0 25
0			S			-	-	-	-	0.20	57	Alarm Get (v3)		39 5 71 4 0 9 0 25
0			S			-	-	-	-	0.20	57	Meter Get (v2/3)		39 7 60 d 0 1 32 1 0 25
0			S			-	-	-	-	0.20	57	Meter Get (v2/3)		39 7 60 d 0 1 32 1 10 25
0			S			-	-	-	-	0.20	57	Alarm Get (v3)		39 9 60 d 0 1 71 4 0 8 0 25
0			S			-	-	-	-	0.20	57	Alarm Get (v3)		39 9 60 d 0 1 71 4 0 9 0 25
1			S			-	-	-	-	0.20	59	Meter Get (v2/3)	Security S2 failed to prepare S2 packet	3b 3 32 1 0 25
0			S			-	-	-	-	0.20	59	Meter Get (v2/3)		3b 3 32 1 10 25
0			S			-	-	-	-	0.20	59	Alarm Get (v3)		3b 5 71 4 0 8 0 25
0			S			-	-	-	-	0.20	59	Alarm Get (v3)		3b 5 71 4 0 9 0 25
0			S			-	-	-	-	0.20	59	Meter Get (v2/3)		3b 7 60 d 0 1 32 1 0 25
0			S			-	-	-	-	0.20	59	Meter Get (v2/3)		3b 7 60 d 0 1 32 1 10 25
0			S			-	-	-	-	0.20	59	Alarm Get (v3)		3b 9 60 d 0 1 71 4 0 8 0 25
0			S			-	-	-	-	0.20	59	Alarm Get (v3)		3b 9 60 d 0 1 71 4 0 9 0 25
0			S			-	-	-	-	0.20	60	Meter Get (v2/3)		3c 7 60 d 0 1 32 1 0 25
0			S			-	-	-	-	0.20	60	Alarm Get (v3)		3c 9 60 d 0 1 71 4 0 4 0 25
0			S			-	-	-	-	0.20	60	Alarm Get (v3)		3c 9 60 d 0 1 71 4 0 8 0 25
0			S			-	-	-	-	0.20	60	Alarm Get (v3)		3c 9 60 d 0 1 71 4 0 9 0 25
0			S			-	-	-	-	0.20	61	Meter Get (v2/3)		3d 7 60 d 0 1 32 1 0 25
0			S			-	-	-	-	0.20	61	Alarm Get (v3)		3d 9 60 d 0 1 71 4 0 4 0 25
0			S			-	-	-	-	0.20	61	Alarm Get (v3)		3d 9 60 d 0 1 71 4 0 8 0 25
0			S			-	-	-	-	0.20	61	Alarm Get (v3)		3d 9 60 d 0 1 71 4 0 9 0 25
0						-	-			0.20	0	Get statistics gathered by the Z-Wave protocol		
0						-	-			0.20	0	Get background noise level		
User avatar
PoltoS
Posts: 7562
Joined: 26 Jan 2011 19:36

Re: Job queue gets stuck

Post by PoltoS »

I don't think the LED (eye-flashing) is related. But who knows.

Please send us the log with the moment where the issue occurs and at least 500 lines before.
knightruby
Posts: 2
Joined: 27 Oct 2021 13:00

Re: Job queue gets stuck

Post by knightruby »

Hi thanks for your response, I analyzed the logs and it gets stuck in a loop.

This is the error

Code: Select all

[2021-10-27 09:49:28.586] [I] [zway] Node info received: 15
[2021-10-27 09:49:28.587] [D] [zway] SETDATA devices.15.data.basicType = 4 (0x00000004)
[2021-10-27 09:49:28.587] [D] [zway] SETDATA devices.15.data.genericType = 17 (0x00000011)
[2021-10-27 09:49:28.587] [D] [zway] SETDATA devices.15.data.specificType = 1 (0x00000001)
[2021-10-27 09:49:28.588] [D] [zway] SETDATA devices.15.data.deviceTypeString = "Routing Multilevel Switch"
[2021-10-27 09:49:28.588] [D] [zway] SETDATA devices.15.data.nodeInfoFrame = byte[19]
[2021-10-27 09:49:28.588] [D] [zway]   ( 5E 7A 86 72 60 5A 70 73 77 71 85 8E 59 26 2B 2C 27 22 31 )
[2021-10-27 09:49:28.588] [D] [zway] SETDATA devices.15.data.lastReceived = 0 (0x00000000)
[2021-10-27 09:49:28.592] [E] [core] Callback execution error: TypeError: Cannot read property 'toString' of null
    at RSSItoText (automation/modules/ZWave/index.js:531:19)
    at prepareRSSI (automation/modules/ZWave/index.js:538:11)
    at createIncomingEntry (automation/modules/ZWave/index.js:756:45)
    at ZDataHolder.inH (automation/modules/ZWave/index.js:458:10)
Then the log is looped for ever until restart of the z-way-server

Code: Select all

[2021-10-27 09:49:28.594] [I] [core] Notification: error (connection): User reset to factory defaults Z-Wave device ID: 15
[2021-10-27 09:49:28.619] [W] [zway] Received SOF, while awaiting ACK
[2021-10-27 09:49:28.624] [D] [zway] RECEIVED: ( 01 0B 00 04 04 0F 02 5A 01 BB 00 00 19 )
[2021-10-27 09:49:28.624] [D] [zway] SENT ACK
[2021-10-27 09:49:28.624] [D] [zway] SETDATA devices.15.data.lastReceived = 0 (0x00000000)
[2021-10-27 09:49:28.625] [D] [zway] SETDATA devices.15.instances.0.commandClasses.90.data.reset = True
[2021-10-27 09:49:28.640] [I] [core] Notification: error (connection): User reset to factory defaults Z-Wave device ID: 15
[2021-10-27 09:49:28.674] [W] [zway] Received SOF, while awaiting ACK
[2021-10-27 09:49:28.682] [D] [zway] RECEIVED: ( 01 1C 00 49 84 0F 16 04 11 01 5E 7A 86 72 60 5A 70 73 77 71 85 8E 59 26 2B 2C 27 22 31 8B )
[2021-10-27 09:49:28.682] [D] [zway] SENT ACK
[2021-10-27 09:49:28.683] [I] [zway] Node info received: 15
[2021-10-27 09:49:28.683] [D] [zway] SETDATA devices.15.data.basicType = 4 (0x00000004)
[2021-10-27 09:49:28.683] [D] [zway] SETDATA devices.15.data.genericType = 17 (0x00000011)
[2021-10-27 09:49:28.683] [D] [zway] SETDATA devices.15.data.specificType = 1 (0x00000001)
[2021-10-27 09:49:28.684] [D] [zway] SETDATA devices.15.data.deviceTypeString = "Routing Multilevel Switch"
[2021-10-27 09:49:28.685] [D] [zway] SETDATA devices.15.data.nodeInfoFrame = byte[19]
[2021-10-27 09:49:28.685] [D] [zway]   ( 5E 7A 86 72 60 5A 70 73 77 71 85 8E 59 26 2B 2C 27 22 31 )
[2021-10-27 09:49:28.685] [D] [zway] SETDATA devices.15.data.lastReceived = 0 (0x00000000)
[2021-10-27 09:49:28.711] [W] [zway] Received SOF, while awaiting ACK
[2021-10-27 09:49:28.717] [D] [zway] RECEIVED: ( 01 0B 00 04 04 0F 02 5A 01 BB 00 00 19 )
[2021-10-27 09:49:28.718] [D] [zway] SENT ACK
[2021-10-27 09:49:28.718] [D] [zway] SETDATA devices.15.data.lastReceived = 0 (0x00000000)
[2021-10-27 09:49:28.718] [D] [zway] SETDATA devices.15.instances.0.commandClasses.90.data.reset = True
[2021-10-27 09:49:28.729] [I] [core] Notification: error (connection): User reset to factory defaults Z-Wave device ID: 15
[2021-10-27 09:49:28.766] [W] [zway] Received SOF, while awaiting ACK
[2021-10-27 09:49:28.775] [D] [zway] RECEIVED: ( 01 1C 00 49 84 0F 16 04 11 01 5E 7A 86 72 60 5A 70 73 77 71 85 8E 59 26 2B 2C 27 22 31 8B )
[2021-10-27 09:49:28.776] [D] [zway] SENT ACK
[2021-10-27 09:49:28.776] [I] [zway] Node info received: 15
[2021-10-27 09:49:28.777] [D] [zway] SETDATA devices.15.data.basicType = 4 (0x00000004)
[2021-10-27 09:49:28.777] [D] [zway] SETDATA devices.15.data.genericType = 17 (0x00000011)
[2021-10-27 09:49:28.777] [D] [zway] SETDATA devices.15.data.specificType = 1 (0x00000001)
[2021-10-27 09:49:28.778] [D] [zway] SETDATA devices.15.data.deviceTypeString = "Routing Multilevel Switch"
[2021-10-27 09:49:28.778] [D] [zway] SETDATA devices.15.data.nodeInfoFrame = byte[19]
[2021-10-27 09:49:28.778] [D] [zway]   ( 5E 7A 86 72 60 5A 70 73 77 71 85 8E 59 26 2B 2C 27 22 31 )
[2021-10-27 09:49:28.778] [D] [zway] SETDATA devices.15.data.lastReceived = 0 (0x00000000)
[2021-10-27 09:49:28.804] [W] [zway] Received SOF, while awaiting ACK
[2021-10-27 09:49:28.810] [D] [zway] RECEIVED: ( 01 0B 00 04 04 0F 02 5A 01 BC 00 00 1E )
[2021-10-27 09:49:28.810] [D] [zway] SENT ACK
[2021-10-27 09:49:28.811] [D] [zway] SETDATA devices.15.data.lastReceived = 0 (0x00000000)
[2021-10-27 09:49:28.811] [D] [zway] SETDATA devices.15.instances.0.commandClasses.90.data.reset = True
[2021-10-27 09:49:28.816] [I] [core] Notification: error (connection): User reset to factory defaults Z-Wave device ID: 15
[2021-10-27 09:49:28.859] [W] [zway] Received SOF, while awaiting ACK
[2021-10-27 09:49:28.868] [D] [zway] RECEIVED: ( 01 1C 00 49 84 0F 16 04 11 01 5E 7A 86 72 60 5A 70 73 77 71 85 8E 59 26 2B 2C 27 22 31 8B )
[2021-10-27 09:49:28.868] [D] [zway] SENT ACK
Node 15 is a STEINEL Outdoor lamp

Turning off the lamp (powering it down completely), rebooting z-way-server, and turing the power back on of the lamp solved the problem for now...
Post Reply