postlund / pyatv

A client library for Apple TV and AirPlay devices
https://pyatv.dev
MIT License
891 stars 100 forks source link

Player management is handled differently in tvOS 14 #905

Closed postlund closed 3 years ago

postlund commented 3 years ago

Describe the bug It seems like tvOS 14 is handling players, I.e. what determines what is currently playing a bit differently. I have not had the chance to investigate this further yet, but I have an example dump.

To Reproduce I'm playing an example video via AirPlay in one terminal:

atvremote -s 10.0.10.81 --airplay-credentials `cat aplay` --debug play_url=bigbuck.mp4

I then listen to push updates in another terminal and just stop the AirPlay stream (Ctrl+C):

$ atvremote -s 10.0.10.81 --debug push_updates
...
Press ENTER to stop
Media type: Video
Device state: Playing
Title:
Position: 7/596s (1.2%)
Repeat: Off
Shuffle: Off
--------------------
2020-12-24 23:00:40 DEBUG: 10.0.10.254:56125<->10.0.10.81:49153 << Receive (Data=9701080420004a6a42004a660a12120a5661726461677372756d18cc86bde204121808af011213636f6d2e6170706c652e5456416972506c61791a360a2a61766b69742d32423730314331302d414539392d343538432d394438362d3334423733433938423039331208706c617965722d36aa052435363939393936302d453031332d343038302d424543352d364445433245313237443343960108362000d203680a660a12120a5661726461677372756d18cc86bde204121808af011213636f6d2e6170706c652e5456416972506c61791a360a2a61766b69742d32423730314331302d414539392d343538432d394438362d333442373343393842303...)
2020-12-24 23:00:40 DEBUG: 10.0.10.254:56125<->10.0.10.81:49153 << Receive: Protobuf: type: SET_STATE_MESSAGE
errorCode: NoError
[setStateMessage] {
  playbackQueueCapabilities {
  }
  playerPath {
origin {
displayName: "Vardagsrum"
identifier: 1280262988
}
client {
processIdentifier: 175
bundleIdentifier: "com.apple.TVAirPlay"  
}
player {
identifier: "avkit-2B701C10-AE99-458C-9D86-34B73C98B093"
displayName: "player-6"
}
  }
}
85: "56999960-E013-4080-BEC5-6DEC2E127D3C"
2020-12-24 23:00:40 DEBUG: Dispatching message with type 4 (SetStateMessage) to Listener(func=<bound method PlayerStateManager._handle_set_state of <pyatv.mrp.player_state.PlayerStateManager object at 0x7ff82cf64b20>>, data=None)
2020-12-24 23:00:40 DEBUG: 10.0.10.254:56125<->10.0.10.81:49153 << Receive: Protobuf: type: REMOVE_PLAYER_MESSAGE
errorCode: NoError
[removePlayerMessage] {
playerPath {
  origin {
displayName: "Vardagsrum"
identifier: 1280262988
}
client {
processIdentifier: 175
bundleIdentifier: "com.apple.TVAirPlay"  
}
player {
identifier: "avkit-2B701C10-AE99-458C-9D86-34B73C98B093"
displayName: "player-6"
}
  }
}
85: "CCF8C3FC-9355-4245-BF67-626CCA8104EF"
2020-12-24 23:00:40 DEBUG: 10.0.10.254:56125<->10.0.10.81:49153 << Receive (Data=8b01082f20009a035d0a5b0a12120a5661726461677372756d18cc86bde204121808af011213636f6d2e6170706c652e5456416972506c61791a2b0a194d6564696152656d6f74652d44656661756c74506c61796572120e44656661756c7420506c61796572aa052434423230344332392d433935352d343039442d393943312d323246394437463533383046)
2020-12-24 23:00:40 DEBUG: 10.0.10.254:56125<->10.0.10.81:49153 << Receive: Protobuf: type: SET_NOT_PLAYING_PLAYER_MESSAGE
errorCode: NoError
[setNowPlayingPlayerMessage] {
playerPath {
origin {
displayName: "Vardagsrum"
identifier: 1280262988
}
client {
processIdentifier: 175
bundleIdentifier: "com.apple.TVAirPlay"  
}
player {
identifier: "MediaRemote-DefaultPlayer"  
displayName: "Default Player"
}
  }
}
85: "4B204C29-C955-409D-99C1-22F9D7F5380F"
Media type: Video
Device state: Playing
Title:
Position: 13/596s (2.2%)
Repeat: Off
Shuffle: Off
--------------------

Characters are encoded wrongly when copying from Termius.

Expected behavior State should be correctly updated to not playing.

System Setup (please complete the following information):

Additional context

postlund commented 3 years ago

Will try to figure this out and place some mental notes here. Using the same use case as above, this is what happens to AirPlay in short form (I have removed supported commands):

[setNowPlayingClientMessage] {
  client {
    processIdentifier: 175
    bundleIdentifier: "com.apple.TVAirPlay"
  }

[updateClientMessage] {
  client {
    processIdentifier: 175
    bundleIdentifier: "com.apple.TVAirPlay"
    processUserIdentifier: 501
    displayName: "AirPlay"
  }
}

[setNowPlayingPlayerMessage] {
  playerPath {
    origin {
      displayName: "Vardagsrum"
      identifier: 1280262988
    }
    client {
      processIdentifier: 175
      bundleIdentifier: "com.apple.TVAirPlay"
    }
    player {
      identifier: "avkit-6E99D9C8-2750-4D34-A411-28263FFD4E9C"
      displayName: "player-7"
    }
  }
}

[setStateMessage] {
  supportedCommands {
    ...
  }
  playbackQueue {
    location: 0
    contentItems {
      identifier: "F326D3FF-BDE3-43D1-8AF8-53D7DB94F43E"
    }
  }
  displayName: "AirPlay"
  playbackState: Paused
  playbackQueueCapabilities {
    requestByRange: true
    requestByIdentifiers: true
  }
  playerPath {
    origin {
      displayName: "Vardagsrum"
      identifier: 1280262988
    }
    client {
      processIdentifier: 175
      bundleIdentifier: "com.apple.TVAirPlay"
    }
    player {
      identifier: "MediaRemote-DefaultPlayer"
      displayName: "Default Player"
    }
  }
  playbackStateTimestamp: 630025231.464317
}

[setStateMessage] {
  supportedCommands {
    ...
  }
  playbackQueue {
    location: 0
    contentItems {
      identifier: "com.apple.avkit.175.da6aee3f"
      metadata {
        title: ""
        duration: 596.4733333333334
        artworkAvailable: false
        infoAvailable: false
        languageOptionsAvailable: true
        numberOfSections: 0
        elapsedTime: 0.0
        isAlwaysLive: false
        playbackRate: 0.0
        mediaType: Video
        nowPlayingInfoData: "bplist00\324\001\002\003\004\005\006\007\nX$versionY$archiverT$topX$objects\022\000\001\206\240_\020\017NSKeyedArchive...
        elapsedTimeTimestamp: 630591678.821276
        inferredTimestamp: 630591678.809078
        legacyUniqueIdentifier: -630526401
      }
    }
    requestId: "PlaybackQueueInvalidation-889FE028-BFB8-4F9E-B1F7-EFB0070D74D8"
    resolvedPlayerPath {
      origin {
        displayName: "Vardagsrum"
        identifier: 1280262988
      }
      client {
        processIdentifier: 175
        bundleIdentifier: "com.apple.TVAirPlay"
      }
      player {
        identifier: "avkit-6E99D9C8-2750-4D34-A411-28263FFD4E9C"
        displayName: "player-7"
        5: 751619276821
      }
    }
  }
  displayName: "AirPlay"
  playbackState: Paused
  playbackQueueCapabilities {
    requestByRange: true
  }
  playerPath {
    origin {
      displayName: "Vardagsrum"
      identifier: 1280262988
    }
    client {
      processIdentifier: 175
      bundleIdentifier: "com.apple.TVAirPlay"
    }
    player {
      identifier: "avkit-6E99D9C8-2750-4D34-A411-28263FFD4E9C"
      displayName: "player-7"
    }
  }
  playbackStateTimestamp: 630591678.687111
}

1: 58
62 {
  1 { <-- likely a PlayerPath
    1 {
      2: "Vardagsrum"
      3: 1280262988
    }
    2 {
      1: 175
      2: "com.apple.TVAirPlay"
    }
    3 {
      1: "avkit-6E99D9C8-2750-4D34-A411-28263FFD4E9C"
      2: "player-7"
      5: 751619276821
    }
  }
}

When stopping the stream, this happens:

[setStateMessage] {
  playbackQueueCapabilities {
  }
  playerPath {
    origin {
      displayName: "Vardagsrum"
      identifier: 1280262988
    }
    client {
      processIdentifier: 175
      bundleIdentifier: "com.apple.TVAirPlay"
    }
    player {
      identifier: "avkit-6E99D9C8-2750-4D34-A411-28263FFD4E9C"
      displayName: "player-7"
    }
  }
}

[removePlayerMessage] {
  playerPath {
    origin {
      displayName: "Vardagsrum"
      identifier: 1280262988
    }
    client {
      processIdentifier: 175
      bundleIdentifier: "com.apple.TVAirPlay"
    }
    player {
      identifier: "avkit-6E99D9C8-2750-4D34-A411-28263FFD4E9C"
      displayName: "player-7"
    }
  }
}

[setNowPlayingPlayerMessage] {
  playerPath {
    origin {
      displayName: "Vardagsrum"
      identifier: 1280262988
    }
    client {
      processIdentifier: 175
      bundleIdentifier: "com.apple.TVAirPlay"
    }
    player {
      identifier: "MediaRemote-DefaultPlayer"
      displayName: "Default Player"
    }
  }
}

What's new to me/pyatv is that MRP seems to care more about the players now. Previous behavior were more in the line of:

Nothing about players. Normally only SetNowPlayingClient would be sent with a player path (even if SetNowPlayingPlayer also existed as a message). When media stopped playing, it would be sent again but without any player path. Doing in the way it's done above implies that the client (app(?)) is still running and outputting to the default player, but since there's no SetStateMessage for that path there's actual no output/nothing playing. Nothing really strange with that and possibly even a good addition, in case it works similarly with apps. Will have to explore that. One small issue here though is how to be backwards compatible in a decent way.

Just hit me that this is probably because of support for Picture-In-Picture support in tvOS 14. In that case there would be two players active at the same time, possibly from two different apps. I have never tried it myself so I don't know how it works. Some logs would be great for this...

AirPlay is also a bit special as that is the only app I have seen that uses another player than the default player (MediaRemote-DefaultPlayer) even in the past.

Will continue my reasoning here as I get time to look into things. I think I need to define a model for how everything in a player path fits together and implement that in pyatv.

Edit: Logs from above obviously came from a streaming session with a hiccup since nothing appeared to be playing. I believe it was buffering or something. Anyway, I tried again and got the result I expected.

postlund commented 3 years ago

I'm adding some of my thoughts regarding how I think it works. Pure speculation alert!

My logical view of a "player path" looks like this (example):

origin
  client1
    player
  client2
    player1
    player2

origin is basically the device itself. A device has multiple apps and each app correspond to a client. Each client has at least one player used to display something, but can be additional in case of for instance picture-in-picture. Another example would be a video conferencing app, where each participant would represent one player (not sure if it's technically possible, but I see that as a use case nonetheless). A more fitting example:

origin: Living Room Apple TV
  client: Netflix
    player: MainPlayer
    player: PipPlayer
  client: SvtPlay
    player: MainPlayer

Based on observations, there's no specific message to create a player. That is done implicitly when using a message with player path including a player, e.g. when receiving a SetStateMessage like this:

[setStateMessage] {
  ...
  playerPath {
    origin {
      displayName: "Vardagsrum"
      identifier: 1280262988
    }
    client {
      processIdentifier: 175
      bundleIdentifier: "com.apple.TVAirPlay"
    }
    player {
      identifier: "MediaRemote-DefaultPlayer"
      displayName: "Default Player"
    }
  }

This would create a player (Default Player) under the app handling AirPlay. Removing a player is however possible with the RemovePlayerMessage, e.g. when stopping a PIP stream.

Clients works similarly to players, e.g. created implicitly and can be removed with RemoveClientMessage.

The part I'm not entirely sure about yet is how active player is determined. Or rather, I understand the basic use case but not if multiple players are involved. There are two messages of interest here: SetNowPlayingClientMessage and SetNowPlayingPlayerMessage. It's easy to deduce purpose based on their names, but again, how are multiple players handled? Hmm, maybe this just refers to which player is the default player to get command requests (like play or pause)? Most commands dealing with playback expects a player path, but it still works if excluded. Maybe these messages determines who receives the request in that case? Reasonable. I'm rambling.

In a time prior to now, the device would only send a SetNowPlayingClient to indicate who is playing something. It would include a player path. When the player stopped, a new SetNowPlayingClient would be sent but it would be empty. Now it seems like both a SetNowPlayingClient and SetNowPlayingPlayer are sent to pick both client and player for said client. When media stops, the player is removed with RemovePlayerMessage but no empty SetNowPlayingClient is ever received. This could be interpreted as that app still being active, jus not playing anything.

As a "backwards compatibility" thing, I would expect that if a SetNowPlayingClient is sent and a state exists for the default player, that would indicate that the default player is active. Basically: there's no need to send a SetNowPlayingPlayer for the default player. I think this case, where a second player is used, was not very common before but used more often now. That's likely why I haven't seen SetNowPlayingPlayer in action before.

Phew, that was long... Much rambling but I do believe I understand this much better now. I kinda investigated as I went along.. Need to think a bit more about it and then figure out how to implement it in a decent way.

lucasec commented 3 years ago

Just to add another interesting tvOS 14 observation: the app display name appears to be gone from resolvedPlayerPath. Still definitely transferred at least once if pyatv is connected when the app is first launched, but it is seemingly never returned again after that (negating some of the assumptions referenced in https://github.com/postlund/pyatv/issues/648).

Wonder if this is in any way related.

postlund commented 3 years ago

Not sure if it's directly related or part of some optimization on their end. But it makes it very obvious that keeping track of clients and players is really important now. I'm re-writing that code to be more generic, hopefully it will work better.

There's another problem though, that I'm not really sure about (it has been reported by other users as well). If I play something via AirPlay using play_url, that borks everything related to metadata. It won't display anything playing in any app anymore. Rebooting the device should fix the problem, anything you have encountered?

lucasec commented 3 years ago

I did some experiments with play_url, and can definitely re-produce something amiss. The content starts up fine and I get metadata about the duration, etc. The issue is when backing out of the AirPlay session. After that, it's like the AirPlay app is still hoarding the focus or something, as no other app/player will get marked as "now playing".

This seems to affect iOS control center and the Apple TV control center too (usually the now playing widget in the ATV control center shows the title of the current video content if you pop it over while an app is playing). Also directional and touch inputs seem to work to navigate the player UI but notably the Play/Pause button (the HID event one) no longer seems to do anything at all.

To me this feels like a tvOS bug.

postlund commented 3 years ago

Thanks for verifying this! Definitely sounds like a bug in tvOS, yes. It shouldn't be possible to end up in this state. I've had all sort of problems with metadata on my Apple TV lately, almost can't remember when it worked properly... I hope they release a fix soon.

Moving along steadily but slow with my re-write, doing unit tests this time around. So hopefully I will have something more reliable available soon.

lucasec commented 3 years ago

I completed a re-write today in my own project to handle multiple players, and the behavior pretty much worked as advertised.

Key messages were the SetNowPlayingPlayerMessage (note what I assume is a typo here) and RemovePlayerMessage as you already f

I've noticed not every app sends a SetNowPlayingPlayerMessage. Seems it gets omitted if the player ID is MediaRemote-DefaultPlayer. Examples include YouTube and Plex.

Another gotcha is I observed once case during the initial connection where a SetNowPlayingPlayerMessage arrived before any SetStateMessage or other message referencing the client ID. So make sure you build your state management code in a way that allows you to create your internal client objects at pretty much whatever point you first see a given client ID appear in a playerPath. I saw this once and was not immediately able to re-produce it though.

I need to dig a little more to tell whether there is any guaranteed order of SetNowPlayingClientMessage and SetNowPlayingPlayerMessage. And whether a SetNowPlayingPlayerMessage implies a certain client is active, etc. So far they do seem to arrive in a strict order of client first.

postlund commented 3 years ago

Sounds like we've discovered more or less the same thing. I'm creating a client or player whenever I see it just to deal with the fact that messages might appear unordered (#875). I also make the assumption that if no SetNowPlayingPlayer has been received, the default player is assumed. Should probably start documenting these things in my docs soon, would be great to have it all written down.

postlund commented 3 years ago

@lucasec Man, I thought I had this figured out but I guess I'm wrong... I now have this situation:

No removal of client or player (but some SetStates of course). I was kinda expecting that reported metadata was that of player Y, but apparently (according to Remote app) it's that of player X. Have you seen this too? What conclusion can we draw from this? The situation remains even when I go back to top menu. In this case, X is the music app which I guess is a bit special since it can play in the background. Either I don't understand this at all or there's yet another bug...

postlund commented 3 years ago

@lucasec Ok, so, one hypothesis... SetNowPlayingClient picks which client/app that outputs something right now. If nothing else is communicated, it's assumed that it's the default player of that client that is the "now playing" player (MediaRemote-DefaultPlayer), otherwise it can be changed with SetNowPlayingPlayer. Changing the "now playing" player will only serve a purpose once the client it belongs to is set as "now playing client". Makes sense?

lucasec commented 3 years ago

What you're describing basically lines up with what I ended up doing. I don't recall seeing that exact ordering of messages, but kind of anticipated it might be possible. So I have an "active player" state as a per-client state that gets updated on every SetNowPlayingPlayer.

e.g. the current metadata always comes from something like

device = {
  clients: [...],
  activeClientId: 0,
  getActiveClient: () => this.clients[this.activeClientId]
};

client = {
  players: [...],
  activePlayerId: 0,
  getActivePlayer: () => this.players[this.activePlayerId]
};

var contentInfo = device.getActiveClient().getActivePlayer().getContentInfo();
lucasec commented 3 years ago

Oh here's another fun one I just saw:

DEBUG: Received message (46 bytes) {
  type: 'SET_NOW_PLAYING_PLAYER_MESSAGE',
  errorCode: 'NoError',
  '.setNowPlayingPlayerMessage': {}
}

Seems like that occurs when there is no active player at all, like when the device has freshly rebooted.

postlund commented 3 years ago

Great, thanks for confirming! I will have to do some minor adjustments to my code then. I've seen the case when "unsetting" a player as well. Kinda just assumed that it means reverting back to the default player.