Binding for Apple-TV

ok when i turned of apple tv from a remote and then restarten openhab it wen online

2025-10-11 12:45:40.556 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'appletv:device:12-54-B9-78-AA-8B' changed from OFFLINE to ONLINE
12:45:50.720 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘Apple_TV_sypialnia_AppleTV_Gen4K_Power_Status’ changed from OFF to ON

Hi-

I think you’ll need to turn debug on in order to see what’s actually happening: Normally, the device will send an initial push of its current state when the binding starts up, but it doesn’t request a change in power status unless a command is sent to the binding and the device is already off. I don’t think there’s a situation where the power status would be changed (from whatever it was) beyond that situation.

Thanks for the great work on this binding and the documentation. I’m very new to OpenHAB and learning something every day. I’ve installed the Apple TV binding and pyatv following the latest links in this thread, however my OpenHAB still can’t find my Apple TV. In the openhab log file I see the following…

2025-11-12 19:57:42.871 [ERROR] [enhab.binding.appletv.internal.PyATV] - Scanning for Apple-TV devices failed!
2025-11-12 19:57:42.873 [INFO ] [ding.appletv.internal.AppleTVHandler] - Apple-TV discovery returned null
2025-11-12 19:57:57.840 [INFO ] [ding.appletv.internal.AppleTVHandler] - Stopping Apple-TV discovery scan

Any ideas how to resolve this? Thanks in advance.

Hi-

Can you describe your openhab installation a bit more? What OS are you using, are you using docker, etc?

If you can go into the directory you installed pyatv into, can you run the command “atvremote scan”? For example, my openhab is in /opt/openhab4:

cd /opt/openhab4/userdata/tmp/appletv-binding

. bin/activate

atvremote scan

Does it see your devices? Let me know and I’ll try to help figure out what’s going wrong.

Bill

hi Bill, i am using it for 30 days right now and i can confirm:

1/ Booting openhab turns on the TV

2/ Sending OFF command to a power state which is OFF sometimes turns the apple tv on (i have a homekit “sleep” scene and the power switch in there (always → OFF)

3/ Maybe you would be so kind and add the app future? i will be gratefull if i can turn on and open an app by default, it should not be so hard to implement it

Hi Bill, thanks for your help and apologies for not including more details in my original post.

I’m running Openhabian 5.0.1 on a Raspberry Pi. Python is installed in a virtual environment. I can run the atvremote scan and see all my devices. Specifically for the Apple TV, I see the following services…

Services:
 - Protocol: Companion, Port: 49153, Credentials: None, Requires Password: False, Password: None, Pairing: Mandatory
 - Protocol: AirPlay, Port: 7000, Credentials: None, Requires Password: False, Password: None, Pairing: Mandatory
 - Protocol: RAOP, Port: 7000, Credentials: None, Requires Password: False, Password: None, Pairing: Mandatory

From within OpenHAB, running a scan still reports the following in the log file…

2025-11-17 17:02:17.175 [ERROR] [enhab.binding.appletv.internal.PyATV] - Scanning for Apple-TV devices failed!
2025-11-17 17:02:17.176 [INFO ] [ding.appletv.internal.AppleTVHandler] - Apple-TV discovery returned null
2025-11-17 17:02:32.155 [INFO ] [ding.appletv.internal.AppleTVHandler] - Stopping Apple-TV discovery scan

What else would be helpful for troubleshooting? Thank you!

I have implemented these lifesavers: (using DSL)
All places I turn it off:

    if (AppleTVLRPower.state == ON) {
        AppleTVLRPower.sendCommand(OFF)
    }

Guard rule: (checking if lights are all off, a deconz group)

rule "AppleTV turns on"
when
    Item AppleTVLRPower changed to ON
then
    val name = "AppleTV"
    logInfo(name, "AppleTVLRPower = " + AppleTVLRPower.state)
    if (AllButBedroomsAnyOn.state == OFF) {
        logInfo(name, "AllButBedroomsAnyOn = " + AllButBedroomsAnyOn.state + " turning off AppleTV again")
        AppleTVLRPower.sendCommand(OFF) // turn AppleTV off if turning itself on again
    }
end

I don’t see any unwanted power on anymore.
Also, on rare occations when hitting the ‘bed’ button and power off doesn’t work perhaps due to coincide with a

AppleTVCommandLoop: Command process=116785 exited.

The rule will trigger when the command loop recovers and turn the ATV off a few seconds later.

1 Like

Hi-

Can you turn on debug for the binding and then restart it? That should produce some more useful information about what’s going on…

log:set TRACE org.openhab.binding.appletv

bundle:list |grep pple

bundle:restart bundleIdNumber

I can’t reproduce the behavior you describe in item 1. Is it possible you have something that checks for the status of the appletv? Can you enable debug logging for the binding to see what’s happening? It should print information about each command being sent to the device.

It’s possible that sending a power off command might turn the device on if it’s off, but it should also send an off command immediately after. The reason the device gets turned on is because it will ignore commands sent to it until the device is woken up. It might be possible to catch this particular situation, but if the device power state gets out of sync and is really off when openhab thinks it is on, commands will get silently ignored. Again, debugging output might show what’s going on more clearly.

The binding does support launching an app. Send the app’s identifier to an item that’s linked to the app identifier channel, and that should trigger the app to open. You’ll need to know the app identifier, of course… such as “com.firecore.infuse”.

Thank you, will do. Newbie question, but where do I add this code?

ssh openhab@localhost -p 8101
habopen

1 Like

sorry, I wasn’t sure if you were familiar with the “karaf” command interface for poking at the internals… nobody likes to be habsplained to haha.

once you’ve changed the logging level and restarted the bundle, you can do a “log:tail” to see logs in real time.

I’m thinking the problem is either a) the scan command isn’t actually running or b) there’s some sort of network strangeness.

1 Like

All good, I’m here to learn and not yet familiar with karaf. I’ve followed the above instructions and I can see there is an issue attempting to run atvscript. Maybe something isn’t [correctly] installed?

Thanks again for your help and guidance!

openhab>                                                                                                                                                     
openhab> log:set TRACE org.openhab.binding.appletv
openhab> bundle:list | grep pple
247 │ Active │  80 │ 5.0.1                 │ openHAB Add-ons :: Bundles :: AppleTV Binding
openhab> bundle:restart 247
openhab> log:tail
11:25:48.716 [DEBUG] [nal.discovery.AppleTVDiscoveryService] - bundle org.openhab.binding.appletv:5.0.1 (247)[org.openhab.binding.appletv.internal.discovery.AppleTVDiscoveryService(406)] : getClassFromComponentClassLoader: Found class org.openhab.binding.appletv.internal.AppleTVHandlerFactory
11:25:48.717 [DEBUG] [nal.discovery.AppleTVDiscoveryService] - bundle org.openhab.binding.appletv:5.0.1 (247)[org.openhab.binding.appletv.internal.discovery.AppleTVDiscoveryService(406)] : doFindMethod: No method taking ServiceReference found, checking method taking org.openhab.binding.appletv.internal.AppleTVHandlerFactory
11:25:48.719 [DEBUG] [nal.discovery.AppleTVDiscoveryService] - bundle org.openhab.binding.appletv:5.0.1 (247)[org.openhab.binding.appletv.internal.discovery.AppleTVDiscoveryService(406)] : doFindMethod: Found Method public void org.openhab.binding.appletv.internal.discovery.AppleTVDiscoveryService.setAppleTVHandlerFactory(org.openhab.binding.appletv.internal.AppleTVHandlerFactory)
11:25:48.720 [DEBUG] [nal.discovery.AppleTVDiscoveryService] - bundle org.openhab.binding.appletv:5.0.1 (247)[org.openhab.binding.appletv.internal.discovery.AppleTVDiscoveryService(406)] : Found bind method: public void org.openhab.binding.appletv.internal.discovery.AppleTVDiscoveryService.setAppleTVHandlerFactory(org.openhab.binding.appletv.internal.AppleTVHandlerFactory)
11:25:48.722 [DEBUG] [nal.discovery.AppleTVDiscoveryService] - bundle org.openhab.binding.appletv:5.0.1 (247)[org.openhab.binding.appletv.internal.discovery.AppleTVDiscoveryService(406)] : This thread collected dependencies
11:25:48.723 [DEBUG] [nal.discovery.AppleTVDiscoveryService] - bundle org.openhab.binding.appletv:5.0.1 (247)[org.openhab.binding.appletv.internal.discovery.AppleTVDiscoveryService(406)] : getService (single component manager) dependencies collected.
11:25:48.724 [DEBUG] [nal.discovery.AppleTVDiscoveryService] - bundle org.openhab.binding.appletv:5.0.1 (247)[org.openhab.binding.appletv.internal.discovery.AppleTVDiscoveryService(406)] : Querying state satisfied
11:25:48.725 [DEBUG] [nal.discovery.AppleTVDiscoveryService] - bundle org.openhab.binding.appletv:5.0.1 (247)[org.openhab.binding.appletv.internal.discovery.AppleTVDiscoveryService(406)] : Querying state satisfied
11:25:48.727 [DEBUG] [nal.discovery.AppleTVDiscoveryService] - bundle org.openhab.binding.appletv:5.0.1 (247)[org.openhab.binding.appletv.internal.discovery.AppleTVDiscoveryService(406)] : For dependency AppleTVHandlerFactory, optional: true; to bind: [[RefPair: ref: [{org.openhab.core.thing.binding.ThingHandlerFactory, org.openhab.binding.appletv.internal.AppleTVHandlerFactory}={service.id=593, service.bundleid=247, service.scope=bundle, osgi.ds.satisfying.condition.target=(osgi.condition.id=true), component.name=org.openhab.binding.appletv.internal.AppleTVHandlerFactory, component.id=405}] service: [org.openhab.binding.appletv.internal.AppleTVHandlerFactory@376aa09f]]]
11:25:48.728 [DEBUG] [nal.discovery.AppleTVDiscoveryService] - bundle org.openhab.binding.appletv:5.0.1 (247)[org.openhab.binding.appletv.internal.discovery.AppleTVDiscoveryService(406)] : For dependency osgi.ds.satisfying.condition, optional: false; to bind: [[RefPair: ref: [{org.osgi.service.condition.Condition}={service.id=6, service.bundleid=0, service.scope=singleton, service.pid=0.org.osgi.service.condition.ConditionImpl, osgi.condition.id=true}] service: [null]]]
11:25:48.731 [DEBUG] [nding.appletv.internal.AppleTVHandler] - Thing types: [appletv:device] registered.
11:25:48.732 [DEBUG] [nal.discovery.AppleTVDiscoveryService] - bundle org.openhab.binding.appletv:5.0.1 (247)[org.openhab.binding.appletv.internal.discovery.AppleTVDiscoveryService(406)] : invoking bind: setAppleTVHandlerFactory: parameters [org.openhab.binding.appletv.internal.AppleTVHandlerFactory]
11:25:48.734 [DEBUG] [nding.appletv.internal.AppleTVHandler] - HandlerFactory bound to AppleTVDiscoveryService
11:25:48.735 [INFO ] [ppletv.internal.AppleTVHandlerFactory] - Binding configuration refreshed
11:25:48.737 [INFO ] [nding.appletv.internal.AppleTVHandler] - Starting background discovery
11:25:48.738 [DEBUG] [nal.discovery.AppleTVDiscoveryService] - bundle org.openhab.binding.appletv:5.0.1 (247)[org.openhab.binding.appletv.internal.discovery.AppleTVDiscoveryService(406)] : invoked bind: setAppleTVHandlerFactory
11:25:48.739 [DEBUG] [nal.discovery.AppleTVDiscoveryService] - bundle org.openhab.binding.appletv:5.0.1 (247)[org.openhab.binding.appletv.internal.discovery.AppleTVDiscoveryService(406)] : getting activate: activate
11:25:48.741 [DEBUG] [nal.discovery.AppleTVDiscoveryService] - bundle org.openhab.binding.appletv:5.0.1 (247)[org.openhab.binding.appletv.internal.discovery.AppleTVDiscoveryService(406)] : Locating method activate in class org.openhab.binding.appletv.internal.discovery.AppleTVDiscoveryService
11:25:48.742 [DEBUG] [nal.discovery.AppleTVDiscoveryService] - bundle org.openhab.binding.appletv:5.0.1 (247)[org.openhab.binding.appletv.internal.discovery.AppleTVDiscoveryService(406)] : Declared Method org.openhab.binding.appletv.internal.discovery.AppleTVDiscoveryService.activate([interface org.osgi.service.component.ComponentContext]) not found
11:25:48.743 [DEBUG] [nal.discovery.AppleTVDiscoveryService] - bundle org.openhab.binding.appletv:5.0.1 (247)[org.openhab.binding.appletv.internal.discovery.AppleTVDiscoveryService(406)] : Found activate method: protected void org.openhab.binding.appletv.internal.discovery.AppleTVDiscoveryService.activate(java.util.Map)
11:25:48.743 [DEBUG] [nal.discovery.AppleTVDiscoveryService] - bundle org.openhab.binding.appletv:5.0.1 (247)[org.openhab.binding.appletv.internal.discovery.AppleTVDiscoveryService(406)] : invoking activate: activate: parameters [org.apache.felix.scr.impl.helper.ReadOnlyDictionary]
11:25:48.745 [DEBUG] [nding.appletv.internal.AppleTVHandler] - Config Parameters: {osgi.ds.satisfying.condition.target=(osgi.condition.id=true), component.name=org.openhab.binding.appletv.internal.discovery.AppleTVDiscoveryService, component.id=406}
11:25:48.746 [DEBUG] [nal.discovery.AppleTVDiscoveryService] - bundle org.openhab.binding.appletv:5.0.1 (247)[org.openhab.binding.appletv.internal.discovery.AppleTVDiscoveryService(406)] : invoked activate: activate
11:25:48.746 [DEBUG] [nal.discovery.AppleTVDiscoveryService] - bundle org.openhab.binding.appletv:5.0.1 (247)[org.openhab.binding.appletv.internal.discovery.AppleTVDiscoveryService(406)] : Set implementation object for component
11:25:48.747 [DEBUG] [nal.discovery.AppleTVDiscoveryService] - bundle org.openhab.binding.appletv:5.0.1 (247)[org.openhab.binding.appletv.internal.discovery.AppleTVDiscoveryService(406)] : Changed state from satisfied to active
11:25:50.506 [INFO ] [ppletv.internal.AppleTVHandlerFactory] - Calling createHandler: appletv:device:169F070D4ABF (ThingTypeUID=appletv:device, Bridge=False, Label=Apple-TV Device, Status=UNINITIALIZED, StatusInfo=UNINITIALIZED (NOT_YET_READY), SemanticEquipmentTag=null)
11:25:50.508 [INFO ] [ppletv.internal.AppleTVHandlerFactory] - Creating a thing handler
11:25:50.521 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing 'appletv:device:169F070D4ABF' changed from UNINITIALIZED (NOT_YET_READY) to INITIALIZING
11:25:50.529 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing 'appletv:device:169F070D4ABF' changed from INITIALIZING to UNKNOWN
11:25:50.534 [INFO ] [nding.appletv.internal.AppleTVHandler] - AppleTV Properties: {}
11:25:50.535 [INFO ] [nding.appletv.internal.AppleTVHandler] - Initializing AppleTV
11:25:50.565 [DEBUG] [nding.appletv.internal.AppleTVHandler] - Configuration updated.
11:25:50.566 [INFO ] [nding.appletv.internal.AppleTVHandler] - Pairing Requirement for Airplay: Disabled
11:25:50.567 [WARN ] [nding.appletv.internal.AppleTVHandler] - Pairing requirement for Airplay is Disabled, but credentials are set.
11:25:50.568 [INFO ] [nding.appletv.internal.AppleTVHandler] - Pairing Requirement for Companion: Disabled
11:25:50.573 [WARN ] [nding.appletv.internal.AppleTVHandler] - Pairing requirement for Companion is Disabled, but credentials are set.
11:25:50.575 [INFO ] [nding.appletv.internal.AppleTVHandler] - Pairing Requirement for MRP: Disabled
11:25:50.576 [INFO ] [nding.appletv.internal.AppleTVHandler] - Pairing Requirement for RAOP: Disabled
11:25:50.577 [WARN ] [nding.appletv.internal.AppleTVHandler] - Pairing requirement for RAOP is Disabled, but credentials are set.
11:25:50.579 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing 'appletv:device:169F070D4ABF' changed from UNKNOWN to OFFLINE (CONFIGURATION_PENDING): Pairing requirement for Airplay is Disabled, but credentials are set.
Pairing requirement for Companion is Disabled, but credentials are set.
Pairing requirement for RAOP is Disabled, but credentials are set.

11:25:53.485 [INFO ] [openhab.event.ItemCommandEvent       ] - Item 'i_HK_Living_Room_Mode' received command 0
11:26:03.635 [INFO ] [openhab.event.ItemCommandEvent       ] - Item 'i_HK_Living_Room_Mode' received command 0
11:26:08.738 [INFO ] [nding.appletv.internal.AppleTVHandler] - Starting Apple-TV discovery
11:26:08.741 [INFO ] [penhab.binding.appletv.internal.PyATV] - Scan for AppleTV devices
11:26:08.742 [INFO ] [penhab.binding.appletv.internal.PyATV] - Sending command scan to deviceId , lid org.openhab.binding.appletv.internal.AppleTVThingConfiguration@29534cb3
11:26:08.744 [WARN ] [penhab.binding.appletv.internal.PyATV] - PaTH: /var/lib/openhab/tmp/appletv-binding/bin:/opt/openhab/pyatv/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
11:26:08.752 [WARN ] [penhab.binding.appletv.internal.PyATV] - Failed to execute commandLine '[/var/lib/openhab/tmp/appletv-binding/bin/atvscript, scan]'
java.io.IOException: Cannot run program "/var/lib/openhab/tmp/appletv-binding/bin/atvscript": error=2, No such file or directory
        at java.lang.ProcessBuilder.start(Unknown Source) ~[?:?]
        at java.lang.ProcessBuilder.start(Unknown Source) ~[?:?]
        at org.openhab.binding.appletv.internal.PyATV.executeCommandLineAndWaitResponse(PyATV.java:224) ~[?:?]
        at org.openhab.binding.appletv.internal.PyATV.exec(PyATV.java:147) ~[?:?]
        at org.openhab.binding.appletv.internal.PyATV.sendCommands(PyATV.java:134) ~[?:?]
        at org.openhab.binding.appletv.internal.PyATV.scanDevices(PyATV.java:176) ~[?:?]
        at org.openhab.binding.appletv.internal.AppleTVHandlerFactory.scanDevices(AppleTVHandlerFactory.java:142) ~[?:?]
        at org.openhab.binding.appletv.internal.discovery.AppleTVDiscoveryService.startScan(AppleTVDiscoveryService.java:104) ~[?:?]
        at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source) ~[?:?]
        at java.util.concurrent.FutureTask.runAndReset(Unknown Source) ~[?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source) ~[?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) ~[?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) ~[?:?]
        at java.lang.Thread.run(Unknown Source) [?:?]
Caused by: java.io.IOException: error=2, No such file or directory
        at java.lang.ProcessImpl.forkAndExec(Native Method) ~[?:?]
        at java.lang.ProcessImpl.<init>(Unknown Source) ~[?:?]
        at java.lang.ProcessImpl.start(Unknown Source) ~[?:?]
        ... 14 more
11:26:08.760 [ERROR] [penhab.binding.appletv.internal.PyATV] - Exception on PyATV call: Error executing [/var/lib/openhab/tmp/appletv-binding/bin/atvscript, scan] (class java.lang.RuntimeException)
java.lang.RuntimeException: Error executing [/var/lib/openhab/tmp/appletv-binding/bin/atvscript, scan]
        at org.openhab.binding.appletv.internal.PyATV.exec(PyATV.java:149) ~[?:?]
        at org.openhab.binding.appletv.internal.PyATV.sendCommands(PyATV.java:134) ~[?:?]
        at org.openhab.binding.appletv.internal.PyATV.scanDevices(PyATV.java:176) ~[?:?]
        at org.openhab.binding.appletv.internal.AppleTVHandlerFactory.scanDevices(AppleTVHandlerFactory.java:142) ~[?:?]
        at org.openhab.binding.appletv.internal.discovery.AppleTVDiscoveryService.startScan(AppleTVDiscoveryService.java:104) ~[?:?]
        at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source) ~[?:?]
        at java.util.concurrent.FutureTask.runAndReset(Unknown Source) ~[?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source) ~[?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) ~[?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) ~[?:?]
        at java.lang.Thread.run(Unknown Source) [?:?]
11:26:08.765 [ERROR] [penhab.binding.appletv.internal.PyATV] - Scanning for Apple-TV devices failed!
11:26:08.766 [INFO ] [nding.appletv.internal.AppleTVHandler] - Apple-TV discovery returned null

Check with ChatGPT (not sure this is the best guide!), and it says…

Great — this log finally shows the root cause.

OpenHAB is not using your pyatv virtualenv, because the Apple TV binding is trying to run:

/var/lib/openhab/tmp/appletv-binding/bin/atvscript

…and that directory does NOT exist.

This means the binding’s embedded PyATV environment never got created, which normally happens automatically when the binding starts — but only if OpenHAB’s environment variables and Python path are correct.

Let’s fix it step-by-step.

The Apple TV binding expects to find:

/var/lib/openhab/tmp/appletv-binding/bin/atvscript

This folder is generated only when the binding successfully runs its Python bootstrap.

Yours is not being created, so the binding falls back to a missing directory → which causes discovery to fail.

The binding could not create its embedded venv

The binding automatically runs:

python3 -m venv /var/lib/openhab/tmp/appletv-binding

But this silently fails when:

:cross_mark: Python is wrong version

The binding requires:

  • Python 3.8 or Python 3.9 ONLY

  • It is not compatible with Python 3.11 and will fail to build scripts under it.

You are using:

/opt/openhab/pyatv/lib/python3.11

That means the binding CANNOT generate its own working env.

:right_arrow: This is the #1 cause of your issue.

But before I blindly following ChatGPT’s guidance, it would be great to hear from real experts! Is this the source of my issue or is something else going on? Thanks!

Hi-

Yeah, there are a few incorrect points (but a valiant effort?)… It is correct that the pyatv commands are not where openhab is expecting them to be. The long term goal is for all of that to be managed by the binding, but that part hasn’t been built yet. I’m using python 3.12, but I’m pretty sure 3.8+ will work.

So, I guess the question is, where is your python virtual environment? The binding is looking in /var/lib/openhab/tmp/appletv-binding, so if it’s not there, you should use that as the virtual environment directory and reinstall pyatv there. That should solve the problem.

As a note to myself, we should probably add a warning when this happens so that there’s a bit more to go on without needing to drop into debug logging.

Let me know how it goes!

1 Like

Definitely a step forward!

I’ve installed the pyatv in the correct location and my Apple TV thing is automatically discovered. I’ve added the pairing strings for each protocol using the atvremote pair function. However the thing remains offline with a configuration error.

Looking at the log file in karaf I see the following…

11:48:24.501 [INFO ] [nding.appletv.internal.AppleTVHandler] - Initializing AppleTV
11:48:24.517 [DEBUG] [nding.appletv.internal.AppleTVHandler] - Configuration updated.
11:48:24.519 [INFO ] [nding.appletv.internal.AppleTVHandler] - Pairing Requirement for Airplay: Mandatory
11:48:24.521 [INFO ] [nding.appletv.internal.AppleTVHandler] - Pairing Requirement for Companion: Mandatory
11:48:24.522 [INFO ] [nding.appletv.internal.AppleTVHandler] - Pairing Requirement for MRP: Disabled
11:48:24.524 [INFO ] [nding.appletv.internal.AppleTVHandler] - Pairing Requirement for RAOP: Mandatory
11:48:24.526 [DEBUG] [nding.appletv.internal.AppleTVHandler] - Starting background status update
11:48:24.528 [WARN ] [penhab.binding.appletv.internal.PyATV] - PaTH: /var/lib/openhab/tmp/appletv-binding/bin:/opt/openhab/pyatv/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
11:48:24.529 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing 'appletv:device:16-9F-07-0D-4A-BF' changed from UNKNOWN to OFFLINE
11:48:24.536 [INFO ] [penhab.binding.appletv.internal.PyATV] - Started process 390208
11:48:24.538 [INFO ] [penhab.binding.appletv.internal.PyATV] - Running [/var/lib/openhab/tmp/appletv-binding/bin/atvremote, -i, 169F070D4ABF, --raop-credentials, 1cc2070fe25e8e585c7da7d725d8972609f8a08566d2c55b8f0078c34db18e89:a1302ec366e90ec5bb0562511101afb05c58e3527151a11985caa540004b9ff6:31353946303730442d344142462d343146342d424445422d463934413746433645383030:39663761613861642d346133622d346631652d383838382d383165343865646566323833, --airplay-credentials, 1cc2070fe25e8e585c7da7d725d8972609f8a08566d2c55b8f0078c34db18e89:7a9a0f34a7c6a99739686e1152fd83439a0a4addf157d248c5764c2dfd8c6370:31353946303730442d344142462d343146342d424445422d463934413746433645383030:30613533313862372d663461632d343561392d623838612d313163646131643436323763, --companion-credentials, 1cc2070fe25e8e585c7da7d725d8972609f8a08566d2c55b8f0078c34db18e89:92d1df058880f7f341addf3ead8b5ad07eebf8ed5aad252712f7274e2cffcb59:31353946303730442d344142462d343146342d424445422d463934413746433645383030:61636430336339362d636337662d346366652d386633302d323766643533386439626637, mac]
11:48:36.258 [WARN ] [nding.appletv.internal.AppleTVHandler] - Pairing failed: Traceback (most recent call last):
  File "/var/lib/openhab/tmp/appletv-binding/lib/python3.11/site-packages/pyatv/support/http.py", line 464, in send_and_receive
    await pending_request.event.wait()
  File "/usr/lib/python3.11/asyncio/locks.py", line 213, in wait
    await fut
asyncio.exceptions.CancelledError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/var/lib/openhab/tmp/appletv-binding/lib/python3.11/site-packages/pyatv/support/http.py", line 463, in send_and_receive
    async with async_timeout.timeout(timeout):
  File "/usr/lib/python3.11/asyncio/timeouts.py", line 98, in __aexit__
    raise TimeoutError
TimeoutError

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/var/lib/openhab/tmp/appletv-binding/lib/python3.11/site-packages/pyatv/protocols/airplay/__init__.py", line 271, in _connect_rc
    await session.setup_remote_control()
  File "/var/lib/openhab/tmp/appletv-binding/lib/python3.11/site-packages/pyatv/protocols/airplay/ap2_session.py", line 80, in setup_remote_control
    await self._setup_event_channel(self.connection.remote_ip)
  File "/var/lib/openhab/tmp/appletv-binding/lib/python3.11/site-packages/pyatv/protocols/airplay/ap2_session.py", line 119, in _setup_event_channel
    resp = await self._setup(
           ^^^^^^^^^^^^^^^^^^
  File "/var/lib/openhab/tmp/appletv-binding/lib/python3.11/site-packages/pyatv/protocols/airplay/ap2_session.py", line 112, in _setup
    resp = await self.rtsp.setup(body=body)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/var/lib/openhab/tmp/appletv-binding/lib/python3.11/site-packages/pyatv/support/rtsp.py", line 177, in setup
    return await self.exchange("SETUP", headers=headers, body=body)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/var/lib/openhab/tmp/appletv-binding/lib/python3.11/site-packages/pyatv/support/rtsp.py", line 294, in exchange
    resp = await self.connection.send_and_receive(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/var/lib/openhab/tmp/appletv-binding/lib/python3.11/site-packages/pyatv/support/http.py", line 475, in send_and_receive
    raise TimeoutError(f"no response to {method} {uri} ({protocol})") from ex
TimeoutError: no response to SETUP rtsp://192.168.0.10/2949972738 (RTSP/1.0)

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/var/lib/openhab/tmp/appletv-binding/lib/python3.11/site-packages/pyatv/scripts/atvremote.py", line 998, in _run_application
    return await cli_handler(loop)
           ^^^^^^^^^^^^^^^^^^^^^^^
  File "/var/lib/openhab/tmp/appletv-binding/lib/python3.11/site-packages/pyatv/scripts/atvremote.py", line 727, in cli_handler
    return await _handle_commands(args, config, storage, loop)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/var/lib/openhab/tmp/appletv-binding/lib/python3.11/site-packages/pyatv/scripts/atvremote.py", line 866, in _handle_commands
    atv = await connect(config, loop, protocol=args.protocol, storage=storage)
          ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/var/lib/openhab/tmp/appletv-binding/lib/python3.11/site-packages/pyatv/__init__.py", line 155, in connect
    await atv.connect()
  File "/var/lib/openhab/tmp/appletv-binding/lib/python3.11/site-packages/pyatv/core/facade.py", line 723, in connect
    if await setup_data.connect():
       ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/var/lib/openhab/tmp/appletv-binding/lib/python3.11/site-packages/pyatv/protocols/airplay/__init__.py", line 280, in _connect_rc
    raise exceptions.ProtocolError(
pyatv.exceptions.ProtocolError: Failed to set up remote control channel

>>> An error occurred, full stack trace above

Thanks for suggestions and/or pointers in the right direction.

I appear to have made a more positive progress. I’ve added all the credential strings, as generated by the atvremote pair command, in the Thing setup. Is it odd that the Thing now says:

Pairing requirement for Airplay is Disabled, but credentials are set. Pairing requirement for Companion is Disabled, but credentials are set. Pairing requirement for RAOP is Disabled, but credentials are set.

Any ideas? Suggestions? Thank you!

This is the output of the log file…

17:56:01.159 [INFO ] [ppletv.internal.AppleTVHandlerFactory] - Calling createHandler: appletv:device:XX-XX-XX-XX-XX-XX (ThingTypeUID=appletv:device, Bridge=False, Label=Apple TV Living Room (AppleTV Gen4K), Status=UNINITIALIZED, StatusInfo=UNINITIALIZED (NOT_YET_READY), SemanticEquipmentTag=null)
17:56:01.160 [INFO ] [ppletv.internal.AppleTVHandlerFactory] - Creating a thing handler
17:56:01.168 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing 'appletv:device:XX-XX-XX-XX-XX-XX' changed from UNINITIALIZED (NOT_YET_READY) to INITIALISING
17:56:01.174 [INFO ] [nding.appletv.internal.AppleTVHandler] - AppleTV Properties: {macAddress=XX-XX-XX-XX-XX-XX, firmwareVersion=TvOS 26.1, modelId=AppleTV Gen4K, deviceId=XX-XX-XX-XX-XX-XX, vendor=Apple}
17:56:01.176 [INFO ] [nding.appletv.internal.AppleTVHandler] - Initializing AppleTV
17:56:01.180 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing 'appletv:device:XX-XX-XX-XX-XX-XX' changed from INITIALIZING to UNKNOWN
17:56:01.188 [DEBUG] [nding.appletv.internal.AppleTVHandler] - Configuration updated.
17:56:01.190 [INFO ] [nding.appletv.internal.AppleTVHandler] - Pairing Requirement for Airplay: Disabled
17:56:01.191 [WARN ] [nding.appletv.internal.AppleTVHandler] - Pairing requirement for Airplay is Disabled, but credentials are set.
17:56:01.192 [INFO ] [nding.appletv.internal.AppleTVHandler] - Pairing Requirement for Companion: Disabled
17:56:01.193 [WARN ] [nding.appletv.internal.AppleTVHandler] - Pairing requirement for Companion is Disabled, but credentials are set.
17:56:01.194 [INFO ] [nding.appletv.internal.AppleTVHandler] - Pairing Requirement for MRP: Disabled
17:56:01.195 [INFO ] [nding.appletv.internal.AppleTVHandler] - Pairing Requirement for RAOP: Disabled
17:56:01.196 [WARN ] [nding.appletv.internal.AppleTVHandler] - Pairing requirement for RAOP is Disabled, but credentials are set.
17:56:01.200 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing 'appletv:device:XX-XX-XX-XX-XX-XX' changed from UNKNOWN to OFFLINE (CONFIGURATION_PENDING): Pairing requirement for Airplay is Disabled, but credentials are set.
Pairing requirement for Companion is Disabled, but credentials are set.
Pairing requirement for RAOP is Disabled, but credentials are set.

Maybe I’m another step closer! Apple TV Thing comes ONLINE then immediately goes OFFLINE and this sequence repeats.

In the log file I see the following…

17:36:59.941 [INFO ] [penhab.binding.appletv.internal.PyATV] - Started process 474295
17:36:59.944 [INFO ] [penhab.binding.appletv.internal.PyATV] - Running [/var/lib/openhab/tmp/appletv-binding/bin/atvremote, -i, XXXXXXXXXXXX, mac]
17:37:00.556 [DEBUG] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: got some json {"result":"failure","datetime":"2025-11-27T17:37:00.555799+00:00","error":"unsupported_command"}
17:37:00.559 [DEBUG] [nding.appletv.internal.AppleTVHandler] - Received command result: {"result":"failure","datetime":"2025-11-27T17:37:00.555799+00:00","error":"unsupported_command"}
17:37:00.563 [DEBUG] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop looking for json
17:37:00.954 [DEBUG] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop looking for json
17:37:00.956 [DEBUG] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: No more JSON
17:37:00.958 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: Command process=474289 exited.
17:37:00.960 [INFO ] [inding.appletv.internal.PyATV$Scanner] - Process 474289 exists.
17:37:00.963 [DEBUG] [inding.appletv.internal.PyATV$Scanner] - process clear: []
17:37:00.965 [INFO ] [nding.appletv.internal.AppleTVHandler] - Received word that device went offline.
17:37:00.969 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: stop()
17:37:00.971 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: Scanner not running, will not attempt to stop.
17:37:00.971 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: Attempt to read command queue was interrupted.
17:37:00.977 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing 'appletv:device:XX-XX-XX-XX-XX-XX' changed from ONLINE to OFFLINE
17:37:00.977 [DEBUG] [nding.appletv.internal.AppleTVHandler] - Starting background status update
17:37:00.975 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: exiting command poller
17:37:00.984 [ERROR] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: Exception thrown in runWriterThread
java.lang.NullPointerException: Cannot invoke "java.lang.Process.pid()" because "this.process" is null
        at org.openhab.binding.appletv.internal.PyATV$Scanner.runWriterThread(PyATV.java:381) ~[?:?]
        at java.lang.Thread.run(Unknown Source) [?:?]
17:37:00.983 [INFO ] [inding.appletv.internal.PyATV$Scanner] - returning because !keepRunning
17:37:00.983 [WARN ] [penhab.binding.appletv.internal.PyATV] - PaTH: /var/lib/openhab/tmp/appletv-binding/bin:/opt/openhab/pyatv/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin

At this point I have no credentials set in the UI for Companion, AirPlay, nor RAOP. Adding credentials brings back the error message of credentials set but pairing requirement is disabled.

ChatGPT suggests there is a compatibility issue between tvOS 26.1 and the binding. Could that be true?

Thanks!

Sorry you’re having difficulties; I’m sure we can figure out what’s going on, it might just take some back-and-forth.

The errors you’re seeing are strange… My device is running 26.1 and seems to be working without problems. I think the log snippet you posted is missing some information… I’m not sure why you’re seeing an “unsupported_command” error. The command it’s attempting to run should appear just before that message. Can you look through your openhab log for the string “AppleTVCommandLoop: Sending command”…

I honestly don’t know if chatGPT can be trusted in this case; it’s possible there are folks reporting trouble outside this forum (or it’s made the connection that pyatv is involved).

I did restart my binding and it looks like it’s able to get the authentication requirements properly, so I think this should work for you as well.

There is a setting that might need to be changed on your device… go into Settings → Airplay and Apple Home → Allow Access and make sure that it’s set to “Same Network” and “No password”. I seem to recall someone reporting a problem involving that.

Also, just to verify, in Settings→Remotes and Devices→Remote App and Devices, there should be an entry for pyatv. I have many, but I think that’s because of my past attempts to get this binding working reliably. You can always remove these, but you’ll need to repair afterwards.

1 Like

Thank you Bill, appreciate your help.

Below is a larger extract from the log:tail within Karaf which may be a little repetitive.

In the Apple TV, in Settings → Remotes and Devices → Remote App and Devices I can confirm there are 3 remotes named pyatv - one each for companion, airplay, and RAOP.

In the Settings → Airplay and Apple Home → AirPlay=On, Allow Access=Everyone, Require Password=Off

Agree with your ChatGPT assessment, it has been helpful to a point but now it keeps sending me in circles.

Thanks again for your help!

09:27:58.752 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing ‘appletv:device:16-9F-07-0D-4A-BF’ changed from OFFLINE to UNINITIALIZED
09:27:58.758 [INFO ] [nding.appletv.internal.AppleTVHandler] - Disposing of AppleTVHandler
09:27:58.769 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing ‘appletv:device:16-9F-07-0D-4A-BF’ changed from UNINITIALIZED to UNINITIALIZED (DISABLED)
09:28:00.691 [INFO ] [ppletv.internal.AppleTVHandlerFactory] - Calling createHandler: appletv:device:16-9F-07-0D-4A-BF (ThingTypeUID=appletv:device, Bridge=False, Label=Apple TV Living Room (AppleTV Gen4K), Status=UNINITIALIZED, StatusInfo=UNINITIALIZED (DISABLED), SemanticEquipmentTag=null)
09:28:00.693 [INFO ] [ppletv.internal.AppleTVHandlerFactory] - Creating a thing handler
09:28:00.702 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing ‘appletv:device:16-9F-07-0D-4A-BF’ changed from UNINITIALIZED (DISABLED) to INITIALIZING
09:28:00.711 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing ‘appletv:device:16-9F-07-0D-4A-BF’ changed from INITIALIZING to UNKNOWN
09:28:00.711 [INFO ] [nding.appletv.internal.AppleTVHandler] - AppleTV Properties: {macAddress=16:9F:07:0D:4A:BF, firmwareVersion=TvOS 26.1, modelId=AppleTV Gen4K, deviceId=16:9F:07:0D:4A:BF, vendor=Apple}
09:28:00.714 [INFO ] [nding.appletv.internal.AppleTVHandler] - Initializing AppleTV
09:28:00.724 [INFO ] [nding.appletv.internal.AppleTVHandler] - Pairing Requirement for Airplay: Disabled
09:28:00.726 [INFO ] [nding.appletv.internal.AppleTVHandler] - Pairing Requirement for Companion: Disabled
09:28:00.727 [INFO ] [nding.appletv.internal.AppleTVHandler] - Pairing Requirement for MRP: Disabled
09:28:00.729 [INFO ] [nding.appletv.internal.AppleTVHandler] - Pairing Requirement for RAOP: Disabled
09:28:00.731 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing ‘appletv:device:16-9F-07-0D-4A-BF’ changed from UNKNOWN to OFFLINE
09:28:00.731 [WARN ] [penhab.binding.appletv.internal.PyATV] - PaTH: /var/lib/openhab/tmp/appletv-binding/bin:/opt/openhab/pyatv/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
09:28:00.750 [INFO ] [penhab.binding.appletv.internal.PyATV] - Started process 813605
09:28:00.758 [INFO ] [penhab.binding.appletv.internal.PyATV] - Running [/var/lib/openhab/tmp/appletv-binding/bin/atvremote, -i, 169F070D4ABF, mac]
09:28:02.680 [INFO ] [nding.appletv.internal.AppleTVHandler] - Pairing Verified: 16:9F:07:0D:4A:BF

09:28:02.682 [WARN ] [penhab.binding.appletv.internal.PyATV] - PaTH: /var/lib/openhab/tmp/appletv-binding/bin:/opt/openhab/pyatv/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
09:28:02.686 [INFO ] [penhab.binding.appletv.internal.PyATV] - Started process 813613
09:28:02.688 [INFO ] [penhab.binding.appletv.internal.PyATV] - Running [/var/lib/openhab/tmp/appletv-binding/bin/atvscript, -i, 169F070D4ABF, all_features]
09:28:04.489 [INFO ] [nding.appletv.internal.AppleTVHandler] - Features: [FAILED toString()]
09:28:04.491 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing ‘appletv:device:16-9F-07-0D-4A-BF’ changed from OFFLINE to ONLINE
09:28:04.491 [INFO ] [nding.appletv.internal.AppleTVHandler] - Command Scanner: null
09:28:04.493 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: start()
09:28:04.495 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: starting handler threads
09:28:04.496 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: Scanner starting
09:28:04.496 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: Commander starting
09:28:04.499 [INFO ] [inding.appletv.internal.PyATV$Scanner] - aieee
09:28:04.501 [WARN ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop process not running. waiting 500ms. Scanner{name=‘AppleTVCommandLoop’, process=null, isStarted=true, expectedCommandLine=‘/var/lib/openhab/tmp/appletv-binding/bin/atvscript -i 169F070D4ABF command_loop’}
09:28:04.502 [WARN ] [inding.appletv.internal.PyATV$Scanner] - PATH: /opt/openhab/pyatv/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
09:28:04.506 [INFO ] [inding.appletv.internal.PyATV$Scanner] - Started process 813619
09:28:04.508 [INFO ] [inding.appletv.internal.PyATV$Scanner] - Process 813619 isRunning=true
09:28:04.510 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: Running /var/lib/openhab/tmp/appletv-binding/bin/atvscript -i 169F070D4ABF command_loop
09:28:06.327 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: Command process=813619 exited.
09:28:06.328 [INFO ] [inding.appletv.internal.PyATV$Scanner] - Process 813619 exists.
09:28:06.333 [WARN ] [inding.appletv.internal.PyATV$Scanner] - PATH: /opt/openhab/pyatv/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
09:28:06.335 [INFO ] [inding.appletv.internal.PyATV$Scanner] - Started process 813623
09:28:06.337 [INFO ] [inding.appletv.internal.PyATV$Scanner] - Process 813623 isRunning=true
09:28:06.339 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: Running /var/lib/openhab/tmp/appletv-binding/bin/atvscript -i 169F070D4ABF command_loop
09:28:08.128 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: Command process=813623 exited.
09:28:08.130 [INFO ] [inding.appletv.internal.PyATV$Scanner] - Process 813623 exists.
09:28:08.132 [INFO ] [nding.appletv.internal.AppleTVHandler] - Received word that device went offline.
09:28:08.133 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: stop()
09:28:08.135 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: Scanner not running, will not attempt to stop.
09:28:08.135 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: Attempt to read command queue was interrupted.
09:28:08.137 [WARN ] [penhab.binding.appletv.internal.PyATV] - PaTH: /var/lib/openhab/tmp/appletv-binding/bin:/opt/openhab/pyatv/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
09:28:08.137 [INFO ] [inding.appletv.internal.PyATV$Scanner] - returning because !keepRunning
09:28:08.138 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing ‘appletv:device:16-9F-07-0D-4A-BF’ changed from ONLINE to OFFLINE
09:28:08.138 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: exiting command poller
09:28:08.143 [ERROR] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: Exception thrown in runWriterThread
java.lang.NullPointerException: null
09:28:08.143 [INFO ] [penhab.binding.appletv.internal.PyATV] - Started process 813627
09:28:08.146 [INFO ] [penhab.binding.appletv.internal.PyATV] - Running [/var/lib/openhab/tmp/appletv-binding/bin/atvremote, -i, 169F070D4ABF, mac]
09:28:09.935 [INFO ] [nding.appletv.internal.AppleTVHandler] - Pairing Verified: 16:9F:07:0D:4A:BF

09:28:09.937 [WARN ] [penhab.binding.appletv.internal.PyATV] - PaTH: /var/lib/openhab/tmp/appletv-binding/bin:/opt/openhab/pyatv/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
09:28:09.941 [INFO ] [penhab.binding.appletv.internal.PyATV] - Started process 813630
09:28:09.943 [INFO ] [penhab.binding.appletv.internal.PyATV] - Running [/var/lib/openhab/tmp/appletv-binding/bin/atvscript, -i, 169F070D4ABF, all_features]
09:28:11.644 [INFO ] [openhab.event.ItemCommandEvent       ] - Item ‘i_HK_Front_Bedroom_Mode’ received command 0
09:28:11.663 [INFO ] [openhab.event.ItemCommandEvent       ] - Item ‘i_HK_Living_Room_Mode’ received command 0
09:28:11.670 [INFO ] [openhab.event.ItemCommandEvent       ] - Item ‘i_HK_Garden_Room_Mode’ received command 0
09:28:11.741 [INFO ] [nding.appletv.internal.AppleTVHandler] - Features: [FAILED toString()]
09:28:11.742 [INFO ] [nding.appletv.internal.AppleTVHandler] - Command Scanner: null
09:28:11.743 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing ‘appletv:device:16-9F-07-0D-4A-BF’ changed from OFFLINE to ONLINE
09:28:11.745 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: start()
09:28:11.747 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: starting handler threads
09:28:11.749 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: Scanner starting
09:28:11.749 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: Commander starting
09:28:11.752 [INFO ] [inding.appletv.internal.PyATV$Scanner] - aieee
09:28:11.754 [WARN ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop process not running. waiting 500ms. Scanner{name=‘AppleTVCommandLoop’, process=null, isStarted=true, expectedCommandLine=‘/var/lib/openhab/tmp/appletv-binding/bin/atvscript -i 169F070D4ABF command_loop’}
09:28:11.754 [WARN ] [inding.appletv.internal.PyATV$Scanner] - PATH: /opt/openhab/pyatv/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
09:28:11.758 [INFO ] [inding.appletv.internal.PyATV$Scanner] - Started process 813636
09:28:11.759 [INFO ] [inding.appletv.internal.PyATV$Scanner] - Process 813636 isRunning=true
09:28:11.761 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: Running /var/lib/openhab/tmp/appletv-binding/bin/atvscript -i 169F070D4ABF command_loop
09:28:13.529 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: Command process=813636 exited.
09:28:13.531 [INFO ] [inding.appletv.internal.PyATV$Scanner] - Process 813636 exists.
09:28:13.535 [WARN ] [inding.appletv.internal.PyATV$Scanner] - PATH: /opt/openhab/pyatv/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
09:28:13.537 [INFO ] [inding.appletv.internal.PyATV$Scanner] - Started process 813640
09:28:13.538 [INFO ] [inding.appletv.internal.PyATV$Scanner] - Process 813640 isRunning=true
09:28:13.540 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: Running /var/lib/openhab/tmp/appletv-binding/bin/atvscript -i 169F070D4ABF command_loop
09:28:15.321 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: Command process=813640 exited.
09:28:15.323 [INFO ] [inding.appletv.internal.PyATV$Scanner] - Process 813640 exists.
09:28:15.324 [INFO ] [nding.appletv.internal.AppleTVHandler] - Received word that device went offline.
09:28:15.326 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: stop()
09:28:15.327 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: Attempt to read command queue was interrupted.
09:28:15.327 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: Scanner not running, will not attempt to stop.
09:28:15.329 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: exiting command poller
09:28:15.330 [WARN ] [penhab.binding.appletv.internal.PyATV] - PaTH: /var/lib/openhab/tmp/appletv-binding/bin:/opt/openhab/pyatv/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
09:28:15.331 [ERROR] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: Exception thrown in runWriterThread
java.lang.NullPointerException: null
09:28:15.332 [INFO ] [inding.appletv.internal.PyATV$Scanner] - returning because !keepRunning
09:28:15.337 [INFO ] [penhab.binding.appletv.internal.PyATV] - Started process 813643
09:28:15.334 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing ‘appletv:device:16-9F-07-0D-4A-BF’ changed from ONLINE to OFFLINE
09:28:15.339 [INFO ] [penhab.binding.appletv.internal.PyATV] - Running [/var/lib/openhab/tmp/appletv-binding/bin/atvremote, -i, 169F070D4ABF, mac]
09:28:17.196 [INFO ] [nding.appletv.internal.AppleTVHandler] - Pairing Verified: 16:9F:07:0D:4A:BF

09:28:17.197 [WARN ] [penhab.binding.appletv.internal.PyATV] - PaTH: /var/lib/openhab/tmp/appletv-binding/bin:/opt/openhab/pyatv/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
09:28:17.202 [INFO ] [penhab.binding.appletv.internal.PyATV] - Started process 813646
09:28:17.203 [INFO ] [penhab.binding.appletv.internal.PyATV] - Running [/var/lib/openhab/tmp/appletv-binding/bin/atvscript, -i, 169F070D4ABF, all_features]
09:28:18.991 [INFO ] [nding.appletv.internal.AppleTVHandler] - Features: [FAILED toString()]
09:28:18.993 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing ‘appletv:device:16-9F-07-0D-4A-BF’ changed from OFFLINE to ONLINE
09:28:18.992 [INFO ] [nding.appletv.internal.AppleTVHandler] - Command Scanner: null
09:28:18.995 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: start()
09:28:18.997 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: starting handler threads
09:28:18.998 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: Commander starting
09:28:18.998 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: Scanner starting
09:28:19.000 [INFO ] [inding.appletv.internal.PyATV$Scanner] - aieee
09:28:19.002 [WARN ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop process not running. waiting 500ms. Scanner{name=‘AppleTVCommandLoop’, process=null, isStarted=true, expectedCommandLine=‘/var/lib/openhab/tmp/appletv-binding/bin/atvscript -i 169F070D4ABF command_loop’}
09:28:19.004 [WARN ] [inding.appletv.internal.PyATV$Scanner] - PATH: /opt/openhab/pyatv/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
09:28:19.005 [INFO ] [inding.appletv.internal.PyATV$Scanner] - Started process 813651
09:28:19.007 [INFO ] [inding.appletv.internal.PyATV$Scanner] - Process 813651 isRunning=true
09:28:19.009 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: Running /var/lib/openhab/tmp/appletv-binding/bin/atvscript -i 169F070D4ABF command_loop
09:28:20.740 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: Command process=813651 exited.
09:28:20.741 [INFO ] [inding.appletv.internal.PyATV$Scanner] - Process 813651 exists.
09:28:20.746 [WARN ] [inding.appletv.internal.PyATV$Scanner] - PATH: /opt/openhab/pyatv/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
09:28:20.747 [INFO ] [inding.appletv.internal.PyATV$Scanner] - Started process 813654
09:28:20.749 [INFO ] [inding.appletv.internal.PyATV$Scanner] - Process 813654 isRunning=true
09:28:20.751 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: Running /var/lib/openhab/tmp/appletv-binding/bin/atvscript -i 169F070D4ABF command_loop
09:28:22.569 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: Command process=813654 exited.
09:28:22.571 [INFO ] [inding.appletv.internal.PyATV$Scanner] - Process 813654 exists.
09:28:22.572 [INFO ] [nding.appletv.internal.AppleTVHandler] - Received word that device went offline.
09:28:22.574 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: stop()
09:28:22.575 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: Attempt to read command queue was interrupted.
09:28:22.575 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: Scanner not running, will not attempt to stop.
09:28:22.576 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: exiting command poller
09:28:22.577 [WARN ] [penhab.binding.appletv.internal.PyATV] - PaTH: /var/lib/openhab/tmp/appletv-binding/bin:/opt/openhab/pyatv/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
09:28:22.578 [ERROR] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: Exception thrown in runWriterThread
java.lang.NullPointerException: null
09:28:22.578 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing ‘appletv:device:16-9F-07-0D-4A-BF’ changed from ONLINE to OFFLINE
09:28:22.579 [INFO ] [inding.appletv.internal.PyATV$Scanner] - returning because !keepRunning
09:28:22.583 [INFO ] [penhab.binding.appletv.internal.PyATV] - Started process 813657
09:28:22.585 [INFO ] [penhab.binding.appletv.internal.PyATV] - Running [/var/lib/openhab/tmp/appletv-binding/bin/atvremote, -i, 169F070D4ABF, mac]
09:28:24.376 [INFO ] [nding.appletv.internal.AppleTVHandler] - Pairing Verified: 16:9F:07:0D:4A:BF

09:28:24.378 [WARN ] [penhab.binding.appletv.internal.PyATV] - PaTH: /var/lib/openhab/tmp/appletv-binding/bin:/opt/openhab/pyatv/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
09:28:24.382 [INFO ] [penhab.binding.appletv.internal.PyATV] - Started process 813660
09:28:24.384 [INFO ] [penhab.binding.appletv.internal.PyATV] - Running [/var/lib/openhab/tmp/appletv-binding/bin/atvscript, -i, 169F070D4ABF, all_features]
09:28:26.203 [INFO ] [nding.appletv.internal.AppleTVHandler] - Features: [FAILED toString()]
09:28:26.205 [INFO ] [nding.appletv.internal.AppleTVHandler] - Command Scanner: null
09:28:26.206 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing ‘appletv:device:16-9F-07-0D-4A-BF’ changed from OFFLINE to ONLINE
09:28:26.207 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: start()
09:28:26.210 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: starting handler threads
09:28:26.212 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: Commander starting
09:28:26.212 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: Scanner starting
09:28:26.214 [INFO ] [inding.appletv.internal.PyATV$Scanner] - aieee
09:28:26.217 [WARN ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop process not running. waiting 500ms. Scanner{name=‘AppleTVCommandLoop’, process=null, isStarted=true, expectedCommandLine=‘/var/lib/openhab/tmp/appletv-binding/bin/atvscript -i 169F070D4ABF command_loop’}
09:28:26.218 [WARN ] [inding.appletv.internal.PyATV$Scanner] - PATH: /opt/openhab/pyatv/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
09:28:26.221 [INFO ] [inding.appletv.internal.PyATV$Scanner] - Started process 813665
09:28:26.223 [INFO ] [inding.appletv.internal.PyATV$Scanner] - Process 813665 isRunning=true
09:28:26.226 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: Running /var/lib/openhab/tmp/appletv-binding/bin/atvscript -i 169F070D4ABF command_loop
09:28:28.020 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: Command process=813665 exited.
09:28:28.021 [INFO ] [inding.appletv.internal.PyATV$Scanner] - Process 813665 exists.
09:28:28.026 [WARN ] [inding.appletv.internal.PyATV$Scanner] - PATH: /opt/openhab/pyatv/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
09:28:28.028 [INFO ] [inding.appletv.internal.PyATV$Scanner] - Started process 813668
09:28:28.030 [INFO ] [inding.appletv.internal.PyATV$Scanner] - Process 813668 isRunning=true
09:28:28.031 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: Running /var/lib/openhab/tmp/appletv-binding/bin/atvscript -i 169F070D4ABF command_loop
09:28:29.813 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: Command process=813668 exited.
09:28:29.815 [INFO ] [inding.appletv.internal.PyATV$Scanner] - Process 813668 exists.
09:28:29.817 [INFO ] [nding.appletv.internal.AppleTVHandler] - Received word that device went offline.
09:28:29.818 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: stop()
09:28:29.820 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: Scanner not running, will not attempt to stop.
09:28:29.820 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: Attempt to read command queue was interrupted.
09:28:29.822 [WARN ] [penhab.binding.appletv.internal.PyATV] - PaTH: /var/lib/openhab/tmp/appletv-binding/bin:/opt/openhab/pyatv/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
09:28:29.823 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing ‘appletv:device:16-9F-07-0D-4A-BF’ changed from ONLINE to OFFLINE
09:28:29.821 [INFO ] [inding.appletv.internal.PyATV$Scanner] - returning because !keepRunning
09:28:29.822 [INFO ] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: exiting command poller
09:28:29.826 [ERROR] [inding.appletv.internal.PyATV$Scanner] - AppleTVCommandLoop: Exception thrown in runWriterThread
java.lang.NullPointerException: null
09:28:29.829 [INFO ] [penhab.binding.appletv.internal.PyATV] - Started process 813671
09:28:29.831 [INFO ] [penhab.binding.appletv.internal.PyATV] - Running [/var/lib/openhab/tmp/appletv-binding/bin/atvremote, -i, 169F070D4ABF, mac]
09:28:30.220 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing ‘appletv:device:16-9F-07-0D-4A-BF’ changed from OFFLINE to UNINITIALIZED
09:28:30.226 [INFO ] [nding.appletv.internal.AppleTVHandler] - Disposing of AppleTVHandler
09:28:30.228 [INFO ] [penhab.binding.appletv.internal.PyATV] - forcibly destroying 813671
09:28:30.230 [WARN ] [nding.appletv.internal.AppleTVHandler] - Pairing failed: null
09:28:30.235 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing ‘appletv:device:16-9F-07-0D-4A-BF’ changed from UNINITIALIZED to OFFLINE (CONFIGURATION_ERROR)
09:28:30.237 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing ‘appletv:device:16-9F-07-0D-4A-BF’ changed from OFFLINE (CONFIGURATION_ERROR) to UNINITIALIZED (DISABLED)