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

Plugin stopped responding after some times, reported TV is OFF while it is ON #170

Closed
gengstergile opened this issue May 3, 2023 · 17 comments

Comments

@gengstergile
Copy link

gengstergile commented May 3, 2023

i am having weird issue with this plugin, after some time the plugin seems to be unresponsive where turning on/off from homebridge/homekit doesnt do anything..

homebridge reported the tv is off evethough the tv is currently on.

restarting the child bridge and the issue gone.

TV model : 50UP7750PTB
WebOS Version : 6.32-425

not sure how to produce log my homebridge already set to debug mode

this is the only log appears

[03/05/2023, 19:15:35] [homebridge-lgwebos-tv]Device: 192.168.0.35 TV, set Power: ON
[03/05/2023, 19:15:35] [homebridge-lgwebos-tv]Device: 192.168.0.35 TV, Power: OFF
[03/05/2023, 19:15:35] [homebridge-lgwebos-tv]Device: 192.168.0.35 TV, Power: OFF
[03/05/2023, 19:15:35] [homebridge-lgwebos-tv]Device: 192.168.0.35 TV, Input, Name: Kodi, Reference: com.webos.app.hdmi2
[03/05/2023, 19:15:35] [homebridge-lgwebos-tv]Device: 192.168.0.35 TV, Accessory Name: TV.
[03/05/2023, 19:15:35] [homebridge-lgwebos-tv]Device: 192.168.0.35 TV, Discovery Mode: Always discoverable
[03/05/2023, 19:15:35] [homebridge-lgwebos-tv]Device: 192.168.0.35 TV, Closed Captions: 0
[03/05/2023, 19:15:35] [homebridge-lgwebos-tv]Device: 192.168.0.35 TV, Media: STOP
[03/05/2023, 19:15:35] [homebridge-lgwebos-tv]Device: 192.168.0.35 TV, Target Media: STOP
[03/05/2023, 19:15:35] [homebridge-lgwebos-tv]Device: 192.168.0.35 TV, Picture Mode: 3
[03/05/2023, 19:15:35] [homebridge-lgwebos-tv]Device: 192.168.0.35 TV, Mute: ON
[03/05/2023, 19:15:35] [homebridge-lgwebos-tv]Device: 192.168.0.35 TV, Volume: 6

Under working condition, i can regularly see :
[03/05/2023, 20:03:24] [homebridge-lgwebos-tv] Device: 192.168.0.35 TV, debug: Specialized socket send heartbeat.
[03/05/2023, 20:03:24] [homebridge-lgwebos-tv] Device: 192.168.0.35 TV, debug: Specialized socket received heartbeat.

but none of this message appears when it become unresponsive.

Thanks.

@bollee23
Copy link

bollee23 commented Nov 2, 2023

Hi,

I'am having a very similar issue (although not 100% sure it is the same).
Plugin becomes unresponsive after some time (maybe after TV has been switched off for the night, but maybe sooner than that). Restarting Homebridge fixes the problem.

When it has stopped working, I can see occasionally a socket related error (but not systematically at each button press) :
[02/11/2023 11:48:37] [LgWebOsTv] Device: 192.168.1.128 LG webOS TV Homebridge, set Mute error: Socket not connected.

And while the TV is ON, no error is displayed although TV state seem stuck :

[02/11/2023 11:48:34] [LgWebOsTv] Device: 192.168.1.128 LG webOS TV Homebridge, Power: OFF
[02/11/2023 11:48:34] [LgWebOsTv] Device: 192.168.1.128 LG webOS TV Homebridge, Input, Name: HDMI1, Reference: com.webos.app.hdmi1
[02/11/2023 11:48:34] [LgWebOsTv] Device: 192.168.1.128 LG webOS TV Homebridge, Accessory Name: LG webOS TV Homebridge.
[02/11/2023 11:48:34] [LgWebOsTv] Device: 192.168.1.128 LG webOS TV Homebridge, Discovery Mode: Always discoverable
[02/11/2023 11:48:34] [LgWebOsTv] Device: 192.168.1.128 LG webOS TV Homebridge, Closed Captions: 0
[02/11/2023 11:48:34] [LgWebOsTv] Device: 192.168.1.128 LG webOS TV Homebridge, Media: STOP
[02/11/2023 11:48:34] [LgWebOsTv] Device: 192.168.1.128 LG webOS TV Homebridge, Target Media: STOP
[02/11/2023 11:48:34] [LgWebOsTv] Device: 192.168.1.128 LG webOS TV Homebridge, Picture Mode: 3
[02/11/2023 11:48:34] [LgWebOsTv] Device: 192.168.1.128 LG webOS TV Homebridge, Mute: ON
[02/11/2023 11:48:34] [LgWebOsTv] Device: 192.168.1.128 LG webOS TV Homebridge, Volume: 21

If I restart Homebridge, everything works as expected :

[02/11/2023 11:59:18] [LgWebOsTv] Device: 192.168.1.128 LG webOS TV Homebridge, Connected.
[02/11/2023 11:59:18] [LgWebOsTv] -------- LG webOS TV Homebridge --------
[02/11/2023 11:59:18] [LgWebOsTv] Manufacturer: LG Electronics
[02/11/2023 11:59:18] [LgWebOsTv] Model: 49SM8200PLA
[02/11/2023 11:59:18] [LgWebOsTv] System: webOSTV 4.5
[02/11/2023 11:59:18] [LgWebOsTv] Serialnr: xx:xx:xx:xx:xx:xx
[02/11/2023 11:59:18] [LgWebOsTv] Firmware: 05.30.40
[02/11/2023 11:59:18] [LgWebOsTv] ----------------------------------
....
....
[02/11/2023 11:59:21] LG webOS TV Homebridge 4F15 is running on port 42985.
[02/11/2023 11:59:21] Please add [LG webOS TV Homebridge 4F15] manually in Home app. Setup Code: xxx-xx-xxx
[02/11/2023 11:59:21] [LgWebOsTv] Device: 192.168.1.128 LG webOS TV Homebridge, Power: ON
[02/11/2023 11:59:21] [LgWebOsTv] Device: 192.168.1.128 LG webOS TV Homebridge, Input, Name: HDMI1, Reference: com.webos.app.hdmi1
[02/11/2023 11:59:21] [LgWebOsTv] Device: 192.168.1.128 LG webOS TV Homebridge, Accessory Name: LG webOS TV Homebridge.
[02/11/2023 11:59:21] [LgWebOsTv] Device: 192.168.1.128 LG webOS TV Homebridge, Discovery Mode: Always discoverable
[02/11/2023 11:59:21] [LgWebOsTv] Device: 192.168.1.128 LG webOS TV Homebridge, Closed Captions: 0
[02/11/2023 11:59:21] [LgWebOsTv] Device: 192.168.1.128 LG webOS TV Homebridge, Media: STOP
[02/11/2023 11:59:21] [LgWebOsTv] Device: 192.168.1.128 LG webOS TV Homebridge, Target Media: STOP
[02/11/2023 11:59:21] [LgWebOsTv] Device: 192.168.1.128 LG webOS TV Homebridge, Picture Mode: 3
[02/11/2023 11:59:21] [LgWebOsTv] Device: 192.168.1.128 LG webOS TV Homebridge, Mute: OFF
[02/11/2023 11:59:21] [LgWebOsTv] Device: 192.168.1.128 LG webOS TV Homebridge, Volume: 24

I have a bunch of other plugins (no particular network issue) but I haven't found what could be the issue with my TV.

Thanks for your help !

@grzegorz914
Copy link
Owner

grzegorz914 commented Nov 2, 2023

When it has stopped working, I can see occasionally a socket related error (but not systematically at each button press) :
[02/11/2023 11:48:37] [LgWebOsTv] Device: 192.168.1.128 LG webOS TV Homebridge, set Mute error: Socket not connected.

This is correct, if You try send command to TV and socket is not connected then the error appear in log.

Regarding plugin stop responding this can be local specific issue, I have in my environment 65G6V, 48CX, 48C3, 49SK8500, 32LM6300 and not observe described issue. Plugin stop responding issue in most cases is HB problem and local environment. If you can record this issue with debug mode enabled then will be very helpful to find what is wrong.

@bollee23
Copy link

bollee23 commented Nov 2, 2023

Thanks for your suggestion !
Here is what I found with Debug mode right after its activation (see bottom line) :
[02/11/2023 12:45:10] [LgWebOsTv] Device: 192.168.1.128 LG webOS TV Homebridge, debug: Socked send heartbeat.
[02/11/2023 12:45:10] [LgWebOsTv] Device: 192.168.1.128 LG webOS TV Homebridge, debug: Socked received heartbeat.
[02/11/2023 12:45:12] [LgWebOsTv] Device: 192.168.1.128 LG webOS TV Homebridge, set Mute: OFF
[02/11/2023 12:45:12] [LgWebOsTv] Device: 192.168.1.128 LG webOS TV Homebridge, Mute: ON
[02/11/2023 12:45:12] [LgWebOsTv] Device: 192.168.1.128 LG webOS TV Homebridge, debug: Unknown message type: response, id: 57607e05000c, data: {
"returnValue": true
}

Right after HB restart it took some time for the accessories to work (I use "Mute" for my tests) so maybe this is only a "glitch" / transient effect.

I will check for other unexpected messages in the coming days.

@bollee23
Copy link

bollee23 commented Nov 3, 2023

Hi,

Here is a few extracts from the log.
The latest heartbeat exchanges before TV has been switched-off :

....
^[[37m[03/11/2023 00:13:42] ^[[39m^[[36m[LgWebOsTv]^[[39m Device: 192.168.1.128 LG webOS TV Homebridge, debug: Socked send heartbeat.
^[[37m[03/11/2023 00:13:42] ^[[39m^[[36m[LgWebOsTv]^[[39m Device: 192.168.1.128 LG webOS TV Homebridge, debug: Socked received heartbeat.
^[[37m[03/11/2023 00:13:45] ^[[39m^[[36m[LgWebOsTv]^[[39m Device: 192.168.1.128 LG webOS TV Homebridge, debug: Socked send heartbeat.
^[[37m[03/11/2023 00:13:45] ^[[39m^[[36m[LgWebOsTv]^[[39m Device: 192.168.1.128 LG webOS TV Homebridge, debug: Socked received heartbeat.
^[[37m[03/11/2023 00:13:47] ^[[39m^[[36m[LgWebOsTv]^[[39m Device: 192.168.1.128 LG webOS TV Homebridge, debug: Power: {
"returnValue": true,
"state": "Active Standby",
"processing": "Request Suspend"
}
^[[37m[03/11/2023 00:13:47] ^[[39m^[[36m[LgWebOsTv]^[[39m Device: 192.168.1.128 LG webOS TV Homebridge, debug: Socked closed.
^[[37m[03/11/2023 00:13:47] ^[[39m^[[36m[LgWebOsTv]^[[39m Device: 192.168.1.128 LG webOS TV Homebridge, Socket disconnected.
^[[37m[03/11/2023 00:13:47] ^[[39m^[[36m[LgWebOsTv]^[[39m Device: 192.168.1.128 LG webOS TV Homebridge, debug: Specialized socket closed.
^[[37m[03/11/2023 00:13:47] ^[[39m^[[36m[LgWebOsTv]^[[39m Device: 192.168.1.128 LG webOS TV Homebridge, Specjalized socket disconnected.
^[[37m[03/11/2023 00:13:50] ^[[39m^[[36m[LgWebOsTv]^[[39m Device: 192.168.1.128 LG webOS TV Homebridge, debug: Cconnecting socket.

Then, the only plugin related messages are the following that were repeated regularly during the night (no more heartbeat) :

^[[37m[03/11/2023 09:43:51] ^[[39m^[[36m[LgWebOsTv]^[[39m Device: 192.168.1.128 LG webOS TV Homebridge, Power: OFF
^[[37m[03/11/2023 09:43:51] ^[[39m^[[36m[LgWebOsTv]^[[39m Device: 192.168.1.128 LG webOS TV Homebridge, Input, Name: HDMI1, Reference: com.webos.app.hdmi1
^[[37m[03/11/2023 09:43:51] ^[[39m^[[36m[LgWebOsTv]^[[39m Device: 192.168.1.128 LG webOS TV Homebridge, Accessory Name: LG webOS TV Homebridge.
^[[37m[03/11/2023 09:43:51] ^[[39m^[[36m[LgWebOsTv]^[[39m Device: 192.168.1.128 LG webOS TV Homebridge, Discovery Mode: Always discoverable
^[[37m[03/11/2023 09:43:51] ^[[39m^[[36m[LgWebOsTv]^[[39m Device: 192.168.1.128 LG webOS TV Homebridge, Closed Captions: 0
^[[37m[03/11/2023 09:43:51] ^[[39m^[[36m[LgWebOsTv]^[[39m Device: 192.168.1.128 LG webOS TV Homebridge, Media: STOP
^[[37m[03/11/2023 09:43:51] ^[[39m^[[36m[LgWebOsTv]^[[39m Device: 192.168.1.128 LG webOS TV Homebridge, Target Media: STOP
^[[37m[03/11/2023 09:43:51] ^[[39m^[[36m[LgWebOsTv]^[[39m Device: 192.168.1.128 LG webOS TV Homebridge, Picture Mode: 3
^[[37m[03/11/2023 09:43:51] ^[[39m^[[36m[LgWebOsTv]^[[39m Device: 192.168.1.128 LG webOS TV Homebridge, Mute: ON
^[[37m[03/11/2023 09:43:51] ^[[39m^[[36m[LgWebOsTv]^[[39m Device: 192.168.1.128 LG webOS TV Homebridge, Volume: 16

But nothing when I switched the TV ON (and in particular, no more "log cluster" as shown above).

While going to accessory tab in HB (forcing some kind of update I guesss), I can only see a new log cluster, with exactly the same content as shown above (telling the TV is OFF, mute ON and so on). I searched for socket related messages but strictly none can be found... Until I forced an action (mute) from HB accessory tab :

[03/11/2023 10:28:03] [LgWebOsTv] Device: 192.168.1.128 LG webOS TV Homebridge, set Mute error: Socket not connected.

I'm not clear on the precise moment thing started to go wrong since there were no error messages until I forced the use of an accessory.

Any idea ?

Many thanks

@gengstergile
Copy link
Author

Yeah i believe you have same issues as mine. However i have move on to another plugin and my tv never got disconnected anymore.

Sorry its has been 6 month with no reply. Got to try something right..

@grzegorz914
Copy link
Owner

grzegorz914 commented Nov 3, 2023

Send and receive heart beat is only if plugin is connected to tv. After TV switch to of the socket is closed in log is reported socket closed and next start Connect to tv again. If connection is not possible then reported error in the log and this is correct. As long as the TV i not available in the network plugin try to Connect every some seconds and this need to be visible during whole time when TV is Off. In your log this action is stopped, so here is the problem in your case. This problem doesn’t exist in my environment is very difficult check what is wrong. Check please installed node- min v18 and Homebridge min v1.6.

I will put today later new version with experimental changes to fix this issue.

@bollee23
Copy link

bollee23 commented Nov 3, 2023

I recently (last week) upgraded to node v20.9.0 and HB is up to date with v1.6.1.
Right before, I believe I was in node v18 and the behavior was the same.

@grzegorz914
Copy link
Owner

please try latest 2.14.0-beta and let me know

@bollee23
Copy link

bollee23 commented Nov 4, 2023

Hi !

With the beta I experience an error that makes HB crashing. If I roll back to previous stable version it works again (no crash). I'm pretty sure that at the first restart after update I hadn't this error but I think I only toggle an accessory visibility and since then I couldn't get rid of this error (tried to unistall & reinstall the plugin, restart my RPi, ...). Here is the error I met :

[03/11/2023 19:27:08] Error: Accessory LG webOS TV HB experienced an address collision.
at BridgeService.handlePublishExternalAccessories (/var/lib/homebridge/node_modules/homebridge/src/bridgeService.ts:419:15)
[03/11/2023 19:27:08] Got SIGTERM, shutting down Homebridge...

Any advice ?

@grzegorz914
Copy link
Owner

remove and again plugin child bridge

@bollee23
Copy link

bollee23 commented Nov 4, 2023

Removed plugin and reinstalled as child bridge, but still crashes :

[04/11/2023 11:14:00] [homebridge-lgwebos-tv] Process Ended. Code: 1, Signal: null
...
[04/11/2023 11:14:07] [homebridge-lgwebos-tv] Restarting Process...
[04/11/2023 11:14:08] [homebridge-lgwebos-tv] Launched child bridge with PID 299298
[04/11/2023 11:14:09] Registering platform 'homebridge-lgwebos-tv.LgWebOsTv'
[04/11/2023 11:14:09] [homebridge-lgwebos-tv] Loaded homebridge-lgwebos-tv v2.14.0-beta.36 child bridge successfully
[04/11/2023 11:14:09] Homebridge v1.7.0 (HAP v0.11.1) (homebridge-lgwebos-tv) is running on port 41550.
[04/11/2023 11:14:12] [homebridge-lgwebos-tv] Device: 192.168.1.128 LG TV HB, Connected.
[04/11/2023 11:14:12] [homebridge-lgwebos-tv] -------- LG TV HB --------
[04/11/2023 11:14:12] [homebridge-lgwebos-tv] Manufacturer: LG Electronics
[04/11/2023 11:14:12] [homebridge-lgwebos-tv] Model: 49SM8200PLA
[04/11/2023 11:14:12] [homebridge-lgwebos-tv] System: webOSTV 4.5
[04/11/2023 11:14:12] [homebridge-lgwebos-tv] Serialnr: xx:xx:xx:xx:xx:xx
[04/11/2023 11:14:12] [homebridge-lgwebos-tv] Firmware: 05.30.40
[04/11/2023 11:14:12] [homebridge-lgwebos-tv] ----------------------------------
[04/11/2023 11:14:14] LG TV HB 4F15 is running on port 35369.
[04/11/2023 11:14:14] Please add [LG TV HB 4F15] manually in Home app. Setup Code: xxx-xx-xxx
Error: Accessory LG TV HB experienced an address collision.
at BridgeService.handlePublishExternalAccessories (/var/lib/homebridge/node_modules/homebridge/src/bridgeService.ts:419:15)
at processTicksAndRejections (node:internal/process/task_queues:95:5)
[04/11/2023 11:14:16] [homebridge-lgwebos-tv] Child bridge process ended
[04/11/2023 11:14:16] [homebridge-lgwebos-tv] Process Ended. Code: 1, Signal: null

Need deeper "cleaning" ?

@grzegorz914
Copy link
Owner

@bollee23
fixed

@bollee23
Copy link

bollee23 commented Nov 4, 2023

Indeed, no more crash :-).
At the moment, I cannot see any exported accessory from the child bridge (I added it again under Home app/HomeKit).
I can see and use the accessories (Volume slider, ...) under HB, but not from Home app (that identifies this new bridge but having no accessory). I started from beta 40 (I hadn't no accessory at al even from HB) and now I'm with beta 43.

Maybe I do something wrong (not very familiar with child bridges). If you have any advice for that.

I can nevertheless verify that the plugin don't die after TV being switched Off (from HB GUI)

Many thanks !

@grzegorz914
Copy link
Owner

You need add the accessory itself to the HomeKit not the bridge.
https://github.com/grzegorz914/homebridge-lgwebos-tv/wiki

@bollee23
Copy link

bollee23 commented Nov 4, 2023

Wow ! Works great ! Thank you @grzegorz914
I would just add a precision : the PIN (or QR code) to be used is the one of the "main" bridge (I have been searching for the child bridge, but haven't found so I tried the only one mentioned in config file).

Now I can wait and test to see if it passes the night ;-)

Thanks again for your patience ;-)

@bollee23
Copy link

bollee23 commented Nov 5, 2023

Hi again,
I have good news because so far the plugin works perfectly !

@grzegorz914
Copy link
Owner

Thanks for testing I will publish it.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants