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

Device Power State & HomeKit Fall Out of Sync: TV Off, HomeKit: ON #546

Open
JasonGoldenDDT opened this issue Sep 23, 2024 · 44 comments
Open

Comments

@JasonGoldenDDT
Copy link

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.

Screenshot 2024-09-23 at 9 08 59 AM

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.

@merdok
Copy link
Owner

merdok commented Sep 23, 2024

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.

@JasonGoldenDDT
Copy link
Author

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.

homebridge/homebridge#3700 (comment)

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.

@merdok
Copy link
Owner

merdok commented Sep 25, 2024

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.

@JasonGoldenDDT
Copy link
Author

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.

@merdok
Copy link
Owner

merdok commented Sep 25, 2024

Yeah you need to investigate it further as there certainly could be other issues involved like dropping network connection.

@JasonGoldenDDT
Copy link
Author

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.

Screenshot 2024-09-25 at 8 18 20 AM

The channel used is often very clear here.
Screenshot 2024-09-25 at 8 12 32 AM

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.

@JasonGoldenDDT
Copy link
Author

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.

homebridge/homebridge#3700 (comment)

LMK if I can provide any additional detail. There is an error present in the log (-54) shared.

@merdok
Copy link
Owner

merdok commented Sep 27, 2024

Thanks, the -54 error should be fine. The tv sometimes responds with that maybe because it was busy.

@JasonGoldenDDT
Copy link
Author

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.

@merdok
Copy link
Owner

merdok commented Sep 27, 2024

The error should not affect anything. It just tells that the last request failed but all should continue to work fine.

@JasonGoldenDDT
Copy link
Author

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

@merdok
Copy link
Owner

merdok commented Oct 18, 2024

Not possible currently, the plugin automatically determines if it is needed.

@JasonGoldenDDT
Copy link
Author

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.

Screenshot 2024-10-28 at 9 48 18 AM

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" },

@merdok
Copy link
Owner

merdok commented Oct 28, 2024

The TV also exposes a TelevisionSpeaker characteristic hence you are seeing this. That should not affect anything.

@JasonGoldenDDT
Copy link
Author

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.

@merdok
Copy link
Owner

merdok commented Oct 30, 2024

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.

@JasonGoldenDDT
Copy link
Author

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.

@JasonGoldenDDT
Copy link
Author

Provided additional log data on this thread from last night:

homebridge/homebridge#3700 (comment)

The plugin fails to update Home App status after power on via AppleTV (HDMI).

@merdok
Copy link
Owner

merdok commented Nov 1, 2024

Thanks for the additional log

@JasonGoldenDDT
Copy link
Author

No problem. Let me know if I can look for any patterns on my expanded log data.

@JasonGoldenDDT
Copy link
Author

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.

@merdok
Copy link
Owner

merdok commented Nov 22, 2024

Yeah sometimes node.js might also cause issues. Good to hear that things improved on your side after a downgrade.

@JasonGoldenDDT
Copy link
Author

Quick update. Rolled back Node, finding 18.20.4 is actually less stable for Home App device status. Is there a timeline for when this plugin will be remediated for latest HB version of Node?

@merdok
Copy link
Owner

merdok commented Dec 2, 2024

Not quite sure what you mean, this plugin supports the latest node.js version available for HB.

@JasonGoldenDDT
Copy link
Author

I'm getting this error when I attempt to run latest Node suggested by HB.

Screenshot 2024-12-02 at 11 37 00 AM

@merdok
Copy link
Owner

merdok commented Dec 3, 2024

Version 2.4.6 has added support for node.js v22

@JasonGoldenDDT
Copy link
Author

I'm running that version. I'll check again after I hear back from the developer on the LG Thinq plugin.

@JasonGoldenDDT
Copy link
Author

After a few days monitoring automation performance, I'm finding the TV's status in the Home App continues to fall out of sync when the status changes due to automation trigger.

I extracted some error data from the debug log and I've included some sample log data from recent errors.

Now running Node 22.12.0
Screenshot 2024-12-11 at 9 32 16 AM

Screenshot 2024-12-11 at 9 30 46 AM

����[37m[12/10/2024, 7:04:09 AM] �[39m�[32mDisplay A1E9 is running on port 49183.�[39m
�[37m[12/10/2024, 7:04:09 AM] �[39mPlease add [Display A1E9] manually in Home app. Setup Code: 267-13-522
�[37m[12/10/2024, 7:04:09 AM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] Error - Error: read ECONNRESET�[39m
�[90m    at TCP.onStreamRead (node:internal/stream_base_commons:216:20) {�[39m
�[90m  errno: -54,�[39m
�[90m  code: 'ECONNRESET',�[39m
�[90m  syscall: 'read'�[39m
�[90m}�[39m
�[37m[12/10/2024, 7:04:09 AM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] Connection was reset! Possibly SSL is required!�[39m
�[37m[12/10/2024, 7:04:09 AM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] Trying again with ssl enabled...�[39m
�[37m[12/10/2024, 7:04:09 AM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] Connecting to TV�[39m
�[37m[12/10/2024, 7:04:09 AM] �[39mRegistering platform 'homebridge-xbox-tv.XboxTv'
�[37m[12/10/2024, 7:04:09 AM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] Message from TV �[39m
�[90m�[39m
�[37m[12/10/2024, 7:04:09 AM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display]  {�[39m
�[90m  type: 'utf8',�[39m
�[90m  utf8Data: '{"type":"registered","id":"1d525a590000","payload":{"client-key":"Redacted"}}'�[39m
�[90m}�[39m
�[37m[12/10/2024, 7:04:09 AM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] Connected to TV�[39m
�[37m[12/10/2024, 7:04:09 AM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] Requesting TV information�[39m
�[37m[12/10/2024, 7:04:09 AM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] system service - getSystemInfo requested. �[39m
�[37m[12/10/2024, 7:04:09 AM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] com.webos.service.update service - getCurrentSWInformation requested. �[39m
�[37m[12/10/2024, 7:04:09 AM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] api service - getServiceList requested. �[39m
�[37m[12/10/2024, 7:04:09 AM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] com.webos.applicationManager service - listLaunchPoints requested. �[39m
�[37m[12/10/2024, 7:04:09 AM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] tv service - getExternalInputList requested. �[39m
�[37m[12/10/2024, 7:04:09 AM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] com.webos.applicationManager service - listApps requested. �[39m
�[37m[12/10/2024, 7:04:09 AM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] Message from TV �[39m

[37m[12/10/2024, 1:05:54 PM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] Connecting to TV�[39m
�[37m[12/10/2024, 1:06:01 PM] �[39m�[36m[homebridge-lg-thinq]�[39m �[90m[request] post https://aic-service.lgthinq.com:46030/v1/service/devices/Redacted/control�[39m
�[37m[12/10/2024, 1:06:01 PM] �[39m�[36m[homebridge-lg-thinq]�[39m �[90mThinQ Device Received the Command�[39m
�[37m[12/10/2024, 1:06:19 PM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] Wake on LAN callback - sent magic packet, trying to connect to tv...�[39m
�[37m[12/10/2024, 1:06:19 PM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] Trying to wake up TV! Mac: Redacted, BroadcastAdr: 10.0.145.184�[39m
�[37m[12/10/2024, 1:06:19 PM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] Connecting to TV�[39m
�[37m[12/10/2024, 1:06:29 PM] �[39m�[36m[Broadlink RM]�[39m �[90m**Fakegato-timer: addData  Broadlink Temperature { time: 1733871990, temp: 30.41, humidity: 53.5 }  immediate:  false�[39m
�[37m[12/10/2024, 1:06:43 PM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] Wake on LAN callback - sent magic packet, trying to connect to tv...�[39m
�[37m[12/10/2024, 1:06:43 PM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] Trying to wake up TV! Mac: Redacted, BroadcastAdr: 10.0.145.184�[39m
�[37m[12/10/2024, 1:06:43 PM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] Connecting to TV�[39m
�[37m[12/10/2024, 1:07:01 PM] �[39m�[36m[homebridge-lg-thinq]�[39m �[90m[request] post https://aic-service.lgthinq.com:46030/v1/service/devices/Redacted/control�[39m
�[37m[12/10/2024, 1:07:01 PM] �[39m�[36m[homebridge-lg-thinq]�[39m �[90mThinQ Device Received the Command�[39m
�[37m[12/10/2024, 1:07:14 PM] �[39m�[36m[Broadlink RM]�[39m �[90m**Fakegato-timer: addData  Broadlink Temperature { time: 1733872035, temp: 30.35, humidity: 53.56 }  immediate:  false�[39m
�[37m[12/10/2024, 1:07:17 PM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] Wake on LAN callback - sent magic packet, trying to connect to tv...�[39m
�[37m[12/10/2024, 1:07:17 PM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] Trying to wake up TV! Mac: Redacted, BroadcastAdr: 10.0.145.184�[39m
�[37m[12/10/2024, 1:07:17 PM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] Connecting to TV�[39m
�[37m[12/10/2024, 1:07:32 PM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] Connecting to TV�[39m
�[37m[12/10/2024, 1:07:32 PM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] Connecting to TV�[39m
�[37m[12/10/2024, 1:07:39 PM] �[39m�[36m[Samsung TV]�[39m �[90m[DEBUG] https://api.smartthings.com/v1/devices/e3bf7dc5-e432-412f-92f0-436840af1aea/commands {"commands":[{"component":"main","capability":"refresh","command":"refresh"}]}�[39m
�[37m[12/10/2024, 1:07:39 PM] �[39m�[36m[Samsung TV]�[39m �[90m[DEBUG] {"results":[{"id":"10a017cc-36c8-4cac-b70a-b8f170e0eb9e","status":"FAILED"}]}�[39m
�[37m[12/10/2024, 1:07:39 PM] �[39m�[36m[Samsung TV]�[39m �[90m[DEBUG] https://api.smartthings.com/v1/devices/e3bf7dc5-e432-412f-92f0-436840af1aea/states �[39m
�[37m[12/10/2024, 1:07:39 PM] �[39m�[36m[Samsung TV]�[39m �[90m[DEBUG] {"main":{"mnfv":{"value":"T-PTMCAKUC-2000.2|ST_ENERGY"},"data":{"value":null},"di":{"value":"e3bf7dc5-e432-412f-92f0-436840af1aea"},"supportedInputSources":{"value":"[]"},"mnsl":{"value":""},"dmv":{"value":"res.1.1.0,sh.1.1.0"},"notificationTemplateID":{"value":null},"vid":{"value":"VD-STV-2023"},"supportedPictureModes":{"value":"[\"EyeComfort\",\"Optimized\"]"},"firmwareVersion":{"value":"3.5.1"},"icv":{"value":"core.1.1.0"},"updatedTime":{"value":"1727025712"},"deviceConnectionState":{"value":null},"wifiUpdateSupport":{"value":null},"executableServiceList":{"value":null},"soundMode":{"value":"Standard"},"energySavingLevel":{"value":null},"playbackStatus":{"value":null},"mute":{"value":"muted"},"supportedAmbientApps":{"value":"[\"weather\"]"},"mnmo":{"value":"QN65QN90CAFXZA"},"volume":{"value":"28","unit":"%"},"tvChannel":{"value":""},"energyType":{"value":null},"energySavingSupport":{"value":null},"drMaxDuration":{"value":null},"mnmn":{"value":"Samsung Electronics"},"imeAdvSupported":{"value":"true"},"mnml":{"value":""},"drlcStatus":{"value":null},"tvChannelName":{"value":""},"status":{"value":"Idle"},"mndt":{"value":"2023-01-01"},"supportsPowerOnByOcf":{"value":"true"},"mnhw":{"value":""},"supportedPlaybackCommands":{"value":"[\"play\",\"pause\",\"stop\",\"fastForward\",\"rewind\"]"},"remotelessSupported":{"value":null},"supportedPictureModesMap":{"value":"[{\"id\":\"modeGen_589827\",\"name\":\"EyeComfort\"},{\"id\":\"modeIntelligentHDR\",\"name\":\"Optimized\"}]"},"energySavingInfo":{"value":null},"error":{"value":null},"energySavingOperation":{"value":null},"switch":{"value":"on"},"mnpv":{"value":"7.0"},"supportedSoundModes":{"value":"[\"Standard\"]"},"energySavingOperationSupport":{"value":null},"mediaOutputSupported":{"value":null},"st":{"value":"2024-06-26T20:30:52Z"},"powerConsumption":{"value":null},"pictureMode":{"value":"Optimized"},"supportedSoundModesMap":{"value":"[{\"id\":\"modeExternalStandard\",\"name\":\"Standard\"}]"},"disabledCapabilities":{"value":"[\"powerConsumptionReport\"]"},"supportedTrackControlCommands":{"value":null},"mobileCamSupported":{"value":"true"},"supportedEnergySavingLevels":{"value":null},"n":{"value":"Samsung"},"supportedInputSourcesMap":{"value":"[{\"id\":\"dtv\",\"name\":\"TV\"},{\"id\":\"HDMI3\",\"name\":\"Apple TV\"},{\"id\":\"HDMI4\",\"name\":\"XBOX SeriesX|S\"}]"},"mnos":{"value":"Tizen"},"pi":{"value":"e3bf7dc5-e432-412f-92f0-436840af1aea"},"inputSource":{"value":"HDMI3"},"category":{"value":"tv"}}}�[39m
�[37m[12/10/2024, 1:07:57 PM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] Connecting to TV�[39m
�[37m[12/10/2024, 1:07:59 PM] �[39m�[36m[Broadlink RM]�[39m �[90m**Fakegato-timer: addData  Broadlink Temperature { time: 1733872080, temp: 30.31, humidity: 53.45 }  immediate:  false�[39m
�[37m[12/10/2024, 1:08:01 PM] �[39m�[36m[homebridge-lg-thinq]�[39m �[90m[request] post https://aic-service.lgthinq.com:46030/v1/service/devices/Redacted/control�[39m
�[37m[12/10/2024, 1:08:01 PM] �[39m�[36m[homebridge-lg-thinq]�[39m �[90mThinQ Device Received the Command�[39m
�[37m[12/10/2024, 1:08:21 PM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] Connecting to TV�[39m
�[37m[12/10/2024, 1:08:25 PM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] Error - Error: read ECONNRESET�[39m
�[90m    at TCP.onStreamRead (node:internal/stream_base_commons:216:20) {�[39m
�[90m  errno: -54,�[39m
�[90m  code: 'ECONNRESET',�[39m
�[90m  syscall: 'read'�[39m
�[90m}�[39m
�[37m[12/10/2024, 1:08:25 PM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] Connection was reset! Possibly SSL is required!�[39m
�[37m[12/10/2024, 1:08:25 PM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] Trying again with ssl enabled...�[39m
�[37m[12/10/2024, 1:08:25 PM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] Connecting to TV�[39m
�[37m[12/10/2024, 1:08:38 PM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] Message from TV �[39m
�[90m�[39m
�[37m[12/10/2024, 1:08:38 PM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display]  {�[39m
�[90m  type: 'utf8',�[39m
�[90m  utf8Data: '{"type":"registered","id":"0749f6ac0010","payload":{"client-key":"Redacted"}}'�[39m
�[90m}�[39m
�[37m[12/10/2024, 1:08:38 PM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] Connected to TV�[39m
�[37m[12/10/2024, 1:08:38 PM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] Requesting TV information�[39m
�[37m[12/10/2024, 1:08:38 PM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] system service - getSystemInfo requested. �[39m
�[37m[12/10/2024, 1:08:38 PM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] com.webos.service.update service - getCurrentSWInformation requested. �[39m
�[37m[12/10/2024, 1:08:38 PM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] api service - getServiceList requested. �[39m
�[37m[12/10/2024, 1:08:38 PM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] com.webos.applicationManager service - listLaunchPoints requested. �[39m
�[37m[12/10/2024, 1:08:38 PM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] tv service - getExternalInputList requested. �[39m
�[37m[12/10/2024, 1:08:38 PM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] com.webos.applicationManager service - listApps requested. �[39m
�[37m[12/10/2024, 1:08:38 PM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] Message from TV �[39m
�[90m�[39m
�[37m[12/10/2024, 1:08:38 PM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display]  {�[39m
�[90m  type: 'utf8',�[39m

[37m[12/10/2024, 5:14:14 PM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] Error - Error [ERR_STREAM_WRITE_AFTER_END]: write after end�[39m
�[37m[12/10/2024, 5:14:14 PM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] Disconnected from TV�[39m
�[37m[12/10/2024, 5:14:45 PM] �[39m�[36m[Broadlink RM]�[39m �[90m**Fakegato-timer: addData  Broadlink Temperature { time: 1733886885, temp: 29.96, humidity: 50.84 }  immediate:  false�[39m
�[37m[12/10/2024, 5:15:01 PM] �[39m�[36m[homebridge-lg-thinq]�[39m �[90m[request] post https://aic-service.lgthinq.com:46030/v1/service/devices/Redacted/control�[39m
�[37m[12/10/2024, 5:15:01 PM] �[39m�[36m[homebridge-lg-thinq]�[39m �[90mThinQ Device Received the Command�[39m
�[37m[12/10/2024, 5:15:30 PM] �[39m�[36m[Broadlink RM]�[39m �[90m**Fakegato-timer: addData  Broadlink Temperature { time: 1733886930, temp: 29.96, humidity: 50.84 }  immediate:  false�[39m
�[37m[12/10/2024, 5:15:44 PM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] Starting TV alive polling�[39m
�[37m[12/10/2024, 5:15:44 PM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] Connecting to TV�[39m
�[37m[12/10/2024, 5:15:44 PM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] Connecting to TV�[39m
�[37m[12/10/2024, 5:16:01 PM] �[39m�[36m[homebridge-lg-thinq]�[39m �[90m[request] post https://aic-service.lgthinq.com:46030/v1/service/devices/Redacted/control�[39m
�[37m[12/10/2024, 5:16:01 PM] �[39m�[36m[homebridge-lg-thinq]�[39m �[90mThinQ Device Received the Command�[39m
�[37m[12/10/2024, 5:16:15 PM] �[39m�[36m[Broadlink RM]�[39m �[90m**Fakegato-timer: addData  Broadlink Temperature { time: 1733886975, temp: 29.96, humidity: 50.85 }  immediate:  false�[39m
�[37m[12/10/2024, 5:16:59 PM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] Error - Error: connect ETIMEDOUT 10.0.145.27:3000�[39m
�[90m    at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1615:16) {�[39m
�[90m  errno: -60,�[39m
�[90m  code: 'ETIMEDOUT',�[39m
�[90m  syscall: 'connect',�[39m
�[90m  address: '10.0.145.27',�[39m
�[90m  port: 3000�[39m
�[90m}�[39m
�[37m[12/10/2024, 5:17:00 PM] �[39m�[36m[Broadlink RM]�[39m �[90m**Fakegato-timer: addData  Broadlink Temperature { time: 1733887020, temp: 29.92, humidity: 50.83 }  immediate:  false�[39m
�[37m[12/10/2024, 5:17:01 PM] �[39m�[36m[homebridge-lg-thinq]�[39m �[90m[request] post https://aic-service.lgthinq.com:46030/v1/service/devices/Redacted/control�[39m
�[37m[12/10/2024, 5:17:01 PM] �[39m�[36m[homebridge-lg-thinq]�[39m �[90mThinQ Device Received the Command�[39m
�[37m[12/10/2024, 5:17:28 PM] �[39m�[36m[Broadlink RM]�[39m �[90m**Fakegato-timer: addData  Broadlink Temperature { time: 1733887049, temp: 29.92, humidity: 50.83 }  immediate:  false�[39m
�[37m[12/10/2024, 5:17:45 PM] �[39m�[36m[Broadlink RM]�[39m �[90m**Fakegato-timer: addData  Broadlink Temperature { time: 1733887065, temp: 29.97, humidity: 50.82 }  immediate:  false�[39m
�[37m[12/10/2024, 5:18:01 PM] �[39m�[36m[homebridge-lg-thinq]�[39m �[90m[request] post https://aic-service.lgthinq.com:46030/v1/service/devices/Redacted/control�[39m
�[37m[12/10/2024, 5:18:01 PM] �[39m�[36m[homebridge-lg-thinq]�[39m �[90mThinQ Device Received the Command�[39m
�[37m[12/10/2024, 5:18:29 PM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] Connecting to TV�[39m
�[37m[12/10/2024, 5:18:29 PM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] Connecting to TV�[39m

[37m[12/11/2024, 12:29:00 AM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] Starting TV alive polling�[39m
�[37m[12/11/2024, 12:29:00 AM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] Connecting to TV�[39m
�[37m[12/11/2024, 12:29:00 AM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] Connecting to TV�[39m
�[37m[12/11/2024, 12:29:01 AM] �[39m�[36m[Broadlink RM]�[39m �[90m**Fakegato-timer: addData  Broadlink Temperature { time: 1733912942, temp: 23.15, humidity: 40.7 }  immediate:  false�[39m
�[37m[12/11/2024, 12:29:02 AM] �[39m�[36m[homebridge-lg-thinq]�[39m �[90m[request] post https://aic-service.lgthinq.com:46030/v1/service/devices/Redacted/control�[39m
�[37m[12/11/2024, 12:29:02 AM] �[39m�[36m[homebridge-lg-thinq]�[39m �[90mThinQ Device Received the Command�[39m
�[37m[12/11/2024, 12:29:12 AM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] Error - Error: connect ETIMEDOUT 10.0.145.27:3000�[39m
�[90m    at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1615:16) {�[39m
�[90m  errno: -60,�[39m
�[90m  code: 'ETIMEDOUT',�[39m
�[90m  syscall: 'connect',�[39m
�[90m  address: '10.0.145.27',�[39m
�[90m  port: 3000�[39m
�[90m}�[39m
�[37m[12/11/2024, 12:29:12 AM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] Error - Error: connect ETIMEDOUT 10.0.145.27:3001�[39m
�[90m    at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1615:16) {�[39m
�[90m  errno: -60,�[39m
�[90m  code: 'ETIMEDOUT',�[39m
�[90m  syscall: 'connect',�[39m
�[90m  address: '10.0.145.27',�[39m
�[90m  port: 3001�[39m
�[90m}�[39m
�[37m[12/11/2024, 12:29:46 AM] �[39m�[36m[Broadlink RM]�[39m �[90m**Fakegato-timer: addData  Broadlink Temperature { time: 1733912986, temp: 23.36, humidity: 42.7 }  immediate:  false�[39m
�[37m[12/11/2024, 12:29:47 AM] �[39m�[36m[homebridge-lg-thinq]�[39m �[90mSet power on =  0  - current status =  true�[39m
�[37m[12/11/2024, 12:29:48 AM] �[39m�[36m[homebridge-lg-thinq]�[39m �[90mmqtt message received: {"controlResult":{"messageId":"rlShGfNvahNEOWfHtF1r90","deviceId":"Redacted","returnCode":"0000"}}�[39m
�[37m[12/11/2024, 12:29:48 AM] �[39m�[36m[homebridge-lg-thinq]�[39m �[90m[request] post https://aic-service.lgthinq.com:46030/v1/service/devices/Redacted/control-sync�[39m
�[37m[12/11/2024, 12:29:48 AM] �[39m�[36m[homebridge-lg-thinq]�[39m �[90mThinQ Device Received the Command�[39m
�[37m[12/11/2024, 12:30:02 AM] �[39m�[36m[homebridge-lg-thinq]�[39m �[90mSet power on =  1  - current status =  false�[39m
�[37m[12/11/2024, 12:30:02 AM] �[39m�[36m[homebridge-lg-thinq]�[39m �[90mSet target AC mode =  2�[39m
�[37m[12/11/2024, 12:30:02 AM] �[39m�[36m[homebridge-lg-thinq]�[39m �[90m[request] post https://aic-service.lgthinq.com:46030/v1/service/devices/Redacted/control�[39m
�[37m[12/11/2024, 12:30:02 AM] �[39m�[36m[homebridge-lg-thinq]�[39m �[90mThinQ Device Received the Command�[39m
�[37m[12/11/2024, 12:30:03 AM] �[39m�[36m[homebridge-lg-thinq]�[39m �[90mmqtt message received: {"controlResult":{"messageId":"wHdnvHMvLbaCYZkXM3zUIG","deviceId":"Redacted","returnCode":"0000"}}�[39m
�[37m[12/11/2024, 12:30:03 AM] �[39m�[36m[homebridge-lg-thinq]�[39m �[90m[request] post https://aic-service.lgthinq.com:46030/v1/service/devices/Redacted/control-sync�[39m
�[37m[12/11/2024, 12:30:03 AM] �[39m�[36m[homebridge-lg-thinq]�[39m �[90mThinQ Device Received the Command�[39m
�[37m[12/11/2024, 12:30:31 AM] �[39m�[36m[Broadlink RM]�[39m �[90m**Fakegato-timer: addData  Broadlink Temperature { time: 1733913032, temp: 23.36, humidity: 42.7 }  immediate:  false�[39m
�[37m[12/11/2024, 12:30:42 AM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] Connecting to TV�[39m
�[37m[12/11/2024, 12:30:42 AM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] Connecting to TV�[39m
�[37m[12/11/2024, 12:30:54 AM] �[39m�[36m[homebridge-webos-tv]�[39m �[90m[Display] Error - Error: connect ETIMEDOUT 10.0.145.27:3000�[39m
�[90m    at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1615:16) {�[39m
�[90m  errno: -60,�[39m
�[90m  code: 'ETIMEDOUT',�[39m
�[90m  syscall: 'connect',�[39m
�[90m  address: '10.0.145.27',�[39m
�[90m  port: 3000�[39m
�[90m}�[39m
�[37m[12/11/2024, 12:31:02 AM] �[39m�[36m[homebridge-lg-thinq]�[39m �[90m[request] post https://aic-service.lgthinq.com:46030/v1/service/devices/Redacted/control�[39m
�[37m[12/11/2024, 12:31:02 AM] �[39m�[36m[homebridge-lg-thinq]�[39m �[90mThinQ Device Received the Command�[39m

@merdok
Copy link
Owner

merdok commented Dec 11, 2024

Thanks for the update, i do not see anything unusual...

@JasonGoldenDDT
Copy link
Author

I suspect the EDTIMEOUT event is occurring at moments when automation triggers fire. How can we make this more reliable for TVs?

@merdok
Copy link
Owner

merdok commented Dec 12, 2024

The timeout comes from the fact that the tv does not respond. I am not sure whether we can do something about it

@JasonGoldenDDT
Copy link
Author

Is it possible to incorporate error handling here? The TV exists, it's' not moving IP or location, it's simply the nature of wifi I assume.

Seems like the software could retry in a way that ensures Home has the actual state of the device.

It's odd how a few seconds before I see "Connected" messages then the failure. Then "Connected."

Generally these are around automation triggered events, Home is asking to know and the connection fails.

Could logic be incorporated to not respond to Home until a connection is successful as a possible example of error handling?

I'm flagging this with HomeBridge and Node as well, since the 22.12 I'm noticing odd behavior with this and the Samsung plugin as well. IDK if Node is the cause.

@merdok
Copy link
Owner

merdok commented Dec 12, 2024

Possibly, that would need to be investigated...

@JasonGoldenDDT
Copy link
Author

Still working on collecting meaning full log data around events.

I'm looking at two days of debug data that includes HAP-Node.js messages and I'm seeing a pattern. Repetitive, frequent updates of the same information by this plugin.

In observing this plugin, it seems like it is over sampling the status of the TV, perhaps overwhelming homebridge and HomeKit with repetitive messages.

2024-12-20T18:15:40.669Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:15:49.280Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:15:49.282Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:16:27.881Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:16:40.693Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:16:44.206Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:16:49.465Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:16:49.466Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:17:40.697Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:18:41.408Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:19:41.643Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:20:41.644Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:21:41.651Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:22:41.706Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:23:41.701Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:24:41.701Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:25:41.720Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:26:42.648Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:27:42.656Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:28:42.669Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:29:42.701Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:30:42.710Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:31:42.721Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:32:42.766Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:33:42.811Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:34:43.125Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:35:43.660Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:36:43.658Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:37:38.173Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:37:38.174Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:37:43.677Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:38:43.674Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:39:43.679Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:40:43.719Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:41:43.768Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:42:43.698Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:43:43.688Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:44:44.636Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:45:44.635Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:46:44.642Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:47:44.684Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:48:44.673Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:49:44.688Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:50:44.696Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:51:44.782Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:52:45.643Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:53:45.636Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:54:45.686Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:55:45.688Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:56:45.698Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:57:45.695Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:58:46.633Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T18:59:46.617Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T19:00:46.617Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"
2024-12-20T19:01:46.613Z HAP-NodeJS:Accessory [Display A1E9] Got Characteristic "Firmware Revision" value: "04.41.09"

@merdok
Copy link
Owner

merdok commented Dec 21, 2024

The firmware version is fetched after a connection has been established with the TV, the above log just means that the plugin lost connection to your TV and reconnects after some time.

@JasonGoldenDDT
Copy link
Author

Thanks for that clarification. I assumed as much as I see a lot of TV meta data getting pushed a lot. It seems like a waste of energy for a static device like a TV.

Given the instability of the pipe (Wifi) and its high failure rate it seems like you'd want to send the least to ensure a complete message is received. Perhaps this is not configurable.

For awhile I associated this issue with the iPhone being locked and the home app not being on screen, as when doing so a device's status updates in near real time.

When you can, could you point me to the code that manages the update frequency of TVs and how their status is synced with the Home App?

For awhile I associated this issue with the iPhone being locked and the home app not being on screen, as when doing so a device's status updates in near real time.

If there is a tell I can look for related to connection quality, let me know. I use a inSSIDer on my Mac to manually tune wifi to the least crowded channel and I have an overall wifi connection metric over 87% for the 52 devices on the network with a wired mesh network using Amplifi Alien wifi 6 routers. Devices are coded to a specific SSID ideal for their location and use case.

Let me know if I can share any additional context to assist in the development of this solution . Thank you for working on this project.

@merdok
Copy link
Owner

merdok commented Dec 22, 2024

There is no update frequency, the updates are pushed from the tv whenever something changes there. You have to investigate your local network and check why your tv gets disconnected from the network so frequently.

@JasonGoldenDDT
Copy link
Author

I took a few hours to summarize a few days of debug data, focused on HAP-Node messages "got characteristics." Looking for odd activity.

I have a Samsung tv on my network, also wifi 5Ghz within a few feet of AP.

In looking at summarized log data, something seems off. The TV is only on for 15 minutes a day in the evening between 7 pm and 8:25 pm.

Screenshot 2024-12-22 at 9 50 46 AM Screenshot 2024-12-22 at 9 52 41 AM Screenshot 2024-12-22 at 10 01 20 AM

Homebridge HAP Node Activity Analysis.xlsx

@merdok
Copy link
Owner

merdok commented Dec 22, 2024

Thanks for the data, what does seem off for you?

@JasonGoldenDDT
Copy link
Author

The volume of updates to Firmware version to home app is much higher than other commands.

A lot of activity for a device that is used for 15-20 minute a day.

Im trying to find why this tv falls out of sync with the home app so often.

It's powered on via its hdmi connection when the Apple TV wakes.

Idk if this method is not reported by the tv or acknowledged by the plugin.

@merdok
Copy link
Owner

merdok commented Dec 22, 2024

I mean you have to investigate why your tv disconnects so frequently, did you try to use a LAN connection to see if that results in an improvement?

@JasonGoldenDDT
Copy link
Author

Yeah that's been a year long tuning of wifi here. LAN isn't an option in my current location, and wifi is strong, the AP is within a few feet, line of sight and the connection remains stable when I watch my router's admin UI for network topology. I've tuned my wifi network manually choosing radio channels. Reducing disconnects.

Screenshot 2024-12-23 at 7 26 26 AM

It's something in the software. The failure generally occurs when the tv is called by an automation trigger.

Screenshot 2024-12-23 at 7 24 57 AM

I'll come back to this after the holidays. I'm simply try to track down the cause. Plugin? Node? Home? Homebridge? Hard to say... I can simply say that the plugin's reliability is low and breaks automation daily.

@merdok
Copy link
Owner

merdok commented Dec 23, 2024

Ok, thanks for the update! Let me know when you find anything new. Happy holidays!

@JasonGoldenDDT
Copy link
Author

Happy Holidays!

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

2 participants