jsiegenthaler / homebridge-eosstb

A homebridge plugin for the EOS set-top box as used by Sunrise, Telenet, Ziggo, Virgin Media and maybe more in various countries on the Horizon Go (HGO) platform
https://github.com/jsiegenthaler/homebridge-eosstb
32 stars 4 forks source link

Error Messages #42

Closed mhary269 closed 3 years ago

mhary269 commented 3 years ago

Describe The Bug: After the update to version 1.1.9, error messages appeared in the log again

To Reproduce:

Expected behavior:

Logs: 26.4.2021, 18:15:15 (node:628) UnhandledPromiseRejectionWarning: TypeError: (this.currentChannelId || {}).includes is not a function 26.4.2021, 18:15:15 at stbDevice.updateDeviceState (/home/hoobs/.hoobs/node_modules/homebridge-eosstb/index.js:2494:38) 26.4.2021, 18:15:15 at stbPlatform.mqttDeviceStateHandler (/home/hoobs/.hoobs/node_modules/homebridge-eosstb/index.js:1495:34) 26.4.2021, 18:15:15 at MqttClient. (/home/hoobs/.hoobs/node_modules/homebridge-eosstb/index.js:1440:12) 26.4.2021, 18:15:15 at MqttClient.emit (events.js:315:20) 26.4.2021, 18:15:15 at MqttClient._handlePublish (/home/hoobs/.hoobs/node_modules/homebridge-eosstb/node_modules/mqtt/lib/client.js:1277:12) 26.4.2021, 18:15:15 at MqttClient._handlePacket (/home/hoobs/.hoobs/node_modules/homebridge-eosstb/node_modules/mqtt/lib/client.js:410:12) 26.4.2021, 18:15:15 at work (/home/hoobs/.hoobs/node_modules/homebridge-eosstb/node_modules/mqtt/lib/client.js:321:12) 26.4.2021, 18:15:15 at Writable.writable._write (/home/hoobs/.hoobs/node_modules/homebridge-eosstb/node_modules/mqtt/lib/client.js:335:5) 26.4.2021, 18:15:15 at doWrite (/home/hoobs/.hoobs/node_modules/homebridge-eosstb/node_modules/readable-stream/lib/_stream_writable.js:409:139) 26.4.2021, 18:15:15 at writeOrBuffer (/home/hoobs/.hoobs/node_modules/homebridge-eosstb/node_modules/readable-stream/lib/_stream_writable.js:398:5) 26.4.2021, 18:15:15 at Writable.write (/home/hoobs/.hoobs/node_modules/homebridge-eosstb/node_modules/readable-stream/lib/_stream_writable.js:307:11) 26.4.2021, 18:15:15 at Duplex.ondata (internal/streams/readable.js:719:22) 26.4.2021, 18:15:15 at Duplex.emit (events.js:315:20) 26.4.2021, 18:15:15 at addChunk (internal/streams/readable.js:309:12) 26.4.2021, 18:15:15 at readableAddChunk (internal/streams/readable.js:284:9) 26.4.2021, 18:15:15 at Duplex.Readable.push (internal/streams/readable.js:223:10) 26.4.2021, 18:15:15 (node:628) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag --unhandled-rejections=strict (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 409) 26.4.2021, 18:15:15 (node:628) UnhandledPromiseRejectionWarning: TypeError: (this.currentChannelId || {}).includes is not a function 26.4.2021, 18:15:15 at stbDevice.updateDeviceState (/home/hoobs/.hoobs/node_modules/homebridge-eosstb/index.js:2494:38) 26.4.2021, 18:15:15 at stbPlatform.mqttDeviceStateHandler (/home/hoobs/.hoobs/node_modules/homebridge-eosstb/index.js:1495:34) 26.4.2021, 18:15:15 at MqttClient. (/home/hoobs/.hoobs/node_modules/homebridge-eosstb/index.js:1440:12) 26.4.2021, 18:15:15 at MqttClient.emit (events.js:315:20) 26.4.2021, 18:15:15 at MqttClient._handlePublish (/home/hoobs/.hoobs/node_modules/homebridge-eosstb/node_modules/mqtt/lib/client.js:1277:12) 26.4.2021, 18:15:15 at MqttClient._handlePacket (/home/hoobs/.hoobs/node_modules/homebridge-eosstb/node_modules/mqtt/lib/client.js:410:12) 26.4.2021, 18:15:15 at work (/home/hoobs/.hoobs/node_modules/homebridge-eosstb/node_modules/mqtt/lib/client.js:321:12) 26.4.2021, 18:15:15 at Writable.writable._write (/home/hoobs/.hoobs/node_modules/homebridge-eosstb/node_modules/mqtt/lib/client.js:335:5) 26.4.2021, 18:15:15 at doWrite (/home/hoobs/.hoobs/node_modules/homebridge-eosstb/node_modules/readable-stream/lib/_stream_writable.js:409:139) 26.4.2021, 18:15:15 at writeOrBuffer (/home/hoobs/.hoobs/node_modules/homebridge-eosstb/node_modules/readable-stream/lib/_stream_writable.js:398:5) 26.4.2021, 18:15:15 at Writable.write (/home/hoobs/.hoobs/node_modules/homebridge-eosstb/node_modules/readable-stream/lib/_stream_writable.js:307:11) 26.4.2021, 18:15:15 at Duplex.ondata (internal/streams/readable.js:719:22) 26.4.2021, 18:15:15 at Duplex.emit (events.js:315:20) 26.4.2021, 18:15:15 at addChunk (internal/streams/readable.js:309:12) 26.4.2021, 18:15:15 at readableAddChunk (internal/streams/readable.js:284:9) 26.4.2021, 18:15:15 at Duplex.Readable.push (internal/streams/readable.js:223:10) 26.4.2021, 18:15:15 (node:628) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag --unhandled-rejections=strict (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 410)```


**Plugin Config:**

```json
Show your Homebridge config.json here, remove any sensitive information.

Screenshots:

Environment:

jsiegenthaler commented 3 years ago

That is really weird. Can you share your config so that i can try and reproduce it please? Ensure your username and password as edited out.

mhary269 commented 3 years ago

Here is the config: Important: Despite the error messages, the system runs stably... { "platform": "eosstb", "name": "UPC TV Box", "country": "ch", "username": „xxx@xx“, "password": „xxxxx“, "triplePressTime": 800, "debugLevel": 0, "devices": [ { "deviceId": „xxxx-EOSSTB-xxxxx“, "profile": "M", "accessoryCategory": "settopbox", "playPauseButton": "MediaPlayPause", "backButton": "Escape", "infoButton": "MediaTopMenu", "manufacturer": "ARRIS", "modelName": "DCX960", "serialNumber": „xxxxxxxx“, "firmwareRevision": "4.31", "showChannelNumbers": false, "maxChannels": 50 } ], "plugin_map": { "plugin_name": "homebridge-eosstb" }, "channels": [] }

jsiegenthaler commented 3 years ago

Thanks @mhary269 There's nothing special in your config, it's the same as mine.

I wonder if you are receiving a mqtt message that I am not receiving? I now need to see your mqtt traffic. Can you please set debugLevel to 2 (Enhanced) and then send me / post here the log when the error occurs. I need to see the mqtt message associated with the error message, it will be in the log shortly before the error. But please ensure you show a few mqtt messages.

Make sure you remove any private information that you don't want the internet to see!

meesjan commented 3 years ago

Here the same messages in the log. (country=nl) I am not using hoobs. I will set the debug level to 2, but I have to wait. I can not force these messages.

[24/04/2021, 21:21:15] [eosstb] Mediabox: Media state changed from 2 [STOP] to 0 [PLAY] (node:19321) UnhandledPromiseRejectionWarning: TypeError: (this.currentChannelId || {}).includes is not a function at stbDevice.updateDeviceState (/usr/local/lib/node_modules/homebridge-eosstb/index.js:2494:38) at stbPlatform.mqttDeviceStateHandler (/usr/local/lib/node_modules/homebridge-eosstb/index.js:1495:34) at MqttClient. (/usr/local/lib/node_modules/homebridge-eosstb/index.js:1440:12) at MqttClient.emit (events.js:315:20) at MqttClient._handlePublish (/usr/local/lib/node_modules/homebridge-eosstb/node_modules/mqtt/lib/client.js:1277:12) at MqttClient._handlePacket (/usr/local/lib/node_modules/homebridge-eosstb/node_modules/mqtt/lib/client.js:410:12) at work (/usr/local/lib/node_modules/homebridge-eosstb/node_modules/mqtt/lib/client.js:321:12) at Writable.writable._write (/usr/local/lib/node_modules/homebridge-eosstb/node_modules/mqtt/lib/client.js:335:5) at doWrite (/usr/local/lib/node_modules/homebridge-eosstb/node_modules/readable-stream/lib/_stream_writable.js:409:139) at writeOrBuffer (/usr/local/lib/node_modules/homebridge-eosstb/node_modules/readable-stream/lib/_stream_writable.js:398:5) (Use node --trace-warnings ... to show where the warning was created) (node:19321) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag --unhandled-rejections=strict (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 1) (node:19321) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code. (node:19321) UnhandledPromiseRejectionWarning: TypeError: (this.currentChannelId || {}).includes is not a function at stbDevice.updateDeviceState (/usr/local/lib/node_modules/homebridge-eosstb/index.js:2494:38) at stbPlatform.mqttDeviceStateHandler (/usr/local/lib/node_modules/homebridge-eosstb/index.js:1495:34) at MqttClient. (/usr/local/lib/node_modules/homebridge-eosstb/index.js:1440:12) at MqttClient.emit (events.js:315:20) at MqttClient._handlePublish (/usr/local/lib/node_modules/homebridge-eosstb/node_modules/mqtt/lib/client.js:1277:12) at MqttClient._handlePacket (/usr/local/lib/node_modules/homebridge-eosstb/node_modules/mqtt/lib/client.js:410:12) at work (/usr/local/lib/node_modules/homebridge-eosstb/node_modules/mqtt/lib/client.js:321:12) at Writable.writable._write (/usr/local/lib/node_modules/homebridge-eosstb/node_modules/mqtt/lib/client.js:335:5) at doWrite (/usr/local/lib/node_modules/homebridge-eosstb/node_modules/readable-stream/lib/_stream_writable.js:409:139) at writeOrBuffer (/usr/local/lib/node_modules/homebridge-eosstb/node_modules/readable-stream/lib/_stream_writable.js:398:5) (node:19321) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag --unhandled-rejections=strict (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 2) (node:19321) UnhandledPromiseRejectionWarning: TypeError: (this.currentChannelId || {}).includes is not a function at stbDevice.updateDeviceState (/usr/local/lib/node_modules/homebridge-eosstb/index.js:2494:38) at stbPlatform.mqttDeviceStateHandler (/usr/local/lib/node_modules/homebridge-eosstb/index.js:1495:34) at MqttClient. (/usr/local/lib/node_modules/homebridge-eosstb/index.js:1440:12) at MqttClient.emit (events.js:315:20) at MqttClient._handlePublish (/usr/local/lib/node_modules/homebridge-eosstb/node_modules/mqtt/lib/client.js:1277:12) at MqttClient._handlePacket (/usr/local/lib/node_modules/homebridge-eosstb/node_modules/mqtt/lib/client.js:410:12) at work (/usr/local/lib/node_modules/homebridge-eosstb/node_modules/mqtt/lib/client.js:321:12) at Writable.writable._write (/usr/local/lib/node_modules/homebridge-eosstb/node_modules/mqtt/lib/client.js:335:5) at doWrite (/usr/local/lib/node_modules/homebridge-eosstb/node_modules/readable-stream/lib/_stream_writable.js:409:139) at writeOrBuffer (/usr/local/lib/node_modules/homebridge-eosstb/node_modules/readable-stream/lib/_stream_writable.js:398:5) (node:19321) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag --unhandled-rejections=strict (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 3) (node:19321) UnhandledPromiseRejectionWarning: TypeError: (this.currentChannelId || {}).includes is not a function at stbDevice.updateDeviceState (/usr/local/lib/node_modules/homebridge-eosstb/index.js:2494:38) at stbPlatform.mqttDeviceStateHandler (/usr/local/lib/node_modules/homebridge-eosstb/index.js:1495:34) at MqttClient. (/usr/local/lib/node_modules/homebridge-eosstb/index.js:1440:12) at MqttClient.emit (events.js:315:20) at MqttClient._handlePublish (/usr/local/lib/node_modules/homebridge-eosstb/node_modules/mqtt/lib/client.js:1277:12) at MqttClient._handlePacket (/usr/local/lib/node_modules/homebridge-eosstb/node_modules/mqtt/lib/client.js:410:12) at work (/usr/local/lib/node_modules/homebridge-eosstb/node_modules/mqtt/lib/client.js:321:12) at Writable.writable._write (/usr/local/lib/node_modules/homebridge-eosstb/node_modules/mqtt/lib/client.js:335:5) at doWrite (/usr/local/lib/node_modules/homebridge-eosstb/node_modules/readable-stream/lib/_stream_writable.js:409:139) at writeOrBuffer (/usr/local/lib/node_modules/homebridge-eosstb/node_modules/readable-stream/lib/_stream_writable.js:398:5) (node:19321) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag --unhandled-rejections=strict (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 4)

jsiegenthaler commented 3 years ago

Thanks @meesjan It's linked to a particular mqtt message but I don't know which one

tooh commented 3 years ago

I have the same problem. Noticed that the error messages appear under header [Sonos]. I suspect interference from the homebridge-zp plugin.

When I deactivate this it seems the errors are gone.

jsiegenthaler commented 3 years ago

Hi @tooh Thanks for the comment. This is getting stranger and stranger!.

Coincidentally, I have homebridge-hue and homebridge-zp installed at my house and I use them actively every day. But I have never observed the reported problem....

I would appreciate a log snippet with debugLevel =1 (or 2) and showing the mqtt messages received immediately before the error is logged.

meesjan commented 3 years ago

I don’t have the Hue and zp plug-ins. In my opinion this issue does not occur constantly. I can not reproduce it.

jsiegenthaler commented 3 years ago

Dear All. This bug is related to using an app. You can try and force it by watching Netflix, or using any app on your set-top box. If you can force the bug with debugLevel 2, please post a log snippet.

mhary269 commented 3 years ago

I set debug level 2 this morning. Funnily enough, the system has been stable since then. I'm still waiting for the evening. I don't use an app on the set-top box. Maybe my son started the UPC app for AppleTV and that's why the error messages came up.

jsiegenthaler commented 3 years ago

Ultra super mega weird. It just happened to me, but logged under a different plugin name!!!!!!

[27/04/2021, 20:13:57] [Weather] error: unhandled rejection: TypeError: (this.currentChannelId || {}).includes is not a function
    at stbDevice.updateDeviceState (/usr/lib/node_modules/homebridge-eosstb/index.js:2494:38)
    at stbPlatform.mqttDeviceStateHandler (/usr/lib/node_modules/homebridge-eosstb/index.js:1495:34)
    at MqttClient.<anonymous> (/usr/lib/node_modules/homebridge-eosstb/index.js:1440:12)
    at MqttClient.emit (events.js:315:20)
    at MqttClient._handlePublish (/usr/lib/node_modules/homebridge-eosstb/node_modules/mqtt/lib/client.js:1277:12)
    at MqttClient._handlePacket (/usr/lib/node_modules/homebridge-eosstb/node_modules/mqtt/lib/client.js:410:12)
    at work (/usr/lib/node_modules/homebridge-eosstb/node_modules/mqtt/lib/client.js:321:12)
    at Writable.writable._write (/usr/lib/node_modules/homebridge-eosstb/node_modules/mqtt/lib/client.js:335:5)
    at doWrite (/usr/lib/node_modules/homebridge-eosstb/node_modules/readable-stream/lib/_stream_writable.js:409:139)
    at writeOrBuffer (/usr/lib/node_modules/homebridge-eosstb/node_modules/readable-stream/lib/_stream_writable.js:398:5)

I'm wondering if this is a Homebridge problem...

jsiegenthaler commented 3 years ago

Hello All. Reason for the problem is found. I also understand now why the error is logged under another plugin. Fix coming soon.

mhary269 commented 3 years ago

Thank you :-) I don't think it is necessary to post the logs. The error occurred again.

jsiegenthaler commented 3 years ago

Please try v1.1.10-beta.1 and report here

mhary269 commented 3 years ago

Sorry, but same problem in version 1.1.10 beta 1 Log: [01.05.21, 00:36] (node:23959) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag --unhandled-rejections=strict (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 2)

[01.05.21, 00:36] (node:23959) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code.

[01.05.21, 00:36] (node:23959) UnhandledPromiseRejectionWarning: TypeError: searchChannelId.includes is not a function

[01.05.21, 00:36] at stbDevice.updateDeviceState (/home/hoobs/.hoobs/node_modules/homebridge-eosstb/index.js:2524:43)

[edited for brevity]

jsiegenthaler commented 3 years ago

Thanks. I'll keep working on it

jsiegenthaler commented 3 years ago

Hi All. I have added extra error trapping and handling in an effort to isolate and log the situation triggering this error. Please install v1.1.10-beta.2 It will now now longer throw any unhandled exceptions, as the exceptions are now properly handled. I still however do not know the root cause for the problem, so I appreciate any and all log snippets when the problem reoccurs. I look forward to your feedback...

mhary269 commented 3 years ago

Hi all, perhaps I found a new kind of error messages: Version 1.1.10-Beta.2:

3.5.2021, 13:18:32 [UPC TV Box] Further debug info: 3.5.2021, 13:18:32 [UPC TV Box] this.currentChannelId 99 3.5.2021, 13:18:32 [UPC TV Box] searchChannelId 99 3.5.2021, 13:18:33 [UPC TV Box] Error trapped in updateDeviceState while setting searchChannelId: searchChannelId.includes is not a function 3.5.2021, 13:18:33 [UPC TV Box] Further debug info: 3.5.2021, 13:18:33 [UPC TV Box] this.currentChannelId 99 3.5.2021, 13:18:33 [UPC TV Box] searchChannelId 99 3.5.2021, 13:18:33 [UPC TV Box] Error trapped in updateDeviceState while setting searchChannelId: searchChannelId.includes is not a function 3.5.2021, 13:18:33 [UPC TV Box] Further debug info: 3.5.2021, 13:18:33 [UPC TV Box] this.currentChannelId 99 3.5.2021, 13:18:33 [UPC TV Box] searchChannelId 99 3.5.2021, 13:18:33 [UPC TV Box] Error trapped in updateDeviceState while setting searchChannelId: searchChannelId.includes is not a function 3.5.2021, 13:18:33 [UPC TV Box] Further debug info: 3.5.2021, 13:18:33 [UPC TV Box] this.currentChannelId 99 3.5.2021, 13:18:33 [UPC TV Box] searchChannelId 99 3.5.2021, 13:18:34 [UPC TV Box] Error trapped in updateDeviceState while setting searchChannelId: searchChannelId.includes is not a function This error ist logged since 13:18 and persists at this time.

jsiegenthaler commented 3 years ago

Hi @mhary269. Yes, that's some extra error handling I added in to try and track down what was going wrong. The error is now properly trapped and reported, instead of causing a panic. Thanks for posting the logs, they do help. I will study my code later tonight or tomorrow.

jsiegenthaler commented 3 years ago

Hi @mhary269 I am really sure I found the cause this time. Please update to v1.1.10-beta.3 and report back here

tooh commented 3 years ago

No errors here anymore.

jsiegenthaler commented 3 years ago

@tooh Thanks for the feedback. I am now confident I found the root cause, as this time I found something definitely wrong, instead of being unsure as to what was happening. I'll look at a release tonight or tomorrow.

mhary269 commented 3 years ago

Hi jsiegenthaler, It looks very good :-) No problems since yesterday.

jsiegenthaler commented 3 years ago

Released fix in v1.1.10