search

natumbri / mopidy-youtube

Mopidy extension for playing music from YouTube
Apache License 2.0
261 stars 75 forks source link

Youtube autoplay is not working #185

Closed codeasashu closed 3 years ago

codeasashu commented 3 years ago

I have enabled autoplay which was working good till past couple of days. Here are the mopidy logs:

2021-06-26 01:47:42,128 INFO [52029:YouTubeAutoplayer-13] mopidy_youtube: session.get triggered: list_related_videos
2021-06-26 01:47:43,317 INFO [52029:YouTubeAutoplayer-13] mopidy_youtube: nothing in the soup, trying japi related videos
2021-06-26 01:47:43,377 INFO [52029:YouTubeAutoplayer-13] mopidy_youtube: could not get related videos: ending autoplay

On further investigation, I found it uses jAPI to parse the json results, extracted from html using following logic:

extracted_json = yt_data["contents"][
                    "twoColumnWatchNextResults"
                ]["secondaryResults"]["secondaryResults"][
                    "results"
                ]

The json it extracted is not supported by jAPI. Here is the json I got using the extraction:

{
  "relatedChipCloudRenderer": {
    "content": {
      "chipCloudRenderer": {
        "chips": [
          {
            "chipCloudChipRenderer": {
              "style": {
                "styleType": "STYLE_DEFAULT"
              },
              "text": {
                "simpleText": "All"
              },
              "navigationEndpoint": {
                "clickTrackingParams": "CMoBELuJAxgAIhMIiO6B2Mqz8QIVfeQ4Bh0qeQmG",
                "relatedChipCommand": {
                  "targetSectionIdentifier": "sid-wn-chips",
                  "loadCached": true
                }
              },
              "trackingParams": "CMoBELuJAxgAIhMIiO6B2Mqz8QIVfeQ4Bh0qeQmG",
              "isSelected": true
            }
          }
        ]
      }
    }
  }
}

which seems to be unsupported by jAPI.

natumbri commented 3 years ago

Thanks - will investigate. I use the autoplay functionality quite a bit and haven't noticed anything yet. Is it track dependent or universal?

codeasashu commented 3 years ago

@natumbri It is happening when I added ytmusic playlist song to current playlist. I will try to reset the code to master and see if it i working

natumbri commented 3 years ago

I'd be interested to hear if it is still happening on the yt-playlists branch. There were some strange things going on, which have hopefully been fixed (worked around) now...

natumbri commented 3 years ago

Is it to do with the different headers passed to ytmusic?

codeasashu commented 3 years ago

@natumbri yes it is still happening. I am yet to try the c545267e3961658898f81b2ef71cf0aa234947b3 commit. Will let you know if that works.

codeasashu commented 3 years ago

I have tried c545267 commit. It seems working. Feel free to edit the PR to fixes #185 to autoclose this issue

thanxx commented 3 years ago

hey guys, I would like to pay attention to Youtube API, autoplay is not working there as well. I am on the latest commit in feature/yt-playlists.

when playing a track I see a message in logs

INFO     2021-07-03 19:51:57,096 [6616:YouTubeAutoplayer-10] mopidy_youtube
  could not get related videos: ending autoplay

however, the request is successful

{
  "items": [
    {
      "id": "Ss9i2gmny9w",
      "snippet": {
        "title": "【𝐓𝐎𝐏 𝟏𝟎 𝐌𝐄𝐆𝐀𝐌𝐈𝐗】 𝗝𝗔𝗣𝗔𝗡𝗘𝗦𝗘 𝖢𝖨𝖳𝖸 𝖯𝖮𝖯/𝖥𝖴𝖭𝖪 𝗥𝗘:𝗖𝗢𝗠𝗣𝗜𝗟𝗔𝗧𝗜𝗢𝗡 𝖨𝖭𝖳𝖤𝖱𝖫𝖴𝖣𝖤 𝗣𝗔𝗥𝗧 #𝟭",
        "channelTitle": "Jimmy Koproto"
      },
      "contentDetails": {
        "duration": "PT2H45M51S"
      }
    },
    {
      "id": "z2KoIeZE2zM",
      "snippet": {
        "title": "감성 넘치는 일본 80년대 시티팝 [마리야 타케우치 Mariya Takeuchi]",
        "channelTitle": "시티팝전문채널"
      },
      "contentDetails": {
        "duration": "PT1H33M11S"
      }
.....

I will try to figure out and maybe fix it

logs

INFO     2021-07-03 19:51:56,538 [6616:YouTubeAutoplayer-10] mopidy_youtube
  setting new autoplay base id
DEBUG    2021-07-03 19:51:56,538 [6616:Dummy-11] mopidy.audio.actor
  Audio event: position_changed(position=0)
DEBUG    2021-07-03 19:51:56,539 [6616:MainThread] mopidy.audio.actor
  Audio event: tags_changed(tags=['container-format'])
INFO     2021-07-03 19:51:56,540 [6616:YouTubeAutoplayer-10] mopidy_youtube
  incrementing autoplay degrees of separation
INFO     2021-07-03 19:51:56,542 [6616:YouTubeAutoplayer-10] mopidy_youtube
  session.get triggered: list_related_videos
DEBUG    2021-07-03 19:51:56,541 [6616:MainThread] mopidy.listener
  Sending tags_changed to AudioListener: {'tags': ['container-format']}
DEBUG    2021-07-03 19:51:56,541 [6616:Dummy-11] mopidy.listener
  Sending position_changed to AudioListener: {'position': 0}
DEBUG    2021-07-03 19:51:56,554 [6616:MainThread] mopidy.audio.gst
  Got TAG bus message: tags={'audio-codec': ['Opus'], 'language-code': ['en']}
DEBUG    2021-07-03 19:51:56,554 [6616:MainThread] mopidy.audio.actor
  Audio event: tags_changed(tags=['audio-codec', 'language-code'])
DEBUG    2021-07-03 19:51:56,555 [6616:MainThread] mopidy.listener
  Sending tags_changed to AudioListener: {'tags': ['audio-codec', 'language-code']}
DEBUG    2021-07-03 19:51:56,557 [6616:MainThread] mopidy.audio.gst
  Got TAG bus message: tags={'audio-codec': ['Opus'], 'language-code': ['en']}
DEBUG    2021-07-03 19:51:56,559 [6616:MainThread] mopidy.audio.gst
  Got STATE_CHANGED bus message: old=GST_STATE_READY new=GST_STATE_PAUSED pending=GST_STATE_VOID_PENDING
DEBUG    2021-07-03 19:51:56,560 [6616:MainThread] mopidy.audio.actor
  Audio event: state_changed(old_state=stopped, new_state=paused, target_state=playing)
DEBUG    2021-07-03 19:51:56,561 [6616:MainThread] mopidy.listener
  Sending state_changed to AudioListener: {'old_state': 'stopped', 'new_state': 'paused', 'target_state': 'playing'}
DEBUG    2021-07-03 19:51:56,562 [6616:MainThread] mopidy.audio.gst
  Got ASYNC_DONE bus message.
DEBUG    2021-07-03 19:51:56,603 [6616:HttpServer] mopidy.http.handlers
  Received WebSocket message from 192.168.1.216: '{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":203}'
DEBUG    2021-07-03 19:51:56,607 [6616:HttpServer] mopidy.http.handlers
  Sent WebSocket message to 192.168.1.216: '{"jsonrpc": "2.0", "id": 203, "result": 0}'
DEBUG    2021-07-03 19:51:56,608 [6616:HttpServer] mopidy.http.handlers
  Received WebSocket message from 192.168.1.216: '{"method":"core.library.get_images","params":{"uris":["youtube:video:SRbCxTVUzkw"]},"jsonrpc":"2.0","id":204}'
DEBUG    2021-07-03 19:51:56,611 [6616:HttpServer] mopidy.http.handlers
  Sent WebSocket message to 192.168.1.216: '{"jsonrpc": "2.0", "id": 204, "result": {"youtube:video:SRbCxTVUzkw": [{"__model__": "Image", "uri": "https://i.ytimg.com/vi/SRbCxTVUzkw/default.jpg"}, {"__model__": "Image", "uri": "https://i.ytimg.com/vi/SRbCxTVUzkw/mqdefault.jpg"}, {"__model__": "Image", "uri": "https://i.ytimg.com/vi/SRbCxTVUzkw/hqdefault.jpg"}]}}'
DEBUG    2021-07-03 19:51:56,612 [6616:HttpServer] mopidy.http.handlers
  Received WebSocket message from 192.168.1.216: '{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":205}'
DEBUG    2021-07-03 19:51:56,616 [6616:HttpServer] mopidy.http.handlers
  Sent WebSocket message to 192.168.1.216: '{"jsonrpc": "2.0", "id": 205, "result": 0}'
TRACE    2021-07-03 19:51:56,631 [6616:MainThread] mopidy.audio.gst
  Got BUFFERING bus message: percent=1%
TRACE    2021-07-03 19:51:56,632 [6616:MainThread] mopidy.audio.gst
  Got BUFFERING bus message: percent=0%
TRACE    2021-07-03 19:51:56,634 [6616:MainThread] mopidy.audio.gst
  Got BUFFERING bus message: percent=1%
TRACE    2021-07-03 19:51:56,650 [6616:MainThread] mopidy.audio.gst
  Got BUFFERING bus message: percent=2%
TRACE    2021-07-03 19:51:56,710 [6616:MainThread] mopidy.audio.gst
  Got BUFFERING bus message: percent=3%
TRACE    2021-07-03 19:51:56,747 [6616:MainThread] mopidy.audio.gst
  Got BUFFERING bus message: percent=4%
TRACE    2021-07-03 19:51:56,764 [6616:MainThread] mopidy.audio.gst
  Got BUFFERING bus message: percent=5%
TRACE    2021-07-03 19:51:56,778 [6616:MainThread] mopidy.audio.gst
  Got BUFFERING bus message: percent=6%
TRACE    2021-07-03 19:51:56,806 [6616:MainThread] mopidy.audio.gst
  Got BUFFERING bus message: percent=7%
TRACE    2021-07-03 19:51:56,818 [6616:MainThread] mopidy.audio.gst
  Got BUFFERING bus message: percent=8%
DEBUG    2021-07-03 19:51:56,839 [6616:YouTubeAutoplayer-10] urllib3.connectionpool
  https://www.googleapis.com:443 "GET /youtube/v3/search?relatedToVideoId=SRbCxTVUzkw&part=snippet&maxResults=20&type=video&key=xxxxxxxxx HTTP/1.1" 200 None
TRACE    2021-07-03 19:51:56,859 [6616:MainThread] mopidy.audio.gst
  Got BUFFERING bus message: percent=6%
TRACE    2021-07-03 19:51:56,875 [6616:MainThread] mopidy.audio.gst
  Got BUFFERING bus message: percent=7%
INFO     2021-07-03 19:51:56,908 [6616:ThreadPoolExecutor-8_0] mopidy_youtube
  session.get triggered: list_videos
TRACE    2021-07-03 19:51:56,915 [6616:MainThread] mopidy.audio.gst
  Got BUFFERING bus message: percent=8%
DEBUG    2021-07-03 19:51:57,086 [6616:ThreadPoolExecutor-8_0] urllib3.connectionpool
  https://www.googleapis.com:443 "GET /youtube/v3/videos?part=id%2Csnippet%2CcontentDetails&fields=items%28id%2Csnippet%28title%2CchannelTitle%29%2CcontentDetails%28duration%29%29&id=Ss9i2gmny9w%2Cz2KoIeZE2zM%2Cpwa4U0ccECY%2C5qap5aO4i9A%2CJS0p6p2LuuM%2COycgifzTHgk%2CDM7HvcTc7z0%2CsyK3EZpi1sw%2CIGUhi8nr7F4%2CvBYC31o3dVI%2CjZpeH_UfNiQ%2Ccf_dF74geFI%2CgYSU72ZBvB4%2CqP3SmGl-frg%2C0cxJ4Mg_q1M%2CYoBwKfMluuo%2CWCCovrKvAtU%2CGb_DIa9Y_v8%2C1SU29sO6uCw&key=xxxxxxx HTTP/1.1" 200 None
INFO     2021-07-03 19:51:57,096 [6616:YouTubeAutoplayer-10] mopidy_youtube
  could not get related videos: ending autoplay
natumbri commented 3 years ago

@thanxx - thanks for that report; I think you are right!

Autoplay with the youtube API and ytmusicapi enabled and ytmusicapi authenticated it works for me just fine - playing youtube:video:SRbCxTVUzkw results in autoplay adding youtube:video:SNq4zqTN_DQ to the queue:

2021-07-04 09:47:51,533 INFO [5420:YouTubeBackend-6] mopidy_youtube: youtube PlaybackProvider.translate_uri "youtube:video:SRbCxTVUzkw"
2021-07-04 09:47:57,940 INFO [5420:YouTubeAutoplayer-11] mopidy_youtube: setting new autoplay base id
2021-07-04 09:47:57,941 INFO [5420:YouTubeAutoplayer-11] mopidy_youtube: incrementing autoplay degrees of separation
2021-07-04 09:47:57,941 INFO [5420:YouTubeAutoplayer-11] mopidy_youtube: session.get triggered: list_related_videos
2021-07-04 09:47:58,317 INFO [5420:ThreadPoolExecutor-7_0] mopidy_youtube: session.get triggered: list_videos
2021-07-04 09:47:58,558 INFO [5420:YouTubeBackend-6] mopidy_youtube: youtube LibraryProvider.lookup "youtube:video:SNq4zqTN_DQ"

But with youtube API and ytmusic enabled but not authenticated, or with youtube API only (no ytmusicapi), it fails:

2021-07-04 09:51:24,299 INFO [5605:YouTubeBackend-6] mopidy_youtube: youtube PlaybackProvider.translate_uri "youtube:video:SRbCxTVUzkw"
2021-07-04 09:51:32,775 INFO [5605:YouTubeAutoplayer-11] mopidy_youtube: setting new autoplay base id
2021-07-04 09:51:32,777 INFO [5605:YouTubeAutoplayer-11] mopidy_youtube: incrementing autoplay degrees of separation
2021-07-04 09:51:32,778 INFO [5605:YouTubeAutoplayer-11] mopidy_youtube: session.get triggered: list_related_videos
2021-07-04 09:51:33,369 INFO [5605:ThreadPoolExecutor-2_0] mopidy_youtube: session.get triggered: list_videos
2021-07-04 09:51:33,635 INFO [5605:YouTubeAutoplayer-11] mopidy_youtube: could not get related videos: ending autoplay
natumbri commented 3 years ago

@thanxx - actually, on further investigation, it looks like the related videos for youtube:video:SRbCxTVUzkw are mostly really long. I added a line to log the length of the related videos returned and this is what I got:

2021-07-04 10:45:53,415 INFO [7388:YouTubeBackend-6] mopidy_youtube: youtube PlaybackProvider.translate_uri "youtube:video:SRbCxTVUzkw"
2021-07-04 10:46:02,009 INFO [7388:YouTubeAutoplayer-11] mopidy_youtube: setting new autoplay base id
2021-07-04 10:46:02,010 INFO [7388:YouTubeAutoplayer-11] mopidy_youtube: incrementing autoplay degrees of separation
2021-07-04 10:46:02,011 INFO [7388:YouTubeAutoplayer-11] mopidy_youtube: session.get triggered: list_related_videos
2021-07-04 10:46:02,635 INFO [7388:ThreadPoolExecutor-2_0] mopidy_youtube: session.get triggered: list_videos
2021-07-04 10:46:02,896 INFO [7388:YouTubeAutoplayer-11] mopidy_youtube: 19  # number of related videos returned
2021-07-04 10:46:02,897 INFO [7388:YouTubeAutoplayer-11] mopidy_youtube: 19  # number of related videos not previously played
2021-07-04 10:46:02,898 INFO [7388:YouTubeAutoplayer-11] mopidy_youtube: [9951, 4119, 5591, 3833, 3152, 5429, 4030, 3694, 5860, 6227, 3124, 3727, 2665, 5865, 5586, 2787, 3728, 4492, 2993]  # length of related videos 
2021-07-04 10:46:02,899 INFO [7388:YouTubeAutoplayer-11] mopidy_youtube: 0  # number of related videos < max_autoplay_length (which defaults to 600s)
2021-07-04 10:46:02,900 INFO [7388:YouTubeAutoplayer-11] mopidy_youtube: could not get related videos: ending autoplay

This is the intended behaviour.

The rationale for the default of 600s is the assumption that a person using the autoplayer wants to hear individual tracks in succession, rather than long compilations of tracks or full albums.

The fact that autoplay worked for me with ytmusicapi enabled was just a matter of luck - one of the videos returned by the non-API related_videos method just happened to be less than 600s long. If the non-API method had returned the same related videos as the API method, the behaviour would have been the same (ie. autoplay would have ended). (The related videos returned using the youtube API are not necessarily the same related videos that are returned when not using the API - nothing much I can do about that.)

I've added a patch (907fd4f) that makes it possible to turn off the max_autoplay_length feature. Simply include the following in your mopidy.conf:

max_autoplay_length =
thanxx commented 3 years ago

@natumbri yes, looks like it's not a bug! I changed the setting to several hours and I get related videos now. I indeed prefer listening albums/mixes that obviously have lengths more than 600s. huge thanks for sorting this out