Power off issue

[kaohlive]

The app does not want to be aware that the tv is off. If I power the TV off using the remote the app never detects it as being off. If I power off using the app the app confirms the off state for a second and than the button turns back to on state. It then never gets to the off state again. Pressing the button to the off state does nothing with the tv (probably tries to shutdown but since its off already...).

[kaohlive]

So here is some info from the log on power down: state: 'Active', processing: 'Request Power Off' } state: 'Active', processing: 'Request Active Standby' } state: 'Active', processing: 'Request Suspend' } state: 'Active', processing: 'Prepare Suspend' }

So far seems obvious, but then I get 2020-03-26 23:24:50 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: TV changed to active 2020-03-26 23:24:50 [log] [ManagerDrivers] [webos_plus] [0] powerStateListener: received on 2020-03-26 23:24:50 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://com.webos.service.tvpower/power/getPowerState 2020-03-26 23:24:50 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Power state changed { returnValue: true, Between every power state request

And after the last one:

2020-03-26 23:24:50 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: TV changed to active 2020-03-26 23:24:50 [log] [ManagerDrivers] [webos_plus] [0] powerStateListener: received on 2020-03-26 23:24:50 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://system/turnOff 2020-03-26 23:24:50 [log] [ManagerDrivers] [webos_plus] [0] _turnOff: TV turned off successfully 2020-03-26 23:24:50 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://com.webos.applicationManager/getForegroundAppInfo 2020-03-26 23:24:50 [log] [ManagerDrivers] [webos_plus] [0] _appListener: App/input changed to 2020-03-26 23:24:50 [log] [ManagerDrivers] [webos_plus] [0] appListener: App/input changed from com.webos.app.hdmi2 to 2020-03-26 23:24:50 [log] [ManagerDrivers] [webos_plus] [0] appListener: Store currentApp set to 2020-03-26 23:24:50 [log] [ManagerDrivers] [webos_plus] [0] appListener: Flow trigger app/input changed 2020-03-26 23:24:50 [log] [ManagerDrivers] [webos_plus] [0] appListener: Gather media screen information for 2020-03-26 23:24:50 [log] [ManagerDrivers] [webos_plus] [0] _appList: Send request to retrieve all apps/inputs 2020-03-26 23:25:05 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://com.webos.applicationManager/listLaunchPoints 2020-03-26 23:25:05 [err] [ManagerDrivers] [webos_plus] [0] ssap://com.webos.applicationManager/listLaunchPoints Error: timeout at Timeout._onTimeout (/drivers/webos_plus/lgtv2/lgtv2.js:222:18) at ontimeout (timers.js:498:11) at tryOnTimeout (timers.js:323:5) at Timer.listOnTimeout (timers.js:290:5) 2020-03-26 23:25:05 [err] [ManagerDrivers] [webos_plus] [0] _appList: ssap://com.webos.applicationManager/listLaunchPoints with result: undefined 2020-03-26 23:25:05 [err] [ManagerDrivers] [webos_plus] [0] Error: timeout at Timeout._onTimeout (/drivers/webos_plus/lgtv2/lgtv2.js:222:18) at ontimeout (timers.js:498:11) at tryOnTimeout (timers.js:323:5) at Timer.listOnTimeout (timers.js:290:5) 2020-03-26 23:25:05 [err] [ManagerDrivers] [webos_plus] [0] appListener: No Apps/inputs found

[MaxvandeLaar]

@kaohlive Could you try https://github.com/MaxvandeLaar/homey-webos-plus/releases/tag/v2.0.0-rc2?

[kaohlive]

power on seems to work reliable and when its turned on by remote it still is picked up rather quickly (1 sec). poweroff works through the app ok, inclyding the right state. but it never detects a remote button off

[MaxvandeLaar]

@kaohlive, good to hear things at least improved. Do you by any chance have the logs when you power off with the remote? It's possible the logic is still not good enough for your state changes. I have an idea what the issue could be, however I'd like to verify in the logs before tinkering :)

[MaxvandeLaar]

@kaohlive, So I might just figured out why your tv is much faster than mine and now I experience the same behaviour as you... the tv is not turned off in the app. I guess you have quick start+ turned on?

[kaohlive]

i do, i love these quick loads 😚

[kaohlive]

on the log, need to wait till my family is asleep, can bother them with that during prime time

[MaxvandeLaar]

@kaohlive, that's okay thanks for trying and all the testing. I am amazed with how fast the response time is when quick start+ is turned on. It's pretty much instant detected by the web app. So now I can reproduce it, I can also test it and got a fix already. Currently finetuning the timeout but I suppose it won't be much longer than 1 or 2 seconds. I'll let you know when I have a rc3 released so you can try that instead of uploading logs ☺️

[kaohlive]

@MaxvandeLaar strange, after a while the poweron problem came back, restarting the app made it go away (for now)

[MaxvandeLaar]

@kaohlive hmm okay, I first only wanted to set a timeout on the off state check, but this makes me think it's best to just use the timeout for on and off checking. I made the timeout interval a setting so everyone can fine-tune it to their likings. The default value will be 2 seconds (used to be 2 minutes) so still a drastic improvement. I'll test it a bit more before making a new release

[MaxvandeLaar]

@kaohlive Here is v2.0.0-rc3 https://github.com/MaxvandeLaar/homey-webos-plus/releases/tag/v2.0.0-rc3

So the major problem with the new state listener is that the TV fires an event even when its processing turning on/off (as you probably noticed in the loggin). This makes the state check unreliable and without knowing the possible states and processes the tv goes through I had to come up with something else.

How it works now, when the stateListener is called a timeout is set for x ms (2000ms default). This timeout is reset for every state change event sent by the tv unless the timeout interval is reached.

This means a lower interval setting will give the tv less time to send events when turning on/off. So checking the actual state will be faster however comes with the cost of being less reliable as the tv might send a delayed event... Setting a higher interval setting gives the check more time between events and it's more certain the tv actually reached its final state.

So I tested by turning the tv on/off with the remote for some time and I hardly notice the 2 second delay there is. Let me know how it works for you

[kaohlive]

Unfortunately it is getting a bit worse for my tv :(. Now the TV shutdown again and the off state is still missed in any scenario other than shutdown from the app.

[kaohlive]

Shutdown event using the remote: 2020-03-27 22:25:27 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://com.webos.service.tvpower/power/getPowerState 2020-03-27 22:25:27 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Power state changed { returnValue: true, state: 'Active', processing: 'Request Power Off' } 2020-03-27 22:25:27 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Set timeout to 5000 ms and check the state 2020-03-27 22:25:27 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://com.webos.service.tvpower/power/getPowerState 2020-03-27 22:25:27 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Reset timer 2020-03-27 22:25:27 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Power state changed { returnValue: true, state: 'Active', processing: 'Request Active Standby' } 2020-03-27 22:25:27 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Set timeout to 5000 ms and check the state 2020-03-27 22:25:27 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://com.webos.service.tvpower/power/getPowerState 2020-03-27 22:25:27 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Reset timer 2020-03-27 22:25:27 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Power state changed { returnValue: true, state: 'Active', processing: 'Request Suspend' } 2020-03-27 22:25:27 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Set timeout to 5000 ms and check the state 2020-03-27 22:25:27 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://com.webos.service.tvpower/power/getPowerState 2020-03-27 22:25:27 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Reset timer 2020-03-27 22:25:27 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Power state changed { returnValue: true, state: 'Active', processing: 'Prepare Suspend' } 2020-03-27 22:25:27 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Set timeout to 5000 ms and check the state 2020-03-27 22:25:27 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://com.webos.applicationManager/getForegroundAppInfo 2020-03-27 22:25:27 [log] [ManagerDrivers] [webos_plus] [0] _appListener: App/input changed to 2020-03-27 22:25:27 [log] [ManagerDrivers] [webos_plus] [0] appListener: App/input changed from com.webos.app.hdmi2 to 2020-03-27 22:25:27 [log] [ManagerDrivers] [webos_plus] [0] appListener: Store currentApp set to 2020-03-27 22:25:27 [log] [ManagerDrivers] [webos_plus] [0] appListener: Flow trigger app/input changed 2020-03-27 22:25:27 [log] [ManagerDrivers] [webos_plus] [0] appListener: Gather media screen information for 2020-03-27 22:25:27 [log] [ManagerDrivers] [webos_plus] [0] _appList: Send request to retrieve all apps/inputs 2020-03-27 22:25:27 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://com.webos.applicationManager/listLaunchPoints 2020-03-27 22:25:27 [log] [ManagerDrivers] [webos_plus] [0] _appList: Retrieved all apps/inputs successfully 2020-03-27 22:25:27 [log] [ManagerDrivers] [webos_plus] [0] _appList: Mapped all apps/inputs and resolve 2020-03-27 22:25:27 [err] [ManagerDrivers] [webos_plus] [0] appListener: No app found for 2020-03-27 22:25:32 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Called timeout active Prepare Suspend 2020-03-27 22:25:32 [log] [ManagerDrivers] [webos_plus] [0] powerStateListener: received on

Final result, the App thinks the TV is still on several minutes after the shutdown event.

Next I correct the app mode by turning it off from the app.

Next turn on from the remote:

2020-03-27 22:28:47 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://com.webos.service.tvpower/power/getPowerState 2020-03-27 22:28:47 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Power state changed { returnValue: true, state: 'Suspend' } 2020-03-27 22:28:47 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Set timeout to 5000 ms and check the state 2020-03-27 22:28:47 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://com.webos.service.tvpower/power/getPowerState 2020-03-27 22:28:47 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Reset timer 2020-03-27 22:28:47 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Power state changed { returnValue: true, state: 'Suspend', processing: 'Prepare Resume' } 2020-03-27 22:28:47 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Set timeout to 5000 ms and check the state 2020-03-27 22:28:47 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://com.webos.service.tvpower/power/getPowerState 2020-03-27 22:28:47 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Reset timer 2020-03-27 22:28:47 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Power state changed { returnValue: true, state: 'Suspend', processing: 'LastInput Ready', powerOnReason: 'remoteKey' } 2020-03-27 22:28:47 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Set timeout to 5000 ms and check the state 2020-03-27 22:28:47 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://com.webos.service.tvpower/power/getPowerState 2020-03-27 22:28:47 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Reset timer 2020-03-27 22:28:47 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Power state changed { returnValue: true, state: 'Suspend', processing: 'Screen On' } 2020-03-27 22:28:47 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Set timeout to 5000 ms and check the state 2020-03-27 22:28:47 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://com.webos.service.tvpower/power/getPowerState 2020-03-27 22:28:47 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Reset timer 2020-03-27 22:28:47 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Power state changed { returnValue: true, state: 'Active' } 2020-03-27 22:28:47 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Set timeout to 5000 ms and check the state 2020-03-27 22:28:48 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://com.webos.applicationManager/getForegroundAppInfo 2020-03-27 22:28:48 [log] [ManagerDrivers] [webos_plus] [0] _appListener: App/input changed to com.webos.app.hdmi2 2020-03-27 22:28:48 [log] [ManagerDrivers] [webos_plus] [0] appListener: App/input changed from to com.webos.app.hdmi2 2020-03-27 22:28:48 [log] [ManagerDrivers] [webos_plus] [0] appListener: Store currentApp set to com.webos.app.hdmi2 2020-03-27 22:28:48 [log] [ManagerDrivers] [webos_plus] [0] appListener: Flow trigger app/input changed 2020-03-27 22:28:48 [log] [ManagerDrivers] [webos_plus] [0] appListener: Gather media screen information for com.webos.app.hdmi2 2020-03-27 22:28:48 [log] [ManagerDrivers] [webos_plus] [0] _appList: Send request to retrieve all apps/inputs 2020-03-27 22:28:48 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://com.webos.service.apiadapter/audio/getSoundOutput 2020-03-27 22:28:48 [log] [ManagerDrivers] [webos_plus] [0] _soundOutputListener: Sound output changed to external_speaker 2020-03-27 22:28:48 [log] [ManagerDrivers] [webos_plus] [0] soundOutputListener: Sound output changed from external_speaker to external_speaker 2020-03-27 22:28:48 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://com.webos.applicationManager/listLaunchPoints 2020-03-27 22:28:48 [log] [ManagerDrivers] [webos_plus] [0] _appList: Retrieved all apps/inputs successfully 2020-03-27 22:28:48 [log] [ManagerDrivers] [webos_plus] [0] _appList: Mapped all apps/inputs and resolve 2020-03-27 22:28:48 [log] [ManagerDrivers] [webos_plus] [0] appListener: App found for 'com.webos.app.hdmi2' HDMI2 2020-03-27 22:28:48 [log] [ManagerDrivers] [webos_plus] [0] appListener: Try to get the current channel to gather more media screen information for 'com.webos.app.hdmi2' HDMI2 2020-03-27 22:28:48 [log] [ManagerDrivers] [webos_plus] [0] _channelCurrent: Send request to get the current channel 2020-03-27 22:28:48 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://tv/getCurrentChannel 2020-03-27 22:28:48 [log] [ManagerDrivers] [webos_plus] [0] _channelCurrent: Success getting channel 2020-03-27 22:28:48 [log] [ManagerDrivers] [webos_plus] [0] appListener: Channel found for 'com.webos.app.hdmi2' HDMI2. Set capability speaker_track to '' 2020-03-27 22:28:48 [log] [ManagerDrivers] [webos_plus] [0] appListener: Set image for 'com.webos.app.hdmi2' HDMI2 (http://192.168.1.30:3000/resources/1138b87ec3ca90d975b01b854dcf7b21ba06b1da/HDMI_2.png) 2020-03-27 22:28:53 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Called timeout active null 2020-03-27 22:28:53 [log] [ManagerDrivers] [webos_plus] [0] powerStateListener: received on

Ok, TV turned on and stayed on. The app also detected the ON state nicely.

Next turn off from the app:

2020-03-27 22:30:23 [log] [ManagerDrivers] [webos_plus] [0] toggleOnOff: Called false 2020-03-27 22:30:23 [log] [ManagerDrivers] [webos_plus] [0] toggleOnOff: Try to turn the tv off 2020-03-27 22:30:23 [log] [ManagerDrivers] [webos_plus] [0] _turnOff: Send request to turn the TV off 2020-03-27 22:30:23 [log] [ManagerDrivers] [webos_plus] [0] toggleOnOff: TV turned off. Set capability onoff to false 2020-03-27 22:30:23 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://com.webos.service.tvpower/power/getPowerState 2020-03-27 22:30:23 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Power state changed { returnValue: true, state: 'Active', processing: 'Request Power Off' } 2020-03-27 22:30:23 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Set timeout to 5000 ms and check the state 2020-03-27 22:30:23 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://com.webos.service.tvpower/power/getPowerState 2020-03-27 22:30:23 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Reset timer 2020-03-27 22:30:23 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Power state changed { returnValue: true, state: 'Active', processing: 'Request Active Standby' } 2020-03-27 22:30:23 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Set timeout to 5000 ms and check the state 2020-03-27 22:30:23 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://com.webos.service.tvpower/power/getPowerState 2020-03-27 22:30:23 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Reset timer 2020-03-27 22:30:23 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Power state changed { returnValue: true, state: 'Active', processing: 'Request Suspend' } 2020-03-27 22:30:23 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Set timeout to 5000 ms and check the state 2020-03-27 22:30:23 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://system/turnOff 2020-03-27 22:30:23 [log] [ManagerDrivers] [webos_plus] [0] _turnOff: TV turned off successfully 2020-03-27 22:30:23 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://com.webos.service.tvpower/power/getPowerState 2020-03-27 22:30:23 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Reset timer 2020-03-27 22:30:23 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Power state changed { returnValue: true, state: 'Active', processing: 'Prepare Suspend' } 2020-03-27 22:30:23 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Set timeout to 5000 ms and check the state 2020-03-27 22:30:23 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://com.webos.applicationManager/getForegroundAppInfo 2020-03-27 22:30:23 [log] [ManagerDrivers] [webos_plus] [0] _appListener: App/input changed to 2020-03-27 22:30:23 [log] [ManagerDrivers] [webos_plus] [0] appListener: App/input changed from com.webos.app.hdmi2 to 2020-03-27 22:30:23 [log] [ManagerDrivers] [webos_plus] [0] appListener: Store currentApp set to 2020-03-27 22:30:23 [log] [ManagerDrivers] [webos_plus] [0] appListener: Flow trigger app/input changed 2020-03-27 22:30:23 [log] [ManagerDrivers] [webos_plus] [0] appListener: Gather media screen information for 2020-03-27 22:30:23 [log] [ManagerDrivers] [webos_plus] [0] _appList: Send request to retrieve all apps/inputs 2020-03-27 22:30:23 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://com.webos.applicationManager/listLaunchPoints 2020-03-27 22:30:23 [log] [ManagerDrivers] [webos_plus] [0] _appList: Retrieved all apps/inputs successfully 2020-03-27 22:30:23 [log] [ManagerDrivers] [webos_plus] [0] _appList: Mapped all apps/inputs and resolve 2020-03-27 22:30:23 [err] [ManagerDrivers] [webos_plus] [0] appListener: No app found for 2020-03-27 22:30:28 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Called timeout active Prepare Suspend 2020-03-27 22:30:28 [log] [ManagerDrivers] [webos_plus] [0] powerStateListener: received on

Result, TV turned off ok, but the app showes the TV as on, the timeout is already set to 5 seconds as your can see.

Now I need to turn the app mode to off: 2020-03-27 22:32:19 [log] [ManagerDrivers] [webos_plus] [0] toggleOnOff: Called false 2020-03-27 22:32:19 [log] [ManagerDrivers] [webos_plus] [0] toggleOnOff: Try to turn the tv off 2020-03-27 22:32:19 [log] [ManagerDrivers] [webos_plus] [0] _turnOff: Send request to turn the TV off 2020-03-27 22:32:19 [log] [ManagerDrivers] [webos_plus] [0] toggleOnOff: TV turned off. Set capability onoff to false 2020-03-27 22:32:34 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://system/turnOff 2020-03-27 22:32:34 [err] [ManagerDrivers] [webos_plus] [0] ssap://system/turnOff Error: timeout at Timeout._onTimeout (/drivers/webos_plus/lgtv2/lgtv2.js:222:18) at ontimeout (timers.js:498:11) at tryOnTimeout (timers.js:323:5) at Timer.listOnTimeout (timers.js:290:5) 2020-03-27 22:32:34 [err] [ManagerDrivers] [webos_plus] [0] _turnOff: ssap://system/turnOff with result: undefined 2020-03-27 22:32:34 [err] [ManagerDrivers] [webos_plus] [0] Error: timeout at Timeout._onTimeout (/drivers/webos_plus/lgtv2/lgtv2.js:222:18) at ontimeout (timers.js:498:11) at tryOnTimeout (timers.js:323:5) at Timer.listOnTimeout (timers.js:290:5)

So a timeout since you cant turn off what is already off, makes sense. Now I want to turn the TV back on from the app:

2020-03-27 22:33:20 [log] [ManagerDrivers] [webos_plus] [0] toggleOnOff: Called true 2020-03-27 22:33:20 [log] [ManagerDrivers] [webos_plus] [0] toggleOnOff: Try to turn the tv on 2020-03-27 22:33:20 [log] [ManagerDrivers] [webos_plus] [0] _turnOn: Send request to turn on (WoL) with mac address 78:5d:c8:14:2e:e3 2020-03-27 22:33:20 [log] [ManagerDrivers] [webos_plus] [0] _turnOn: TV turned on successfully 2020-03-27 22:33:20 [log] [ManagerDrivers] [webos_plus] [0] toggleOnOff: TV turned on. Set capability onoff to true 2020-03-27 22:33:25 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://com.webos.service.tvpower/power/getPowerState 2020-03-27 22:33:25 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Power state changed { returnValue: true, state: 'Suspend' } 2020-03-27 22:33:25 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Set timeout to 5000 ms and check the state 2020-03-27 22:33:25 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://com.webos.service.tvpower/power/getPowerState 2020-03-27 22:33:26 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Reset timer 2020-03-27 22:33:26 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Power state changed { returnValue: true, state: 'Suspend', processing: 'Prepare Resume' } 2020-03-27 22:33:26 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Set timeout to 5000 ms and check the state 2020-03-27 22:33:26 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://com.webos.service.tvpower/power/getPowerState 2020-03-27 22:33:26 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Reset timer 2020-03-27 22:33:26 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Power state changed { returnValue: true, state: 'Suspend', processing: 'LastInput Ready', powerOnReason: 'wakeOnLan' } 2020-03-27 22:33:26 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Set timeout to 5000 ms and check the state 2020-03-27 22:33:26 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://com.webos.service.tvpower/power/getPowerState 2020-03-27 22:33:26 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Reset timer 2020-03-27 22:33:26 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Power state changed { returnValue: true, state: 'Suspend', processing: 'Screen On' } 2020-03-27 22:33:26 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Set timeout to 5000 ms and check the state 2020-03-27 22:33:26 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://com.webos.service.tvpower/power/getPowerState 2020-03-27 22:33:26 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Reset timer 2020-03-27 22:33:26 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Power state changed { returnValue: true, state: 'Active' } 2020-03-27 22:33:26 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Set timeout to 5000 ms and check the state 2020-03-27 22:33:26 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://com.webos.applicationManager/getForegroundAppInfo 2020-03-27 22:33:26 [log] [ManagerDrivers] [webos_plus] [0] _appListener: App/input changed to com.webos.app.hdmi2 2020-03-27 22:33:26 [log] [ManagerDrivers] [webos_plus] [0] appListener: App/input changed from to com.webos.app.hdmi2 2020-03-27 22:33:26 [log] [ManagerDrivers] [webos_plus] [0] appListener: Store currentApp set to com.webos.app.hdmi2 2020-03-27 22:33:26 [log] [ManagerDrivers] [webos_plus] [0] appListener: Flow trigger app/input changed 2020-03-27 22:33:26 [log] [ManagerDrivers] [webos_plus] [0] appListener: Gather media screen information for com.webos.app.hdmi2 2020-03-27 22:33:26 [log] [ManagerDrivers] [webos_plus] [0] _appList: Send request to retrieve all apps/inputs 2020-03-27 22:33:26 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://com.webos.service.apiadapter/audio/getSoundOutput 2020-03-27 22:33:26 [log] [ManagerDrivers] [webos_plus] [0] _soundOutputListener: Sound output changed to external_speaker 2020-03-27 22:33:26 [log] [ManagerDrivers] [webos_plus] [0] soundOutputListener: Sound output changed from external_speaker to external_speaker 2020-03-27 22:33:27 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://com.webos.service.tvpower/power/getPowerState 2020-03-27 22:33:27 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Reset timer 2020-03-27 22:33:27 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Power state changed { returnValue: true, state: 'Active', processing: 'Request Power Off' } 2020-03-27 22:33:27 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Set timeout to 5000 ms and check the state 2020-03-27 22:33:27 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://com.webos.applicationManager/listLaunchPoints 2020-03-27 22:33:27 [log] [ManagerDrivers] [webos_plus] [0] _appList: Retrieved all apps/inputs successfully 2020-03-27 22:33:27 [log] [ManagerDrivers] [webos_plus] [0] _appList: Mapped all apps/inputs and resolve 2020-03-27 22:33:27 [log] [ManagerDrivers] [webos_plus] [0] appListener: App found for 'com.webos.app.hdmi2' HDMI2 2020-03-27 22:33:27 [log] [ManagerDrivers] [webos_plus] [0] appListener: Try to get the current channel to gather more media screen information for 'com.webos.app.hdmi2' HDMI2 2020-03-27 22:33:27 [log] [ManagerDrivers] [webos_plus] [0] _channelCurrent: Send request to get the current channel 2020-03-27 22:33:27 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://com.webos.service.tvpower/power/getPowerState 2020-03-27 22:33:27 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Reset timer 2020-03-27 22:33:27 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Power state changed { returnValue: true, state: 'Active', processing: 'Request Active Standby' } 2020-03-27 22:33:27 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Set timeout to 5000 ms and check the state 2020-03-27 22:33:27 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://com.webos.service.tvpower/power/getPowerState 2020-03-27 22:33:27 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Reset timer 2020-03-27 22:33:27 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Power state changed { returnValue: true, state: 'Active', processing: 'Request Suspend' } 2020-03-27 22:33:27 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Set timeout to 5000 ms and check the state 2020-03-27 22:33:27 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://com.webos.service.tvpower/power/getPowerState 2020-03-27 22:33:27 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Reset timer 2020-03-27 22:33:27 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Power state changed { returnValue: true, state: 'Active', processing: 'Prepare Suspend' } 2020-03-27 22:33:27 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Set timeout to 5000 ms and check the state 2020-03-27 22:33:27 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://com.webos.applicationManager/getForegroundAppInfo 2020-03-27 22:33:27 [log] [ManagerDrivers] [webos_plus] [0] _appListener: App/input changed to 2020-03-27 22:33:27 [log] [ManagerDrivers] [webos_plus] [0] appListener: App/input changed from com.webos.app.hdmi2 to 2020-03-27 22:33:27 [log] [ManagerDrivers] [webos_plus] [0] appListener: Store currentApp set to 2020-03-27 22:33:27 [log] [ManagerDrivers] [webos_plus] [0] appListener: Flow trigger app/input changed 2020-03-27 22:33:27 [log] [ManagerDrivers] [webos_plus] [0] appListener: Gather media screen information for 2020-03-27 22:33:27 [log] [ManagerDrivers] [webos_plus] [0] _appList: Send request to retrieve all apps/inputs 2020-03-27 22:33:27 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://tv/getCurrentChannel 2020-03-27 22:33:27 [log] [ManagerDrivers] [webos_plus] [0] _channelCurrent: Success getting channel 2020-03-27 22:33:27 [log] [ManagerDrivers] [webos_plus] [0] appListener: Channel found for 'com.webos.app.hdmi2' HDMI2. Set capability speaker_track to '' 2020-03-27 22:33:27 [log] [ManagerDrivers] [webos_plus] [0] appListener: Set image for 'com.webos.app.hdmi2' HDMI2 (http://192.168.1.30:3000/resources/1138b87ec3ca90d975b01b854dcf7b21ba06b1da/HDMI_2.png) 2020-03-27 22:33:32 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Called timeout active Prepare Suspend 2020-03-27 22:33:32 [log] [ManagerDrivers] [webos_plus] [0] powerStateListener: received on 2020-03-27 22:33:42 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://com.webos.applicationManager/listLaunchPoints 2020-03-27 22:33:42 [err] [ManagerDrivers] [webos_plus] [0] ssap://com.webos.applicationManager/listLaunchPoints Error: timeout at Timeout._onTimeout (/drivers/webos_plus/lgtv2/lgtv2.js:222:18) at ontimeout (timers.js:498:11) at tryOnTimeout (timers.js:323:5) at Timer.listOnTimeout (timers.js:290:5) 2020-03-27 22:33:42 [err] [ManagerDrivers] [webos_plus] [0] _appList: ssap://com.webos.applicationManager/listLaunchPoints with result: undefined 2020-03-27 22:33:42 [err] [ManagerDrivers] [webos_plus] [0] Error: timeout at Timeout._onTimeout (/drivers/webos_plus/lgtv2/lgtv2.js:222:18) at ontimeout (timers.js:498:11) at tryOnTimeout (timers.js:323:5) at Timer.listOnTimeout (timers.js:290:5) 2020-03-27 22:33:42 [err] [ManagerDrivers] [webos_plus] [0] appListener: No Apps/inputs found

Result, TV turned on for a couple of seconds and then turned off again. App thinks it ON now though.

Hope these logs help, if you can get this stable its an amazing app 👍

[kaohlive]

On the poweroff detection: What strikes me as odd is the line: 2020-03-27 22:25:32 [log] [ManagerDrivers] [webos_plus] [0] powerStateListener: received on

After both shutdown events we still receive an ON. I think that's the main bug. You can see in the first part the remote power off did trigger a Request Power Off event nicely. Then the entire state cycle happens: Request Active Standby/Request Suspend/Prepare Suspend it does this in both cases (from remote and app). But if we than receive the powerStateListener: received on your code triggers the: this.log(powerStateListener: received on); //The log entry we see there this.setCapabilityValue(capabilities.onOff, true); //Setting the capability back to ON, seems wrong

So I do not think you need the polling, since the TV is sending the events properly, but why is the received ON event triggered.

[kaohlive]

On the poweroff while activating the TV, the last log: 2020-03-27 22:33:27 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Power state changed { returnValue: true, state: 'Active', processing: 'Request Power Off' } There is a clear log entry that something seems to perform a request power off. The big question is here, what is now doing that? As soon as this happens you see the logs mixed with events trying to handle the ON while the OFF is resulting in the power down cycle, including the received on entry.

I see no log that shows the app might be sending the power down, so you would almost think its the remote button. But I promise I am not messing with it ;)

[kaohlive]

Now after writing the above comments, I turned it on with the remote resulting in this log: 2020-03-27 22:51:02 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://com.webos.service.tvpower/power/getPowerState 2020-03-27 22:51:02 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Power state changed { returnValue: true, state: 'Suspend' } 2020-03-27 22:51:02 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Set timeout to 5000 ms and check the state 2020-03-27 22:51:02 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://com.webos.service.tvpower/power/getPowerState 2020-03-27 22:51:02 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Reset timer 2020-03-27 22:51:02 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Power state changed { returnValue: true, state: 'Suspend', processing: 'Prepare Resume' } 2020-03-27 22:51:02 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Set timeout to 5000 ms and check the state 2020-03-27 22:51:02 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://com.webos.service.tvpower/power/getPowerState 2020-03-27 22:51:02 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Reset timer 2020-03-27 22:51:02 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Power state changed { returnValue: true, state: 'Suspend', processing: 'LastInput Ready', powerOnReason: 'remoteKey' } 2020-03-27 22:51:02 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Set timeout to 5000 ms and check the state 2020-03-27 22:51:02 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://com.webos.service.tvpower/power/getPowerState 2020-03-27 22:51:02 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Reset timer 2020-03-27 22:51:02 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Power state changed { returnValue: true, state: 'Suspend', processing: 'Screen On' } 2020-03-27 22:51:02 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Set timeout to 5000 ms and check the state 2020-03-27 22:51:02 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://com.webos.service.tvpower/power/getPowerState 2020-03-27 22:51:03 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Reset timer 2020-03-27 22:51:03 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Power state changed { returnValue: true, state: 'Active' } 2020-03-27 22:51:03 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Set timeout to 5000 ms and check the state 2020-03-27 22:51:03 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://com.webos.applicationManager/getForegroundAppInfo 2020-03-27 22:51:03 [log] [ManagerDrivers] [webos_plus] [0] _appListener: App/input changed to com.webos.app.hdmi2 2020-03-27 22:51:03 [log] [ManagerDrivers] [webos_plus] [0] appListener: App/input changed from to com.webos.app.hdmi2 2020-03-27 22:51:03 [log] [ManagerDrivers] [webos_plus] [0] appListener: Store currentApp set to com.webos.app.hdmi2 2020-03-27 22:51:03 [log] [ManagerDrivers] [webos_plus] [0] appListener: Flow trigger app/input changed 2020-03-27 22:51:03 [log] [ManagerDrivers] [webos_plus] [0] appListener: Gather media screen information for com.webos.app.hdmi2 2020-03-27 22:51:03 [log] [ManagerDrivers] [webos_plus] [0] _appList: Send request to retrieve all apps/inputs 2020-03-27 22:51:03 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://com.webos.service.apiadapter/audio/getSoundOutput 2020-03-27 22:51:03 [log] [ManagerDrivers] [webos_plus] [0] _soundOutputListener: Sound output changed to external_speaker 2020-03-27 22:51:03 [log] [ManagerDrivers] [webos_plus] [0] soundOutputListener: Sound output changed from external_speaker to external_speaker 2020-03-27 22:51:03 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://com.webos.applicationManager/listLaunchPoints 2020-03-27 22:51:03 [log] [ManagerDrivers] [webos_plus] [0] _appList: Retrieved all apps/inputs successfully 2020-03-27 22:51:03 [log] [ManagerDrivers] [webos_plus] [0] _appList: Mapped all apps/inputs and resolve 2020-03-27 22:51:03 [log] [ManagerDrivers] [webos_plus] [0] appListener: App found for 'com.webos.app.hdmi2' HDMI2 2020-03-27 22:51:03 [log] [ManagerDrivers] [webos_plus] [0] appListener: Try to get the current channel to gather more media screen information for 'com.webos.app.hdmi2' HDMI2 2020-03-27 22:51:03 [log] [ManagerDrivers] [webos_plus] [0] _channelCurrent: Send request to get the current channel 2020-03-27 22:51:03 [log] [ManagerDrivers] [webos_plus] [0] _handleResponse: ssap://tv/getCurrentChannel 2020-03-27 22:51:03 [log] [ManagerDrivers] [webos_plus] [0] _channelCurrent: Success getting channel 2020-03-27 22:51:03 [log] [ManagerDrivers] [webos_plus] [0] appListener: Channel found for 'com.webos.app.hdmi2' HDMI2. Set capability speaker_track to '' 2020-03-27 22:51:03 [log] [ManagerDrivers] [webos_plus] [0] appListener: Set image for 'com.webos.app.hdmi2' HDMI2 (http://192.168.1.30:3000/resources/1138b87ec3ca90d975b01b854dcf7b21ba06b1da/HDMI_2.png) 2020-03-27 22:51:08 [log] [ManagerDrivers] [webos_plus] [0] _powerStateListener: Called timeout active null 2020-03-27 22:51:08 [log] [ManagerDrivers] [webos_plus] [0] powerStateListener: received on

And a properly turnon tv.

[kaohlive]

I think I see the issue, on your state checks during the power down you get: { returnValue: true, state: 'Active', processing: 'Request Active Standby' } { returnValue: true, state: 'Active', processing: 'Request Suspend' } { returnValue: true, state: 'Active', processing: 'Prepare Suspend' }

So this last state check should put the state value to 'Active' And then you call the timer with the state value and wait x seconds and call Active! timer = setTimeout(() => { this.log(_powerStateListener: Called timeout, status, processing); if (status === 'active') { handleOn(); } if (status !== 'active') { handleOff(); } clearTimeout(timer); timer = null; }, this.getSettings().powerStateTimeout || 2000);

But within the Timer you do not update the state, so you assume an state event will come in with a non active value. So you reset the timer on such a new event, so it gives you 2 seconds to get a new event in. In the hope one will be with the !=== 'active' state. But that never happens, No matter how long I watch the log, no event comes in with after the power down with a state 'suspend' or something like that. That only happens during the poweron.

[kaohlive]

So I changed the code to: timer = setTimeout(() => { this.log(_powerStateListener: Called timeout, status, processing); if (processing === null || processing === 'Screen On') { handleOn(); } else if (processing === 'Prepare Suspend') { handleOff(); } clearTimeout(timer); timer = null; }, this.getSettings().powerStateTimeout || 2000);

And for me it seems to work, put the delay down to 500ms and almost instand on and off detection on my screen. So instead of using the active value I use the processing value to detect what is happening.

[MaxvandeLaar]

@kaohlive without checking all the log lines you send (just woke up) I agree with what the actually issue is. I am not yet really sure if the fix you wrote will work. So I have 2 LG tv's one in the living room and one on the second floor. The living room tv works (my rc3.0 code) perfectly, the second floor tv did not registered it going off.

I could not check the log at that time, however I believe it is the same issue as you are experiencing. I will need to do some comparing to create the correct off logic but it looks like LG tv don't share the same off process...

[MaxvandeLaar]

@kaohlive can we close this? Or do you still experience issues with the release of v2.0.0?

[kaohlive]

i did not update since my own hotfixed version. ill give the new one a go tonight. but you can close this one, its related to an old versiin anyway 👍

[MaxvandeLaar]

@kaohlive, I implemented your hot fix however changed it slightly so I suppose you can upgrade without any issues