Open JasonGoldenDDT opened 2 months ago
You would need to try to reproduce your issue and observe the log if anything appears there whenever you expect the event to happen. That way you could at least check and confirm if the event from the tv arrives.
I captured a recording of the updates, and shared my experience on the hombridge GitHub.
One contributor suggested a change to this plugin's methods for updating HomeKit.
https://github.com/homebridge/homebridge/issues/3700#issuecomment-2372582579
As I try to recreate the issue I found I'm not able to recreate the issue when observing it. It works until it's been left idle for several hours. Then I find automation fails.
The link shared suggests changing how the plugin updates values.
The plugin already calls updateValue on all relevant TV updates, and I am pretty sure that it was working fine as this was explicitly done many years ago for exactly the automation use cases. It has to be checked if the tv is correctly sending the updates hence you need to reproduce the issue and check the log at that particular time to verify if the tv sends out events.
Oddly it works perfectly in rapid succession. If I'm turning the tv on and off within a few minutes. I find it fails when the tv is left off for hours.
Our use case is built around our Apple TV and LG TV both using Wifi on 5Ghz on a strong channel. At night we have a shortcut that turns the TV on by waking the AppleTV and it launches an app.
We have automation for the lights in the bedroom that check to see if the TV is on when motion is detected. If it is the lights don't turn on.
I'd day this works 70% of the time. Tonight I am going to enable deep logging and debugging on homebridge to see if I can capture the event.
Yesterday as I was watching the activity it all worked perfectly, except the macOS Home App at one point showed the TV on when it was actually off and it didn't update until I restarted the application.
I didn't see any obvious issues in the log at that time.
Yeah you need to investigate it further as there certainly could be other issues involved like dropping network connection.
Yeah, its possible.. I've spent a few months tuning our wifi here and our headless AppleTV 4k wired has improved issues considerably. Homebridge is hosted on my iMac M3, configured to stay awake. The wired Apple TV is set to preferred in 18.1 Public Beta d.
The TV is within a few feet of an Alien Wifi 6 router with a 5ghz SSID assigned to the TV.
The channel used is often very clear here.
I'm going to go through our nightly routine tonight with detailed debugging logs turned on, run through our typical use case without any home app open and our iPhones locked. I'll pass along our findings.
Wanted to quality connect this thread to the discussions on the Hombridge github, I've been working through testing collecting deep logs related to devices falling out of sync with the Home App.
I captured an example of the Home app failing to reflect the current power state of the LG TV, and failing to respond to power on commands from the home app.
https://github.com/homebridge/homebridge/issues/3700#issuecomment-2378080983
LMK if I can provide any additional detail. There is an error present in the log (-54) shared.
Thanks, the -54 error should be fine. The tv sometimes responds with that maybe because it was busy.
Thank you @merdok, last night the TV's status appeared to update closer to real time as light automation worked as expected.
My efforts to log the activity failed, with logs getting truncated. Will try again this evening.
I am curious however, why after this error the TV's status did not reflect accurately in the home app or why I was unable to turn the tv on via the home app.
The error should not affect anything. It just tells that the last request failed but all should continue to work fine.
Is it possible to force it to only use SSL?
[37m[10/16/2024, 8:00:30 PM] [39m[36m[homebridge-webos-tv][39m [90m[Display] Connecting to TV[39m [37m[10/16/2024, 8:00:30 PM] [39m[36m[homebridge-webos-tv][39m [90m[Display] Error - Error: read ECONNRESET[39m [90m at TCP.onStreamRead (node:internal/stream_base_commons:218:20) {[39m [90m errno: -54,[39m [90m code: 'ECONNRESET',[39m [90m syscall: 'read'[39m [90m}[39m [37m[10/16/2024, 8:00:30 PM] [39m[36m[homebridge-webos-tv][39m [90m[Display] Connection was reset! Possibly SSL is required![39m [37m[10/16/2024, 8:00:30 PM] [39m[36m[homebridge-webos-tv][39m [90m[Display] Trying again with ssl enabled...[39m [37m[10/16/2024, 8:00:30 PM] [39m[36m[homebridge-webos-tv][39m [90m[Display] Connecting to TV[39m
Not possible currently, the plugin automatically determines if it is needed.
Quick update. I recently installed Controller for Homekit and reviewed its logs for my install. I noticed the WebOS TV is showing up as a "Speaker". I'm wondering if this classification is causing my HomePod based automations to fail.
Is there a configuration setting I need to adjust to resolve this? The Samsung TV I have in another room shows up as a Television.
I continue to face challenges with automation reliability that uses this devices power state.
{ "devices": [ { "name": "Display", "ip": "xx", "mac": "xx:xx:xx:xx:xx:xx", "broadcastAdr": "xx", "pollingInterval": 90, "deepDebugLog": true, "silentLog": true, "hideTvService": false, "volumeLimit": 100, "volumeControl": "none", "channelControl": false } ], "_bridge": { "username": "xx:xx:xx:xx:xx", "name": "WebOS TV", "env": { "DEBUG": "HAP-NodeJS:EventedHTTPServer:Connection,HAP-NodeJS:Accessory,HAP-NodeJS:Advertiser,HAP-NodeJS:Characteristic,HAP-NodeJS:Controller:TransitionControl,HAP-NodeJS:ControllerStorage,HAP-NodeJS:DataStream:Management,HAP-NodeJS:DataStream:Server,HAP-NodeJS:EventedHTTPServer,HAP-NodeJS:EventedHTTPServer:Connection,HAP-NodeJS:EventEmitter,HAP-NodeJS:HAPServer,HAP-NodeJS:Remote:Controller,HAP-NodeJS:Remote:Controller,HAP-NodeJS:Service" } }, "platform": "webostv" },
The TV also exposes a TelevisionSpeaker characteristic hence you are seeing this. That should not affect anything.
Thank you for that clarification. I'm still unpacking how HB and HomeKit interact. Controller for Homekit has some major logging gaps unfortunately and the HB Debug logs are a pain to sort through when mixed timestamps.
I still continue to experience issues with the LG TV NOT updating HomeKit when it's Turned on via Automation. I have a nightly automaton that turns the TV on via the connected AppleTV, the AppleTV loads an App and the TV comes on, however the HomeKit App failed to register this state change, I have to manually go into the Home App with my iPhone and turn the TV on.
[37m[10/29/2024, 8:00:26 PM] [39m[36m[homebridge-webos-tv][39m [90m[Display] Error - Error: read ECONNRESET[39m [90m at TCP.onStreamRead (node:internal/stream_base_commons:218:20) {[39m [90m errno: -54,[39m [90m code: 'ECONNRESET',[39m [90m syscall: 'read'[39m [90m}[39m [37m[10/29/2024, 8:00:26 PM] [39m[36m[homebridge-webos-tv][39m [90m[Display] Connection was reset! Possibly SSL is required![39m [37m[10/29/2024, 8:00:26 PM] [39m[36m[homebridge-webos-tv][39m [90m[Display] Trying again with ssl enabled...[39m [37m[10/29/2024, 8:00:26 PM] [39m[36m[homebridge-webos-tv][39m [90m[Display] Connecting to TV[39m 2024-10-30T06:00:28.206Z HAP-NodeJS:EventedHTTPServer:Connection [xx::xx:xx:xx:aaf%en0] HTTP request: /characteristics?id=5.10,6.10 2024-10-30T06:00:28.206Z HAP-NodeJS:HAPServer [xx:xx:xx:xx:xx:2D] HAP Request: GET /characteristics?id=5.10,6.10 2024-10-30T06:00:28.207Z HAP-NodeJS:Accessory [Broadlink RM 0350] Got Characteristic "On" value: "0" 2024-10-30T06:00:28.207Z HAP-NodeJS:Accessory [Broadlink RM 0350] Got Characteristic "On" value: "0" 2024-10-30T06:00:28.207Z HAP-NodeJS:EventedHTTPServer:Connection [xx::xx:xx:xx:aaf%en0] HTTP Response is finished 2024-10-30T06:00:32.475Z HAP-NodeJS:EventedHTTPServer:Connection [xx::xx:xx:xx:aaf%en0] HTTP request: /characteristics?id=1.10 2024-10-30T06:00:32.475Z HAP-NodeJS:HAPServer [xx:xx:xx:xx:xx:xx] HAP Request: GET /characteristics?id=1.10 2024-10-30T06:00:32.475Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Active" value: "0"
Today I noticed the TV disconnects after a period of time from wifi (I can't wire it).
The TV powers on via the HDMI connection with the AppleTV. The wifi connection is restored and the plugin is able to communicate. However the Home app device state does not get updated.
The wifi disconnect is functioning as designed. I'm wondering if this plugin could push a refresh to the Home app once it completes its reconnection steps. Performing come kind of check to ensure HB/HK = Current Device Status after connection could resolve this issue completely.
In this example I don't see a status update until 8:07pm when I open the app and tap the device in the UI, the TV is already on, it just appears off in the app.
2024-10-30T06:07:06.902Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Active" value: "1"
I'm also seeing references to "WebOS TV 151D" a device I do not see in HomeKit and I assume is a translation layer between HB Plugin and the HomeKit "Display" device I do see in home kit. They are the
2024-10-30T08:08:46.926Z HAP-NodeJS:Accessory [WebOS TV 151D] Got Characteristic "Version" value: "1.1.0" 2024-10-30T08:08:50.131Z HAP-NodeJS:Accessory [WebOS TV 151D] Got Characteristic "Version" value: "1.1.0" 2024-10-30T08:09:35.850Z HAP-NodeJS:Accessory [WebOS TV 151D] Got Characteristic "Firmware Revision" value: "1.8.5" 2024-10-30T08:09:50.497Z ciao:Responder [WebOS TV 151D._hap._tcp.local.] Removing service from the network 2024-10-30T08:09:50.497Z ciao:Announcer [WebOS TV 151D._hap._tcp.local.] Sending goodbye for service 2024-10-30T08:09:50.498Z ciao:Announcer [WebOS TV 151D._hap._tcp.local.] Sending goodbye number 1 2024-10-30T08:10:02.097Z HAP-NodeJS:Advertiser Preparing Advertiser for 'WebOS TV 151D' using ciao backend! 2024-10-30T08:10:02.107Z HAP-NodeJS:Advertiser Starting to advertise 'WebOS TV 151D' using ciao backend! 2024-10-30T08:10:02.107Z ciao:Responder [WebOS TV 151D._hap._tcp.local.] Going to advertise service... 2024-10-30T08:10:02.108Z ciao:CiaoService [WebOS TV 151D] Rebuilding service records... 2024-10-30T08:10:02.108Z ciao:Prober Starting to probe for 'WebOS TV 151D._hap._tcp.local.'... 2024-10-30T08:10:02.188Z ciao:Prober Sending prober query number 1 for 'WebOS TV 151D._hap._tcp.local.'... 2024-10-30T08:10:02.442Z ciao:Prober Sending prober query number 2 for 'WebOS TV 151D._hap._tcp.local.'... 2024-10-30T08:10:02.693Z ciao:Prober Sending prober query number 3 for 'WebOS TV 151D._hap._tcp.local.'... 2024-10-30T08:10:02.946Z ciao:Prober Probing for 'WebOS TV 151D._hap._tcp.local.' finished successfully 2024-10-30T08:10:02.947Z ciao:Announcer [WebOS TV 151D._hap._tcp.local.] Sending announcement for service 2024-10-30T08:10:02.947Z ciao:CiaoService [WebOS TV 151D] Rebuilding service records... 2024-10-30T08:10:02.949Z ciao:Announcer [WebOS TV 151D._hap._tcp.local.] Sending announcement number 1 2024-10-30T08:10:02.972Z HAP-NodeJS:Accessory [WebOS TV 151D] Processing characteristic set: {"characteristics":[{"aid":-1,"iid":-1}]} 2024-10-30T08:10:02.972Z HAP-NodeJS:Accessory [WebOS TV 151D] Could not find a Characteristic with aid of -1 and iid of -1 2024-10-30T08:10:03.040Z HAP-NodeJS:Accessory [WebOS TV 151D] Got Characteristic "Version" value: "1.1.0" 2024-10-30T08:10:03.129Z HAP-NodeJS:Accessory [WebOS TV 151D] Got Characteristic "Version" value: "1.1.0" 2024-10-30T08:10:03.660Z HAP-NodeJS:Accessory [WebOS TV 151D] Got Characteristic "Version" value: "1.1.0"
LMK what other context I can provide. I have two LG plugins however the TV "Display" is only configured with this webOS TV plugin.
On every connection already a full update is being done of the TV status to HomeKit. But that should not matter anyway in your case because you mention that the TV disconnects from wifi and reconnects again in a very short time where it would be unlikely that something has changed.
In the example of log data I shared, I see the reconnect but I do not see the status update reflecting the TV as on until I trigger it via the Home App directly.
not clear where that command gets lost, with the second "WebTV" reference in Ciao and Display reference on HAP.
Provided additional log data on this thread from last night:
https://github.com/homebridge/homebridge/issues/3700#issuecomment-2452430882
The plugin fails to update Home App status after power on via AppleTV (HDMI).
Thanks for the additional log
No problem. Let me know if I can look for any patterns on my expanded log data.
Saw the NODE.js update come through. Thank you for that. I just realized my issues were likely related to this.
Homebridge alerts an update without providing much insight into Node.js dependencies. Noticed things improved when I rollback to 18 for this plugin.
Thanks for the update.
Yeah sometimes node.js might also cause issues. Good to hear that things improved on your side after a downgrade.
It seems like HomeKit doesn't work well unless observed from my iPhone. If the iPhone is asleep it's hit or miss if Homekit Updates.
I have a LG TV configured with this plugin (2.4.5) and it works as expected when my iPhone is used to control it. However when the iPhone is asleep and I use the HomeApp from my iMac for example, it doesn't. Or if I want automation to trigger based on device state: If "TV ON" don't turn on lights. When this fails, I wake my phone and the device status MIGHT update. Sometimes I have to restart homebridge to get the status to reflect correctly in HomeKit.
Right now as I troubleshoot this issue, the Home app on my iMac shows the TV power is on. My iPhone how's it as Off, if I restart the home app on the iMac, the status is reflected correctly as off.
I am having issues with automation tied to device state, for example I don't want motion to turn on bedroom lights if the tv is on. This doesn't work 80% of the time.
Setup:
headless wired AppleTV as Home Hub - iOS 18.1 public beta installed (this issue predates this version). Homebridge 1.8.4, UI 4.58.0 Node.js 20.17.0
Homebridge is running on M3 iMac. Does not sleep. iMac is Wired. TV is on 5Ghz Wifi within 8 feet of Wifi 6 AP with 100% signal strength.
Deep Log Sample:
`[9/23/2024, 8:59:47 AM] [homebridge-webos-tv] [Display] { "returnValue": true, "state": "Active", "processing": "Prepare Active Standby", "onOff": "off", "reason": "hdmiCec" } [9/23/2024, 8:59:47 AM] [homebridge-webos-tv] [Display] TV power status changed, status: state: Active, processing: Prepare Active Standby, [9/23/2024, 8:59:47 AM] [homebridge-webos-tv] [Display] Message from TV
[9/23/2024, 8:59:47 AM] [homebridge-webos-tv] [Display] { type: 'utf8', utf8Data: '{"type":"response","id":"67b10ee90007","payload":{"returnValue":true,"state":"Active Standby"}}' } [9/23/2024, 8:59:47 AM] [homebridge-webos-tv] [Display] { "returnValue": true, "state": "Active Standby" } [9/23/2024, 8:59:47 AM] [homebridge-webos-tv] [Display] TV power status changed, status: state: Active Standby, [9/23/2024, 8:59:47 AM] [homebridge-webos-tv] [Display] Pixel refresher started! [9/23/2024, 8:59:47 AM] [homebridge-webos-tv] [Display] Message from TV
[9/23/2024, 8:59:47 AM] [homebridge-webos-tv] [Display] { type: 'utf8', utf8Data: '{"type":"response","id":"67b10ee90009","payload":{"subscribed":true,"returnValue":true,"appId":"","processId":"","windowId":""}}' } [9/23/2024, 8:59:47 AM] [homebridge-webos-tv] [Display] { "subscribed": true, "returnValue": true, "appId": "", "processId": "", "windowId": "" } [9/23/2024, 8:59:47 AM] [homebridge-webos-tv] [Display] Message from TV
[9/23/2024, 8:59:47 AM] [homebridge-webos-tv] [Display] { type: 'utf8', utf8Data: '{"type":"response","id":"67b10ee9000d","payload":{"returnValue":true,"category":"picture","settings":{"contrast":"100","brightness":"50","color":"60","backlight":"100"}}}' } [9/23/2024, 8:59:47 AM] [homebridge-webos-tv] [Display] { "returnValue": true, "category": "picture", "settings": { "contrast": "100", "brightness": "50", "color": "60", "backlight": "100" } } [9/23/2024, 8:59:47 AM] [homebridge-webos-tv] [Display] Picture settings changed. Current picture settings: {"brightness":50,"backlight":100,"contrast":100,"color":60}`
TV doesn't show "power state change" message.
Device Config:
{ "devices": [ { "name": "Display", "ip": "Static", "mac": "xxx", "broadcastAdr": "static", "pollingInterval": 90, "deepDebugLog": true, "silentLog": true, "hideTvService": false, "volumeLimit": 100, "volumeControl": "none", "channelControl": false } ], "_bridge": { "username": "xxx" }, "platform": "webostv" },
LMK if I can provide any additional context.