PatchworkBoy / homebridge-edomoticz

Domoticz Homebridge-Plugin
Other
118 stars 44 forks source link

Homebridge crashing after edomoticz update #192

Closed Spelvoud closed 4 years ago

Spelvoud commented 4 years ago

Updated Edomoticz and now my homebtidge keeps crashing... Just a few lights are served from domoticz. Running domoticz V4.11631 (beta)

[1/21/2020, 10:44:10 PM] SyntaxError: Unexpected end of JSON input
    at JSON.parse (<anonymous>)
    at eDomoticzAccessory.<anonymous> (/usr/local/lib/node_modules/homebridge-edomoticz/lib/domoticz_accessory.js:253:35)
    at Array.map (<anonymous>)
    at eDomoticzAccessory.<anonymous> (/usr/local/lib/node_modules/homebridge-edomoticz/lib/domoticz_accessory.js:251:20)
    at eDomoticzAccessory.<anonymous> (/usr/local/lib/node_modules/homebridge-edomoticz/lib/domoticz.js:157:9)
    at Request.self.callback (/usr/local/lib/node_modules/homebridge-edomoticz/node_modules/request/request.js:185:22)
    at Request.emit (events.js:189:13)
    at Request.<anonymous> (/usr/local/lib/node_modules/homebridge-edomoticz/node_modules/request/request.js:1161:10)
    at Request.emit (events.js:189:13)
    at IncomingMessage.<anonymous> (/usr/local/lib/node_modules/homebridge-edomoticz/node_modules/request/request.js:1083:12)
    at Object.onceWrapper (events.js:277:13)
    at IncomingMessage.emit (events.js:194:15)
    at endReadableNT (_stream_readable.js:1103:12)
    at process._tickCallback (internal/process/next_tick.js:63:19)
[1/21/2020, 10:44:10 PM] Got SIGTERM, shutting down Homebridge...
gkirstei commented 4 years ago

Same here. Latest oznu/homebridge docker image. At first glance it looks like network/mqtt issue. I have two bridges running and that on the same hw with my mosquitto srv is not crashing. I sent test json msg without ending, both instances crashed immediately.

SyntaxError: Unexpected end of JSON input
    at JSON.parse (<anonymous>)
    at eDomoticzAccessory.<anonymous> (/homebridge/node_modules/homebridge-edomoticz/lib/domoticz_accessory.js:253:35)
    at Array.map (<anonymous>)
PatchworkBoy commented 4 years ago

Update to latest (2.1.19), remove ~/.homebridge/accessories/cachedAccessories, restart, and let me know if issue resolved.

gkirstei commented 4 years ago

Same behavior. After 3h I got:

SyntaxError: Unexpected end of JSON input
    at JSON.parse (<anonymous>)
    at eDomoticzAccessory.<anonymous> (/homebridge/node_modules/homebridge-edomoticz/lib/domoticz_accessory.js:254:35)
    at Array.map (<anonymous>)
    at eDomoticzAccessory.<anonymous> (/homebridge/node_modules/homebridge-edomoticz/lib/domoticz_accessory.js:253:20)
    at eDomoticzAccessory.<anonymous> (/homebridge/node_modules/homebridge-edomoticz/lib/domoticz.js:157:9)
    at Request.self.callback (/homebridge/node_modules/homebridge-edomoticz/node_modules/request/request.js:185:22)
    at Request.emit (events.js:223:5)
    at Request.<anonymous> (/homebridge/node_modules/homebridge-edomoticz/node_modules/request/request.js:1161:10)
    at Request.emit (events.js:223:5)
    at IncomingMessage.<anonymous> (/homebridge/node_modules/homebridge-edomoticz/node_modules/request/request.js:1083:12)

and Hombridge restarted.

PatchworkBoy commented 4 years ago

You’re going to need to turn on logging and identify the specific JSON message causing the error I’m afraid... (stop homebridge, then run from CLI with DEBUG=* homebridge -D which should then show the incoming messages.)

Or grab an MQTT client and install on machine of choice, connect to your MQTT server, and subscribe to domoticz/out & domoticz/in, and watch for the message triggering the crash, then share it here.

Something (a WW light) is transmitting duff JSON to domoticz/out, which technically isn’t the plugin’s problem (it’s whatever’s sending that message) but could probably be handled more gracefully than crashing out homebridge.

FWIW, I know there are no issues with Hue Ambience bulbs, as they’re what I test with.

PatchworkBoy commented 4 years ago

homebridge-eDomoticz will now gracefully handle malformed JSON via https://github.com/PatchworkBoy/homebridge-edomoticz/commit/4fdce6096c475d4ff5cc121d2313c634af356cda (v2.1.22)

Actual error should be viewable via home bridge’s native debug mode - stop your current instance then run with DEBUG=* homebridge -D

This error appeared as a result of proper WW light handling being introduced. Previously they were just treated as plain dimmers. At the moment, invalid JSON is simply discarded, so whatever the MQTT message is won’t have any effect on the target device, and homebridge will no longer restart. So, I’m closing this issue... but please feel free to open a new one with the actual invalid JSON message that Domoticz is transmitting once you’ve managed to capture it.

gkirstei commented 4 years ago

I found out that crashing is not related to mqtt, but homebridge and plugin itself. Crashing only occurs when in homekit app checks status of particular device (two devices in my case). There are no new messages during that time. Both devices are created with zigbee2mqtt domoticz python plugin. Both are color switches with subtype WW. There are two more similar devices in the same bridge what are not initiating crash.

PatchworkBoy commented 4 years ago

Get the JSON HTTP output for the devices from the Domoticz API... the only two things that trigger that error are incoming data over MQTT, or requested data from Domoticz over HTTP via the Domoticz API.

See https://www.domoticz.com/wiki/Domoticz_API/JSON_URL's

Either way, the invalid JSON data is coming from Domoticz...

In a web browser head to your Domoticz instance...

http://RaspberryPi.local/json.htm?type=devices&rid=253

Replace 253 with device IDX of lights in question, replace http://RaspberryPi.local with your particular address.

Paste output here.

gkirstei commented 4 years ago

here you are:

{
    "ActTime" : 1581584799,
    "AstrTwilightEnd" : "19:26",
    "AstrTwilightStart" : "05:47",
    "CivTwilightEnd" : "17:57",
    "CivTwilightStart" : "07:16",
    "DayLength" : "09:20",
    "NautTwilightEnd" : "18:42",
    "NautTwilightStart" : "06:31",
    "ServerTime" : "2020-02-13 11:06:39",
    "SunAtSouth" : "12:37",
    "Sunrise" : "07:57",
    "Sunset" : "17:17",
    "app_version" : "4.11674",
    "result" : 
    [
        {
            "AddjMulti" : 1.0,
            "AddjMulti2" : 1.0,
            "AddjValue" : 0.0,
            "AddjValue2" : 0.0,
            "BatteryLevel" : 255,
            "Color" : "",
            "CustomImage" : 0,
            "Data" : "Off",
            "Description" : "",
            "DimmerType" : "abs",
            "Favorite" : 0,
            "HardwareID" : 16,
            "HardwareName" : "zigbee2mqtt",
            "HardwareType" : "Zigbee2MQTT",
            "HardwareTypeVal" : 94,
            "HaveDimmer" : true,
            "HaveGroupCmd" : false,
            "HaveTimeout" : false,
            "ID" : "0x8418260000096035_light",
            "Image" : "Light",
            "IsSubDevice" : false,
            "LastUpdate" : "2020-02-13 06:56:39",
            "Level" : 100,
            "LevelInt" : 100,
            "MaxDimLevel" : 100,
            "Name" : "Alex w1",
            "Notifications" : "false",
            "PlanID" : "0",
            "PlanIDs" : 
            [
                0
            ],
            "Protected" : false,
            "ShowNotifications" : true,
            "SignalLevel" : "-",
            "Status" : "Off",
            "StrParam1" : "",
            "StrParam2" : "",
            "SubType" : "WW",
            "SwitchType" : "Dimmer",
            "SwitchTypeVal" : 7,
            "Timers" : "false",
            "Type" : "Color Switch",
            "TypeImg" : "dimmer",
            "Unit" : 80,
            "Used" : 1,
            "UsedByCamera" : false,
            "XOffset" : "0",
            "YOffset" : "0",
            "idx" : "13282"
        }
    ],
    "status" : "OK",
    "title" : "Devices"
}
PatchworkBoy commented 4 years ago

It’s not being presented correctly for a WW type light... the “Color” : “” entry should be populated with an array/object, or an empty array/object ([] or {}), not be set to “” ... ie: "Color": "[]" or "Color":"{}"

I can write in code to handle it this evening (UK time) but ultimately the light is being built incorrectly in Domoticz by the zigbee plugin or built as the wrong type.

Spelvoud commented 4 years ago

This is the lamp that (I think) crashes my homebridge.

{ "Name" : "Yeelight Desklight", "SubType" : "WW", "Type" : "Color Switch", "idx" : "82" }, { "DimmerLevels" : "0,1,2,3,4,5,6,7,8,9,10,11,12,13,14,15,16,17,18,19,20,21,22,23,24,25,26,27,28,29,30,31,32,33,34,35,36,37,38,39,40,41,42,43,44,45,46,47,48,49,50,51,52,53,54,55,56,57,58,59,60,61,62,63,64,65,66,67,68,69,70,71,72,73,74,75,76,77,78,79,80,81,82,83,84,85,86,87,88,89,90,91,92,93,94,95,96,97,98,99,100", "IsDimmer" : true, }

PatchworkBoy commented 4 years ago

OK - so @spelvoud that isn’t a complete JSON message, so whatever / however you got that Yeelight into Domoticz is to blame and needs rewriting, not homebridge-edomoticz.

Here is what valid JSON output from Domoticz for a WW type light should look like (Hue Ambience) - retrieved from http://domoticz.ip.address/json.htm?type=devices&rid=298 using web browser (Safari), copied and pasted in it’s entirety:

{
   "ActTime" : 1581620083,
   "AstrTwilightEnd" : "19:09",
   "AstrTwilightStart" : "05:31",
   "CivTwilightEnd" : "17:47",
   "CivTwilightStart" : "06:53",
   "DayLength" : "09:41",
   "NautTwilightEnd" : "18:28",
   "NautTwilightStart" : "06:12",
   "ServerTime" : "2020-02-13 18:54:43",
   "SunAtSouth" : "12:20",
   "Sunrise" : "07:30",
   "Sunset" : "17:11",
   "app_version" : "4.10717",
   "result" : [
      {
         "AddjMulti" : 1.0,
         "AddjMulti2" : 1.0,
         "AddjValue" : 0.0,
         "AddjValue2" : 0.0,
         "BatteryLevel" : 255,
         "Color" : "{\"b\":0,\"cw\":42,\"g\":0,\"m\":2,\"r\":0,\"t\":213,\"ww\":213}",
         "CustomImage" : 0,
         "Data" : "Off",
         "Description" : "",
         "DimmerType" : "abs",
         "Favorite" : 1,
         "HardwareID" : 22,
         "HardwareName" : "Hue",
         "HardwareType" : "Philips Hue Bridge",
         "HardwareTypeVal" : 38,
         "HaveDimmer" : true,
         "HaveGroupCmd" : false,
         "HaveTimeout" : false,
         "ID" : "00000003",
         "Image" : "Light",
         "IsSubDevice" : false,
         "LastUpdate" : "2020-02-13 17:20:50",
         "Level" : 100,
         "LevelInt" : 100,
         "MaxDimLevel" : 100,
         "Name" : "Bedroom Light",
         "Notifications" : "false",
         "PlanID" : "0",
         "PlanIDs" : [ 0 ],
         "Protected" : false,
         "ShowNotifications" : true,
         "SignalLevel" : "-",
         "Status" : "Off",
         "StrParam1" : "",
         "StrParam2" : "",
         "SubType" : "WW",
         "SwitchType" : "Dimmer",
         "SwitchTypeVal" : 7,
         "Timers" : "false",
         "Type" : "Color Switch",
         "TypeImg" : "dimmer",
         "Unit" : 1,
         "Used" : 1,
         "UsedByCamera" : false,
         "XOffset" : "0",
         "YOffset" : "0",
         "idx" : "298"
      }
   ],
   "status" : "OK",
   "title" : "Devices"
}

You need to go back to whoever wrote the yeelight support. I can’t fix the incomplete mess that domoticz is transmitting for your device.

If the plugin / whatever method you used to get your devices into Domoticz causes Domoticz to produce garbage JSON (I’ve NEVER seen that whole "DimmerLevels" line from any other hardware) you can’t expect homebridge plugins to be able to communicate with them reliably I’m afraid.

Spelvoud commented 4 years ago

@Marci I'm not sure I did it right. I read the json page @ domoticz en tried to get the info you requested. Just trying to help. All the other yeelights I own (and this one before) worked fine in your module, now I've narrowed it down to this lamp, that caused homebridge to crash after I updated your module. But thanks so far.

PatchworkBoy commented 4 years ago

It’s because this module didn’t attempt to support WW type lights’ ability to change color temperature from warm white to cold white prior to the update, it just treated it as a monochrome white dimmer. Now, because your bulb is incorrectly or badly advertising itself as a WW light, it’s throwing errors because the plugin is EXPECTING the light to tell it what color it currently is when asked, and it isn’t.

Try upgrading to v2.1.34 (specific change is here: https://github.com/PatchworkBoy/homebridge-edomoticz/commit/8b29ee3f0c64c12ffe58b8e75c6b757890b34697) and see if that helps (dimming should work, color changing probably won’t unless the light is transmitting valid MQTT)... but really, if your WW light doesn’t provide a Color object via Domoticz JSON API, it technically shouldn’t be telling things that it’s a WW light.

PatchworkBoy commented 4 years ago

@Spelvoud go to http://domoticz.ip.address/json.htm?type=devices&rid=82 in a web browser. Copy and paste EVERYTHING back here.

Spelvoud commented 4 years ago

@Marci Here you are :

{ "ActTime" : 1581710449, "AstrTwilightEnd" : "19:50", "AstrTwilightStart" : "06:10", "CivTwilightEnd" : "18:32", "CivTwilightStart" : "07:27", "DayLength" : "09:56", "NautTwilightEnd" : "19:11", "NautTwilightStart" : "06:48", "ServerTime" : "2020-02-14 21:00:49", "SunAtSouth" : "12:60", "Sunrise" : "08:02", "Sunset" : "17:57", "app_version" : "4.11674", "result" : [ { "AddjMulti" : 1.0, "AddjMulti2" : 1.0, "AddjValue" : 0.0, "AddjValue2" : 0.0, "BatteryLevel" : 255, "Color" : "", "CustomImage" : 0, "Data" : "Off", "Description" : "", "DimmerType" : "abs", "Favorite" : 0, "HardwareID" : 16, "HardwareName" : "Yeelight", "HardwareType" : "YeeLight LED", "HardwareTypeVal" : 91, "HaveDimmer" : true, "HaveGroupCmd" : false, "HaveTimeout" : false, "ID" : "C0A8016B", "Image" : "Light", "IsSubDevice" : false, "LastUpdate" : "2020-02-10 18:35:40", "Level" : 60, "LevelInt" : 60, "MaxDimLevel" : 100, "Name" : "Yeelight Desklight", "Notifications" : "false", "PlanID" : "0", "PlanIDs" : [ 0 ], "Protected" : false, "ShowNotifications" : true, "SignalLevel" : "-", "Status" : "Off", "StrParam1" : "", "StrParam2" : "", "SubType" : "WW", "SwitchType" : "Dimmer", "SwitchTypeVal" : 7, "Timers" : "false", "Type" : "Color Switch", "TypeImg" : "dimmer", "Unit" : 0, "Used" : 1, "UsedByCamera" : false, "XOffset" : "0", "YOffset" : "0", "idx" : "82" } ], "status" : "OK", "title" : "Devices" }

On Thu, Feb 13, 2020, 21:20 Marci notifications@github.com wrote:

@Spelvoud https://github.com/Spelvoud go to http://domoticz.ip.address/json.htm?type=devices&rid=82 in a web browser. Copy and paste EVERYTHING back here.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/PatchworkBoy/homebridge-edomoticz/issues/192?email_source=notifications&email_token=AB3F64FI4S66L7C6RN73QULRCWTPVA5CNFSM4KJ3GXWKYY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOELWO6BI#issuecomment-585953029, or unsubscribe https://github.com/notifications/unsubscribe-auth/AB3F64G5HSGKCAH7TCW4PWLRCWTPVANCNFSM4KJ3GXWA .

PatchworkBoy commented 4 years ago

Righty - that’s more like it! Yep, same issue as @gkirstei - light says it’s a WW light / Color switch but then has nothing where it’s Color info should be. Should be handled now and work as a regular dimmer under v2.1.34 without crashing now - give it a try and let me know.

If zigbee2mqtt & yeelight Domoticz plug-ins get updated (I suspect authors haven’t updated them since @gizmocuz et alle overhauled Domoticz’ Color handling) to provide the proper Color object, eDomoticz should detect this and the Color temperature control will start functioning properly. Til then, on / off / brightness should work fine.

Spelvoud commented 4 years ago

Added the light again and it doesn't crash homebridge, great ! Thanks a lot !

On Fri, Feb 14, 2020, 22:45 Marci notifications@github.com wrote:

Righty - that’s more like it! Yep, same issue as @gkirstei https://github.com/gkirstei - light says it’s a WW light but then has nothing where it’s Color info should be. Should be fixed now and work as a regular dimmer under v2.1.34 without crashing now - give it a try and let me know.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/PatchworkBoy/homebridge-edomoticz/issues/192?email_source=notifications&email_token=AB3F64D6BOX3HQEFYUO5CRLRC4GG5A5CNFSM4KJ3GXWKYY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOEL2Q2ZQ#issuecomment-586485094, or unsubscribe https://github.com/notifications/unsubscribe-auth/AB3F64AXLUNMB3XS6UT3VA3RC4GG5ANCNFSM4KJ3GXWA .