Closed Madelaide closed 3 years ago
I'm experiencing something similar with the 114 beta release. I don't know if it is related to your issue since my devices start to work after a while or rebooting the ozw docker container. This is what I reported in the HA beta discord channel:
When I reboot homeassistant all z-wave devices are unavailable and unusable untill I manually use the device or it reports some information in case it is a sensor. When I force a reboot of the (external) OZW docker everything is available when OZW has finished loading. I noticed this on the dev builds to, but since it is development that can happen. I tried the several dev builds again to see when it stopped working for me and that is 0.114.0-dev20200724. So 0.114.0-dev20200723 does work as expected. My production system which runs 113.3 keeps working without any problem and keeps receiving all the information.
(I also have quite a few devices, 80+)
Also reporting this issue. The ozwdaemon process in the container goes to 100% CPU and the log is filled with these buffer errors.
2020-08-08 02:18:22.483420764 [20200808 2:18:22.483 UTC] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer
2020-08-08 02:18:22.483513689 [20200808 2:18:22.483 UTC] [ozw.logging] [debug]: popping Log Mesages
2020-08-08 02:18:23.283851523 [20200808 2:18:23.283 UTC] [ozw.values] [debug]: delValue: Removing Value QVariant(QString, "Code 122:") QVariant(qulonglong, 34339947281956887) 0
2020-08-08 02:18:23.285041728 [20200808 2:18:23.284 UTC] [ozw.notifications] [debug]: Notification pvt_valueRemoved: 34621422258667543 Thread: 0x7f451b0b89c0
2020-08-08 02:18:23.482340194 [20200808 2:18:23.482 UTC] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer
2020-08-08 02:18:23.482413600 [20200808 2:18:23.482 UTC] [ozw.logging] [debug]: popping Log Mesages
2020-08-08 02:18:23.483437180 [20200808 2:18:23.483 UTC] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer
2020-08-08 02:18:23.483493617 [20200808 2:18:23.483 UTC] [ozw.logging] [debug]: popping Log Mesages
Possibly related: https://github.com/OpenZWave/open-zwave/issues/673
Add another one to the list with this issue. 80+ device network, Rpi 3b+, HUSBZB-1 stick plugged into pi. Worked fine in 1.4 in homeassistant.
In 1.6...Upon daemon startup, MQTT status shows "offline" and never changes. However, in the logs you can see ozw polling all of the nodes... but then a few min go by (maybe 5) and it starts with lods of "valueRemoved" and "Not enough space in stream buffer":
[20200821 16:45:49.572 EDT] [ozw.notifications] [debug]: Notification pvt_valueRemoved: 25895697968267281 Thread: 0x76f2d558
[20200821 16:46:02.021 EDT] [ozw.values] [debug]: delValue: Removing Value QVariant(QString, "Wattage threshold percent") QVariant(qulonglong, 25895697968267281) 0
[20200821 16:46:02.025 EDT] [ozw.notifications] [debug]: Notification pvt_valueRemoved: 28147497781952536 Thread: 0x76f2d558
[20200821 16:46:14.599 EDT] [ozw.values] [debug]: delValue: Removing Value QVariant(QString, "Default Group Reports") QVariant(qulonglong, 28147497781952536) 0
[20200821 16:46:14.603 EDT] [ozw.notifications] [debug]: Notification pvt_valueRemoved: 28428972758663187 Thread: 0x76f2d558
[20200821 16:46:27.261 EDT] [ozw.values] [debug]: delValue: Removing Value QVariant(QString, "Report type G1") QVariant(qulonglong, 28428972758663187) 0
[20200821 16:46:27.264 EDT] [ozw.notifications] [debug]: Notification pvt_valueRemoved: 28710447735373843 Thread: 0x76f2d558
[20200821 16:46:42.169 EDT] [ozw.values] [debug]: delValue: Removing Value QVariant(QString, "Report type G2") QVariant(qulonglong, 28710447735373843) 0
[20200821 16:46:42.175 EDT] [ozw.notifications] [debug]: Notification pvt_valueRemoved: 28991922712084499 Thread: 0x76f2d558
[20200821 16:46:58.475 EDT] [ozw.values] [debug]: delValue: Removing Value QVariant(QString, "Report type G3") QVariant(qulonglong, 28991922712084499) 0
[20200821 16:46:58.479 EDT] [ozw.notifications] [debug]: Notification pvt_valueRemoved: 30962247549059096 Thread: 0x76f2d558
[20200821 16:47:13.643 EDT] [ozw.values] [debug]: delValue: Removing Value QVariant(QString, "Default Group Time") QVariant(qulonglong, 30962247549059096) 0
[20200821 16:47:13.646 EDT] [ozw.notifications] [debug]: Notification pvt_valueRemoved: 31243722525769747 Thread: 0x76f2d558
[20200821 16:47:27.751 EDT] [ozw.values] [debug]: delValue: Removing Value QVariant(QString, "Send interval G1") QVariant(qulonglong, 31243722525769747) 0
[20200821 16:47:27.755 EDT] [ozw.notifications] [debug]: Notification pvt_valueRemoved: 31525197502480403 Thread: 0x76f2d558
[20200821 16:47:41.902 EDT] [ozw.values] [debug]: delValue: Removing Value QVariant(QString, "Send interval G2") QVariant(qulonglong, 31525197502480403) 0
[20200821 16:47:41.905 EDT] [ozw.notifications] [debug]: Notification pvt_valueRemoved: 31806672479191059 Thread: 0x76f2d558
[20200821 16:47:55.876 EDT] [ozw.values] [debug]: delValue: Removing Value QVariant(QString, "Send interval G3") QVariant(qulonglong, 31806672479191059) 0
[20200821 16:47:55.880 EDT] [ozw.notifications] [debug]: Notification pvt_valueRemoved: 71494644195393558 Thread: 0x76f2d558
[20200821 16:47:57.794 EDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer
[20200821 16:47:57.794 EDT] [ozw.logging] [debug]: popping Log Mesages
[20200821 16:47:58.790 EDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer
[20200821 16:47:58.791 EDT] [ozw.logging] [debug]: popping Log Mesages
[20200821 16:47:59.790 EDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer
[20200821 16:47:59.791 EDT] [ozw.logging] [debug]: popping Log Mesages
[20200821 16:48:00.791 EDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer
[20200821 16:48:00.791 EDT] [ozw.logging] [debug]: popping Log Mesages
[20200821 16:48:10.817 EDT] [ozw.values] [debug]: delValue: Removing Value QVariant(QString, "Device tag") QVariant(qulonglong, 71494644195393558) 0
[20200821 16:48:10.821 EDT] [ozw.notifications] [debug]: Notification pvt_valueRe moved: 71776119172104216 Thread: 0x76f2d558
[20200821 16:48:18.132 EDT] [ozw.mqtt.publisher] [debug]: Removing CommandClass Topic for 6 1 112
[20200821 16:48:25.296 EDT] [ozw.values] [debug]: delValue: Removing Value QVariant(QString, "Reset device") QVariant(qulonglong, 71776119172104216) 0
[20200821 16:48:25.300 EDT] [ozw.notifications] [debug]: Notification pvt_valueRemoved: 115114003 Thread: 0x76f2d558
[20200821 16:48:27.137 EDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer
[20200821 16:48:27.138 EDT] [ozw.logging] [debug]: popping Log Mesages
[20200821 16:48:28.131 EDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer
[20200821 16:48:28.132 EDT] [ozw.logging] [debug]: popping Log Mesages
[20200821 16:48:29.130 EDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer
[20200821 16:48:29.131 EDT] [ozw.logging] [debug]: popping Log Mesages
[20200821 16:48:30.130 EDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer
[20200821 16:48:30.131 EDT] [ozw.logging] [debug]: popping Log Mesages
[20200821 16:48:31.130 EDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer
[20200821 16:48:31.131 EDT] [ozw.logging] [debug]: popping Log Mesages
[20200821 16:48:32.130 EDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer
[20200821 16:48:32.131 EDT] [ozw.logging] [debug]: popping Log Mesages
[20200821 16:48:33.131 EDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer
[20200821 16:48:33.131 EDT] [ozw.logging] [debug]: popping Log Mesages
[20200821 16:48:34.131 EDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer
[20200821 16:48:34.131 EDT] [ozw.logging] [debug]: popping Log Mesages
[20200821 16:48:35.131 EDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer
[20200821 16:48:35.131 EDT] [ozw.logging] [debug]: popping Log Mesages
[20200821 16:48:36.130 EDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer
[20200821 16:48:36.131 EDT] [ozw.logging] [debug]: popping Log Mesages
[20200821 16:48:37.130 EDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer
[20200821 16:48:37.131 EDT] [ozw.logging] [debug]: popping Log Mesages
[20200821 16:48:38.131 EDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer
[20200821 16:48:38.131 EDT] [ozw.logging] [debug]: popping Log Mesages
[20200821 16:48:39.691 EDT] [ozw.values] [debug]: delValue: Removing Value QVariant(QString, "Loaded Config Revision") QVariant(qulonglong, 115114003) 0
[20200821 16:48:39.696 EDT] [ozw.notifications] [debug]: Notification pvt_valueRemoved: 281475091824659 Thread: 0x76f2d558
[20200821 16:48:55.425 EDT] [ozw.values] [debug]: delValue: Removing Value QVariant(QString, "Config File Revision") QVariant(qulonglong, 281475091824659) 0
[20200821 16:48:55.429 EDT] [ozw.notifications] [debug]: Notification pvt_valueRemoved: 562950068535315 Thread: 0x76f2d558
1598042936: Saving in-memory database to /data/mosquitto.db.
[20200821 16:49:03.474 EDT] [ozw.mqtt.publisher] [debug]: Removing CommandClass Topic for 6 1 114
[20200821 16:49:11.464 EDT] [ozw.values] [debug]: delValue: Removing Value QVariant(QString, "Latest Available Config File Revision") QVariant(qulonglong, 562950068535315) 0
[20200821 16:49:11.468 EDT] [ozw.notifications] [debug]: Notification pvt_valueRemoved: 115441687 Thread: 0x76f2d558
[20200821 16:49:26.914 EDT] [ozw.values] [debug]: delValue: Removing Value QVariant(QString, "Library Version") QVariant(qulonglong, 115441687) 0
[20200821 16:49:26.920 EDT] [ozw.notifications] [debug]: Notification pvt_valueRemoved: 281475092152343 Thread: 0x76f2d558
[20200821 16:49:42.760 EDT] [ozw.values] [debug]: delValue: Removing Value QVariant(QString, "Protocol Version") QVariant(qulonglong, 281475092152343) 0
[20200821 16:49:42.763 EDT] [ozw.notifications] [debug]: Notification pvt_valueRemoved: 562950068862999 Thread: 0x76f2d558
[20200821 16:49:49.001 EDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer
[20200821 16:49:49.002 EDT] [ozw.logging] [debug]: popping Log Mesages
[20200821 16:49:49.991 EDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer
[20200821 16:49:49.992 EDT] [ozw.logging] [debug]: popping Log Mesages
[20200821 16:49:50.880 EDT] [ozw.mqtt.publisher] [debug]: Removing CommandClass Topic for 6 1 134
[20200821 16:49:50.992 EDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer
[20200821 16:49:50.992 EDT] [ozw.logging] [debug]: popping Log Mesages
[20200821 16:49:51.992 EDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer
[20200821 16:49:51.992 EDT] [ozw.logging] [debug]: popping Log Mesages
[20200821 16:49:53.000 EDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer
[20200821 16:49:53.000 EDT] [ozw.logging] [debug]: popping Log Mesages
[20200821 16:49:53.991 EDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer
[20200821 16:49:53.992 EDT] [ozw.logging] [debug]: popping Log Mesages
[20200821 16:49:54.992 EDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer
[20200821 16:49:54.992 EDT] [ozw.logging] [debug]: popping Log Mesages
[20200821 16:49:55.992 EDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer
[20200821 16:49:55.992 EDT] [ozw.logging] [debug]: popping Log Mesages
[20200821 16:49:56.992 EDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer
[20200821 16:49:56.992 EDT] [ozw.logging] [debug]: popping Log Mesages
[20200821 16:49:57.995 EDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer
[20200821 16:49:57.995 EDT] [ozw.logging] [debug]: popping Log Mesages
[20200821 16:49:58.797 EDT] [ozw.mqtt.publisher] [debug]: Removing Instance Topic for 6 1
[20200821 16:49:58.799 EDT] [ozw.values] [debug]: delValue: Removing Value QVariant(QString, "Application Version") QVariant(qulonglong, 562950068862999) 0
[20200821 16:49:58.992 EDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer
[20200821 16:49:58.992 EDT] [ozw.logging] [debug]: popping Log Mesages
[20200821 16:49:59.991 EDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer
[20200821 16:49:59.991 EDT] [ozw.logging] [debug]: popping Log Mesages
[20200821 16:50:00.992 EDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer
[20200821 16:50:00.992 EDT] [ozw.logging] [debug]: popping Log Mesages
My issue seems to be triggered after the network has started -which takes about 15-20 mins.
Thdd Ed error occurs when I try refresh a node that is reviving packets and has neighbours-but doesn’t resolve with a type. It seems to kill ozw without fail
Having exactly the same problem (both the "Not enough space in stream buffer" and "delValue: Removing Value ..."), with the network not starting. I'm not even able to view the OZW UI (it stays on the connect screen with ConnectingState 0%).
EDIT: Just noticed that before it fails, I have some logs related to the stick (not sure what they mean) and MQTT failures:
[20200907 12:28:31.466 WEST] [ozw.mqtt.publisher] [debug]: Publishing Event ozwNotification
[20200907 12:28:31.466 WEST] [ozw.notifications] [debug]: Notification pvt_ozwNotification NotificationTypes::Notification_Code_MsgTimeout Thread: 0x7fb945d5bd48
[20200907 12:28:31.466 WEST] [ozw.mqtt.publisher] [debug]: Publishing Event ozwNotification
[20200907 12:28:31.466 WEST] [ozw.notifications] [debug]: Notification pvt_ozwNotification NotificationTypes::Notification_Code_MsgTimeout Thread: 0x7fb945d5bd48
[20200907 12:28:31.466 WEST] [ozw.mqtt.publisher] [debug]: Publishing Event ozwNotification
[20200907 12:28:31.467 WEST] [ozw.notifications] [debug]: Notification pvt_nodeQueriesComplete 1 Thread: 0x7fb945d5bd48
[20200907 12:28:31.467 WEST] [ozw.nodes] [debug]: setNodeData 1 : QTOZW_Nodes::NodeDeviceType : QVariant(int, 0) Transaction: true
[20200907 12:28:31.467 WEST] [ozw.nodes] [debug]: setNodeData 1 : QTOZW_Nodes::NodeDeviceTypeString : QVariant(QString, "Unknown Type (0x0000)") Transaction: true
[20200907 12:28:31.467 WEST] [ozw.nodes] [debug]: setNodeData 1 : QTOZW_Nodes::NodeRole : QVariant(int, 0) Transaction: true
[20200907 12:28:31.467 WEST] [ozw.nodes] [debug]: setNodeData 1 : QTOZW_Nodes::NodeRoleString : QVariant(QString, "Central Controller") Transaction: true
[20200907 12:28:31.467 WEST] [ozw.nodes] [debug]: setNodeData 1 : QTOZW_Nodes::NodePlusType : QVariant(int, 0) Transaction: true
[20200907 12:28:31.467 WEST] [ozw.nodes] [debug]: setNodeData 1 : QTOZW_Nodes::NodePlusTypeString : QVariant(QString, "Z-Wave+ node") Transaction: true
[20200907 12:28:31.467 WEST] [ozw.nodes] [debug]: setNodeData 1 : QTOZW_Nodes::NodeQueryStage : QVariant(QString, "Complete") Transaction: true
[20200907 12:28:31.467 WEST] [default] [debug]: QVariant(int, 1)
[20200907 12:28:31.467 WEST] [default] [debug]: QVariant(QString, "")
[20200907 12:28:31.467 WEST] [default] [debug]: QVariant(QString, "")
[20200907 12:28:31.467 WEST] [default] [debug]: QVariant(QString, "AEON Labs")
[20200907 12:28:31.467 WEST] [default] [debug]: QVariant(QString, "ZW090 Z-Stick Gen5 EU")
[20200907 12:28:31.467 WEST] [default] [debug]: QVariant(QString, "Static Controller")
[20200907 12:28:31.467 WEST] [default] [debug]: QVariant(int, 2)
[20200907 12:28:31.467 WEST] [default] [debug]: QVariant(QString, "Static Controller")
[20200907 12:28:31.467 WEST] [default] [debug]: QVariant(int, 2)
[20200907 12:28:31.467 WEST] [default] [debug]: QVariant(QString, "Static PC Controller")
[20200907 12:28:31.467 WEST] [default] [debug]: QVariant(int, 1)
[20200907 12:28:31.467 WEST] [default] [debug]: QVariant(QString, "Unknown Type (0x0000)")
[20200907 12:28:31.467 WEST] [default] [debug]: QVariant(int, 0)
[20200907 12:28:31.467 WEST] [default] [debug]: QVariant(int, 0)
[20200907 12:28:31.467 WEST] [default] [debug]: QVariant(QString, "Central Controller")
[20200907 12:28:31.467 WEST] [default] [debug]: QVariant(int, 0)
[20200907 12:28:31.467 WEST] [default] [debug]: QVariant(QString, "Z-Wave+ node")
[20200907 12:28:31.467 WEST] [default] [debug]: QVariant(QString, "Complete")
[20200907 12:28:31.467 WEST] [default] [debug]: QVariant(QString, "0x0086")
[20200907 12:28:31.467 WEST] [default] [debug]: QVariant(QString, "0x0001")
[20200907 12:28:31.468 WEST] [default] [debug]: QVariant(QString, "0x005a")
[20200907 12:28:31.468 WEST] [default] [debug]: QVariant(uint, 100000)
[20200907 12:28:31.468 WEST] [default] [debug]: QVariant(int, 4)
[20200907 12:28:31.468 WEST] [default] [debug]: QVariant(int, 0)
[20200907 12:28:31.468 WEST] [default] [debug]: QVariant(QBitArray, QBitArray(1010 0011 0))
[20200907 12:28:31.468 WEST] [ozw.mqtt.publisher] [debug]: Publishing Event nodeQueriesComplete: 1
[20200907 12:28:31.468 WEST] [ozw.notifications] [debug]: Notification pvt_ozwNotification NotificationTypes::Notification_Code_MsgTimeout Thread: 0x7fb945d5bd48
[20200907 12:28:31.468 WEST] [ozw.mqtt.publisher] [debug]: Publishing Event ozwNotification
[20200907 12:28:31.468 WEST] [ozw.notifications] [debug]: Notification pvt_ozwNotification NotificationTypes::Notification_Code_MsgTimeout Thread: 0x7fb945d5bd48
[20200907 12:28:31.468 WEST] [ozw.mqtt.publisher] [debug]: Publishing Event ozwNotification
[20200907 12:28:31.468 WEST] [ozw.notifications] [debug]: Notification pvt_ozwNotification NotificationTypes::Notification_Code_MsgTimeout Thread: 0x7fb945d5bd48
[20200907 12:28:31.468 WEST] [ozw.mqtt.publisher] [debug]: Publishing Event ozwNotification
[20200907 12:28:31.468 WEST] [ozw.notifications] [debug]: Notification pvt_ozwNotification NotificationTypes::Notification_Code_MsgTimeout Thread: 0x7fb945d5bd48
.....
[20200907 12:28:31.471 WEST] [ozw.mqtt.publisher] [debug]: Publishing Event nodeGroupChanged: 32 Group: 2
[20200907 12:28:31.471 WEST] [ozw.mqtt.publisher] [debug]: MQTT State Change "Disconnected"
[20200907 12:28:31.471 WEST] [ozw.mqtt.publisher] [warning]: Exiting on Failure
[20200907 12:28:31.471 WEST] [ozw.mqtt.publisher] [warning]: MQTT Client Disconnnected
[20200907 12:28:31.471 WEST] [ozw.mqtt.publisher] [warning]: MQTT Client Error "Transport Invalid"
[20200907 12:28:31.471 WEST] [ozw.library] [info]: Info - Node: 0 mgr, Driver for controller /dev/serial/by-id/usb-0658_0200-if00 pending removal
[20200907 12:28:31.472 WEST] [ozw.library] [debug]: Detail - Node: 0 Notification: DriverRemoved
[20200907 12:28:31.473 WEST] [ozw.notifications] [debug]: Notification pvt_driverRemoved 3605578536 Thread: 0x7fb945d5bd48
[20200907 12:28:31.473 WEST] [ozw.notifications] [debug]: Notification pvt_nodeRemoved 1 Thread: 0x7fb945d5bd48
[20200907 12:28:31.473 WEST] [ozw.notifications] [debug]: Notification pvt_valueRemoved: 17301521 Thread: 0x7fb945d5bd48
One month later, B115b0, same error - occurred this time after removing a node from the network (a working node, can't seem to get dead nodes out) - Can't heal either it seems... anyway , the logs
20200909 16:14:24.314 ACST] [ozw.notifications] [debug]: Notification pvt_valueRemoved: 281475091841041 Thread: 0x7f6fe47b3d48 [20200909 16:14:25.965 ACST] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20200909 16:14:25.966 ACST] [ozw.logging] [debug]: popping Log Mesages [20200909 16:14:25.968 ACST] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20200909 16:14:25.968 ACST] [ozw.logging] [debug]: popping Log Mesages [20200909 16:14:26.922 ACST] [ozw.values] [debug]: delValue: Removing Value QVariant(QString, "Timeout") QVariant(qulonglong, 281475091841041) 0 [20200909 16:14:26.923 ACST] [ozw.notifications] [debug]: Notification pvt_valueRemoved: 562950068551704 Thread: 0x7f6fe47b3d48 [20200909 16:14:26.965 ACST] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20200909 16:14:26.965 ACST] [ozw.logging] [debug]: popping Log Mesages [20200909 16:14:26.967 ACST] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20200909 16:14:26.967 ACST] [ozw.logging] [debug]: popping Log Mesages [20200909 16:14:27.965 ACST] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20200909 16:14:27.965 ACST] [ozw.logging] [debug]: popping Log Mesages [20200909 16:14:27.966 ACST] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20200909 16:14:27.966 ACST] [ozw.logging] [debug]: popping Log Mesages [20200909 16:14:28.965 ACST] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20200909 16:14:28.965 ACST] [ozw.logging] [debug]: popping Log Mesages [20200909 16:14:28.967 ACST] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20200909 16:14:28.967 ACST] [ozw.logging] [debug]: popping Log Mesages [20200909 16:14:29.473 ACST] [ozw.values] [debug]: delValue: Removing Value QVariant(QString, "Set Powerlevel") QVariant(qulonglong, 562950068551704) 0 [20200909 16:14:29.474 ACST] [ozw.notifications] [debug]: Notification pvt_valueRemoved: 844425045262353 Thread: 0x7f6fe47b3d48 [20200909 16:14:29.965 ACST] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20200909 16:14:29.965 ACST] [ozw.logging] [debug]: popping Log Mesages [20200909 16:14:29.966 ACST] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20200909 16:14:29.966 ACST] [ozw.logging] [debug]: popping Log Mesages [20200909 16:14:30.964 ACST] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20200909 16:14:30.965 ACST] [ozw.logging] [debug]: popping Log Mesages [20200909 16:14:30.966 ACST] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20200909 16:14:30.967 ACST] [ozw.logging] [debug]: popping Log Mesages [20200909 16:14:31.965 ACST] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20200909 16:14:31.965 ACST] [ozw.logging] [debug]: popping Log Mesages [20200909 16:14:31.966 ACST] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20200909 16:14:31.966 ACST] [ozw.logging] [debug]: popping Log Mesages [20200909 16:14:32.006 ACST] [ozw.values] [debug]: delValue: Removing Value QVariant(QString, "Test Node") QVariant(qulonglong, 844425045262353) 0 [20200909 16:14:32.007 ACST] [ozw.notifications] [debug]: Notification pvt_valueRemoved: 1125900021973012 Thread: 0x7f6fe47b3d48 [20200909 16:14:32.964 ACST] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20200909 16:14:32.965 ACST] [ozw.logging] [debug]: popping Log Mesages [20200909 16:14:32.966 ACST] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20200909 16:14:32.966 ACST] [ozw.logging] [debug]: popping Log Mesages [20200909 16:14:33.964 ACST] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20200909 16:14:33.965 ACST] [ozw.logging] [debug]: popping Log Mesages [20200909 16:14:33.967 ACST] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20200909 16:14:33.967 ACST] [ozw.logging] [debug]: popping Log Mesages [20200909 16:14:34.534 ACST] [ozw.values] [debug]: delValue: Removing Value QVariant(QString, "Test Powerlevel") QVariant(qulonglong, 1125900021973012) 0 [20200909 16:14:34.535 ACST] [ozw.notifications] [debug]: Notification pvt_valueRemoved: 1407374998683670 Thread: 0x7f6fe47b3d48 [20200909 16:14:34.965 ACST] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20200909 16:14:34.965 ACST] [ozw.logging] [debug]: popping Log Mesages [20200909 16:14:34.967 ACST] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20200909 16:14:34.967 ACST] [ozw.logging] [debug]: popping Log Mesages [20200909 16:14:35.964 ACST] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20200909 16:14:35.965 ACST] [ozw.logging] [debug]: popping Log Mesages [20200909 16:14:35.967 ACST] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20200909 16:14:35.967 ACST] [ozw.logging] [debug]: popping Log Mesages [20200909 16:14:36.965 ACST] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20200909 16:14:36.965 ACST] [ozw.logging] [debug]: popping Log Mesages [20200909 16:14:36.966 ACST] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20200909 16:14:36.966 ACST] [ozw.logging] [debug]: popping Log Mesages [20200909 16:14:37.131 ACST] [ozw.values] [debug]: delValue: Removing Value QVariant(QString, "Frame Count") QVariant(qulonglong, 1407374998683670) 0 [20200909 16:14:37.132 ACST] [ozw.notifications] [debug]: Notification pvt_valueRemoved: 1688849975394328 Thread: 0x7f6fe47b3d48 [20200909 16:14:39.679 ACST] [ozw.values] [debug]: delValue: Removing Value QVariant(QString, "Test") QVariant(qulonglong, 1688849975394328) 0 [20200909 16:14:39.680 ACST] [ozw.notifications] [debug]: Notification pvt_valueRemoved: 1970324952104984 Thread: 0x7f6fe47b3d48 [20200909 16:14:42.206 ACST] [ozw.values] [debug]: delValue: Removing Value QVariant(QString, "Report") QVariant(qulonglong, 1970324952104984) 0 [20200909 16:14:42.208 ACST] [ozw.notifications] [debug]: Notification pvt_valueRemoved: 2251799928815636 Thread: 0x7f6fe47b3d48 [20200909 16:14:43.442 ACST] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20200909 16:14:43.442 ACST] [ozw.logging] [debug]: popping Log Mesages [20200909 16:14:43.444 ACST] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20200909 16:14:43.445 ACST] [ozw.logging] [debug]: popping Log Mesages [20200909 16:14:44.435 ACST] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20200909 16:14:44.435 ACST] [ozw.logging] [debug]: popping Log Mesages [20200909 16:14:44.436 ACST] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20200909 16:14:44.436 ACST] [ozw.logging] [debug]: popping Log Mesages [20200909 16:14:44.766 ACST] [ozw.values] [debug]: delValue: Removing Value QVariant(QString, "Test Status") QVariant(qulonglong, 2251799928815636) 0 [20200909 16:14:44.767 ACST] [ozw.notifications] [debug]: Notification pvt_valueRemoved: 2533274905526294 Thread: 0x7f6fe47b3d48 [20200909 16:14:45.435 ACST] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20200909 16:14:45.435 ACST] [ozw.logging] [debug]: popping Log Mesages [20200909 16:14:45.437 ACST] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20200909 16:14:45.437 ACST] [ozw.logging] [debug]: popping Log Mesages [20200909 16:14:46.054 ACST] [ozw.mqtt.publisher] [debug]: Removing CommandClass Topic for 6 1 115 [20200909 16:14:46.435 ACST] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20200909 16:14:46.436 ACST] [ozw.logging] [debug]: popping Log Mesages [20200909 16:14:46.437 ACST] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20200909 16:14:46.437 ACST] [ozw.logging] [debug]: popping Log Mesages [20200909 16:14:47.351 ACST] [ozw.values] [debug]: delValue: Removing Value QVariant(QString, "Acked Frames") QVariant(qulonglong, 2533274905526294) 0 [20200909 16:14:47.352 ACST] [ozw.notifications] [debug]: Notification pvt_valueRemoved: 115441687 Thread: 0x7f6fe47b3d48 [20200909 16:14:47.435 ACST] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20200909 16:14:47.435 ACST] [ozw.logging] [debug]: popping Log Mesages [20200909 16:14:47.436 ACST] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20200909 16:14:47.436 ACST] [ozw.logging] [debug]: popping Log Mesages [20200909 16:14:48.435 ACST] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20200909 16:14:48.435 ACST] [ozw.logging] [debug]: popping Log Mesages [20200909 16:14:49.435 ACST] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20200909 16:14:49.435 ACST] [ozw.logging] [debug]: popping Log Mesages [20200909 16:14:49.859 ACST] [ozw.values] [debug]: delValue: Removing Value QVariant(QString, "Library Version") QVariant(qulonglong, 115441687) 0 [20200909 16:14:49.860 ACST] [ozw.notifications] [debug]: Notification pvt_valueRemoved: 281475092152343 Thread: 0x7f6fe47b3d48 [20200909 16:14:50.435 ACST] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20200909 16:14:50.435 ACST] [ozw.logging] [debug]: popping Log Mesages [20200909 16:14:51.435 ACST] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20200909 16:14:51.435 ACST] [ozw.logging] [debug]: popping Log Mesages [20200909 16:14:51.436 ACST] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20200909 16:14:51.437 ACST] [ozw.logging] [debug]: popping Log Mesages
I've been receiving this error in ozwadmin, but changing the Network Object Cache to >1,000 in the ozwadmin preferences pane fixes it. I have no idea in which file its making that change in the backend but it works.
@blhoward2 what do you mean you have been getting this error in ozwadmin? you mean you've been seeing it the ozw logs which you are viewing through ozwadmin?
And you had a reproducible case, and this fixed it?
@blhoward2 what do you mean you have been getting this error in ozwadmin? you mean you've been seeing it the ozw logs which you are viewing through ozwadmin?
And you had a reproducible case, and this fixed it?
I meant that I get this same error in a pop-up in ozwadmin. At least I think its the same error...it's been a few weeks since I did it and I haven't received it since. It is possible that I'm wrong and it was a similar error but it should be easy enough for someone experiencing the error to test.
If it is truly the USB stream buffer size in the kernel, has anyone tried raising the allocated USB memory? https://support.pixelink.com/support/solutions/articles/3000054087-image-transfer-fails-to-start-when-image-size-is-bigger-than-2-mb#:~:text=By%20default%2C%20the%20Linux%20kernel,time%20before%20data%20loss%20occurs.
@blhoward2 I think the error you're talking about is this one https://github.com/home-assistant/hassio-addons/issues/1415#issuecomment-646523535
this issue remains. I have now two different configs. I can reproduce this 100% of the time
I tried to increase the USB stream buffer like @blhoward2 mentioned and I haven’t seen this problem since.
@karl-gustav you did that on the host machine or in the docker image somewhere? And I think this still leaves all of the people running Home Assistant supervised install on a Pi out of luck...
@karl-gustav you did that on the host machine or in the docker image somewhere? And I think this still leaves all of the people running Home Assistant supervised install on a Pi out of luck...
What I posted is a boot-level command line option added to the boot loader. It has nothing to do with docker as the issue is a Linux kernel issue. I’ve never used Supervised but I’d be surprised if there is no way to pass boot loader commands during boot.
if the issue is a Linux kernel problem, why it doesnt happen with 1.4 and also why it happens with a specific zwave config file?
if the issue is a Linux kernel problem, why it doesnt happen with 1.4 and also why it happens with a specific zwave config file?
I don't have the issue so I can't test it, but I suspect that 1.6 is requesting a dump from the usb device in a different manner or order and so it is receiving a larger dump, which depending on the data being dumped is overflowing the stream buffer. It's not so much a "problem" as the stream buffer is set too small by default in the kernel for the amount of data being retrieved at once in this instance.
if the issue is a Linux kernel problem, why it doesnt happen with 1.4 and also why it happens with a specific zwave config file?
Try this to temporarily change the stream buffer size, and see if it fixes it:
sudo modprobe usbcore usbfs_memory_mb=1000
i can't find usbcore as a module:
[~] # lsmod | grep usb
snd_usb_caiaq 53248 0
snd_usb_audio 188416 0
snd_usbmidi_lib 28672 1 snd_usb_audio
snd_rawmidi 32768 3 snd_usb_caiaq,snd_usbmidi_lib,snd_seq_midi
usbserial 40960 1 pl2303
usb_storage 65536 1 uas
usblp 24576 0
i can't find usbcore as a module:
[~] # lsmod | grep usb snd_usb_caiaq 53248 0 snd_usb_audio 188416 0 snd_usbmidi_lib 28672 1 snd_usb_audio snd_rawmidi 32768 3 snd_usb_caiaq,snd_usbmidi_lib,snd_seq_midi usbserial 40960 1 pl2303 usb_storage 65536 1 uas usblp 24576 0
If it’s compiled in then you’d have to do it as a command prompt during booting I believe.
Just tried changing usbfs_memory_mb to 500 and it didn't solve the issue
Just tried changing usbfs_memory_mb to 500 and it didn't solve the issue
Just to be sure. Did you check in the /sys folder in the link I posted to confirm that it took after you restarted?
Just tried changing usbfs_memory_mb to 500 and it didn't solve the issue
Just to be sure. Did you check in the /sys folder in the link I posted to confirm that it took after you restarted?
cat /sys/module/usbcore/parameters/usbfs_memory_mb ? Yep, prints 500.
Definitely overkill, but I added usbcore.usbfs_memory_mb=1024
to the end of /boot/cmdline.txt
like this:
console=serial0,115200 console=tty1 root=/dev/sda1 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait usbcore.usbfs_memory_mb=1024
This worked and the value stayed on reboot. Hopefully this fixes the issue, I can't reliably reproduce this bug, but it happens every couple of days. If it stops, I will likely lower this value to 512.
This unfortunately did not solve the problem. The process no longer responds and spams this message.
I am not very familiar with the code, or why certain decisions have been made. However, at the surface, it looked like this value is set to low: https://github.com/OpenZWave/open-zwave/blob/e3e34f6da799e7e3bd740350294407e104bc35d6/cpp/src/platform/Controller.h#L67
Is the buffer just not being drained fast enough?
I thought this might be similar to issue #140. Instead of working on the z-wave messages too much and blocking mqtt messages, maybe ozwdaemon is too busy doing mqtt/other things (or is in a deadlock) so it stops processing the z-wave notifications, which would cause the stream buffer to fill up. But I wasn't entirely sure because the logs don't seem to indicate that.
I'm not sure you can say the buffer size is too low, maybe it is fine for a normally functioning application? 2MB is quite large compared to typical z-wave message sizes. There are no kinds of statistics captured for the stream buffer so we don't really know what would be "normal". If ozwdaemon has such a bug, then the problem is not the buffer size but the application, and if there's a deadlock for example, increasing the size won't help. However, it would be a useful experiment to increase the value and see if it makes a difference. Maybe making it much larger would workaround an ozwdaemon bug and let it get back to processing the zwave messages. Or maybe it's like you say, and it's too low for large networks, but the comments about this not being a problem with OZW 1.4 would seem to indicate it's not a buffer size problem...
If you know how to build docker images it would be pretty simple to clone your own copy of open-zwave, change the buffer size and reference your repo to build with. https://github.com/OpenZWave/qt-openzwave/blob/89cc0d86c983101aacd89c780bae18bb3dffe9b4/Docker/Dockerfile#L48
I updated my boot parameters so that /sys/module/usbcore/parameters/usbfs_memory_mb
reads 1000. But it still spams the Not enough space in stream buffer error. And the /usr/local/bin/ozwdaemon process is now constantly at 100% CPU. I have tried to switch to zwave2mqtt and that runs perfectly stable. I wonder if that is based on the same or different underlying zwave library 🤔
I have tried to switch to zwave2mqtt and that runs perfectly stable.
Sounds like an application (ozwdaemon) bug to me then. zwave2mqtt uses the same OpenZWave library (but they are switching to entirely different library).
And the /usr/local/bin/ozwdaemon process is now constantly at 100% CPU.
Can you get a stack trace when it's in that state?
@kpine I assume you mean logs and not stack trace since it doesn't crash 🙂
Here I haven't let the process run long enough to produce the Not enough space in stream buffer, BUT it does produce 5MB of logs in 2 minutes on startup: ozwdaemon.log.xz
Here is one of my older logs (i.e. 1 hour older) with 10k lines of the Not enough space in stream buffer error: ozwdaemon.old.log.xz
(I'm hoping there aren't any sensitive information in these I haven't found ¯\_(ツ)_/¯)
If ozwdaemon is stuck at 100% for a significant time, maybe it is stuck in some kind of loop. If you captured a stack trace (of all threads) at that time it might provide a clue. It's just cheap way of doing some performance analysis.
@karl-gustav In the two logs you provided it's actually showing issue #140
2020-10-23 07:50:39.329783827 [20201023 7:50:39.329 UTC] [ozw.notifications] [debug]: Notification pvt_valueRefreshed: 72057594579812384 Thread: 0x7fd9ee5d19c0
2020-10-23 07:50:39.346337557 [20201023 7:50:39.346 UTC] [ozw.mqtt.publisher] [debug]: Publishing Event valueRefreshed: 72057594579812384
2020-10-23 07:50:39.347635931 [20201023 7:50:39.347 UTC] [ozw.mqtt.publisher] [debug]: MQTT State Change "Disconnected"
2020-10-23 07:50:39.347771316 [20201023 7:50:39.347 UTC] [ozw.mqtt.publisher] [warning]: Exiting on Failure
2020-10-23 07:50:39.347857158 [20201023 7:50:39.347 UTC] [ozw.mqtt.publisher] [warning]: MQTT Client Disconnnected
2020-10-23 07:50:39.347934048 [20201023 7:50:39.347 UTC] [ozw.mqtt.publisher] [warning]: MQTT Client Error "Transport Invalid"
2020-10-23 07:50:39.348067118 [20201023 7:50:39.348 UTC] [ozw.library] [info]: Info - Node: 0 mgr, Driver for controller /dev/ttyUSB.ZWAVE pending removal
2020-10-23 07:50:39.348183850 [20201023 7:50:39.348 UTC] [ozw.logging] [debug]: popping Log Mesages
2020-10-23 07:50:39.349312103 [20201023 7:50:39.349 UTC] [ozw.library] [debug]: Detail - Node: 0 Notification: DriverRemoved
Because ozwdaemon is not handling the MQTT messages, the broker is disconnecting it. Once disconnected, ozwdaemon will shutdown, which is why the "DriverRemoved" message is shown. The stream buffer errors only seem to occur after the driver has been removed, so ozwdaemon has probably stopped handling ozw notifications at this point. It is just taking a long time for it to shutdown, as it does cleanup work.
This seems to be seems to be true for all the other logs posted in this issue, the error happens following all of the "value removed" messages. It's looking more like this is just a duplicate of #140, unless someone has logs of the stream buffer error occurring w/o an MQTT disconnect?
I’ve had mosquito itself crash a few times requiring a restart particularly upon refreshing nodes. I wonder if this is an upstream error? Has an issue been opened on Mosquitto’s GitHub?
Issue #140, and the logs here are a bug in ozwdaemon. There is a keepalive timeout value set when connecting to the broker. If ozwdaemon does not respond to a ping request within that time, the broker is closing that connection.
I can't comment on the mosquitto crashes you're seeing though. If mosquitto crashes, ozwdaemon is going to restart. Either way, ozwdaemon is not working properly.
@kpine Thanks for the insight, delteting the ozwcache file (temproary fix for #140) does indead solve my issues 👍
Hmm, V117 and 3 months later and this issue is still a problem...
[20201030 19:20:45.268 ACDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20201030 19:20:45.269 ACDT] [ozw.logging] [debug]: popping Log Mesages [20201030 19:20:45.270 ACDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20201030 19:20:45.270 ACDT] [ozw.logging] [debug]: popping Log Mesages [20201030 19:20:46.262 ACDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20201030 19:20:46.263 ACDT] [ozw.logging] [debug]: popping Log Mesages [20201030 19:20:46.264 ACDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20201030 19:20:46.264 ACDT] [ozw.logging] [debug]: popping Log Mesages [20201030 19:20:46.562 ACDT] [ozw.values] [debug]: delValue: Removing Value QVariant(QString, "Active flashing alarm time") QVariant(qulonglong, 10977524202602518) 0 [20201030 19:20:46.564 ACDT] [ozw.notifications] [debug]: Notification pvt_valueRemoved: 11258999179313169 Thread: 0x7f4e7166fd48 [20201030 19:20:47.262 ACDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20201030 19:20:47.263 ACDT] [ozw.logging] [debug]: popping Log Mesages [20201030 19:20:47.264 ACDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20201030 19:20:47.264 ACDT] [ozw.logging] [debug]: popping Log Mesages [20201030 19:20:48.262 ACDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20201030 19:20:48.263 ACDT] [ozw.logging] [debug]: popping Log Mesages [20201030 19:20:48.264 ACDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20201030 19:20:48.265 ACDT] [ozw.logging] [debug]: popping Log Mesages [20201030 19:20:49.262 ACDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20201030 19:20:49.262 ACDT] [ozw.logging] [debug]: popping Log Mesages [20201030 19:20:49.264 ACDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20201030 19:20:49.264 ACDT] [ozw.logging] [debug]: popping Log Mesages [20201030 19:20:49.285 ACDT] [ozw.values] [debug]: delValue: Removing Value QVariant(QString, "Updating the dimming level without the input from the switch") QVariant(qulonglong, 11258999179313169) 0 [20201030 19:20:49.285 ACDT] [ozw.notifications] [debug]: Notification pvt_valueRemoved: 11540474156023828 Thread: 0x7f4e7166fd48 [20201030 19:20:50.263 ACDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20201030 19:20:50.263 ACDT] [ozw.logging] [debug]: popping Log Mesages [20201030 19:20:50.263 ACDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20201030 19:20:50.263 ACDT] [ozw.logging] [debug]: popping Log Mesages [20201030 19:20:50.704 ACDT] [ozw.mqtt.publisher] [debug]: Removing CommandClass Topic for 6 1 112 [20201030 19:20:51.262 ACDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20201030 19:20:51.263 ACDT] [ozw.logging] [debug]: popping Log Mesages [20201030 19:20:51.264 ACDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20201030 19:20:51.264 ACDT] [ozw.logging] [debug]: popping Log Mesages [20201030 19:20:52.065 ACDT] [ozw.values] [debug]: delValue: Removing Value QVariant(QString, "Scene activation functionality") QVariant(qulonglong, 11540474156023828) 0 [20201030 19:20:52.066 ACDT] [ozw.notifications] [debug]: Notification pvt_valueRemoved: 115114003 Thread: 0x7f4e7166fd48 [20201030 19:20:52.262 ACDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20201030 19:20:52.262 ACDT] [ozw.logging] [debug]: popping Log Mesages
The HA version has nothing to do with qt-openzwave. Qt-openzwave hasn’t released any new versions in that time and word is that the maintainer was stepping back for a bit because of hardware failures and some personal things. If you check the issues and PRs nothing has changed really at all since August
Sent from my iPhone
On Oct 30, 2020, at 4:53 AM, Madelaide notifications@github.com wrote:
Hmm, V117 and 3 months later and this issue is still a problem...
[20201030 19:20:45.268 ACDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20201030 19:20:45.269 ACDT] [ozw.logging] [debug]: popping Log Mesages [20201030 19:20:45.270 ACDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20201030 19:20:45.270 ACDT] [ozw.logging] [debug]: popping Log Mesages [20201030 19:20:46.262 ACDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20201030 19:20:46.263 ACDT] [ozw.logging] [debug]: popping Log Mesages [20201030 19:20:46.264 ACDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20201030 19:20:46.264 ACDT] [ozw.logging] [debug]: popping Log Mesages [20201030 19:20:46.562 ACDT] [ozw.values] [debug]: delValue: Removing Value QVariant(QString, "Active flashing alarm time") QVariant(qulonglong, 10977524202602518) 0 [20201030 19:20:46.564 ACDT] [ozw.notifications] [debug]: Notification pvt_valueRemoved: 11258999179313169 Thread: 0x7f4e7166fd48 [20201030 19:20:47.262 ACDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20201030 19:20:47.263 ACDT] [ozw.logging] [debug]: popping Log Mesages [20201030 19:20:47.264 ACDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20201030 19:20:47.264 ACDT] [ozw.logging] [debug]: popping Log Mesages [20201030 19:20:48.262 ACDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20201030 19:20:48.263 ACDT] [ozw.logging] [debug]: popping Log Mesages [20201030 19:20:48.264 ACDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20201030 19:20:48.265 ACDT] [ozw.logging] [debug]: popping Log Mesages [20201030 19:20:49.262 ACDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20201030 19:20:49.262 ACDT] [ozw.logging] [debug]: popping Log Mesages [20201030 19:20:49.264 ACDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20201030 19:20:49.264 ACDT] [ozw.logging] [debug]: popping Log Mesages [20201030 19:20:49.285 ACDT] [ozw.values] [debug]: delValue: Removing Value QVariant(QString, "Updating the dimming level without the input from the switch") QVariant(qulonglong, 11258999179313169) 0 [20201030 19:20:49.285 ACDT] [ozw.notifications] [debug]: Notification pvt_valueRemoved: 11540474156023828 Thread: 0x7f4e7166fd48 [20201030 19:20:50.263 ACDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20201030 19:20:50.263 ACDT] [ozw.logging] [debug]: popping Log Mesages [20201030 19:20:50.263 ACDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20201030 19:20:50.263 ACDT] [ozw.logging] [debug]: popping Log Mesages [20201030 19:20:50.704 ACDT] [ozw.mqtt.publisher] [debug]: Removing CommandClass Topic for 6 1 112 [20201030 19:20:51.262 ACDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20201030 19:20:51.263 ACDT] [ozw.logging] [debug]: popping Log Mesages [20201030 19:20:51.264 ACDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20201030 19:20:51.264 ACDT] [ozw.logging] [debug]: popping Log Mesages [20201030 19:20:52.065 ACDT] [ozw.values] [debug]: delValue: Removing Value QVariant(QString, "Scene activation functionality") QVariant(qulonglong, 11540474156023828) 0 [20201030 19:20:52.066 ACDT] [ozw.notifications] [debug]: Notification pvt_valueRemoved: 115114003 Thread: 0x7f4e7166fd48 [20201030 19:20:52.262 ACDT] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer [20201030 19:20:52.262 ACDT] [ozw.logging] [debug]: popping Log Mesages
— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub, or unsubscribe.
The HA version has nothing to do with qt-openzwave. Qt-openzwave hasn’t released any new versions in that time and word is that the maintainer was stepping back for a bit because of hardware failures and some personal things. If you check the issues and PRs nothing has changed really at all since August …
it doesn't, however HA is planning to ditch their native zwave integration (based on v1.4) and pickup the OZWbeta that is plaggued with this issue. Not a HA issue, but an OZWdaemon issue
That’s the roadmap but they haven’t announced a timeline. The whole point was to allow time for these issues to be worked through so they aren’t a mad rush to fix.
— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub, or unsubscribe.
I am having the same issue I think. According to logs seems like devices are being polled, then I get a mqtt shutdown message, but things still appear to be polled. I have to keep restarting the add-on and then at some point it will work. This is on RPI 4b with Nortek Z wave stick. Oddly enough, I didnt have this issue at all when I was running HA on virtual machin; but I had to switch to PI because I needed to move where the Z stick is.
And I dont know much on the Pi side of how to even attempt to increase USB allocation. Think I am going back to 1.4 for now.
I'm testing to switch from HA integrated Zwave over to ozwdaemon and get the same error:
2021-01-09 00:57:57.101006746 [20210109 0:57:57.092 UTC] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer
I'm on a rpi3 with a Aeotec Zstick get5 running latest qt-openzwave docker image. Mosqito MQTT running on the same device. I have a zwave network with about 50 nodes.
The errors usually come after running for 10-20 minues. I'm not getting any MQTT disconnect warning logs, so I guess its not the same reason as issue #140.
However, I have observed that right before the errors start, the ozwdaemon seem to freeze for about 2 minutes. During that time there are no log entries at all in the log file and at that time OpenZwave-integration in HA start reporting the OZWDaemon as offline. The cpu usage of ozwdaemon does not go to 100%.
There are no other warning or error logs in the ozwdaemon log before the the freeze.
Here's what it looks like (observer the 2 min freeze before the errors:
2021-01-09 17:04:04.630031534 [20210109 17:04:04.629 UTC] [ozw.library] [debug]: Detail - Node: 44 Notification: ValueChanged CC: COMMAND_CLASS_CLIMATE_CONTROL_SCHEDULE Instance: 1 Index: 8 2021-01-09 17:04:04.630424814 [20210109 17:04:04.630 UTC] [ozw.logging] [debug]: popping Log Mesages 2021-01-09 17:04:04.639097079 [20210109 17:04:04.638 UTC] [ozw.library] [debug]: Detail - Node: 44 Notification: ValueChanged CC: COMMAND_CLASS_CLIMATE_CONTROL_SCHEDULE Instance: 1 Index: 9 2021-01-09 17:04:04.639495932 [20210109 17:04:04.639 UTC] [ozw.logging] [debug]: popping Log Mesages 2021-01-09 17:04:04.648497832 [20210109 17:04:04.647 UTC] [ozw.library] [debug]: Detail - Node: 44 Received: 0x01, 0x08, 0x00, 0x04, 0x00, 0x2c, 0x02, 0x84, 0x07, 0x5e 2021-01-09 17:04:04.648876529 [20210109 17:04:04.648 UTC] [ozw.logging] [debug]: popping Log Mesages 2021-01-09 17:04:04.657634992 [20210109 17:04:04.657 UTC] [ozw.library] [info]: Info - Node: 44 Received Wakeup Notification from node 44 2021-01-09 17:04:04.658034106 [20210109 17:04:04.657 UTC] [ozw.logging] [debug]: popping Log Mesages 2021-01-09 17:04:04.666738819 [20210109 17:04:04.666 UTC] [ozw.library] [info]: Info - Node: 44 Node 44 has been marked as awake 2021-01-09 17:04:04.667139391 [20210109 17:04:04.666 UTC] [ozw.logging] [debug]: popping Log Mesages 2021-01-09 17:06:10.649178887 [20210109 17:06:10.648 UTC] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer 2021-01-09 17:06:10.649564667 [20210109 17:06:10.649 UTC] [ozw.logging] [debug]: popping Log Mesages 2021-01-09 17:06:10.658522766 [20210109 17:06:10.657 UTC] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer 2021-01-09 17:06:10.659207295 [20210109 17:06:10.658 UTC] [ozw.logging] [debug]: popping Log Mesages 2021-01-09 17:06:11.650047858 [20210109 17:06:11.649 UTC] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer 2021-01-09 17:06:11.650522075 [20210109 17:06:11.650 UTC] [ozw.logging] [debug]: popping Log Mesages 2021-01-09 17:06:12.661856330 [20210109 17:06:12.648 UTC] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer 2021-01-09 17:06:12.661900913 [20210109 17:06:12.649 UTC] [ozw.logging] [debug]: popping Log Mesages 2021-01-09 17:06:12.661921121 [20210109 17:06:12.657 UTC] [ozw.library] [critical]: Error - Node: 0 ERROR: Not enough space in stream buffer 2021-01-09 17:06:12.661940704 [20210109 17:06:12.658 UTC] [ozw.logging] [debug]: popping Log Mesages
I have this problem too. Im pretty sure that this is actually a hardware corruption of EEPROM on the stick, but im not sure what is causing it. Let me start from the beginning. Ive been seeing this error for at least 9 months now. My Hass machine is Dell PowerEdge R720 so definitely not a low-powered machine. From time to time, after restarting the host (or supervisor), i start getting those errors and when they start they carry on forever - restarting the host, powercycling the stick, none of it makes the stick work again. I have also tried taking the stick out, putting it onto Windows machine and running OZW troubleshooting tool - even then the stick doesnt work correctly. The only solution i have found so far is to restore an EEPROM backup onto the stick - after that everything starts to work again. I have tried 4 different Aeotec gen 5 sticks, including the latest "updated" version and been able to replicate the issue on all four of them.
It's not the stick. I moved to zwave2jsmqtt a few months ago and have had zero issues since. Restoring the eeprom likely just clears out the queue for the buffer.
I disagree, or we are experiencing two completely different issues maybe? If i backup the "faulty" stick and restore it onto another stick (and mind you im taking backups on a completely different computer so the stick is powercycles after unplugging), stick it back into OZW server it still throws the errors, every time i start ozwdaemon. But if i am restoring a backup made before stick starts throwing errors, it "fixes" it. Also, as ive said, once the stick starts throwing errors in qt-openzwave, i can move it to any other machine, run any OZW software and it wont work until EEPROM restore. This being said, sticks only starts throwing out errors when im on qt-openzwave. Before i was using Zwave2MQTT and before that Zwave 1.4 and never had this problem until i migrated to qt-openzwave (HA addon)
It's unlikely this is due to the stick given the fact it affects many different brands of sticks and only on qt-openzwave. There are lots of reasons that might happen, including the usb identifier changing and so the kernel sees it as a different device. (I don't know that happens, it's just an example.) Even if it is corrupted qt-openzwave is clearly causing the corruption somehow.
Also deleting the cache sometimes helps fix it temporarily.
Definitely not the stick. I moved to zwavejs - no issues.
It’s that the MQTT broker is not stroked when the zwave stack is busy.
Do yourself a favor move to zwavejs. It is easy
https://community.home-assistant.io/t/switching-from-openzwave-beta-to-zwave-js/276723
On Sat, Feb 20, 2021 at 2:17 PM blhoward2 notifications@github.com wrote:
It's unlikely this is due to the stick given the fact it affects many different brands of sticks. There are lots of reasons that might happen, including the usb identifier changing and so the kernel sees it as a different device. (I don't know that happens, it's just an example.)
— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/OpenZWave/qt-openzwave/issues/150#issuecomment-782757831, or unsubscribe https://github.com/notifications/unsubscribe-auth/ABM2GAKNWFZTDRNGKOH44FLTAAYINANCNFSM4PXBZQ2Q .
Ozw dead. Closing.
HA 114b1, ozw 0.52 addon, now locks up with the error above, approximately 100 nodes in the NW - was working okay in my test system NW of 10 nodes.
Now all the ZW devices are marked as "unavailable" and my ZW network is unusable; WAF is very low...