nicoduj / homebridge-harmony

Harmony websocket plugin for homebridge
The Unlicense
214 stars 23 forks source link

Harmony Plugin causes Hoobs-Homebridge to crash #217

Closed TheBassfly closed 4 years ago

TheBassfly commented 4 years ago

Describe the bug Since the last update, the Plugin causes Homebridge to crash nearly everyday

To Reproduce Nothing to reproduce, as it happens randomly

Logs This is, what he log produces, before it crashes:

[Homebridge] [1/23/2020, 08:05:05] [HarmonyHub] ERROR - refreshCurrentActivity Error: WebSocket closed with reason: connection failed (1006). [Homebridge] [1/23/2020, 08:05:05] [HarmonyHub] ERROR - refreshCurrentActivity Error: WebSocket closed with reason: connection failed (1006). [Homebridge] [1/23/2020, 08:05:05] [HarmonyHub] ERROR - refreshCurrentActivity Error: WebSocket closed with reason: connection failed (1006). [Homebridge] [1/23/2020, 08:05:05] [HarmonyHub] ERROR - refreshCurrentActivity Error: WebSocket closed with reason: connection failed (1006). [Homebridge] [1/23/2020, 08:05:05] [HarmonyHub] ERROR - refreshCurrentActivity Error: WebSocket closed with reason: connection failed (1006). [Homebridge] [1/23/2020, 08:05:05] [HarmonyHub] ERROR - refreshCurrentActivity Error: WebSocket closed with reason: connection failed (1006). [Homebridge] [1/23/2020, 08:05:05] [HarmonyHub] ERROR - refreshCurrentActivity Error: WebSocket closed with reason: connection failed (1006). [Homebridge] [1/23/2020, 08:05:05] [HarmonyHub] ERROR - refreshCurrentActivity Error: WebSocket closed with reason: connection failed (1006). [Homebridge] [1/23/2020, 08:05:05] [HarmonyHub] ERROR - refreshCurrentActivity Error: WebSocket closed with reason: connection failed (1006). [Homebridge] [1/23/2020, 08:05:05] [HarmonyHub] ERROR - refreshCurrentActivity Error: WebSocket closed with reason: connection failed (1006). [Homebridge] [1/23/2020, 08:05:05] [HarmonyHub] ERROR - refreshCurrentActivity Error: WebSocket closed with reason: connection failed (1006). [Homebridge] [1/23/2020, 08:05:05] [HarmonyHub] ERROR - refreshCurrentActivity Error: WebSocket closed with reason: connection failed (1006). [Homebridge] [1/23/2020, 08:05:05] [HarmonyHub] ERROR - refreshCurrentActivity Error: WebSocket closed with reason: connection failed (1006). [Homebridge] [1/23/2020, 08:05:05] [HarmonyHub] ERROR - refreshCurrentActivity Error: WebSocket closed with reason: connection failed (1006). [Homebridge] <--- Last few GCs ---> [Homebridge] [24554:0x2d57700] 31778024 ms: Mark-sweep 226.8 (231.6) -> 226.6 (231.6) MB, 2464.6 / 2.5 ms (average mu = 0.226, current mu = 0.225) allocation failure scavenge might not succeed [Homebridge] [24554:0x2d57700] 31781328 ms: Mark-sweep 226.9 (231.6) -> 226.8 (231.8) MB, 3296.8 / 1.9 ms (average mu = 0.114, current mu = 0.002) allocation failure scavenge might not succeed [Homebridge] <--- JS stacktrace ---> [Homebridge] ==== JS stack trace ========================================= [Homebridge] 0: ExitFrame [pc: 0xe52060] [Homebridge] Security context: 0x3e58e225 [Homebridge] 1: / anonymous / [0x7142e941] [/home/hoobs/.hoobs/node_modules/homebridge-harmony/harmonySubPlatform.js:~552] [pc=0x4ad36e2c](this=0x4d8422f5 ) [Homebridge] 2: / anonymous / [0x2a15940d] [/home/hoobs/.hoobs/node_modules/homebridge-harmony/harmonyBase.js:~290] [pc=0x4ad38af4](this=0x4d8422f5 ,0x5db75281 ) [Homebridge] 3: Stub... [Homebridge] FATAL ERROR: Ineffective mark-compacts near heap limit Allocation failed - JavaScript heap out of memory [Homebridge] Writing Node.js report to file: report.20200123.080556.24554.0.001.json [Homebridge] Node.js report completed

Config "name": "HarmonyHub", "hubIP": "xxx", "TVAccessory": false, "switchAccessories": true, "publishSwitchActivitiesAsIndividualAccessories": true, "platform": "HarmonyHubWebSocket", "plugin_map": { "plugin_name": "homebridge-harmony" }, "cleanCache": false, "activitiesToPublishAsInputForTVMode": [], "remoteOverrideCommandsList": [], "activitiesToPublishAsAccessoriesSwitch": [], "skippedIfSameStateActivities": [], "devicesToPublishAsAccessoriesSwitch": [], "sequencesToPublishAsAccessoriesSwitch": [], "homeControlsToPublishAsAccessoriesSwitch": [], "otherPlatforms": []

Additional context I'm using the Plugin with Hoobs

nicoduj commented 4 years ago

Hi, when you say last update , what do you mean ? Hoobs update ? Harmony hub update ? Plugin update ? It seems that the plugin can’t connect to your hub .

Sent with GitHawk

TheBassfly commented 4 years ago

Sorry

I mean the last Update ob the Homebridge Harmony Plugin

And yes, the Log says this. But this was the only thing that I changed and it happens randomly. After a restart of the Homebridge Service everything is fine again for the day.

I also posted the same issue in the Hoobs area, because I'm not sure if it's the plugin or hoobs.

nicoduj commented 4 years ago

Make sure your harmony hub has got a fixed IP and that it does not change .

Sent with GitHawk

TheBassfly commented 4 years ago

I has. Because of homebridge I always let the important devices get the same IP everytime.

nicoduj commented 4 years ago

Could you tell me versions of node / websocket dependency ? I don’t have hoobs, but I think there is an issue with reconnection while socket is closed between the plugin and the hub. As far as I understand, it works a bit, and then crash that’s it ?

Sent with GitHawk

TheBassfly commented 4 years ago

Okay, here the Stats: Hoobs: 3.1.20 Node: 12.14.0 Homebridge: 0.4.50

And yes, that's exactly the behavior. Until the Update from 21/12/2019 it worked with any issues.

nicoduj commented 4 years ago

Ok, that is strange will check the changes in the code and dependencies , you say 21/12 what was the version you updated from / to ?

Sent with GitHawk

nicoduj commented 4 years ago

Ok so web socket lib was indeed updated to websocket-as-promised": "^1.0.1" at least from 0.x ... will investigate

Sent with GitHawk

TheBassfly commented 4 years ago

Cool

Thanks

nicoduj commented 4 years ago

Hi again, I tried to reproduce with no luck for know, by generating an error exactly where you got one. The thing is I am nnot looping on the error itself, like your config seems to do.

Could you please run those commands :

npm -version npm list websocket-as-promised

I think there might be a problem of dependencies but not quite sure right now.

TheBassfly commented 4 years ago

Okay

So at the end it is because hoops maybe.

NPM Version: 6.13.4 @hoobs/hoobs@3.1.20 /home/hoobs/.hoobs └─┬ homebridge-harmony@1.2.2 ├─┬ harmony-websocket@1.5.0 │ └── websocket-as-promised@1.0.1 └── websocket-as-promised@1.0.1

nicoduj commented 4 years ago

could you try to modify your package.json in harmony plugin directory (probably in something like /homebridge/node_modules/homebridge-harmony) and set :

"dependencies": {
    ...
 "websocket-as-promised": "^1.0.1"

to

"dependencies": {
    ...
    "websocket-as-promised": "^0.10.1"

then run

npm update 
npm list websocket-as-promised

and then restart homebridge and see if the problem is still there. I would like also you to check log at startup and ensure that there is no problem at first to get the hub config in the startup process.

nicoduj commented 4 years ago

Just in case, you can also do this :

npm list websocket
TheBassfly commented 4 years ago

To be Honest, I'm not a skilled programmer. I would need help to change jsons or such stuff.

the out put says: @hoobs/hoobs@3.1.20 /home/hoobs/.hoobs └─┬ homebridge-harmony@1.2.2 ├─┬ harmony-websocket@1.5.0 │ └── websocket@1.0.31 └── websocket@1.0.31

There is also a Message that a Patch Version for NPM ist available, but I can't update it, as the user I'm using in hoops is not allowed to change such files.

TheBassfly commented 4 years ago

Oh and here is the startup Log from the actually System Situation:

[Homebridge] [1/24/2020, 10:38:24] Loaded config.json with 2 accessories and 3 platforms. [Homebridge] [1/24/2020, 10:38:24] Loaded plugin: "homebridge-delay-switch" [Homebridge] [1/24/2020, 10:38:24] Registering accessory "homebridge-delay-switch.DelaySwitch" [Homebridge] [1/24/2020, 10:38:24] Loaded plugin: "homebridge-fritz" [Homebridge] [1/24/2020, 10:38:25] Registering platform "homebridge-fritz.Fritz!Box" [Homebridge] [1/24/2020, 10:38:25] Loaded plugin: "homebridge-harmony" [Homebridge] [1/24/2020, 10:38:25] Registering platform "homebridge-harmonyHub.HarmonyHubWebSocket" [Homebridge] [1/24/2020, 10:38:25] Plugin /home/hoobs/.hoobs/node_modules/homebridge-hue requires Node version of ^12.14.1 which does not satisfy the current Node version of v12.14.0. You may need to upgrade your installation of Node. [Homebridge] [1/24/2020, 10:38:27] Loaded plugin: "homebridge-hue" [Homebridge] [1/24/2020, 10:38:27] Registering platform "homebridge-hue.Hue" [Homebridge] [1/24/2020, 10:38:27] Loading 3 platforms... [Homebridge] [1/24/2020, 10:38:27] [Hue] Initializing Hue platform... [Homebridge] [1/24/2020, 10:38:27] [Hue] homebridge-hue v0.11.50, node v12.14.0, homebridge v0.4.50 [Homebridge] [1/24/2020, 10:38:27] [Hue] warning: not using recommended node version v12.14.1 LTS [Homebridge] [1/24/2020, 10:38:27] [HarmonyHub] Initializing HarmonyHubWebSocket platform... [Homebridge] [1/24/2020, 10:38:27] [HarmonyHub] HarmonyPlatform Init [Homebridge] [1/24/2020, 10:38:27] [My FritzBox] Initializing Fritz!Box platform... [Homebridge] [1/24/2020, 10:38:27] Loading 2 accessories... [Homebridge] [1/24/2020, 10:38:27] [TVSwitch] Initializing DelaySwitch accessory... [Homebridge] [1/24/2020, 10:38:27] [AppleSwitch] Initializing DelaySwitch accessory... [Homebridge] [1/24/2020, 10:38:27] [HarmonyHub] DidFinishLaunching [Homebridge] [1/24/2020, 10:38:27] [HarmonyHub] INFO - Loading activities... [Homebridge] [1/24/2020, 10:38:27] API launched [Homebridge] [1/24/2020, 10:38:28] [Hue] Philips hue: Philips BSB002 bridge v1935144040, api v1.35.0 [Homebridge] [1/24/2020, 10:38:28] [Hue] Philips hue: 6 accessories [Homebridge] [1/24/2020, 10:38:28] [Hue] masked debug info dumped to /home/hoobs/.hoobs/etc/homebridge-hue.json.gz [Homebridge] [1/24/2020, 10:38:28] [Hue] Initializing platform accessory "Philips hue". [Homebridge] [1/24/2020, 10:38:28] [Hue] Philips hue: 2 services [Homebridge] [1/24/2020, 10:38:28] [Hue] Initializing platform accessory "Zirkulation". [Homebridge] [1/24/2020, 10:38:28] [Hue] Initializing platform accessory "Homebridge". [Homebridge] [1/24/2020, 10:38:28] [Hue] Initializing platform accessory "Sonos Bad". [Homebridge] [1/24/2020, 10:38:28] [Hue] Initializing platform accessory "Schnee". [Homebridge] [1/24/2020, 10:38:28] [Hue] Initializing platform accessory "Schreibtisch". [Homebridge] [1/24/2020, 10:38:28] [My FritzBox] Fritz!Box platform login successful [Homebridge] [1/24/2020, 10:38:28] [My FritzBox] Discovering accessories [Homebridge] [1/24/2020, 10:38:28] [My FritzBox] Using tr64 api for guest Wifi [Homebridge] [1/24/2020, 10:38:29] [HarmonyHub] (HarmonyHub)INFO - Discovered Activity : AppleTV [Homebridge] [1/24/2020, 10:38:29] [HarmonyHub] (HarmonyHub)INFO - Discovered Activity : Wii spielen [Homebridge] [1/24/2020, 10:38:29] [HarmonyHub] (HarmonyHub)INFO - Discovered Activity : Fernsehen [Homebridge] [1/24/2020, 10:38:29] [HarmonyHub] (HarmonyHub)INFO - Discovered Activity : Switch [Homebridge] [1/24/2020, 10:38:29] [HarmonyHub] (HarmonyHub)INFO - Discovered Activity : BluRay [Homebridge] [1/24/2020, 10:38:29] [HarmonyHub] (HarmonyHub)INFO - Discovered Activity : Airplay [Homebridge] [1/24/2020, 10:38:32] [My FritzBox] Alarm sensors found: none [Homebridge] [1/24/2020, 10:38:32] [My FritzBox] Buttons found: none [Homebridge] [1/24/2020, 10:38:32] [My FritzBox] Outlets found: 087610089419,087610219054 [Homebridge] [1/24/2020, 10:38:32] [My FritzBox] Updating outlet 087610089419 [Homebridge] [1/24/2020, 10:38:32] [My FritzBox] Updating outlet 087610219054 [Homebridge] [1/24/2020, 10:38:33] [My FritzBox] Thermostats found: none [Homebridge] [1/24/2020, 10:38:33] [My FritzBox] Sensors found: none [Homebridge] [1/24/2020, 10:38:33] [My FritzBox] Initializing platform accessory "Guest WLAN". [Homebridge] [1/24/2020, 10:38:33] [My FritzBox] Initializing platform accessory "TV Bank". [Homebridge] [1/24/2020, 10:38:33] [My FritzBox] Initializing platform accessory "Katzenbrunnen". [Homebridge] [1/24/2020, 10:38:33] Service is running on port 51827.

mkellsy commented 4 years ago

HOOBS installs plugins in ~/.hoobs/node_modules not in the global scope. This may be causing issues, however it shouldn't.

I reviewed the lines of code that are causing this. issue. And I think there might be a memory leak.

In https://github.com/nicoduj/homebridge-harmony/blob/Dynamic-Platform/harmonyBase.js around line 284.

this.harmony
    .getCurrentActivity()
    .then(response => {
        harmonyPlatform.refreshCurrentActivity(response);
            if (!callbackDone) callback();
        })
    .catch(e => {
        harmonyPlatform.log('ERROR - refreshCurrentActivity ' + e);
        harmonyPlatform.refreshCurrentActivity(
            HarmonyConst.CURRENT_ACTIVITY_NOT_SET_VALUE
        );
        if (!callbackDone) callback();
    });

Doing something like this, putting a half second gap between retries could make this more memory friendly.

this.harmony
    .getCurrentActivity()
    .then(response => {
        harmonyPlatform.refreshCurrentActivity(response);
            if (!callbackDone) callback();
        })
    .catch(e => {
        harmonyPlatform.log('ERROR - refreshCurrentActivity ' + e);
        setTimeout(() => {
            harmonyPlatform.refreshCurrentActivity(
                HarmonyConst.CURRENT_ACTIVITY_NOT_SET_VALUE
            );
            if (!callbackDone) callback();
        }, 500);
    });

I am going to test a half second gap at first, but this may need to be longer. I do know that my Harmony Hub disconnects from my SmartThings hub all the time, but after a few seconds it's back.

I don't know if this will help. I will attempt to test this with my Harmony Hub.

nicoduj commented 4 years ago

Hi, it is not doing a retry, harmonyPlform is not harmonyBase. It is only setting the activity to unset value . that is what is strange to me, since when I generate an error manually in this code, like this :


      this.harmony
        .getCurrentActivity()
        .then(response => {
//TEST
          harmonyPlatform.log('ERROR - refreshCurrentActivity TEST');
          harmonyPlatform.refreshCurrentActivity(
            HarmonyConst.CURRENT_ACTIVITY_NOT_SET_VALUE
          );
          if (!callbackDone) callback();
/*
          harmonyPlatform.refreshCurrentActivity(response);
          if (!callbackDone) callback();
*/

        })
        .catch(e => {
          harmonyPlatform.log('ERROR - refreshCurrentActivity ' + e);
          harmonyPlatform.refreshCurrentActivity(
            HarmonyConst.CURRENT_ACTIVITY_NOT_SET_VALUE
          );
          if (!callbackDone) callback();
        });

I only get the error once, no retry :


[24/01/2020 à 10:01:30] [NicoHarmonyHub] ERROR - refreshCurrentActivity TEST
[24/01/2020 à 10:01:30] [NicoHarmonyHub] keysMap is :{}

might be missing something, retry maybe comes from another context at top level .

nicoduj commented 4 years ago

A new version is on its way (1.2.3) that removes unecessary websocket dependency at my plugin level, to see if it helps.

EDIT : it is released, took some times travis had some breaking change :)

@TheBassfly can you try to update and tell us if it is better ?

TheBassfly commented 4 years ago

Hey I updated the plugin. It will take a few days to see if it‘s crashing again. But for the las 4 hours it was stable. Let‘s see.

nicoduj commented 4 years ago

It will take a few days to see if it‘s crashing again.

Hi, great. How often did it crash before ? you had no update of the harmony hub firmware in the same period as you updated the plugin, right ?

TheBassfly commented 4 years ago

The crash happened every 1-2 days.

As far as I could see, there was no firmware update. Only an update of the harmony app.

MikeDeltaHH commented 4 years ago

Yesterday i made the update to the newest version and at this morning my homebridge was crashed after a long time for the first time - i have to reboot the whole machine from remote, so i haven´t logs at the moment, will investigate this...

nicoduj commented 4 years ago

Hi @MikeDeltaHH, could you please tell us if you are using hoobs, and which update did you do (from / to) ?

@mkells, could you tell me which version of websocket / websocket as promised hoobs depends on ?

MikeDeltaHH commented 4 years ago

Hi @nicoduj i have a hoobs installation and a homebridge installation on two seperate virtual machines for all plugins doesn´t work properly with hoobs - i´ve made the issue in the hoobs github "Strange problem with the homebridge-harmony plugin #432 " and switched this plugin to the native homebridge installation last week! I update from 1.2.2 to 1.2.3!

nicoduj commented 4 years ago

Interesting. And it is your homebridge without hoobs that failed, right ? logs would be much appreciated, especially since there is quite no difference between 1.2.2 and 1.2.3 (only a dependency in package.json)

MikeDeltaHH commented 4 years ago

Yes... i wake up this moring and my homebridge installation wasn´t responding so i reboot the whole machine with a ssh app on my smartphone - the logs i can see (i´m using Homebridge Config UI X) are from the time after the reboot - any chance to collect logs from the point before i reboot the machine? Sorry, my english isn´t great and i´m not a linux specialist...

nicoduj commented 4 years ago

as far as I know config UI X do not erase logs after a reboot, at least it is the case on my installation.

You should find whole logs there : /homebridge/logs

nicoduj commented 4 years ago

@mkellsy Interesting changes in underlying websocket lib that might be related : https://github.com/theturtle32/WebSocket-Node/compare/v1.0.30...v1.0.31

nicoduj commented 4 years ago

Yes... i wake up this moring and my homebridge installation wasn´t responding so i reboot the whole machine with a ssh app on my smartphone - the logs i can see (i´m using Homebridge Config UI X) are from the time after the reboot - any chance to collect logs from the point before i reboot the machine? Sorry, my english isn´t great and i´m not a linux specialist...

Did you reboot after updating ?

MikeDeltaHH commented 4 years ago

Searching for the logs... i´m running homebridge as system.d so the rellated logs are stored in /var/log/syslog - investigate the logs but doesn´t find any entries for the crash... my homebrdige do a planned reboot every day at 03:00 and the crash must be in the time windows between 03:00 and 09:00... Andy yes, do a reboot after update!


syslog.txt

syslog.1.txt

nicoduj commented 4 years ago

Hi, from the log I see, you have cleanCache option activated ->

Jan 25 03:00:13 homebridge homebridge[892]: [2020-1-25 03:00:13] [HarmonyHub Wohnzimmer] Initializing HarmonyHubWebSocket platform... Jan 25 03:00:13 homebridge homebridge[892]: [2020-1-25 03:00:13] [HarmonyHub Wohnzimmer] HarmonyPlatform Init Jan 25 03:00:13 homebridge homebridge[892]: [2020-1-25 03:00:13] [HarmonyHub Wohnzimmer] undefined Jan 25 03:00:13 homebridge homebridge[892]: [2020-1-25 03:00:13] Loading 0 accessories... Jan 25 03:00:13 homebridge homebridge[892]: [2020-1-25 03:00:13] [HarmonyHub Wohnzimmer] DidFinishLaunching Jan 25 03:00:13 homebridge homebridge[892]: [2020-1-25 03:00:13] [HarmonyHub Wohnzimmer] WARNING - Removing Accessories Jan 25 03:00:14 homebridge homebridge[892]: [2020-1-25 03:00:13] [HarmonyHub Wohnzimmer] INFO - Loading activities...

This might explain why you lost everything at restart in hoobs.

nicoduj commented 4 years ago

And your error is not from harmony :

Jan 25 03:00:24 homebridge homebridge[892]: [2020-1-25 03:00:24] Error: listen EADDRINUSE: address already in use :::51826 Jan 25 03:00:24 homebridge homebridge[892]: at Server.setupListenHandle [as _listen2] (net.js:1259:14) Jan 25 03:00:24 homebridge homebridge[892]: at listenInCluster (net.js:1307:12) Jan 25 03:00:24 homebridge homebridge[892]: at Server.listen (net.js:1395:7) Jan 25 03:00:24 homebridge homebridge[892]: at EventedHTTPServer.listen (/usr/lib/node_modules/homebridge/node_modules/hap-nodejs/lib/util/eventedhttp.js:60:19) Jan 25 03:00:24 homebridge homebridge[892]: at HAPServer.listen (/usr/lib/node_modules/homebridge/node_modules/hap-nodejs/lib/HAPServer.js:158:20) Jan 25 03:00:24 homebridge homebridge[892]: at Bridge.Accessory.publish (/usr/lib/node_modules/homebridge/node_modules/hap-nodejs/lib/Accessory.js:616:16) Jan 25 03:00:24 homebridge homebridge[892]: at Server._publish (/usr/lib/node_modules/homebridge/lib/server.js:132:16) Jan 25 03:00:24 homebridge homebridge[892]: at Server. (/usr/lib/node_modules/homebridge/lib/server.js:421:14) Jan 25 03:00:24 homebridge homebridge[892]: at /usr/lib/node_modules/homebridge/node_modules/hap-nodejs/lib/util/once.js:16:19 Jan 25 03:00:24 homebridge homebridge[892]: at HomeMaticPlatform.buildaccesories (/usr/lib/node_modules/homebridge-homematic/index.js:429:3) Jan 25 03:00:24 homebridge homebridge[892]: at regarequest.script.data (/usr/lib/node_modules/homebridge-homematic/index.js:244:12) Jan 25 03:00:24 homebridge homebridge[892]: at IncomingMessage. (/usr/lib/node_modules/homebridge-homematic/HomeMaticRegaRequest.js:42:9) Jan 25 03:00:24 homebridge homebridge[892]: at IncomingMessage.emit (events.js:198:15) Jan 25 03:00:24 homebridge homebridge[892]: at endReadableNT (_stream_readable.js:1139:12) Jan 25 03:00:24 homebridge homebridge[892]: at processTicksAndRejections (internal/process/task_queues.js:81:17)

-> seem to be homematic -> it says some bunch of problems at startup

Jan 25 03:00:13 homebridge homebridge[892]: [2020-1-25 03:00:13] [HomeMatic CCU3] local ip used : 192.168.2.247. you may change that with local_ip parameter in config Jan 25 03:00:13 homebridge homebridge[892]: [2020-1-25 03:00:13] [HomeMatic CCU3] init RPC for VirtualDevices. Jan 25 03:00:13 homebridge homebridge[892]: [2020-1-25 03:00:13] [HomeMatic CCU3] local ip used : 192.168.2.247. you may change that with local_ip parameter in config Jan 25 03:00:13 homebridge homebridge[892]: [2020-1-25 03:00:13] [HomeMatic CCU3] init RPC for HmIP-RF. Jan 25 03:00:13 homebridge homebridge[892]: [2020-1-25 03:00:13] [HomeMatic CCU3] local ip used : 192.168.2.247. you may change that with local_ip parameter in config

MikeDeltaHH commented 4 years ago

Ah ok... i wonder why this doesn´t happen in the homebridge installation with the same config... but thanks for the info, will change this option... and thanks again for investigating my logs and finding a problem with an other plugin... :)

MikeDeltaHH commented 4 years ago

@nicoduj my cleanCache option was set to "false"... so, i wonder why this happens...this is my config:

{ "platform": "HarmonyHubWebSocket", "plugin_map": { "plugin_name": "homebridge-harmony" }, "name": "HarmonyHub Wohnzimmer", "hubIP": "192.168.2.34", "cleanCache": "false", "publishAllTVAsExternalAccessory": "true", "TVAccessory": "true", "mainActivity": "Fernsehen", "playPauseBehavior": "true", "numberOfCommandsSentForVolumeControl": 1, "switchAccessories": "true", "showTurnOffActivity": "true", "publishGeneralMuteSwitch": "false", "addAllActivitiesToSkippedIfSameStateActivitiesList": "true", "publishSwitchActivitiesAsIndividualAccessories": "false", "publishDevicesAsIndividualAccessories": "true", "publishSequencesAsIndividualAccessories": "true", "showCommandsAtStartup": "false", "publishHomeControlsAsIndividualAccessories": "true"

nicoduj commented 4 years ago

try removing completely the option . Clearly it sees it as true from your logs ! (or you might have multiple config files) .

or write it like this : "cleanCache": false !

You maybe used configUI X ... might be a bug there !

MikeDeltaHH commented 4 years ago

Removing the option helps... thanks!

Jan 25 11:08:21 homebridge homebridge[2247]: [2020-1-25 11:08:21] [HarmonyHub Wohnzimmer] Initializing HarmonyHubWebSocket platform... Jan 25 11:08:21 homebridge homebridge[2247]: [2020-1-25 11:08:21] [HarmonyHub Wohnzimmer] HarmonyPlatform Init Jan 25 11:08:21 homebridge homebridge[2247]: [2020-1-25 11:08:21] [HarmonyHub Wohnzimmer] undefined Jan 25 11:08:21 homebridge homebridge[2247]: [2020-1-25 11:08:21] Loading 0 accessories... Jan 25 11:08:21 homebridge homebridge[2247]: [2020-1-25 11:08:21] [HarmonyHub Wohnzimmer] DidFinishLaunching

nicoduj commented 4 years ago

All your false options are not good, it must be false and not "false", otherwise will be interpreted as true

MikeDeltaHH commented 4 years ago

All your false options are not good, it must be false and not "false", otherwise will be interpreted as true

Oh.... i haven´t noticed yet that i have such an error in my config, thanks a lot!

MikeDeltaHH commented 4 years ago

@TheBassfly Can you provide please an information when the plugin runs stable with hoobs in the next days? I will then switch back the plugin from my homebridge to hoobs, thanks! :)

TheBassfly commented 4 years ago

@TheBassfly Can you provide please an information when the plugin runs stable with hoobs in the next days? I will then switch back the plugin from my homebridge to hoobs, thanks! :)

Sure!

nicoduj commented 4 years ago

@TheBassfly Can you provide please an information when the plugin runs stable with hoobs in the next days? I will then switch back the plugin from my homebridge to hoobs, thanks! :)

Like I said on Hoobs topic I have published a new version that should tolerate such difference that can lead to misbehaviours :)

TheBassfly commented 4 years ago

Hello

I update the Plugin to 1.2.4 yesterday

And today the crash came up again:

[Homebridge] [1/26/2020, 17:15:26] [HarmonyHub] ERROR - refreshCurrentActivity TimeoutError: Can't open WebSocket within allowed timeout: 10000 ms. [Homebridge] [1/26/2020, 17:15:26] [HarmonyHub] ERROR - refreshCurrentActivity TimeoutError: Can't open WebSocket within allowed timeout: 10000 ms. [Homebridge] [1/26/2020, 17:15:26] [HarmonyHub] ERROR - refreshCurrentActivity TimeoutError: Can't open WebSocket within allowed timeout: 10000 ms. [Homebridge] [1/26/2020, 17:15:26] [HarmonyHub] ERROR - refreshCurrentActivity TimeoutError: Can't open WebSocket within allowed timeout: 10000 ms. [Homebridge] [1/26/2020, 17:15:26] [HarmonyHub] ERROR - refreshCurrentActivity TimeoutError: Can't open WebSocket within allowed timeout: 10000 ms. [Homebridge] [1/26/2020, 17:15:26] [HarmonyHub] ERROR - refreshCurrentActivity TimeoutError: Can't open WebSocket within allowed timeout: 10000 ms. [Homebridge] [1/26/2020, 17:15:26] [HarmonyHub] ERROR - refreshCurrentActivity TimeoutError: Can't open WebSocket within allowed timeout: 10000 ms. [Homebridge] <--- Last few GCs ---> [Homebridge] [464:0x21e0700] 35765654 ms: Mark-sweep 227.8 (234.8) -> 227.2 (235.3) MB, 2945.7 / 0.1 ms (average mu = 0.127, current mu = 0.070) allocation failure scavenge might not succeed [Homebridge] [464:0x21e0700] 35769596 ms: Mark-sweep 228.6 (235.3) -> 228.0 (235.8) MB, 3908.2 / 0.1 ms (average mu = 0.065, current mu = 0.008) allocation failure scavenge might not succeed [Homebridge] <--- JS stacktrace ---> [Homebridge] ==== JS stack trace ========================================= [Homebridge] Security context: 0x2368e225 [Homebridge] 0: builtin exit frame: stringify(this=0x5fa26611 ,0x4af80275 ,0x4af80275 ,0x70267b25 ,0x5fa26611 ) [Homebridge] 1: arguments adaptor frame: 1->3 [Homebridge] 2: _send [0x388bdb59] [internal/child_process.js:~687] [pc=0x31bef748](this=0x5fa01205 ,0x70267b25 ,0x4af8027... [Homebridge] FATAL ERROR: Ineffective mark-compacts near heap limit Allocation failed - JavaScript heap out of memory

nicoduj commented 4 years ago

Hi, thank you for the update.

So first of all, it is not the same error . Clearly here this happens because the hub is not reachable at the moment.

Secondly, I think that the number of logs is not because of a loop, but because of multiple simultaneous refresh calls to homekit status that needed a connection to the hub to get the status of activities. Maybe that in hoobs memory available for this number of simultaneous async request is not enough ?

So, at the time of the crash, did you have any screen or automations that could have asked for multiple accessories refresh ?

I am trying to improve those kind of situation with some queue mechanism but it is not really easy / I don't have a robust solution for now due to the plugin design and my understanding of homekit events.

nicoduj commented 4 years ago

By the way, if you could launch homebridge with -D option, I might have more info logs around the crash to see what happens. don't know how to do it with hoobs however.

TheBassfly commented 4 years ago

Hi, thank you for the update.

So first of all, it is not the same error . Clearly here this happens because the hub is not reachable at the moment.

Secondly, I think that the number of logs is not because of a loop, but because of multiple simultaneous refresh calls to homekit status that needed a connection to the hub to get the status of activities. Maybe that in hoobs memory available for this number of simultaneous async request is not enough ?

So, at the time of the crash, did you have any screen or automations that could have asked for multiple accessories refresh ?

I am trying to improve those kind of situation with some queue mechanism but it is not really easy / I don't have a robust solution for now due to the plugin design and my understanding of homekit events.

I can't say it exactly , because it is happening at night, when we ware asleep, and when I look in the log at at the morning, I can't see that much into the past, where and when it happened.

I'm afraid, that Hoops and the standard user is limited in the level of commands. I don't think that I can't start it with debug.

nicoduj commented 4 years ago

Hi,

I would really like to narrow this issue, and see if it is an update I make that in certain circumstances provoque the issue or if it is somewhere else.

Could you try to downgrade the harmony plugin ? I think you can do it in hoobs following this steps (feel free to ask hoobs maintainers since I don't know this environment) :

https://github.com/hoobs-org/HOOBS/wiki/4.0-Plugins#installing-plugins-manually the command should be something like this (I think you said it was ok in 1.2.1) :

npm install homebridge-harmony@1.2.1
mkellsy commented 4 years ago

Yes that's the way.

  1. Make sure the plugin is installed with the UI before doing this.
  2. cd ~/.hoobs
  3. npm install homebridge-harmony@1.2.1
DJay-X commented 4 years ago

I also get this error recently and homebridge crashed and reboot.

HarmonyHub] ERROR - refreshCurrentActivity TimeoutError: Can't open WebSocket within allowed timeout: 10000 ms.

I run the plugin for a long time now. Not sure why this happens now. PI 3 B+ Raspbian 9 (stretch),homebridge@0.4.50 | node@12.14.1 | npm 6.13.6 | n@6.1.3

TheBassfly commented 4 years ago

Hi,

I would really like to narrow this issue, and see if it is an update I make that in certain circumstances provoque the issue or if it is somewhere else.

Could you try to downgrade the harmony plugin ? I think you can do it in hoobs following this steps (feel free to ask hoobs maintainers since I don't know this environment) :

https://github.com/hoobs-org/HOOBS/wiki/4.0-Plugins#installing-plugins-manually the command should be something like this (I think you said it was ok in 1.2.1) :

npm install homebridge-harmony@1.2.1

Small Update: Haven't had a crash in the last days. I still observe it and will give you information, when it's happening again. But to be sure I'll do the downgrade for now.

nicoduj commented 4 years ago

I also get this error recently and homebridge crashed and reboot.

HarmonyHub] ERROR - refreshCurrentActivity TimeoutError: Can't open WebSocket within allowed timeout: 10000 ms.

I run the plugin for a long time now. Not sure why this happens now. PI 3 B+ Raspbian 9 (stretch),homebridge@0.4.50 | node@12.14.1 | npm 6.13.6 | n@6.1.3

Hi, Do you have full logs ? Was there multiple ones before the crash ? You are not on hoobs right ?