WoL constantly checking status, insanity in logs

[bbaraniec]

After upgrading to latest version I'm getting spammed in logs, by spammed I mean wall of text like this:

[1/14/2020, 00:32:42] [xxx] Attempting to ping "xxx" (ip..7) [1/14/2020, 00:32:42] [yyy] Result of pinging "yyy" (ip..8): offline [1/14/2020, 00:32:43] [bbb] Result of pinging "bbb" (ip..9): offline [1/14/2020, 00:32:43] [zzz] Attempting to ping "zzz" (ip..1) [1/14/2020, 00:32:43] [zzz] Result of pinging "zzz" (ip..1): online [1/14/2020, 00:32:43] [aaa] Attempting to ping "aaa" (ip..3) [1/14/2020, 00:32:43] [yyy] Attempting to ping "yyy" (ip..8) [1/14/2020, 00:32:43] [xxx] Result of pinging "xxx" (ip..7): offline [1/14/2020, 00:32:44] [bbb] Attempting to ping "bbb" (ip..9) [1/14/2020, 00:32:44] [aaa] Result of pinging "aaa" (ip..3): offline [1/14/2020, 00:32:44] [xxx] Attempting to ping "xxx" (ip..7) [1/14/2020, 00:32:44] [yyy] Result of pinging "yyy" (ip..8): offline [1/14/2020, 00:32:45] [zzz] Attempting to ping "zzz" (ip..1) [1/14/2020, 00:32:45] [zzz] Result of pinging "zzz" (ip..1): online [1/14/2020, 00:32:45] [aaa] Attempting to ping "aaa" (ip..3))

It doesn't stop.

[AlexGustafsson]

This is not default behaviour but intended behaviour. Something is trigging the debug logs to activate.

This can happen if your environment contains the environment variable DEBUG=*. You can see if it does by running env. Also check any homebridge configuration to see if a debug mode is triggered.

It can also happen if a log mode is activated in the homebridge-wol configuration. Read the configuration documentation in the README file and ensure that you accessory configuration does not activate any of the log modes.

I can not recommend downgrading the plugin as there are known issues. The newest version is tested and has no known issues.

[bbaraniec]

I don't see any debug mode enabled. What wonders me that you have added pinginterval default is 2. If I set in config something like 45 for one machine, that one will not show every 2 seconds. Anyway after restart I'm really dead in the water:

[1/14/2020, 17:28:00] Plugin /usr/lib/node_modules does not have a package name that begins with 'homebridge-'. [1/14/2020, 17:28:00] No plugins found. See the README for information on installing plugins. [1/14/2020, 17:28:00] Error: The requested platform 'config' was not registered by any plugin. at API.platform (/usr/lib/node_modules/homebridge/lib/api.js:134:13) at Server._loadPlatforms (/usr/lib/node_modules/homebridge/lib/server.js:327:45) at Server.run (/usr/lib/node_modules/homebridge/lib/server.js:90:36) at module.exports (/usr/lib/node_modules/homebridge/lib/cli.js:59:10) at Object. (/usr/lib/node_modules/homebridge/bin/homebridge:17:22) at Module._compile (internal/modules/cjs/loader.js:955:30) at Object.Module._extensions..js (internal/modules/cjs/loader.js:991:10) at Module.load (internal/modules/cjs/loader.js:811:32) at Function.Module._load (internal/modules/cjs/loader.js:723:14) at Function.Module.runMain (internal/modules/cjs/loader.js:1043:10)

[AlexGustafsson]

Could you post your entire configuration file? From the error log above it seems as if it is badly written.

[bbaraniec]

{
    "bridge": {
        "name": "Homebridge",
        "username": "mac",
        "port": 51826,
        "pin": "123-61-123"
    },
    "description": "This is an example configuration file with one fake accessory and one fake platform. You can use this as a template for creating your own configuration file containing devices you actually own.",
    "accessories": [
        {
            "accessory": "Xbox",
            "name": "XboxOne",
            "ipAddress": "192.168.0.11",
            "liveId": "redacted"
        },
        {
            "accessory": "NetworkDevice",
            "name": "BartekPC",
            "mac": "redacted",
            "ip": "192.168.0.1",
            "shutdownCommand": "net rpc shutdown --ipaddress 192.168.0.1 --user homebridge%password"
        },
        {
            "accessory": "NetworkDevice",
            "name": "MichalPC",
            "mac": "redacted",
            "ip": "192.168.0.3",
            "shutdownCommand": "net rpc shutdown --ipaddress 192.168.0.3 --user homebridge%password"
        },
        {
            "accessory": "NetworkDevice",
            "name": "Dodo",
            "mac": "redacted",
            "ip": "192.168.0.7",
            "shutdownCommand": "net rpc shutdown --ipaddress 192.168.0.7 --user homebridge%password"
        },
        {
            "accessory": "NetworkDevice",
            "name": "Tiny",
            "mac": "redacted",
            "ip": "192.168.0.8",
            "shutdownCommand": "net rpc shutdown --ipaddress 192.168.0.8 --user homebridge%password"
        },
        {
            "accessory": "NetworkDevice",
            "name": "ESXi",
            "mac": "redacted",
            "ip": "192.168.0.9",
            "shutdownCommand": "ssh root@192.168.0.9 halt"
        }
    ],
    "platforms": [
        {
            "name": "config.json",
            "port": 8080,
            "auth": "form",
            "theme": "dark-mode",
            "restart": "/etc/init.d/homebridge restart",
            "tempUnits": "c",
            "sudo": true,
            "debug": false,
            "log": {
                "method": "file",
                "path": "/var/log/homebridge.log"
            },
            "platform": "config"
        },
        {
            "platform": "cmdSwitch2",
            "name": "CMD Switch",
            "switches": [
                {
                    "name": "Backup 7 Days To Die",
                    "on_cmd": "/home/pi/Backup_7_Days_To_Die.sh",
                    "off_cmd": ".",
                    "state_cmd": "/home/pi/alwaysoff.sh",
                    "polling": true,
                    "interval": 3
                },
                {
                    "name": "Backup Conan Exiles",
                    "on_cmd": "/home/pi/Backup_Conan_Exiles.sh",
                    "off_cmd": ".",
                    "state_cmd": "/home/pi/alwaysoff.sh",
                    "polling": true,
                    "interval": 3
                },
                {
                    "name": "Backup Space Engineers",
                    "on_cmd": "/home/pi/Backup_Space_Engineers.sh",
                    "off_cmd": ".",
                    "state_cmd": "/home/pi/alwaysoff.sh",
                    "polling": true,
                    "interval": 3
                },
                {
                    "name": "Backup Medieval Engineers",
                    "on_cmd": "/home/pi/Backup_Medieval_Engineers.sh",
                    "off_cmd": ".",
                    "state_cmd": "/home/pi/alwaysoff.sh",
                    "polling": true,
                    "interval": 3
                },
                {
                    "name": "Backup The Forest",
                    "on_cmd": "/home/pi/Backup_The_Forest.sh",
                    "off_cmd": ".",
                    "state_cmd": "/home/pi/alwaysoff.sh",
                    "polling": true,
                    "interval": 3
                }
            ]
        }
    ]
}

That config was working yesterday. I've only stopped homebdrige

[AlexGustafsson]

You've configured a platform called config, however, no plugin is installed to handle that platform - therefore Homebridge exits with an error.

Homebridge also warns that you've got no plugins installed.

Basically, re-read your configuration, ensure that you've got all the plugins installed and that everything is up-to-date.

[bbaraniec]

Well, I have done no changes, the plugis are there. No touching config and it started yesterday.

/usr/var/node_modules/ I have all plugins that I'm trying to load.

[AlexGustafsson]

The log you posted says otherwise. Could you try to restart Homebridge in debug mode and post the full log from the start of its execution?

[bbaraniec]

pi@Homebridge:~ $ DEBUG=* homebridge -D [1/14/2020, 18:12:56] Loaded config.json with 6 accessories and 2 platforms. [1/14/2020, 18:12:56] --- [1/14/2020, 18:12:56] Plugin /usr/lib/node_modules does not have a package name that begins with 'homebridge-'. [1/14/2020, 18:12:56] No plugins found. See the README for information on installing plugins. [1/14/2020, 18:12:56] Loading 2 platforms... [1/14/2020, 18:12:56] Error: The requested platform 'config' was not registered by any plugin. at API.platform (/usr/lib/node_modules/homebridge/lib/api.js:134:13) at Server._loadPlatforms (/usr/lib/node_modules/homebridge/lib/server.js:327:45) at Server.run (/usr/lib/node_modules/homebridge/lib/server.js:90:36) at module.exports (/usr/lib/node_modules/homebridge/lib/cli.js:59:10) at Object. (/usr/lib/node_modules/homebridge/bin/homebridge:17:22) at Module._compile (internal/modules/cjs/loader.js:955:30) at Object.Module._extensions..js (internal/modules/cjs/loader.js:991:10) at Module.load (internal/modules/cjs/loader.js:811:32) at Function.Module._load (internal/modules/cjs/loader.js:723:14) at Function.Module.runMain (internal/modules/cjs/loader.js:1043:10) [1/14/2020, 18:12:56] Got SIGTERM, shutting down Homebridge...

the config registered by https://github.com/oznu/homebridge-config-ui-x

[bbaraniec]

I've read that after updating node, you need to rebuild modules but apparently that's also no go: pi@Homebridge:/usr/lib/node_modules $ sudo su root@Homebridge:/usr/lib/node_modules# npm rebuild

@nestjs/core@6.10.14 postinstall /usr/lib/node_modules/homebridge-config-ui-x/node_modules/@nestjs/core opencollective || exit 0

                      Thanks for installing nest 🙏
             Please consider donating to our open collective
                    to help us maintain this package.

                       Number of contributors: 406
                          Number of backers: 280
                          Annual budget: $63,916
                         Current balance: $5,091

   👉  Become a partner: https://opencollective.com/nest/donate

node-pty-prebuilt-multiarch@0.9.0 install /usr/lib/node_modules/homebridge-config-ui-x/node_modules/node-pty-prebuilt-multiarch prebuild-install || node scripts/install.js

prebuild-install WARN install EACCES: permission denied, access '/root/.npm' gyp ERR! clean error gyp ERR! stack Error: EACCES: permission denied, rmdir 'build' gyp ERR! System Linux 4.19.66-v7+ gyp ERR! command "/usr/bin/node" "/usr/lib/node_modules/npm/node_modules/node-gyp/bin/node-gyp.js" "rebuild" gyp ERR! cwd /usr/lib/node_modules/homebridge-config-ui-x/node_modules/node-pty-prebuilt-multiarch gyp ERR! node -v v12.14.1 gyp ERR! node-gyp -v v5.0.5 gyp ERR! not ok npm ERR! code ELIFECYCLE npm ERR! errno 1 npm ERR! node-pty-prebuilt-multiarch@0.9.0 install: prebuild-install || node scripts/install.js npm ERR! Exit status 1 npm ERR! npm ERR! Failed at the node-pty-prebuilt-multiarch@0.9.0 install script. npm ERR! This is probably not a problem with npm. There is likely additional logging output above.

npm ERR! A complete log of this run can be found in: npm ERR! /root/.npm/_logs/2020-01-14T17_19_47_744Z-debug.log root@Homebridge:/usr/lib/node_modules#

[AlexGustafsson]

So for the first issue, you'll have to check in with https://github.com/oznu/homebridge-config-ui-x. I have never used that package so I cannot help you with it. The issue you're facing with Homebridge is currently not related to this plugin.

As for not being able to update, you're facing privilege issues which you'll have to debug. This could be a good place to start: https://docs.npmjs.com/resolving-eacces-permissions-errors-when-installing-packages-globally. You can also try this: https://npm.community/t/eacces-permission-denied-access-root-npm/5667.

Basically, from what I can see you only have issues related to other packages or Node / NPM itself and I can't be much of assistance there. If you do resolve these issues and are able to start Homebridge but still face issues related to this package, please get back and I'll try to help you.

[bbaraniec]

Yesterday after long fight I was able to repair and bring back homebridge back to life. Logs are still going crazy but adding "pingInterval": 45, slows down craziness. I've also reset and readd homebridge Siri executes commands but I'm getting: "Hmm, I didn't hear back from your devices".

[AlexGustafsson]

Great!

The logs still isn’t intended behaviour. We’re you able to find if there were any mention of DEBUG in your environment?

As for the second issue, it’s described here: #85. Basically it’s an unfixable issue where you need to decide between two semi-working solutions.

[bbaraniec]

I'm still looking for anything in Debug mode. Regarding issue 2. Could you please explain me why things changed? It was working before v4.

[AlexGustafsson]

@bbaraniec It was working, but only to a point. Basically the code was handing over the execution to Homekit as soon as possible because it knew no better. This could result in inaccurate values given back to Siri.

With the new version, all of the asynchronous code has been rewritten to greatly simplify the plugin in terms of readability and control flow complexity to update it for the coming years, this also resulted in a more "proper" solution for when execution was handed back to Homekit.

But as you can tell from #85, Siri does not like waiting for too long which made me implement both modes - the old and imperfect one which is fast enough for Siri and the new which properly waits for shutdown commands etc. to be accurate.

[AlexGustafsson]

If you don't find what's causing the debug mode to trigger, you could manually override the logging in order to prevent all logs.

These lines to these:

this.log = () => {};
this.debugLog = () => {};
this.pingLog = () => {};

Closing this for now as it cannot be replicated.