Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[BUG] WARNING - socket closed causing SIGTERM & SIGINT which is crashing HOOBS #362

Closed
MacFlagg opened this issue Apr 13, 2021 · 23 comments
Closed
Assignees
Labels
bug Something isn't working waiting for feedback Waiting for feedback from users

Comments

@MacFlagg
Copy link

Describe the bug

I keep getting the following error:

(Harmony)WARNING - socket closed

then

Got SIGTERM, shutting down Bridge...

Then my HOOBS shuts completely down.

To Reproduce

When I install the harmony plugin, I only fill in the following fields:

  1. Name of YourHub
  2. IP Address of Your Hub (must be fixed)
  3. Hub name in Your Harmony App
  4. Main Activity

I leave everything else to default.

Expected behavior
For the Harmony plugin to not crash HOOBS when it runs into an issue. Maybe just the Harmony plugin could crash, leaving HOOBS, and all my other plugins, running.

Screenshots
If applicable, add screenshots to help explain your problem.

IOS (please complete the following information):

  • Version [iOS 14.4.2]
  • Device: [3rd Gen 12” iPad Pro]

Logs

Log 1:

4/5/2021, 2:34:56 PM [Harmony] (Harmony)WARNING - socket closed
4/5/2021, 2:35:16 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/5/2021, 2:35:41 PM Error: connect EHOSTUNREACH 192.168.1.196:8088
at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16)
4/5/2021, 2:35:41 PM Got SIGTERM, shutting down Bridge...
4/5/2021, 2:35:41 PM [Harmony] INFO - shutdown
4/5/2021, 2:35:41 PM [Harmony] INFO - shutdown

Log 2:

4/5/2021, 8:39:00 PM [Harmony] (Harmony)INFO - Loading activities...
4/5/2021, 8:39:00 PM [Harmony] (Harmony)Error - Error retrieving info from hub : network timeout at: http://192.168.1.196:8088/-(2)
4/5/2021, 8:39:10 PM [Harmony] (Harmony)INFO - Loading activities...
4/5/2021, 8:39:10 PM [Harmony] (Harmony)Error - Error retrieving info from hub : network timeout at: http://192.168.1.196:8088/-(3)
4/5/2021, 8:39:14 PM Got SIGINT, shutting down Bridge...
4/5/2021, 8:39:14 PM [Harmony] INFO - shutdown
4/5/2021, 8:39:14 PM [Harmony] INFO - shutdown

Log 3:

[Harmony] (Harmony)WARNING - socket closed
4/6/2021, 7:52:26 PM [Harmony] (Harmony)WARNING - socket closed
4/6/2021, 7:56:45 PM [Harmony-TV A2D1@Active] The read handler for the characteristic 'Active' on the accessory 'Harmony-TV A2D1' was slow to respond!
4/6/2021, 7:56:51 PM [Harmony-TV A2D1@Active] The read handler for the characteristic 'Active' on the accessory 'Harmony-TV A2D1' didn't respond at all!. Please check that you properly call the callback!
4/6/2021, 7:58:11 PM [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/6/2021, 7:58:11 PM [Harmony] (Harmony)WARNING - socket closed

Log 4:

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

Config

{
"platform": "HarmonyHubWebSocket",
"plugin_map": {
"plugin_name": "homebridge-harmony"
},
"name": "Harmony",
"hubIP": "192.168.1.196",
"hubName": "Theater Room",
"mainActivity": "Vizio",
"activitiesToPublishAsInputForTVMode": [],
"remoteOverrideCommandsList": [],
"activitiesToPublishAsAccessoriesSwitch": [],
"skippedIfSameStateActivities": [],
"devicesToPublishAsAccessoriesSwitch": [],
"sequencesToPublishAsAccessoriesSwitch": [],
"homeControlsToPublishAsAccessoriesSwitch": [],
"otherPlatforms": []
}
]

Additional context

I have erased and factory reset my HOOBS several times trying to resolve the issue.
HOOBS v3.3.5
Node v14.15.1

@MacFlagg MacFlagg added the bug Something isn't working label Apr 13, 2021
@nicoduj
Copy link
Owner

nicoduj commented Apr 14, 2021

Hi,

Like I said to others, I can't reproduce this outside of hoobs in regular homebridge. The crash is network lib related which seems to be shared with hoobs .

Concerning the network problem itself, did you try with a fixed ip on your hub ?

@MacFlagg
Copy link
Author

Hello,

My hub has a fixed IP. It has been 192.168.1.196 for the last 5 years. Also, I do not know of a setting on the Harmony hub to change or alter the setting of the IP address.

About the other issue: I reported the (Harmony)WARNING - socket closed on the HOOBS page and no one responded after weeks of it being up. So, I posted here.

Do you know if any of the other Harmony plug-ins suffer the same bug with HOOBS? Just looking for a stable solution.

@nicoduj
Copy link
Owner

nicoduj commented Apr 14, 2021

Did you have the problem before or did it happen after a plugin and/or hoobs update ?
In regular homebridge you can now set independant bridge per plugin, which allow also to have a more stable solution in case of problems with one plugin.

Does your hub loose sometimes connectivity (red light ? )

Do you have xmpp enabled on the hub ?

@MacFlagg
Copy link
Author

MacFlagg commented Apr 14, 2021

When I first installed Hoobs and your plugin, maybe 4 years ago now, it was rock solid. But then about a year and a half ago, the issues started, where I’d find the Hoobs Hub had completely shut down. Sometimes it’s only 1-2 times a month and it was easy to ignore. But other times, HOOBS is shutting down daily. I was hoping that an update would take care of the issue. Recently, HOOBS was shutting down 3-4 a week and that’s when i decided to reach out to the community for help. FYI Your plugin is always the culprit with (Harmony)WARNING - socket closed which always leads to Got SIGTERM, shutting down Bridge...

At first, I contacted the HOOBS team directly and they said it was a plugin setting that was causing the problem and that i should check my configuration. I then posted in the HOOBS github community and did not get a response. Then I contacted you.

Occasionally I’ll find our Harmony Hub with a red light, but that’s maybe only 3-4 a year.

I do not know about Xmpp is or how to enable it. Is this something on the HOOBS hub or the Harmony Hub?

@nicoduj
Copy link
Owner

nicoduj commented Apr 14, 2021

Did you try reverting to a "stable" version of the plugin as far as you know to see if it is plugin or hoobs related maybe ?

@MacFlagg
Copy link
Author

MacFlagg commented Apr 14, 2021

How would I go about finding and installing a previous version of your plug-in?

But that question is likely moot, since I have no idea which previous version was stable.

I know I started finding my HOOBS shut down by SIGTERM roughly 1.5-2 years ago. Wait, now that I think about it, it might be closer to 2-2.5 years ago, because 2020 is like a lost year for me. I’m just not sure about time anymore. It’s been a minute.

But, like I said it cycles from 1-2 times a month, which is easy to ignore, to once a day which is a real issue. Right now, it’s happening maybe 1-2 times a week.

@ecoen66
Copy link

ecoen66 commented Apr 19, 2021

Running into the same issue on Homebridge 1.3.4, with plugin v. 1.5.1. This is crashing Homebridge with a SIGTERM:

[4/19/2021, 9:55:28 AM] [Living Room Harmony Hub] (Living Room Harmony Hub)WARNING - socket closed
[4/19/2021, 9:55:38 AM] [Living Room Harmony Hub] INFO - starting hub discovery
[4/19/2021, 9:55:39 AM] Error [ERR_SOCKET_DGRAM_NOT_RUNNING]: Not running
at healthCheck (dgram.js:897:11)
at Socket.send (dgram.js:622:3)
at Ping.emit (/homebridge/node_modules/homebridge-harmony/node_modules/harmonyhubjs-discover/lib/ping.js:25:15)
at listOnTimeout (internal/timers.js:554:17)
at processTimers (internal/timers.js:497:7)
[4/19/2021, 9:55:39 AM] Got SIGTERM, shutting down Homebridge...
[4/19/2021, 9:55:39 AM] [Living Room Harmony Hub] INFO - shutdown
[4/19/2021, 9:55:39 AM] Got SIGTERM, shutting down child bridge process...
[4/19/2021, 9:55:40 AM] Error [ERR_SOCKET_DGRAM_NOT_RUNNING]: Not running
at healthCheck (dgram.js:897:11)
at Socket.send (dgram.js:622:3)
at Ping.emit (/homebridge/node_modules/homebridge-harmony/node_modules/harmonyhubjs-discover/lib/ping.js:25:15)
at listOnTimeout (internal/timers.js:554:17)
at processTimers (internal/timers.js:497:7)
[4/19/2021, 9:55:41 AM] Error [ERR_SOCKET_DGRAM_NOT_RUNNING]: Not running
at healthCheck (dgram.js:897:11)
at Socket.send (dgram.js:622:3)
at Ping.emit (/homebridge/node_modules/homebridge-harmony/node_modules/harmonyhubjs-discover/lib/ping.js:25:15)
at listOnTimeout (internal/timers.js:554:17)
at processTimers (internal/timers.js:497:7)

@nicoduj
Copy link
Owner

nicoduj commented Apr 19, 2021

Hi, not the same issue, your error is happening in hub discovery (which is not my lib). Can you try with a fixed ip ?

@MacFlagg
Copy link
Author

As far as I know, my Harmony hub has had the same IP for the last 5 years.

@nicoduj
Copy link
Owner

nicoduj commented Apr 20, 2021

@MacFlagg sorry was answering to @ecoen66 . I will try to bump some dep and publish a new version, see if it helps but so far this problem is more network related than plugin related i my opinion (or underlying network lib, where I don't have a lot of control)

@nicoduj nicoduj added the waiting for feedback Waiting for feedback from users label Apr 20, 2021
@ecoen66
Copy link

ecoen66 commented Apr 20, 2021

@nicoduj Thank you. The change to a static DHCP address fixed this for my Homebridge issue.

@MacFlagg
Copy link
Author

Updated to the latest version of the Harmony plug-in and this happened in less than 24 hours:

4/24/2021, 7:15:01 AM [Harmony] DidFinishLaunching
4/24/2021, 7:15:01 AM [Harmony] (Harmony)INFO - Loading activities...
4/24/2021, 7:15:01 AM Preparing Advertiser for 'HOOBS D0C1' using bonjour-hap backend!
4/24/2021, 7:15:03 AM Error: listen EADDRINUSE: address already in use :::51826
at Server.setupListenHandle [as _listen2] (net.js:1318:16)
at listenInCluster (net.js:1366:12)
at Server.listen (net.js:1452:7)
at EventedHTTPServer.listen (/usr/local/lib/node_modules/@hoobs/hoobs/node_modules/hap-nodejs/src/lib/util/eventedhttp.ts:155:20)
at HAPServer.listen (/usr/local/lib/node_modules/@hoobs/hoobs/node_modules/hap-nodejs/src/lib/HAPServer.ts:316:21)
at Bridge.Accessory.publish (/usr/local/lib/node_modules/@hoobs/hoobs/node_modules/hap-nodejs/src/lib/Accessory.ts:1231:18)
at Server.publishBridge (/usr/local/lib/node_modules/@hoobs/hoobs/bridge/server.js:189:21)
at /usr/local/lib/node_modules/@hoobs/hoobs/bridge/server.js:158:53
at processTicksAndRejections (internal/process/task_queues.js:93:5)
at Server.start (/usr/local/lib/node_modules/@hoobs/hoobs/bridge/server.js:158:9)
4/24/2021, 7:15:03 AM Got SIGTERM, shutting down Bridge...
4/24/2021, 7:15:03 AM [Harmony] INFO - shutdown
4/24/2021, 7:15:03 AM [Harmony] INFO - shutdown

@MacFlagg
Copy link
Author

Ok, I’ve had to delete the Harmony plug-in to keep my HOOBS running.

The Harmony plug-in is immediately shutting down the hub.

@MacFlagg
Copy link
Author

After I deleted the Harmony plug-in, I get this in my logs.

4/24/2021, 7:26:49 AM [HarmonyHubWebSocket] INFO - stopping hub discovery, hubs found : 192.168.1.196|Theater Room|8588790
4/24/2021, 7:26:49 AM [HarmonyHubWebSocket] (undefined)INFO - received discovered hubs 192.168.1.196|Theater Room|8588790
4/24/2021, 7:26:52 AM [HarmonyHubWebSocket] (undefined)INFO - Adding Accessory : undefined-TV
4/24/2021, 7:26:53 AM [undefined-TV@@model] characteristic value expected string and received undefined
4/24/2021, 7:26:53 AM [HarmonyHubWebSocket] (undefined)INFO - configuring Main TV Service
4/24/2021, 7:26:53 AM [HarmonyHubWebSocket] (undefined)INFO - Creating TV Service
4/24/2021, 7:26:53 AM [undefined-TV@@configured Name] characteristic value expected string and received undefined
4/24/2021, 7:26:53 AM [undefined-TV@@name] characteristic value expected string and received undefined
4/24/2021, 7:26:53 AM [HarmonyHubWebSocket] (undefined)INFO - Creating Input Service - Theater AC
4/24/2021, 7:26:53 AM [HarmonyHubWebSocket] (undefined)INFO - Creating Input Service - 3D Movie
4/24/2021, 7:26:53 AM [HarmonyHubWebSocket] (undefined)INFO - Creating Input Service - Fan Only
4/24/2021, 7:26:53 AM [HarmonyHubWebSocket] (undefined)INFO - Creating Input Service - Vizio
4/24/2021, 7:26:53 AM [HarmonyHubWebSocket] (undefined)WARNING - No main Activity that match config file found, default to first one
4/24/2021, 7:26:53 AM [HarmonyHubWebSocket] (undefined)INFO - Configuring Main Activity Theater AC
4/24/2021, 7:26:53 AM [HarmonyHubWebSocket] (undefined)INFO - Creating TV Speaker Service
4/24/2021, 7:26:53 AM [undefined-TV@@name] characteristic value expected string and received undefined
4/24/2021, 7:26:53 AM [HarmonyHubWebSocket] (undefined)INFO - setupFoundAccessories - TV accessory added as external accessory
4/24/2021, 7:26:53 AM Preparing Advertiser for 'undefined-TV A53A' using bonjour-hap backend!
4/24/2021, 7:26:53 AM Starting to advertise 'undefined-TV A53A' using bonjour-hap backend!
4/24/2021, 7:26:53 AM undefined-TV A53A is running on port 41169.
4/24/2021, 7:26:53 AM Please add [undefined-TV A53A] manually in Home app. Setup Code: 031-45-154

@nicoduj
Copy link
Owner

nicoduj commented Apr 24, 2021

@MacFlagg
Hi, I am not really supporting Hoobs and prefer regular homebridge. From your (last) logs it seems it is not correctly uninstalled.
concerning the initial error, might be because your hoobs was not running correct hap version or there is a problem with cached accessories / port conflict (harmony plugin expose an external accessory).

@MacFlagg
Copy link
Author

I shut down my HOOBS hub. Unplugged it. Waited 30 seconds. Plugged it back in. Re-downloaded the Harmony plug-in. As soon as I configured it, it immediately shut my HOOBS hub down. If I try and start service, the Harmony Plug-in immediately shuts HOOBS down again.

The latest update has rendered the Harmony plug-in totally unusable for me.

@nicoduj
Copy link
Owner

nicoduj commented Apr 24, 2021

You can try 1.5.1 so to see, underlying lib for hub discovery has changed in 1.5.2. Or you can 1/ share your config (like it is asked in bug report) 2/ try with a fixed IP if you don't have one.

@MacFlagg
Copy link
Author

I have no idea how to download an older version of the Harmony plugin. There seems to be no option for that in HOOBS.

I have had a static IP for the last 5 years. Since its been fixed for so long, I know it off the top of my head - 192.168.1.196.

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",
"hubName": "Theater Room",
"mainActivity": "Vizio"
}
]
}

@MacFlagg
Copy link
Author

If you’re not really supporting HOOBS, why is your plug-in HOOBS Certified?

@nicoduj
Copy link
Owner

nicoduj commented Apr 25, 2021

@MacFlagg they did the certification; not me, and I don't have any Hoobs instance (and don't intend to). If you want some help on this, like it is said on the readme, please ask Hoobs support.

By the way, you should not specify hubName if you have an ip set.

Since the error seems to be linked to some port conflict (I think the tv accessory is published to a port by homebridge used by hoobs), you can try, like explained in the readme, to define another port in homebridge config (If hoobs allow that) :

    "ports": {
        "start": 52100,
        "end": 52150,
        "comment": "This section is used to control the range of ports that separate accessory (like camera or television) should be bind to."
      },

Or maybe you have some "dead process/ instance that use this port ...

Can't help much more.

@MacFlagg
Copy link
Author

Thanks for your help.

I actually contacted the HOOBS team before I contacted you and they said it was your plug-in and to contact you. I re-reached out to them yesterday, after you said you don’t support HOOBS. I’ve not heard back.

One last question. Which hub name do I leave blank? I’ve always been confused as to why there’s

  1. Name of YourHub

And

  1. Hub name in Your Harmony App

Which one do I leave blank, 1 or 2 or is it both?

Your plug-in doesn’t seem to have a place to set ports and have no idea how to change it on HOOBS. I don’t read/write code, which is why I bought HOOBS and don’t use regular Homebridge, so I’ve no idea how to use:

"ports": {
    "start": 52100,
    "end": 52150,
  },

or where it where even be applied in HOOBS.

@nicoduj
Copy link
Owner

nicoduj commented Apr 25, 2021

HubName should be blank . Concerning the config, it is in the json config of homebridge itself, but don't know where / if it will work with hoobs.
The port is not handle by the plugin but by homebridge itself when adding an external accessory .

Regular homebridge does not need any programming skill with latest version / excellent @oznu configUI plugin :)

@nicoduj nicoduj closed this as completed Jul 7, 2021
@nicoduj
Copy link
Owner

nicoduj commented Jul 7, 2021

Not testing on hoobs, but saw that new versions are released that are not anymore based on some cusotm websocket imp, so maybe it will be better.

@brummbaer brummbaer mentioned this issue Nov 26, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working waiting for feedback Waiting for feedback from users
Projects
None yet
Development

No branches or pull requests

3 participants