Open alikhodrali opened 2 years ago
Hi @alikhodrali.
Judging by the timeout error, I don't believe it is an error caused by the shell script. I would bet for the homebridge configuration. I say that the shell script is never called.
Have you located the shell script file at /var/lib/homebridge/? And did you make it executable?
When you go to /var/lib/homebridge/ and you execute an ls command, you should get something like this for the script. Check for execution and owner:
pi@homebridge:/var/lib/homebridge $ ls -al
-rwxr-xr-x 1 pi pi 4830 Dec 30 08:35 appletv_control.sh
I did make it executable. I'm getting exactly -rwxr-xr-x as well. I will show you the part of my config file for homebridge. Maybe I'm missing something?
{ "platform": "Cmd4", "name": "Cmd4", "interval": 5, "timeout": 4000, "debug": true, "stateChangeResponseTime": 3, "queueTypes": [ { "queue": "A", "queueType": "WoRm" } ], "accessories": [ { "type": "Switch", "displayName": "Apple TV Power", "on": "FALSE", "queue": "A", "polling": [ { "characteristic": "on" } ], "state_cmd": "bash /var/lib/homebridge/appletv_control.sh" }, { "type": "Switch", "displayName": "Apple TV Play State", "on": "FALSE", "queue": "A", "polling": [ { "characteristic": "on" } ], "state_cmd": "bash /var/lib/homebridge/appletv_control.sh" } ] },
I believe I found the issue.
You seem to have changed the characteristics into all small letters but they need to be exactly as in the shell script.
What answer do you get when you execute this command in the terminal?
/var/lib/homebridge/appletv_control.sh Get "Apple TV Power" on
And when you execute this command?
/var/lib/homebridge/appletv_control.sh Get "Apple TV Power" On
If the first one fails and the second one gives you the status of the Apple TV in the form of 0 or 1, then you have to change the lines in your Homebridge configuration from this:
"characteristic": "on"
To this
"characteristic": "On"
So I changed it to "On" because you were right and it worked that way but I'm still getting the error. Should I change the commands in the homebridge config in that case?
I removed the comments for the debug lines in appletv_control.sh and here is my homebridge log below. It's showing error 255. What does this signify?
[24/02/2022, 21:52:59] [Cmd4] Processing high priority queue "Get" entry: 106 isUpdate: true length: 3 [24/02/2022, 21:52:59] [Cmd4] getValue: accTypeEnumIndex:( 106 )-"On" function for: Apple TV Play State cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Play State' 'On' timeout: 5000 [24/02/2022, 21:53:00] [Cmd4] Processing high priority queue "Get" entry: 106 isUpdate: true length: 2 [24/02/2022, 21:53:00] [Cmd4] getValue: accTypeEnumIndex:( 106 )-"On" function for: Apple TV Power cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On' timeout: 5000 [24/02/2022, 21:53:00] [Cmd4] Processing high priority queue "Get" entry: 106 isUpdate: true length: 1 [24/02/2022, 21:53:00] [Cmd4] getValue: accTypeEnumIndex:( 106 )-"On" function for: Apple TV Power cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On' timeout: 5000 [24/02/2022, 21:53:00] [Cmd4] Processing high priority queue "Get" entry: 106 isUpdate: true length: 0 [24/02/2022, 21:53:00] [Cmd4] getValue: accTypeEnumIndex:( 106 )-"On" function for: Apple TV Play State cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Play State' 'On' timeout: 5000 [24/02/2022, 21:53:00] [Cmd4] getValue On function failed for Apple TV Power cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On' Failed. Generated Error: Error: Command failed: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On'
[24/02/2022, 21:53:00] [Cmd4] getValue On function failed for Apple TV Power cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On' Failed. Error: 255. Perhaps your device is busy? [24/02/2022, 21:53:00] [Cmd4] getValue On function failed for Apple TV Power cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On' Failed. Generated Error: Error: Command failed: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On'
[24/02/2022, 21:53:00] [Cmd4] getValue On function failed for Apple TV Power cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On' Failed. Error: 255. Perhaps your device is busy? [24/02/2022, 21:53:00] [Cmd4] getValue On function failed for Apple TV Play State cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Play State' 'On' Failed. Generated Error: Error: Command failed: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Play State' 'On'
[24/02/2022, 21:53:00] [Cmd4] getValue On function failed for Apple TV Play State cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Play State' 'On' Failed. Error: 255. Perhaps your device is busy? [24/02/2022, 21:53:00] [Cmd4] getValue On function failed for Apple TV Play State cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Play State' 'On' Failed. Generated Error: Error: Command failed: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Play State' 'On'
[24/02/2022, 21:53:00] [Cmd4] getValue On function failed for Apple TV Play State cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Play State' 'On' Failed. Error: 255. Perhaps your device is busy?
So I changed it to "On" because you were right and it worked that way but I'm still getting the error. Should I change the commands in the homebridge config in that case?
No. Do not change the commands in the Homebridge config.
Homebridge is calling the command and adding some modifiers depending on your actions on the Home switch or the queue intervals. For example, when you press the Apple TV Power switch on the Home app, Homebridge will execute the command and will add:
Another example would be at every interval, Homebridge will execute the command with the following modifiers:
Therefore, the modifiers are been added dynamically and you must not hardcode them.
I removed the comments for the debug lines in appletv_control.sh and here is my homebridge log below. It's showing error 255. What does this signify?
Do not remove the debug comments if you execute the command from Homebridge because Homebridge will expect a simple 0 or 1 from the output of the shell script. If it gets any comment, it will not know what to do with it and raise unpredictable errors.
From your logs, you can see that Homebridge is executing the complete command like this:
/var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On'
When you execute exactly this line at your terminal, do you get 0 or 1 as the output? If yes, then something is still wrong with your Homebridge configuration.
I see that you have set the debug modifier for the Cmd4 plugin to true. I don't know what are the consequences of this. Have you tried with "debug": false,
?
When I see in your logs Error: Command failed
, I understand that Homebridge could not execute the command. You wrote earlier that you have made the shell script executable, but who is the owner of the file? The owner must be the same user that is executing Homebridge. Can you check this?
So I ran it once with the Apple TV on and then a second time with it off, and I'm getting 1 the first time and 0 the second which means that the command is working fine from terminal. I ran it with the uncommented debug lines and it seems to be working just fine, but I will re-comment those lines. I get the same expected behaviour without the debug lines uncommented in terminal which is good. I'm only getting the unexpected behaviour when run from Homebridge for some reason. I can set the Apple TV on and off by changing from Get to Set in terminal, and it works just fine. The issue is just when run in Homebridge.
I created the file using Sublime Text on my Macbook and dropped it onto my RaspberryPi into the Homebridge folder using SFTP with Filezilla. Do you think that could be the problem? Am I supposed to create this file on the RaspberryPi itself perhaps? How do you check who is the owner? How can I change the owner to "pi" which is the user that runs Homebridge and that I used to execute the command from Homebridge's terminal?
Below is my terminal input/output: pi@homebridge:/var/lib/homebridge $ /var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On' args =3 arg1 =Get io=Get device = Apple TV Power Characteristic = On 1
pi@homebridge:/var/lib/homebridge $ /var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On' args =3 arg1 =Get io=Get device = Apple TV Power Characteristic = On 0
Normally, if you used the pi user for the FileZilla connection, it should be ok, But we can check it with a simple ls command. Please, execute this on your Homebridge terminal:
$ ls -al /var/lib/homebridge/
This will answer with the list of files inside that folder, their characteristics, owner and group. You are looking for something like this, where the owner is pi and the group is also pi:
-rwxr-xr-x 1 pi pi 4830 Dec 30 08:35 appletv_control.sh
Remember to comment again all the lines in the shell script because Homebridge will not understand the output of these.
I'm getting this: -rwxr-xr-x 1 pi pi 4834 Feb 25 04:40 appletv_control.sh
It looks good to me. I did login to SFTP using the pi user.
I have commented all the debug lines once again and I set debug to false.
The plugin is now working albeit very buggy and slow. It's taking about 15 seconds to turn off and on. Then there's another issue where it just keeps turning on and off repeatedly in a loop once every 15 seconds. So on for 15 then off for 15. The Play State switch also doesn't update to ON when playing Netflix, but I'm assuming that it's because of the slow issue. I'm assuming the slow issue is from the 100% CPU usage. Not really sure why that is, but the problem goes away when I disable the plugin. I normally only get 8% CPU usage.
Yes, it also looks good to me.
Now, it seems that the configuration is working. Regarding the buggyness, I would start with a good reboot of Homebride so it will forget about the previous issues and it will start from scratch.
What do you get after rebooting?
The Homebridge configuration "interval": 5
will make the Get queue to be executed every 5s. Because there are two switches, it will execute the Get request for each command every 5s. This means that you may have to wait up to 5s for seeing the switch update to the actual state. The precise amount of time will depend on the moment where you acted on the Apple TV and the queue pooling interval status. It can be from almost instant to almost 5s.
I have it exactly like that on my Raspberry Pi and the CPU usage is far from 100%. Yours should too.
Same problem after rebooting, unfortunately. I've rebooted so many times trying to figure this problem out that my Govee API token for my Govee plugin got revoked (hopefully only for the next 24 hours lol). Is there any way to make them not poll at the same time? Like instead of both polling at the same exact moment every 5 seconds, have one be polled 2.5 seconds later maybe?
I don't know if Cmd4 offers such functionality. You should ask the creator of it. But I don't believe that this queue processing is causing the trouble.
Now that you have commented out the debug lines in the shell script, can you enable the debug in the Homebridge plugin and post the results? I want to compare with mine to see if there is a way to find out what the issue is.
Actually:
[26/02/2022, 15:33:25] [Cmd4] getValue: On function for: Apple TV Play State returned: 0
[26/02/2022, 15:33:25] [Cmd4] Scheduling Poll of index: 106 characteristic: On for: Apple TV Play State timeout: 4000 interval: 5000
[26/02/2022, 15:33:28] [Cmd4] Processing low priority queue entry: 106
[26/02/2022, 15:33:28] [Cmd4] getValue: accTypeEnumIndex:( 106 )-"On" function for: Apple TV Power cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On' timeout: 4000
[26/02/2022, 15:33:30] [Cmd4] getValue: On function for: Apple TV Power returned: 0
[26/02/2022, 15:33:30] [Cmd4] Scheduling Poll of index: 106 characteristic: On for: Apple TV Power timeout: 4000 interval: 5000
[26/02/2022, 15:33:30] [Cmd4] Processing low priority queue entry: 106
[26/02/2022, 15:33:30] [Cmd4] getValue: accTypeEnumIndex:( 106 )-"On" function for: Apple TV Play State cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Play State' 'On' timeout: 4000
[26/02/2022, 15:33:32] [Cmd4] getValue: On function for: Apple TV Play State returned: 0
[26/02/2022, 15:33:32] [Cmd4] Scheduling Poll of index: 106 characteristic: On for: Apple TV Play State timeout: 4000 interval: 5000
[26/02/2022, 15:33:35] [Cmd4] Processing low priority queue entry: 106
[26/02/2022, 15:33:35] [Cmd4] getValue: accTypeEnumIndex:( 106 )-"On" function for: Apple TV Power cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On' timeout: 4000
[26/02/2022, 15:33:36] [Cmd4] getValue: On function for: Apple TV Power returned: 0
[26/02/2022, 15:33:36] [Cmd4] Scheduling Poll of index: 106 characteristic: On for: Apple TV Power timeout: 4000 interval: 5000
These are the logs you wanted. This time around, the plugin didn't seem to work. It didn't update the switch to On despite my Apple TV being on.
[26/02/2022, 23:57:29] [Cmd4] getCachedValue Name for: Apple TV Power returned (CACHED) value: Apple TV Power [26/02/2022, 23:57:29] [Cmd4] Processing high priority queue "Get" entry: 106 isUpdate: true length: 0 [26/02/2022, 23:57:29] [Cmd4] getValue: accTypeEnumIndex:( 106 )-"On" function for: Apple TV Power cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On' timeout: 4000 [26/02/2022, 23:57:29] [Cmd4] getCachedValue Name for: Apple TV Play State returned (CACHED) value: Apple TV Play State [26/02/2022, 23:57:29] [Cmd4] Processing high priority queue "Get" entry: 106 isUpdate: true length: 0 [26/02/2022, 23:57:29] [Cmd4] getValue: accTypeEnumIndex:( 106 )-"On" function for: Apple TV Play State cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Play State' 'On' timeout: 4000
[26/02/2022, 23:57:33] [Cmd4] getValue On function failed for Apple TV Power cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On' Failed. Generated Error: Error: Command failed: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On'
[26/02/2022, 23:57:33] [Cmd4] getValue On function timed out 4000ms for Apple TV Power cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On' Failed [26/02/2022, 23:57:33] [Cmd4] getValue On function failed for Apple TV Play State cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Play State' 'On' Failed. Generated Error: Error: Command failed: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Play State' 'On'
[26/02/2022, 23:57:33] [Cmd4] getValue On function timed out 4000ms for Apple TV Play State cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Play State' 'On' Failed [26/02/2022, 23:57:43] [Cmd4] Processing high priority queue "Get" entry: 106 isUpdate: true length: 1 [26/02/2022, 23:57:43] [Cmd4] getValue: accTypeEnumIndex:( 106 )-"On" function for: Apple TV Power cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On' timeout: 4000 [26/02/2022, 23:57:43] [Cmd4] Processing high priority queue "Get" entry: 106 isUpdate: true length: 0 [26/02/2022, 23:57:43] [Cmd4] getValue: accTypeEnumIndex:( 106 )-"On" function for: Apple TV Play State cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Play State' 'On' timeout: 4000 [26/02/2022, 23:57:47] [Cmd4] getValue On function failed for Apple TV Power cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On' Failed. Generated Error: Error: Command failed: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On'
[26/02/2022, 23:57:47] [Cmd4] getValue On function timed out 4000ms for Apple TV Power cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On' Failed [26/02/2022, 23:57:47] [Cmd4] getValue On function failed for Apple TV Play State cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Play State' 'On' Failed. Generated Error: Error: Command failed: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Play State' 'On'
[26/02/2022, 23:57:47] [Cmd4] getValue On function timed out 4000ms for Apple TV Play State cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Play State' 'On' Failed [26/02/2022, 23:57:48] [Govee] [TV Lights] [API] receiving update [{"source":"API","online":true,"powerState":"on","brightness":100,"color":{"r":255,"b":255,"g":250}}]. [26/02/2022, 23:57:48] [Govee] [Cloud Lights] [API] receiving update [{"source":"API","online":"true","powerState":"off","brightness":100,"color":{"r":68,"b":255,"g":0}}]. [26/02/2022, 23:57:49] [Govee] [TV Lights (Grimsby)] [API] receiving update [{"source":"API","online":true,"powerState":"off","brightness":100,"color":{"r":255,"b":0,"g":0}}]. [26/02/2022, 23:57:49] [Govee] [Flood Lights] [API] receiving update [{"source":"API","online":"true","powerState":"off","brightness":100,"colorTemInKelvin":6500,"colorTem":6500}]. [26/02/2022, 23:57:57] [Cmd4] Processing high priority queue "Get" entry: 106 isUpdate: true length: 1 [26/02/2022, 23:57:57] [Cmd4] getValue: accTypeEnumIndex:( 106 )-"On" function for: Apple TV Power cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On' timeout: 4000 [26/02/2022, 23:57:57] [Cmd4] Processing high priority queue "Get" entry: 106 isUpdate: true length: 0 [26/02/2022, 23:57:57] [Cmd4] getValue: accTypeEnumIndex:( 106 )-"On" function for: Apple TV Play State cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Play State' 'On' timeout: 4000
[26/02/2022, 23:58:01] [Cmd4] getValue On function failed for Apple TV Power cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On' Failed. Generated Error: Error: Command failed: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On'
[26/02/2022, 23:58:01] [Cmd4] getValue On function timed out 4000ms for Apple TV Power cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On' Failed [26/02/2022, 23:58:01] [Cmd4] getValue On function failed for Apple TV Play State cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Play State' 'On' Failed. Generated Error: Error: Command failed: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Play State' 'On'
[26/02/2022, 23:58:01] [Cmd4] getValue On function timed out 4000ms for Apple TV Play State cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Play State' 'On' Failed [26/02/2022, 23:58:01] [Cmd4] Starting Polling [26/02/2022, 23:58:01] [Cmd4] enablePolling for the first time [26/02/2022, 23:58:01] [Cmd4] Started staggered kick off of 2 polled characteristics for queue: "A" [26/02/2022, 23:58:01] [Cmd4] Kicking off polling for: Apple TV Power On interval:5000, staggered:3000 [26/02/2022, 23:58:01] [Cmd4] Scheduling Poll of index: 106 characteristic: On for: Apple TV Power timeout: 4000 interval: 5000 [26/02/2022, 23:58:04] [Cmd4] Kicking off polling for: Apple TV Play State On interval:5000, staggered:3000 [26/02/2022, 23:58:04] [Cmd4] Scheduling Poll of index: 106 characteristic: On for: Apple TV Play State timeout: 4000 interval: 5000 [26/02/2022, 23:58:04] [Cmd4] All characteristics are now being polled for queue: "A" [26/02/2022, 23:58:04] [Cmd4] All characteristics are now being polled [26/02/2022, 23:58:07] [Cmd4] processsQueue returned false [26/02/2022, 23:58:07] [Cmd4] Scheduling Poll of index: 106 characteristic: On for: Apple TV Power timeout: 4000 interval: 5000 [26/02/2022, 23:58:09] [Cmd4] processsQueue returned false [26/02/2022, 23:58:09] [Cmd4] Scheduling Poll of index: 106 characteristic: On for: Apple TV Play State timeout: 4000 interval: 5000 [26/02/2022, 23:58:11] [Cmd4] Processing high priority queue "Get" entry: 106 isUpdate: true length: 1 [26/02/2022, 23:58:11] [Cmd4] getValue: accTypeEnumIndex:( 106 )-"On" function for: Apple TV Power cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On' timeout: 4000 [26/02/2022, 23:58:11] [Cmd4] Processing high priority queue "Get" entry: 106 isUpdate: true length: 0 [26/02/2022, 23:58:11] [Cmd4] getValue: accTypeEnumIndex:( 106 )-"On" function for: Apple TV Play State cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Play State' 'On' timeout: 4000 [26/02/2022, 23:58:12] [Cmd4] Processing low priority queue entry: 106 [26/02/2022, 23:58:12] [Cmd4] getValue: accTypeEnumIndex:( 106 )-"On" function for: Apple TV Power cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On' timeout: 4000
I’m still seing yogur command failing.
Please, execute this command at the terminal and paste here the complete result:
/var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On'
Here it is: pi@homebridge:/var/lib/homebridge $ /var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On' 1
Works perfectly fine. It's outputting 1 as it should because my Apple TV is on. It takes about 8 seconds to get this output. Is this time the same for you?
Just for background, I'm running Homebridge on a Raspberry Pi 3B+ and the highest CPU usage it ever reaches is 35% but only when starting up Homebridge so lack of processing power shouldn't be the issue. My Homebridge has about 49 accessories and about 6-8 devices are being pinged constantly at any given time through other plugins, and they all update instantly (constantly pinged Roomba with about 6 live updated sensors, 4 constantly pinged Govee lights, 2 Broadlink IR/RF Universal remote and a bunch of stateless IR/RF switches/1 stateful, 2 constantly pinged Samsung Smart TVs with many inputs and multiple switches for mute (stateful) and volume(stateless), stateful WoLAN switch for my Windows PC getting pinged every 2 seconds, 8 stateless LIFX light mode HTTP switches and 1 stateful). This one is the only one I'm having problems with unfortunately. I'm also running my Apple TV 4K as the home hub for Homekit with about an additional 47-50 Homekit native devices. Those ones all ping instantly as well with no issues.
Currently, I've resorted to turning on and off and pausing my Apple TV with IR Hex codes and my Broadlink RM4 Pro for the time being, but this means that even though my switches are stateful that they don't actually represent the true states of the Apple TV.
8 seconds! Not at all. Mine gives the answer back instantly.
I have 5 plugins and 45 accessories in a Raspberry Pi and processor load is around 15%.
I believe that your problem might come from the pyatv script. What happens if you execute this on the terminal?
/home/pi/.local/bin/atvremote --id ${ATV_id} --airplay-credentials ${airplay_credentials} power_state
Replace ${ATV_id} with your Apple TV id data and ${airplay_credentials} with your AirPlay credentials.
You should get PowerState.On
or PowerState.Off
. Also check how long to get the answer.
I'm getting PowerState.On when its on and PowerState.Off when its Off as expected. It takes 6 seconds to get an answer after I press enter in terminal.
So all seems to be correctly configured, but those 6s are absolutely not normal. The Homebridge plugin configuration is set for a 4s timeout.
I believe that you can make it work if you change the interval to 15s and the timeout to 10s.
"interval": 15,
"timeout": 10000,
But that is not a friendly usage at all. This means that you will have to wait up to 15s for the Home app to get the new status of your Apple TV. Not usable.
Just to be sure, are you running Cmd4 on a child bridge? If not, can you do it and check if there are differences in the execution times?
Another test would be to temporary disable all other plugins and let only Cmd4 running. Check again for the execution times. It might be that another plugin that you use is not compatible with pyatv for some reason that I can't imagine.
If I disable all the other plugins, won't I lose all of my automations relating to their corresponding accessories?
Yes, you will loose. It happened to me already.
Damn :/ I screenshotted all the affected automations and shortcuts and I will do it sometime this week. I may buy a new Raspberry Pi 4 and start a fresh Homebridge + HomeAssistant setup to see if that clears up this issue in the future. I'll update you as soon as I can, just have exams coming up this week and I've been spending too much time programming and configuring Homekit devices.
Go for your exams! Good luck!
Thank you!
I have a Raspberry Pi 4B and cpu went also from 5% to 100% and I have a delay of 5 seconds.
I think when the interval is too fast and the delay too high there is stacking up a queue with requests.
atvremote --id 90:DD:5D:A7:02:20 --airplay-credentials `cat /homebridge/atv_airplay.cred` --companion-credentials `cat /homebridge/atv_companion.cred` power_state
Without Script ~2,3s
/homebridge/appletv_control.sh Get "Apple TV Play State" "On"
With Script ~5-7s
LAN or Wifi makes no difference
When apple tv is in sleep, appletv_control.sh runs in 2,7s.
What are the commands that you use to make this benchmark? I would like to try it myself.
At first by hand but i get 5s also when i put these command at the begin and the end:
start=$(date +%s%N)
end=$(date +%s%N)
echo "Elapsed time: $(($(($end-$start))/1000000)) ms"
root@docker:/homebridge# /homebridge/appletv_control.sh Get "Apple TV Play State" "On"
0
Elapsed time: 2363 ms
root@docker:/homebridge# /homebridge/appletv_control.sh Get "Apple TV Play State" "On"
1
Elapsed time: 4925 ms
I see now in the script that before get Playing state, a power state is requested. That's why execution time doubles. I removed it for me. My tv is not waking up from sleep when i request the playing state, only when switched off by this script. This what i get now:
root@docker:/homebridge# /homebridge/appletv_control.sh Get "Apple TV Play State" "On"
0
Elapsed time: 2329 ms
root@docker:/homebridge# /homebridge/appletv_control.sh Get "Apple TV Play State" "On"
1
Elapsed time: 2317 ms
When in sleep the power state request is still going crazy :
"queueType": "Sequential" fixes this
I'm getting 1900ms of execution time within Homebridge. Also, it is correct that the playing state command is not waking up the Apple TV as was happening before, so the previous power state can be removed. I guess this is because of some improvement on atvremote side.
As for the original 100% CPU usage, I agree with @m4rkv5 that the queue must be stacked with requests. This would mean that increasing the 5s delay should also solve the problem but it is not an interesting solution.
Ok, now we know that execution time can be reduced by removing the power state request before the play state. I will do that.
As for the queue type, what could be the consequence for the user if we change the queue type to sequential? I'm afraid that it will take more time to get the play state because it would be busy getting previous state requests. Can this be? I'm not expert in queues :)
Also, it is correct that the playing state command is not waking up the Apple TV as was happening before, so the previous power state can be removed. I guess this is because of some improvement on atvremote side.
Mine is not waking up when put to sleep by HDMI, Siri or physical remote. It woke up when powered off by atvremote --id ${ATV_id} --companion-credentials ${companion_credentials} turn_off
As for the queue type, what could be the consequence for the user if we change the queue type to sequential? I'm afraid that it will take more time to get the play state because it would be busy getting previous state requests. Can this be? I'm not expert in queues :)
I found no Worm explanation. I would expect that only one request can be exectuted in one "timeout": 4000 window and not multiple request with each in a "timeout": 4000 window. In conclusion if you have two accessories it would take longer to get both states.
I understand that the sequential queue is waiting for one request and it’s corresponding answer before sending the next request. So I assume that this will take longer time for the script to process. Tu when I looked out for information about the worm queue, I didn’t find anything convincing.
Maybe John can help us. @ztalbot2000, if you are reading this, what is the precise difference between the worm and the sequential queue? Or which type is best for short interval times? Thank you.
I would recommend using push updates (either via atvremote or atvscript) instead of polling. Setting up a new connection every time is quite expensive, especially on low-end systems. https://github.com/postlund/pyatv/issues/1709#issuecomment-1168357703
How would you implement push updates?
I found this in the documentation:
With pipe | stdout can be forwarded.
I switch to Node-RED with node-red-node-daemon and node-red-contrib-homekit-bridged.
Here are demo videos: https://kleverapps.com/apple-tv-info/
Node-Red can create homekit devices too.
Hi,
The Sequential Queue is one command at a time, as you know. The WoRm Queue is Write Once Read Many. There are devices out there, the AirCon for instance) which does not let you do a GetValue when A SetValue is in progress. To handle this a "SetValue" is done when all the "GetValues" have finished and no "GetValue" will be done when a "SetValue" is in progress.
Please send me your config.json file. The probably is most likely there, usually how much polling you do. You can also send me your script and I will review it. For security, send it to me directly at @.*** so that Git does not have a copy of it.
Ttyl, John
On Tue, Apr 26, 2022 at 6:37 AM Cristian @.***> wrote:
I understand that the sequential queue is waiting for one request and it’s corresponding answer before sending the next request. So I assume that this will take longer time for the script to process. Tu when I looked out for information about the worm queue, I didn’t find anything convincing.
Maybe John can help us. @ztalbot2000 https://github.com/ztalbot2000, if you are reading this, what is the precise difference between the worm and the sequential queue? Or which type is best for short interval times? Thank you.
— Reply to this email directly, view it on GitHub https://github.com/cristian5th/homebridge-appletv/issues/2#issuecomment-1109634838, or unsubscribe https://github.com/notifications/unsubscribe-auth/ABSBCXY45NX6SN2TZKJDESTVG7BPHANCNFSM5O34D4WQ . You are receiving this because you were mentioned.Message ID: @.***>
Hi @ztalbot2000.
Thanks for helping.
We cannot send you the script because GitHub has masked your e-mail. But no worries as the script is already in GitHub: https://github.com/cristian5th/homebridge-appletv/blob/main/appletv_control.sh
You will notice that the script is based on your templates. There is only need to change the identification data as per your needs and make sure that all paths are correct.
The config.json is like this (at least the newest version, more details on this below):
{
"platform": "Cmd4",
"name": "Cmd4",
"interval": 5,
"timeout": 4000,
"debug": false,
"stateChangeResponseTime": 3,
"queueTypes": [
{
"queue": "A",
"queueType": "WoRm"
}
],
"accessories": [
{
"type": "Switch",
"displayName": "ATV Power",
"on": "FALSE",
"queue": "A",
"polling": [
{
"characteristic": "on"
}
],
"state_cmd": "bash /var/lib/homebridge/appletv_control.sh"
},
{
"type": "Switch",
"displayName": "ATV Play",
"on": "FALSE",
"queue": "A",
"polling": [
{
"characteristic": "on"
}
],
"state_cmd": "bash /var/lib/homebridge/appletv_control.sh"
},
{
"type": "Switch",
"displayName": "ATV Video Play",
"on": "FALSE",
"queue": "A",
"polling": [
{
"characteristic": "on",
"interval": 6,
"timeout": 5000
}
],
"state_cmd": "bash /var/lib/homebridge/appletv_control.sh"
}
}
I have recently experienced the same issue as @alikhodrali and the reason is because I changed the script to request some more information coming from the device (Apple TV) and this makes that the answer is taking slightly more than 4s to arrive and I was pooling the get command every 5s with a 4s timeout. I changed the pooling for the second switch to 6s and 5s timeout and my issues were gone.
My guess is that @alikhodrali is receiving the response after the timeout and this is the origin of the collapse.
Do you see any possible improvement on the json or the script?
Many thanks.
Hey there. Same issues for me, but the issue seems to be latency in the ATV Power
subcommand, which is the only one I'm using. I am able to resolve it by bumping the timeout to 7000ms and the interval to 10000ms.
It seems to me that pyatv
it just too slow.
Also, and this may be unrelated so I'd be happy to open a separate issue on this, but it seems to me that Cmd4
repeatedly attempts to set the ATV Power, not just poll for the state.
Hello.
It's clear that we are not experiencing the exact same situation. My guess is that the hardware and network configuration are influencing big in the result.
I don't even think that the origin of the problem comes from pyatv as it is the same module used by Home Assistant, and in there the power or play status return is being given almost instantly. With Homebridge I have to wait 5s to see the play result and you @ledhed2222 have to wait for almost 7s. The man in the middle is being slow :)
Also, and this may be unrelated so I'd be happy to open a separate issue on this, but it seems to me that
Cmd4
repeatedly attempts to set the ATV Power, not just poll for the state.
What makes you believe that Cmd4 is attempting to set ATV Power? Does it switch on and off when unrequested? Do you have some logs?
From my understanding of the Home Assistant implementation, they have a persistent connection. With this implementation every time we wish to poll we have to:
1) find the ATV on the network via MAC address 2) connect to the ATV 3) send command 4) wait for response 5) close connection
I believe HA has a persistent connection, which would definitely account for the difference in performance. If I'm right, this plugin should be implemented using some message queue, like MQTT
I'm getting an error saying "More than 50 errors were encountered in a row for "Apple TV Power" getValue. Last errorfound Getting: "On". Perhaps you should run in debug mode to find out what the problem might be." in the Homebridge log accompanied by 100% CPU usage on my RaspberryPi.
This is what my log looks like in debug mode: [19/02/2022, 23:18:15] [Cmd4] getValue On function failed for Apple TV Power cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On' Failed. Generated Error: Error: Command failed: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On'
[19/02/2022, 23:18:15] [Cmd4] getValue On function timed out 4000ms for Apple TV Power cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On' Failed [19/02/2022, 23:18:15] [Cmd4] getValue On function failed for Apple TV Play State cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Play State' 'On' Failed. Generated Error: Error: Command failed: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Play State' 'On'
[19/02/2022, 23:18:15] [Cmd4] getValue On function timed out 4000ms for Apple TV Play State cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Play State' 'On' Failed [19/02/2022, 23:18:25] [Cmd4] Processing high priority queue "Get" entry: 106 isUpdate: true length: 1 [19/02/2022, 23:18:25] [Cmd4] getValue: accTypeEnumIndex:( 106 )-"On" function for: Apple TV Power cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On' timeout: 4000 [19/02/2022, 23:18:25] [Cmd4] Processing high priority queue "Get" entry: 106 isUpdate: true length: 0 [19/02/2022, 23:18:25] [Cmd4] getValue: accTypeEnumIndex:( 106 )-"On" function for: Apple TV Play State cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Play State' 'On' timeout: 4000 [19/02/2022, 23:18:29] [Cmd4] getValue On function failed for Apple TV Power cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On' Failed. Generated Error: Error: Command failed: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On'
[19/02/2022, 23:18:29] [Cmd4] getValue On function timed out 4000ms for Apple TV Power cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On' Failed [19/02/2022, 23:18:29] [Cmd4] getValue On function failed for Apple TV Play State cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Play State' 'On' Failed. Generated Error: Error: Command failed: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Play State' 'On'
[19/02/2022, 23:18:29] [Cmd4] getValue On function timed out 4000ms for Apple TV Play State cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Play State' 'On' Failed [19/02/2022, 23:18:39] [Cmd4] Processing high priority queue "Get" entry: 106 isUpdate: true length: 1 [19/02/2022, 23:18:39] [Cmd4] getValue: accTypeEnumIndex:( 106 )-"On" function for: Apple TV Power cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On' timeout: 4000 [19/02/2022, 23:18:39] [Cmd4] Processing high priority queue "Get" entry: 106 isUpdate: true length: 0 [19/02/2022, 23:18:39] [Cmd4] getValue: accTypeEnumIndex:( 106 )-"On" function for: Apple TV Play State cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Play State' 'On' timeout: 4000 [19/02/2022, 23:18:43] [Cmd4] getValue On function failed for Apple TV Power cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On' Failed. Generated Error: Error: Command failed: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On'
[19/02/2022, 23:18:43] [Cmd4] getValue On function timed out 4000ms for Apple TV Power cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On' Failed [19/02/2022, 23:18:43] [Cmd4] getValue On function failed for Apple TV Play State cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Play State' 'On' Failed. Generated Error: Error: Command failed: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Play State' 'On'
[19/02/2022, 23:18:43] [Cmd4] getValue On function timed out 4000ms for Apple TV Play State cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Play State' 'On' Failed [19/02/2022, 23:18:44] [Cmd4] Starting Polling [19/02/2022, 23:18:44] [Cmd4] enablePolling for the first time [19/02/2022, 23:18:44] [Cmd4] Started staggered kick off of 2 polled characteristics for queue: "A" [19/02/2022, 23:18:44] [Cmd4] Kicking off polling for: Apple TV Power On interval:5000, staggered:3000 [19/02/2022, 23:18:44] [Cmd4] Scheduling Poll of index: 106 characteristic: On for: Apple TV Power timeout: 4000 interval: 5000 [19/02/2022, 23:18:47] [Cmd4] Kicking off polling for: Apple TV Play State On interval:5000, staggered:3000 [19/02/2022, 23:18:47] [Cmd4] Scheduling Poll of index: 106 characteristic: On for: Apple TV Play State timeout: 4000 interval: 5000 [19/02/2022, 23:18:47] [Cmd4] All characteristics are now being polled for queue: "A" [19/02/2022, 23:18:47] [Cmd4] All characteristics are now being polled [19/02/2022, 23:18:49] [Cmd4] processsQueue returned false [19/02/2022, 23:18:49] [Cmd4] Scheduling Poll of index: 106 characteristic: On for: Apple TV Power timeout: 4000 interval: 5000 [19/02/2022, 23:18:52] [Cmd4] processsQueue returned false [19/02/2022, 23:18:52] [Cmd4] Scheduling Poll of index: 106 characteristic: On for: Apple TV Play State timeout: 4000 interval: 5000 [19/02/2022, 23:18:53] [Cmd4] Processing high priority queue "Get" entry: 106 isUpdate: true length: 1 [19/02/2022, 23:18:53] [Cmd4] getValue: accTypeEnumIndex:( 106 )-"On" function for: Apple TV Power cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On' timeout: 4000 [19/02/2022, 23:18:53] [Cmd4] Processing high priority queue "Get" entry: 106 isUpdate: true length: 0 [19/02/2022, 23:18:53] [Cmd4] getValue: accTypeEnumIndex:( 106 )-"On" function for: Apple TV Play State cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Play State' 'On' timeout: 4000 [19/02/2022, 23:18:54] [Cmd4] Processing low priority queue entry: 106 [19/02/2022, 23:18:54] [Cmd4] getValue: accTypeEnumIndex:( 106 )-"On" function for: Apple TV Power cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On' timeout: 4000 [19/02/2022, 23:18:57] [Cmd4] Processing low priority queue entry: 106 [19/02/2022, 23:18:57] [Cmd4] getValue: accTypeEnumIndex:( 106 )-"On" function for: Apple TV Play State cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Play State' 'On' timeout: 4000 [19/02/2022, 23:18:57] [Cmd4] getValue On function failed for Apple TV Power cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On' Failed. Generated Error: Error: Command failed: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On'
[19/02/2022, 23:18:57] [Cmd4] getValue On function timed out 4000ms for Apple TV Power cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On' Failed [19/02/2022, 23:18:57] [Cmd4] getValue On function failed for Apple TV Play State cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Play State' 'On' Failed. Generated Error: Error: Command failed: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Play State' 'On'
[19/02/2022, 23:18:57] [Cmd4] getValue On function timed out 4000ms for Apple TV Play State cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Play State' 'On' Failed [19/02/2022, 23:18:58] [Cmd4] getValue On function failed for Apple TV Power cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On' Failed. Generated Error: Error: Command failed: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On'
[19/02/2022, 23:18:58] [Cmd4] getValue On function timed out 4000ms for Apple TV Power cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On' Failed [19/02/2022, 23:18:58] [Cmd4] Scheduling Poll of index: 106 characteristic: On for: Apple TV Power timeout: 4000 interval: 5000 [19/02/2022, 23:19:01] [Cmd4] getValue On function failed for Apple TV Play State cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Play State' 'On' Failed. Generated Error: Error: Command failed: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Play State' 'On'
[19/02/2022, 23:19:01] [Cmd4] getValue On function timed out 4000ms for Apple TV Play State cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Play State' 'On' Failed [19/02/2022, 23:19:01] [Cmd4] Scheduling Poll of index: 106 characteristic: On for: Apple TV Play State timeout: 4000 interval: 5000 [19/02/2022, 23:19:03] [Cmd4] processsQueue returned false [19/02/2022, 23:19:03] [Cmd4] Scheduling Poll of index: 106 characteristic: On for: Apple TV Power timeout: 4000 interval: 5000 [19/02/2022, 23:19:06] [Cmd4] processsQueue returned false [19/02/2022, 23:19:06] [Cmd4] Scheduling Poll of index: 106 characteristic: On for: Apple TV Play State timeout: 4000 interval: 5000 [19/02/2022, 23:19:07] [Cmd4] Processing high priority queue "Get" entry: 106 isUpdate: true length: 1 [19/02/2022, 23:19:07] [Cmd4] getValue: accTypeEnumIndex:( 106 )-"On" function for: Apple TV Power cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On' timeout: 4000 [19/02/2022, 23:19:07] [Cmd4] Processing high priority queue "Get" entry: 106 isUpdate: true length: 0 [19/02/2022, 23:19:07] [Cmd4] getValue: accTypeEnumIndex:( 106 )-"On" function for: Apple TV Play State cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Play State' 'On' timeout: 4000 [19/02/2022, 23:19:08] [Cmd4] Processing low priority queue entry: 106 [19/02/2022, 23:19:08] [Cmd4] getValue: accTypeEnumIndex:( 106 )-"On" function for: Apple TV Power cmd: bash /var/lib/homebridge/appletv_control.sh Get 'Apple TV Power' 'On' timeout: 4000
My appletv_control.sh file contains exactly the following (copied and pasted here):
!/bin/bash
set -e
Exit immediately for unbound variables.
set -u
length=$# device="" io="" characteristic="" option="" ATV_id="C8:D0:83:BB:43:55" airplay_credentials="4591443d042b7d88f697f35727e95dc46378627361177c0b5702f9dac3eca4f3:d13bfc5a7e790d36a1656ed6883d58f8d67065c229871c80c208ba6e5faf3313:32314243334143362d373536412d343637452d413643352d383935364532414642373846:31643635646335332d323630362d343636662d396336632d393065323035613065636661" companion_credentials="4591443d042b7d88f697f35727e95dc46378627361177c0b5702f9dac3eca4f3:7800bf15b9ce2fd780764d0ee428a16505aaed43bd47ad9212ba3b95da2116f7:32314243334143362d373536412d343637452d413643352d383935364532414642373846:62633333356533302d623037642d346433382d626633342d656530353639313561323561"
if [ $length -le 1 ]; then printf "Usage: $0 Get < AccessoryName > < Characteristic >\n" printf "Usage: $0 Set < AccessoryName > < Characteristic > < Value >\n" exit -1 fi
printf "args =$#\n" # debug
printf "arg1 =$1\n" # debug
if [ $length -ge 1 ]; then io=$1
printf "io=$io\n" # debug
fi if [ $length -ge 2 ]; then device=$2
printf "device = ${device}\n" # debug
fi if [ $length -ge 3 ]; then characteristic=$3
printf "Characteristic = ${characteristic}\n" # debug
fi if [ $length -ge 4 ]; then option=$4
printf "option = ${option}\n" # debug
fi
if [ "${io}" == "Get" ]; then case $device in 'Apple TV Power') case $characteristic in 'On')
Get Apple TV power state
esac fi if [ "${io}" == 'Set' ]; then case $device in 'Apple TV Power') case $characteristic in 'On')
Get Apple TV current power state and switch accordingly
esac fi printf "Unknown io command ${io}\n" exit -1