hoobs-org / HOOBS

Build your Smart Home with HOOBS. Connect over 2,000 Accessories to your favorite Ecosystem.
https://hoobs.org
GNU General Public License v3.0
552 stars 51 forks source link

TCP connection error resulting in Server Shutdown #1236

Closed efthymakis closed 3 years ago

efthymakis commented 3 years ago

Description A clear and concise description of what the bug is.

I cannot tell if this is a plug-in issue or core issue...

The hoobs service randomly stops. In general the service will run no more than 3 days before randomly stopping. I've seen it stop in as little as a few hours but never stays up more than 2-3 days.

The only constant is that the log suggests this isn't a failure but a deliberate shutdown of the after a TCP error is detected.

Here is an example:

4/22/2021, 8:20:39 AM Error: read ECONNRESET at TCP.onStreamRead (internal/stream_base_commons.js:201:27) 4/22/2021, 8:20:39 AM Got SIGTERM, shutting down Bridge... 4/22/2021, 8:20:39 AM [Living Room] INFO - shutdown 4/22/2021, 8:20:39 AM [Living Room] INFO - shutdown

Version Please include the version of HOOBS you are using.

Hoobs 3.3.5 Node 12.13.0

Did you upgrade Please let us know if you upgraded from a previous version.

Pervious version If you upgraded, please let us know your previous version.

N/A

Did you orginally upgrade to HOOBS 3 from HOOBS 2.1.1? Did you perform an upgrade from HOOBS 2.1.1? Some things are different.

What device are you using? Please let us know the device you are running HOOBS on.

If this is a custom install, what's your operating system? Please let us know what operating system and version you are using. Ex. Fedora 30 or macOS Catalina.

N/A

List your plugins Please include a list of the plugins you are using. We need to be able to find it on NPM. If the plugin is no published, please include a link to the repository.

Plugins: Platform Insteonlocal 0.4.17 Ring 9.17.0 Harmony 1.5.2 MyLink 1.3.0

Post your config This can be found in the interface, Configuration -> Advanced or you can get it via SSH cat ~/.hoobs/etc/config.json


{
    "server": {
        "port": 8080,
        "origin": "*",
        "autostart": 10,
        "home_setup_id": "X-HM://0023ISYWYXPKZ",
        "polling_seconds": 5
    },
    "client": {
        "default_route": "status",
        "inactive_logoff": 30,
        "theme": "hoobs-dark",
        "locale": "en",
        "temp_units": "fahrenheit",
        "country_code": "US",
        "postal_code": "POSTAL CODE"
    },
    "bridge": {
        "name": "HOOBS",
        "port": 51826,
        "pin": "031-45-154",
        "username": "USERNAME"
    },
    "description": "",
    "ports": {},
    "accessories": [],
    "platforms": [
        {
            "platform": "Somfy myLink",
            "plugin_map": {
                "plugin_name": "homebridge-mylink"
            },
            "targets": [
                {
                    "targetID": "ID",
                    "name": "Awning",
                    "orientation": {
                        "closed": "up",
                        "middle": "stop",
                        "opened": "down"
                    }
                }
            ],
            "ipAddress": "192.168.X.X",
            "systemID": "mySystem"
        },
        {
            "platform": "InsteonLocal",
            "user": "USER",
            "pass": "PASSWORD",
            "host": "192.168.X.X",
            "port": "25105",
            "model": "2245",
            "server_port": "3000",
            "devices": [
                {
                    "name": "Deck",
                    "deviceID": "ID",
                    "dimmable": "yes",
                    "deviceType": "dimmer"
                },
                {
                    "name": "Patio",
                    "deviceID": "ID",
                    "deviceType": "dimmer",
                    "dimmable": "yes"
                },
                {
                    "name": "Rear Landscape",
                    "deviceID": "ID",
                    "deviceType": "lightbulb",
                    "dimmable": "no"
                },
                {
                    "name": "Basement Back",
                    "deviceID": "ID",
                    "deviceType": "dimmer",
                    "dimmable": "yes"
                },
                {
                    "name": "Basement Front",
                    "deviceID": "ID",
                    "deviceType": "dimmer",
                    "dimmable": "yes"
                },
                {
                    "name": "Side Entrance",
                    "deviceID": "ID",
                    "deviceType": "dimmer",
                    "dimmable": "yes"
                },
                {
                    "name": "Bathroom Light",
                    "deviceID": "ID",
                    "deviceType": "dimmer",
                    "dimmable": "yes"
                },
                {
                    "name": "Fan",
                    "deviceID": "ID",
                    "deviceType": "fan",
                    "dimmable": "no"
                },
                {
                    "name": "Hallway",
                    "deviceID": "ID",
                    "deviceType": "dimmer",
                    "dimmable": "yes"
                },
                {
                    "name": "Foyer",
                    "deviceID": "ID",
                    "deviceType": "dimmer",
                    "dimmable": "yes"
                },
                {
                    "name": "Front Landscape",
                    "deviceID": "ID",
                    "deviceType": "switch",
                    "dimmable": "no"
                },
                {
                    "name": "Holiday",
                    "deviceID": "ID",
                    "deviceType": "switch",
                    "dimmable": "no"
                },
                {
                    "name": "Porch",
                    "deviceID": "ID",
                    "deviceType": "dimmer",
                    "dimmable": "yes"
                },
                {
                    "name": "Garage Light",
                    "deviceID": "ID",
                    "deviceType": "dimmer",
                    "dimmable": "yes"
                },
                {
                    "name": "Motion",
                    "deviceID": "ID",
                    "deviceType": "motionsensor",
                    "dimmable": "no"
                },
                {
                    "name": "Kitchen Light",
                    "deviceID": "ID",
                    "deviceType": "dimmer",
                    "dimmable": "yes"
                },
                {
                    "name": "Kitchen Table",
                    "deviceID": "ID",
                    "deviceType": "dimmer",
                    "dimmable": "yes"
                },
                {
                    "name": "Under Cabinet",
                    "deviceID": "ID",
                    "deviceType": "dimmer",
                    "dimmable": "yes"
                },
                {
                    "name": "Living Room Light",
                    "deviceID": "ID",
                    "deviceType": "dimmer",
                    "dimmable": "yes"
                },
                {
                    "name": "Christmas Tree",
                    "deviceID": "ID",
                    "deviceType": "outlet",
                    "dimmable": "no"
                },
                {
                    "name": "Dining Room Light",
                    "deviceID": "ID",
                    "deviceType": "dimmer",
                    "dimmable": "yes"
                },
                {
                    "name": "Entrance",
                    "deviceID": "ID",
                    "deviceType": "dimmer",
                    "dimmable": "yes"
                },
                {
                    "name": "Sitting Room Light",
                    "deviceID": "ID",
                    "dimmable": "yes",
                    "deviceType": "lightbulb"
                },
                {
                    "name": "Hall",
                    "deviceID": "ID",
                    "deviceType": "dimmer",
                    "dimmable": "yes"
                },
                {
                    "name": "Hallway Secondary",
                    "deviceID": "ID",
                    "deviceType": "dimmer",
                    "dimmable": "yes"
                },
                {
                    "name": "Entrance Secondary",
                    "deviceID": "ID",
                    "deviceType": "dimmer",
                    "dimmable": "yes"
                },
                {
                    "name": "Kitchen Secondary",
                    "deviceID": "ID",
                    "deviceType": "dimmer",
                    "dimmable": "yes"
                },
                {
                    "name": "Side Entrance Secondary",
                    "deviceID": "ID",
                    "deviceType": "dimmer",
                    "dimmable": "yes"
                },
                {
                    "name": "Hall Secondary",
                    "deviceID": "ID",
                    "deviceType": "dimmer",
                    "dimmable": "yes"
                }
            ],
            "plugin_map": {
                "plugin_name": "homebridge-platform-insteonlocal"
            }
        },
        {
            "platform": "HarmonyHubWebSocket",
            "plugin_map": {
                "plugin_name": "homebridge-harmony"
            },
            "name": "Living Room",
            "hubIP": "192.168.X.X",
            "hubName": "Living Room",
            "cleanCache": false,
            "playPauseBehavior": true,
            "switchAccessories": true,
            "publishGeneralMuteSwitch": true,
            "linkVolumeControlToTV": true,
            "addAllActivitiesToSkippedIfSameStateActivitiesList": false,
            "showCommandsAtStartup": false,
            "DELAY_BEFORE_RETRY_AFTER_NETWORK_LOSS": 60000,
            "HUB_CONNECT_TIMEOUT": 10000,
            "HUB_SEND_TIMEOUT": 30000,
            "activitiesToPublishAsInputForTVMode": [],
            "remoteOverrideCommandsList": [],
            "activitiesToPublishAsAccessoriesSwitch": [],
            "skippedIfSameStateActivities": [],
            "devicesToPublishAsAccessoriesSwitch": [],
            "sequencesToPublishAsAccessoriesSwitch": [],
            "homeControlsToPublishAsAccessoriesSwitch": [],
            "otherPlatforms": []
        },
        {
            "platform": "Ring",
            "plugin_map": {
                "plugin_name": "homebridge-ring"
            },
            "alarmOnEntryDelay": false,
            "hideCameraMotionSensor": false,
            "hideDoorbellSwitch": false,
            "hideCameraSirenSwitch": true,
            "hideAlarmSirenSwitch": true,
            "hideUnsupportedServices": true,
            "showPanicButtons": false,
            "avoidSnapshotBatteryDrain": false,
            "sendCameraMotionNotificationsToTv": false,
            "sendDoorbellMotionNotificationsToTv": false,
            "debug": false,
            "refreshToken": "TOKEN",
            "hideLightGroups": true,
            "hideInHomeDoorbellSwitch": true,
            "hideDeviceIds": [],
            "locationIds": [],
            "onlyDeviceTypes": []
        }
    ]
}

Post your log You can get the log from the interface. This is in the Log section.


4/22/2021, 8:20:39 AM Error: read ECONNRESET
    at TCP.onStreamRead (internal/stream_base_commons.js:201:27)
4/22/2021, 8:20:39 AM Got SIGTERM, shutting down Bridge...
4/22/2021, 8:20:39 AM [Living Room] INFO - shutdown
4/22/2021, 8:20:39 AM [Living Room] INFO - shutdown

Additional context Add any other context about the problem here.

On occasion I see warnings similar to this that suggests maybe the Insteon plugin is playing a role here:

4/22/2021, 10:03:56 AM (node:18197) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 connect listeners added to [Insteon]. Use emitter.setMaxListeners() to increase limit

mkellsy commented 3 years ago

ECONNRESET is a connection reset. A connection reset is send by the host.

The only way to troubleshoot these errors is to remove plugins one by one. I have a gut feeling that it is homebridge-harmony, it uses websockets that go down all the time.

MacFlagg commented 3 years ago

I experience this issue all the time.

Here is the data from my HOOBS:

Typical log:

4/10/2021, 7:59:06 AM [Harmony] (Harmony)WARNING - socket closed 4/10/2021, 8:16:12 AM [Harmony] (Harmony)WARNING - socket closed 4/10/2021, 8:45:03 AM [Harmony] (Harmony)WARNING - socket closed 4/10/2021, 9:01:16 AM [Harmony] (Harmony)WARNING - socket closed 4/10/2021, 9:58:53 AM [Harmony-TV A2D1@Active Identifier] The read handler for the characteristic 'Active Identifier' on the accessory 'Harmony-TV A2D1' was slow to respond! 4/10/2021, 9:58:59 AM [Harmony-TV A2D1@Active Identifier] The read handler for the characteristic 'Active Identifier' on the accessory 'Harmony-TV A2D1' didn't respond at all!. Please check that you properly call the callback! 4/10/2021, 9:59:31 AM [Harmony] (Harmony)ERROR (1)- refreshCurrentActivity Error: WebSocket closed with reason: undefined (undefined). - Stack : Error: WebSocket closed with reason: undefined (undefined). at WebSocketAsPromised._handleClose (/home/hoobs/.hoobs/node_modules/websocket-as-promised/src/index.js:353:19) at WebSocket.listener (/home/hoobs/.hoobs/node_modules/websocket-as-promised/src/index.js:311:64) at WebSocket.emit (events.js:315:20) at WebSocket.emitClose (/home/hoobs/.hoobs/node_modules/harmony-websocket/node_modules/ws/lib/websocket.js:198:10) at Socket.socketOnClose (/home/hoobs/.hoobs/node_modules/harmony-websocket/node_modules/ws/lib/websocket.js:886:15) at Socket.emit (events.js:315:20) at TCP. (net.js:673:12) 4/10/2021, 9:59:31 AM [Harmony] (Harmony)WARNING - socket closed 4/10/2021, 10:06:27 AM [Harmony] (Harmony)WARNING - socket closed 4/10/2021, 11:49:59 AM [Ring] Reconnecting location socket.io connection 4/10/2021, 11:50:00 AM [Ring] Creating location socket.io connection - Brunswick 4/10/2021, 11:50:01 AM [Ring] Ring connected to socket.io server 4/10/2021, 3:04:35 PM [Harmony] (Harmony)WARNING - socket closed 4/10/2021, 3:04:55 PM [Harmony] (Harmony)ERROR (1)- refreshCurrentActivity TimeoutError: Can't open WebSocket within allowed timeout: 10000 ms. - Stack : TimeoutError: Can't open WebSocket within allowed timeout: 10000 ms. at PromiseController._handleTimeout (/home/hoobs/.hoobs/node_modules/promise-controller/src/index.js:172:19) at Timeout. (/home/hoobs/.hoobs/node_modules/promise-controller/src/index.js:178:43) at listOnTimeout (internal/timers.js:554:17) at processTimers (internal/timers.js:497:7) 4/10/2021, 3:05:21 PM Error: connect EHOSTUNREACH 192.168.1.196:8088 at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) 4/10/2021, 3:05:21 PM Got SIGTERM, shutting down Bridge... 4/10/2021, 3:05:21 PM [Harmony] INFO - shutdown 4/10/2021, 3:05:21 PM [Harmony] INFO - shutdown

My configuration:

{ "platform": "HarmonyHubWebSocket", "plugin_map": { "plugin_name": "homebridge-harmony" }, "DELAY_BEFORE_RETRY_AFTER_NETWORK_LOSS": 60000, "HUB_CONNECT_TIMEOUT": 10000, "HUB_SEND_TIMEOUT": 30000, "name": "Harmony Hub", "hubIP": "192.168.1.196", "mainActivity": "Vizio" }

To configure the plug-in, I only fill in:

  1. Name of your hub
  2. IP Address of your hub (must be fixed)
  3. Main Activity

I leave all other fields to default.

HOOBS Core v3.3.5 Node v14.15.1

Plug-ins installed

Harmony v1.5.2 published 4/20/2021 OnStar v1.5.2 published 4/14/2021 Ring v9.17.0 published 4/17/2021

HOOBS Box

mkellsy commented 3 years ago

Thanks for the logs. Most complete to date.

There definitely is a conflict with some websocket libraries. HOOBS 3 uses a websocket to get live updates from Homebridge. And the UI and bridge run in the same process.

I can verify that this is a non issue with HOOBS 4 (currently in beta) due to an architectural change. HOOBS 4 runs bridges in separate processes. The "bridge" doesn't use a websocket, rather it sends updates to the "hub" via an IPC. The "hub" does use a websocket but we switched to Socket.IO which in our testing is more stable, plus the hub is a completely different process.

For now I did un-certify the Harmony plugin, however this doesn't actually change anything. You can still use the plugin in HOOBS 3.

You can sign up for the HOOBS 4 beta here https://hoobs.org/hoobs-4-beta-testing-program/

efthymakis commented 3 years ago

I've uninstalled the harmony plugin and reset hoobs to clear all accessory caches. Just finished adding all accessories back for the remaining accessories and everything is up and running.

If you leave the ticket open for a bit, I'll update it in a few days to confirm this was the culprit.

efthymakis commented 3 years ago

Although much more stable than before, as the service has been running for a few days without incident, a stop event was recorded earlier this morning.

4/29/2021, 5:25:59 AM Error: read ECONNRESET at TCP.onStreamRead (internal/stream_base_commons.js:201:27) 4/29/2021, 5:25:59 AM Got SIGTERM, shutting down Bridge...

With the Harmony plug-in installed, the error was much more frequent.

I'll review Hoobs 4 beta sometime next week to see if it's right for me to install and begin testing.

MacFlagg commented 3 years ago

How stable is HOOBS 4?

I don’t want to install it to kill one bug, only to get new and different bugs.

mkellsy commented 3 years ago

HOOBS 4 is in beta. So far it has been stable, but there could be issues.

Also there is no migration tool yet. And it doesn't support v3 backups. You will have to start fresh.

MacFlagg commented 3 years ago

Got this new error today. My HOOBS service was running, but Harmony was unavailable.

5/7/2021, 4:41:24 PM [Harmony Hub] (Harmony Hub)WARNING - refreshCurrentActivity : NO refresh done since too much socket errors - will retry later 5/7/2021, 4:41:24 PM [Harmony Hub] (Harmony Hub)WARNING - socket closed 5/7/2021, 4:41:34 PM [Harmony Hub] (Harmony Hub)WARNING - refreshCurrentActivity : NO refresh done since too much socket errors - will retry later 5/7/2021, 4:41:39 PM [Harmony Hub] (Harmony Hub)WARNING - refreshCurrentActivity : NO refresh done since too much socket errors - will retry later 5/7/2021, 4:41:39 PM [Harmony Hub] (Harmony Hub)WARNING - refreshCurrentActivity : NO refresh done since too much socket errors - will retry later 5/7/2021, 4:41:40 PM [Harmony Hub] (Harmony Hub)WARNING - refreshCurrentActivity : NO refresh done since too much socket errors - will retry later 5/7/2021, 4:41:40 PM [Harmony Hub] (Harmony Hub)WARNING - refreshCurrentActivity : NO refresh done since too much socket errors - will retry later 5/7/2021, 4:41:46 PM [Harmony Hub] (Harmony Hub)WARNING - refreshCurrentActivity : NO refresh done since too much socket errors - will retry later 5/7/2021, 4:41:46 PM [Harmony Hub] (Harmony Hub)WARNING - refreshCurrentActivity : NO refresh done since too much socket errors - will retry later 5/7/2021, 4:41:48 PM [Harmony Hub] (Harmony Hub)WARNING - refreshCurrentActivity : NO refresh done since too much socket errors - will retry later 5/7/2021, 4:41:48 PM [Harmony Hub] (Harmony Hub)WARNING - refreshCurrentActivity : NO refresh done since too much socket errors - will retry later 5/7/2021, 4:41:49 PM [Harmony Hub] (Harmony Hub)WARNING - refreshCurrentActivity : NO refresh done since too much socket errors - will retry later 5/7/2021, 4:41:49 PM [Harmony Hub] (Harmony Hub)WARNING - refreshCurrentActivity : NO refresh done since too much socket errors - will retry later 5/7/2021, 4:42:06 PM [Harmony Hub] (Harmony Hub)WARNING - refreshCurrentActivity : NO refresh done since too much socket errors - will retry later 5/7/2021, 4:42:06 PM [Harmony Hub] (Harmony Hub)WARNING - refreshCurrentActivity : NO refresh done since too much socket errors - will retry later 5/7/2021, 4:42:08 PM [Harmony Hub] (Harmony Hub)WARNING - refreshCurrentActivity : NO refresh done since too much socket errors - will retry later 5/7/2021, 4:42:08 PM [Harmony Hub] (Harmony Hub)WARNING - refreshCurrentActivity : NO refresh done since too much socket errors - will retry later 5/7/2021, 4:42:08 PM [Harmony Hub] (Harmony Hub)WARNING - refreshCurrentActivity : NO refresh done since too much socket errors - will retry later 5/7/2021, 4:42:08 PM [Harmony Hub] (Harmony Hub)WARNING - refreshCurrentActivity : NO refresh done since too much socket errors - will retry later

stale[bot] commented 3 years ago

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.