Apple TV - apple_tv:failed to login

Configuration
53

Just installed 0.40.1, which has introduced a new crop of Apple TV related errors:

Mar 16 10:50:36 raspberrypi2 hass[21163]: 17-03-16 10:50:36 WARNING (MainThread) [homeassistant.components.media_player.apple_tv] A <class 'AttributeError'> error occurred: 'NoneType' object has no attribute 'cancel'
Mar 16 10:50:46 raspberrypi2 hass[21163]: 17-03-16 10:50:46 WARNING (MainThread) [homeassistant.components.media_player.apple_tv] A <class 'AttributeError'> error occurred: 'NoneType' object has no attribute 'cancel'
Mar 16 10:50:56 raspberrypi2 hass[21163]: 17-03-16 10:50:56 WARNING (MainThread) [homeassistant.components.media_player.apple_tv] A <class 'AttributeError'> error occurred: 'NoneType' object has no attribute 'cancel'
Mar 16 10:51:01 raspberrypi2 hass[21163]: 17-03-16 10:51:01 ERROR (MainThread) [homeassistant.core] Error doing job: Unclosed connection
Mar 16 10:51:01 raspberrypi2 hass[21163]: 17-03-16 10:51:01 ERROR (MainThread) [homeassistant.core] Error doing job: Unclosed response
Mar 16 10:51:01 raspberrypi2 hass[21163]: 17-03-16 10:51:01 ERROR (MainThread) [homeassistant.core] Error doing job: Unclosed connection
Mar 16 10:51:01 raspberrypi2 hass[21163]: 17-03-16 10:51:01 ERROR (MainThread) [homeassistant.core] Error doing job: Unclosed response
Mar 16 10:51:01 raspberrypi2 hass[21163]: 17-03-16 10:51:01 ERROR (MainThread) [homeassistant.core] Error doing job: Unclosed connection
Mar 16 10:51:01 raspberrypi2 hass[21163]: 17-03-16 10:51:01 ERROR (MainThread) [homeassistant.core] Error doing job: Unclosed response
Mar 16 10:51:06 raspberrypi2 hass[21163]: 17-03-16 10:51:06 WARNING (MainThread) [homeassistant.components.media_player.apple_tv] A <class 'AttributeError'> error occurred: 'NoneType' object has no attribute 'cancel'

Is anyone else seeing this in their log?

54

Yeah, it seems to be an issue: https://github.com/home-assistant/home-assistant/issues/6642

55

Still seeing quite a few failed logins, also my atv tiles do the little dance as well.

grep "failed to login" /etc/homeassistant/home-assistant.log |wc -l
5769

Running version 0.41.0

56

Can you try to do something with atvremote when you see these errors? A theory I have is that a re-login would help and maybe if you login from somewhere else, Home Assistant would perform a new login since the session it uses would no longer be valid. So basically, run Home Assistant as usual and just run “atvremote -a playing” or so in another shell. Hopefully you should find a log printout along the line “implicitly logged out” in your log. If this works, I can add a check I pyatv do a re-login of error 400 happens.

57

Yea, I’ll give that a try the next time I see the 400 errors in my logs, and report back.

58

@aaronwolen @Jer78 I couldn’t find a specific thread about the dancing media player component, that I’m also experiencing, so I started one! Media_Player Dancing

59

So I was working on HA again today, and noticed the good ole “400” error. In another terminal, I ran “atvremote -a playing”, but I did not see the “implicitly logged out” message in my logs.

Here’s what I did see…

17-04-09 19:34:00 WARNING (MainThread) [homeassistant.components.media_player.apple_tv] A <class 'pyatv.exceptions.AuthenticationError'> error occurred: failed to login: 400
17-04-09 19:34:10 WARNING (MainThread) [homeassistant.components.media_player.apple_tv] A <class 'pyatv.exceptions.AuthenticationError'> error occurred: failed to login: 400
17-04-09 19:34:20 WARNING (MainThread) [homeassistant.components.media_player.apple_tv] A <class 'pyatv.exceptions.AuthenticationError'> error occurred: failed to login: 400
17-04-09 19:34:30 WARNING (MainThread) [homeassistant.components.media_player.apple_tv] A <class 'pyatv.exceptions.AuthenticationError'> error occurred: failed to login: 400
17-04-09 19:34:40 WARNING (MainThread) [homeassistant.components.media_player.apple_tv] A <class 'pyatv.exceptions.AuthenticationError'> error occurred: failed to login: 400
Apr  9 19:34:40 droid hass[7767]: #033[33m17-04-09 19:34:40 WARNING (MainThread) [homeassistant.components.media_player.apple_tv] A <class 'pyatv.exceptions.AuthenticationError'> error occurred: failed to login: 400#033[0m
17-04-09 19:34:50 WARNING (MainThread) [homeassistant.components.media_player.apple_tv] A <class 'pyatv.exceptions.AuthenticationError'> error occurred: failed to login: 400
Apr  9 19:34:50 droid hass[7767]: #033[33m17-04-09 19:34:50 WARNING (MainThread) [homeassistant.components.media_player.apple_tv] A <class 'pyatv.exceptions.AuthenticationError'> error occurred: failed to login: 400#033[0m
Apr  9 19:35:00 droid hass[7767]: #033[33m17-04-09 19:35:00 WARNING (MainThread) [homeassistant.components.media_player.apple_tv] A <class 'pyatv.exceptions.AuthenticationError'> error occurred: failed to login: 400#033[0m
17-04-09 19:35:00 WARNING (MainThread) [homeassistant.components.media_player.apple_tv] A <class 'pyatv.exceptions.AuthenticationError'> error occurred: failed to login: 400
17-04-09 19:35:10 WARNING (MainThread) [homeassistant.components.media_player.apple_tv] A <class 'pyatv.exceptions.AuthenticationError'> error occurred: failed to login: 400
Apr  9 19:35:10 droid hass[7767]: #033[33m17-04-09 19:35:10 WARNING (MainThread) [homeassistant.components.media_player.apple_tv] A <class 'pyatv.exceptions.AuthenticationError'> error occurred: failed to login: 400#033[0m
17-04-09 19:35:20 WARNING (MainThread) [homeassistant.components.media_player.apple_tv] A <class 'pyatv.exceptions.AuthenticationError'> error occurred: failed to login: 400
Apr  9 19:35:20 droid hass[7767]: #033[33m17-04-09 19:35:20 WARNING (MainThread) [homeassistant.components.media_player.apple_tv] A <class 'pyatv.exceptions.AuthenticationError'> error occurred: failed to login: 400#033[0m
60

Hi all,

Chiming in with the same issue.

“atvremote -a playing” gives the correct output, but no “implicitly logged out” message appears in the logs. 400 errors continue.

61

Thanks for the update! I believe that this is linked to the “dancing media player” issue. Requests are made for the artwork but it isn’t available. I’m hoping to fix this soon, but I’m currently blocked from releasing next version of pyatv with lots of updates due to external requirement issues. Hopefully this will be resolved once I can get the release out the door.

62

I made the change without upgrading the library and it was merged quickly. So, feel free to try latest dev out and see if it works!

63

To add on to my post from yesterday:

I restarted HA and the 400 errors went away, the module connected and reported and controlled the ATV successfully. The “dancing” continued obviously.

Scratch that, error comes back eventually.

64

Updated HA to 0.43. Rather than multiple 400 errors, I now have just one (I imagine this is due to the “dancing” player fix :slight_smile: ).

atv shell command still works successfully, but the component does not update when the ATV starts playing something. It only ever displays “No title”.

65

That is somewhat better at least :blush: What have you tried playing? I’m not sure how much metadata is avsilande through DAAP on the ATV4. If you try to stream some music, can you see title then?

66

I use it primarily with Plex, and occasionally BBC iPlayer.

The best I can say is it sometimes works. I haven’t yet managed to find a pattern where I can make it not connect, nor a pattern where I can make it connect.

Happy to try any suggestions!

67

I think it’s a bit up to the app and I know that plex in particular is a bit strange. Not much I can do I’m afraid until I can implement the new protocol.

68

Hmm I’m not sure I agree with that - because when I use the actual atv command I get a correct output. That’s what I don’t understand. It should work. If I didn’t get a 400 error at some point during HA execution, it should work.

I don’t know what causes the 400 error though, and I don’t know at what point it tends to occur.

69

Oh, ok, that’s very strange yes. Question is what the library is getting for information during updates. Can you add debug logging for pyatv.daap and upload some log outputs?

70

Done. Will get back to you after I’ve got some data :slight_smile:

1 Like
71

I have just seen these errors in the logs too, they appear every 10 seconds

If it is of interest , the media player widget that I have for my Apple TV on the main screen says that it is 'Not Connected to Apple TV"

If I press the power button icon on that widget, which changes it to ‘off’ - it looks like those 10 second log entries stop.

If I power it back on again, it still shows that it is 'Not Connected…" and the log starts to fill up again.

72

Is this with the latest version of home assistant installed?