Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Youtube ads neither skipped nor muted on CC with Google TV #27

Open
schumi4 opened this issue Sep 24, 2023 · 42 comments
Open

Youtube ads neither skipped nor muted on CC with Google TV #27

schumi4 opened this issue Sep 24, 2023 · 42 comments

Comments

@schumi4
Copy link

schumi4 commented Sep 24, 2023

The ads don't show up in the log or mute/skip, skipping segments works though. Casting to Chromecast with Google TV (or Android TV, it also needs a Youtube API key). Older 'standard' Chromecasts on same network work fine.

@schumi4 schumi4 changed the title Youtube ads neither skipper nor muted on CC with Google TV Youtube ads neither skipped nor muted on CC with Google TV Sep 24, 2023
@gabe565
Copy link
Owner

gabe565 commented Sep 27, 2023

Interesting. I'm also using a Chromecast with Google TV and it worked last I checked...hopefully something didn't change in the Cast API. I'll see if I can replicate this!

Could you set CSS_LOG_LEVEL=debug to see if anything useful gets logged?

@schumi4
Copy link
Author

schumi4 commented Sep 27, 2023

Log only shows the continuous msg=Update device also during ads, nothing else gets logged. Segments get skipped as usual.

@gabe565
Copy link
Owner

gabe565 commented Sep 28, 2023

Thanks, that's helpful. Sounds like ads aren't being detected for your device. Still planning to try to replicate!

@pengi
Copy link

pengi commented Oct 2, 2023

I got the same issue when testing. This is the log I got (with actual video title removed though, but it was the title of the video I watched, so it detected it)

My comments inline for what I did

time=2023-10-02T20:30:57.493Z level=INFO msg="CastSponsorSkip v0.5.0 (73d1f7a)"
time=2023-10-02T20:30:57.494Z level=INFO msg="Searching for devices..."
time=2023-10-02T20:30:57.799Z level=INFO msg="Connected to cast device." device="Living Room TV"
time=2023-10-02T20:30:58.299Z level=DEBUG msg=Update device="Living Room TV"
time=2023-10-02T20:31:08.369Z level=DEBUG msg=Update device="Living Room TV"
time=2023-10-02T20:31:18.513Z level=DEBUG msg=Update device="Living Room TV"

Started video

time=2023-10-02T20:31:18.647Z level=INFO msg="Video ID not found. Searching for video on YouTube..." device="Living Room TV"
time=2023-10-02T20:31:18.647Z level=DEBUG msg="Searching for video ID" query="\"channelname\"+intitle:\"videotitle\""
time=2023-10-02T20:31:19.256Z level=DEBUG msg="Searching for video ID" query="\"channelname\"+intitle:\"videotitle\""
time=2023-10-02T20:31:20.297Z level=DEBUG msg="Searching for video ID" query="\"channelname\"+intitle:\"videotitle\""

Entered a segment of ads, nothing skipped

time=2023-10-02T20:31:22.339Z level=DEBUG msg="Searching for video ID" query="\"channelname\"+intitle:\"videotitle\""
time=2023-10-02T20:31:26.378Z level=DEBUG msg="Searching for video ID" query="\"channelname\"+intitle:\"videotitle\""

I'm testing with:

[Service]
Environment="CSS_PAUSED_INTERVAL=10s"
Environment="CSS_YOUTUBE_API_KEY=--api key--"
Environment="CSS_LOG_LEVEL=debug"

It also seems to not continue to log when changing to a new video, and the logging of "Searching for video ID " seems to be more seldom. So seems like it gets stuck somewhere

@gabe565
Copy link
Owner

gabe565 commented Oct 3, 2023

I've been doing some testing and so far ad skip works reliably on a Chromecast Ultra and a Nest Hub. I don't think this is due to the device type, but I have another thought.

@pengi Thanks for the log and the extra info! Your log made me realize the retry logic for the YouTube search might be getting in the way of ad skip. When a video is found, it will log the video information, but that never happened here. Instead, it kept retrying the search. This is currently expected: if the YouTube search fails, it will pause the update cycle and retry up to 10 times with an exponential backoff. Could you let that search happen 10 times and see if an error is printed?

It seems like I should improve the retry logic, and I should also log the first error instead of waiting for the last. I may change it to just log every error. That could get chatty but I think more info would have more easily shown what's going on here.

@gabe565
Copy link
Owner

gabe565 commented Oct 3, 2023

I just found a couple more bugs that could be contributing to this:

  1. When the YouTube search fails, the update interval is changed to the slower "paused" interval. I originally added this before ad skip was supported. It is only causing issues now so I'll remove it.
  2. If the YouTube search returns no videos, the log message is suppressed. This seemed to make sense at first, but I'd rather that get logged.

I'll fix all of this and release an update soon. Hopefully it helps 🤞

@pengi
Copy link

pengi commented Oct 3, 2023

Yeah, it definitely looks like exponential backoff, and it seems to stop after 10 times. But no comment afterwards.

I'm trying to setup a go development environment here too to see if I can investigate a bit myself, but meanwhile, here is the log.

time=2023-10-03T06:45:24.116Z level=INFO msg="CastSponsorSkip v0.5.0 (73d1f7a)"
time=2023-10-03T06:45:24.117Z level=INFO msg="Searching for devices..."
time=2023-10-03T06:45:24.264Z level=INFO msg="Connected to cast device." device="Living Room TV"
time=2023-10-03T06:45:24.766Z level=DEBUG msg=Update device="Living Room TV"
time=2023-10-03T06:45:30.976Z level=DEBUG msg=Update device="Living Room TV"
time=2023-10-03T06:45:40.996Z level=DEBUG msg=Update device="Living Room TV"
time=2023-10-03T06:45:41.079Z level=INFO msg="Video ID not found. Searching for video on YouTube..." device="Living Room TV"
time=2023-10-03T06:45:41.079Z level=DEBUG msg="Searching for video ID" query="\"channel\"+intitle:\"video\""
time=2023-10-03T06:45:41.706Z level=DEBUG msg="Searching for video ID" query="\"channel\"+intitle:\"video\""
time=2023-10-03T06:45:42.745Z level=DEBUG msg="Searching for video ID" query="\"channel\"+intitle:\"video\""
time=2023-10-03T06:45:44.783Z level=DEBUG msg="Searching for video ID" query="\"channel\"+intitle:\"video\""
time=2023-10-03T06:45:48.810Z level=DEBUG msg="Searching for video ID" query="\"channel\"+intitle:\"video\""
time=2023-10-03T06:45:56.880Z level=DEBUG msg="Searching for video ID" query="\"channel\"+intitle:\"video\""
time=2023-10-03T06:46:12.948Z level=DEBUG msg="Searching for video ID" query="\"channel\"+intitle:\"video\""
time=2023-10-03T06:46:45.009Z level=DEBUG msg="Searching for video ID" query="\"channel\"+intitle:\"video\""
time=2023-10-03T06:47:49.048Z level=DEBUG msg="Searching for video ID" query="\"channel\"+intitle:\"video\""
time=2023-10-03T06:49:57.091Z level=DEBUG msg="Searching for video ID" query="\"channel\"+intitle:\"video\""
time=2023-10-03T06:50:24.329Z level=DEBUG msg="Ignoring device." device="Living Room TV" reason="Already connected"

I also have a run where the "ignoring device" happened before the last "searching for video id"

time=2023-10-03T06:40:41.894Z level=INFO msg="Video ID not found. Searching for video on YouTube..." device="Living Room TV"
time=2023-10-03T06:40:41.894Z level=DEBUG msg="Searching for video ID" query="\"channel\"+intitle:\"video\""
time=2023-10-03T06:40:42.496Z level=DEBUG msg="Searching for video ID" query="\"channel\"+intitle:\"video\""
time=2023-10-03T06:40:43.539Z level=DEBUG msg="Searching for video ID" query="\"channel\"+intitle:\"video\""
time=2023-10-03T06:40:45.586Z level=DEBUG msg="Searching for video ID" query="\"channel\"+intitle:\"video\""
time=2023-10-03T06:40:49.657Z level=DEBUG msg="Searching for video ID" query="\"channel\"+intitle:\"video\""
time=2023-10-03T06:40:57.685Z level=DEBUG msg="Searching for video ID" query="\"channel\"+intitle:\"video\""
time=2023-10-03T06:41:13.758Z level=DEBUG msg="Searching for video ID" query="\"channel\"+intitle:\"video\""
time=2023-10-03T06:41:45.788Z level=DEBUG msg="Searching for video ID" query="\"channel\"+intitle:\"video\""
time=2023-10-03T06:42:49.828Z level=DEBUG msg="Searching for video ID" query="\"channel\"+intitle:\"video\""
time=2023-10-03T06:44:29.198Z level=DEBUG msg="Ignoring device." device="Living Room TV" reason="Already connected"
time=2023-10-03T06:44:57.901Z level=DEBUG msg="Searching for video ID" query="\"channel\"+intitle:\"video\""

In both runs, the retries was longer than the video clip itself, so had to scroll back a couple of times during playback, but that didn't seem to reset anything for what I could tell... but not sure.

@gabe565
Copy link
Owner

gabe565 commented Oct 3, 2023

@pengi The "ignoring device" log is unrelated. That gets logged when a device is discovered that already has an active connection.

@pengi
Copy link

pengi commented Oct 3, 2023

I got the go enviornment up and running and found the error.

Added some logging:

diff --git a/internal/youtube/youtube.go b/internal/youtube/youtube.go
index 7ad89fc..0dbf6b0 100644
--- a/internal/youtube/youtube.go
+++ b/internal/youtube/youtube.go
@@ -43,6 +43,7 @@ func QueryVideoId(ctx context.Context, artist, title string) (string, error) {
                Context(ctx).
                Do()
        if err != nil {
+               slog.Debug("error", "response", response, "err", err)
                return "", err
        }

and got:

level=DEBUG msg=error response=<nil> err="googleapi: Error 403: YouTube Data API v3 has not been used in project XXXX before or it is disabled. Enable it by visiting https://console.developers.google.com/apis/api/youtube.googleapis.com/overview?project=XXXX then retry. If you enabled this API recently, wait a few minutes for the action to propagate to our systems and retry.\nDetails:\n[\n  {\n    \"@type\": \"type.googleapis.com/google.rpc.Help\",\n    \"links\": [\n      {\n        \"description\": \"Google developers console API activation\",\n        \"url\": \"https://console.developers.google.com/apis/api/youtube.googleapis.com/overview?project=XXXX\"\n      }\n    ]\n  },\n  {\n    \"@type\": \"type.googleapis.com/google.rpc.ErrorInfo\",\n    \"domain\": \"googleapis.com\",\n    \"metadata\": {\n      \"consumer\": \"projects/XXXX\",\n      \"service\": \"youtube.googleapis.com\"\n    },\n    \"reason\": \"SERVICE_DISABLED\"\n  }\n]\n, accessNotConfigured"

Or slightly easier formatted:

googleapi: Error 403: YouTube Data API v3 has not been used in project XXXX before or it is disabled. Enable it by visiting https://console.developers.google.com/apis/api/youtube.googleapis.com/overview?project=XXXX then retry. If you enabled this API recently, wait a few minutes for the action to propagate to our systems and retry.
Details:
[
  {
    "@type": "type.googleapis.com/google.rpc.Help",
    "links": [
      {
        "description": "Google developers console API activation",
        "url": "https://console.developers.google.com/apis/api/youtube.googleapis.com/overview?project=XXXX"
      }
    ]
  },
  {
    "@type": "type.googleapis.com/google.rpc.ErrorInfo",
    "domain": "googleapis.com",
    "metadata": {
      "consumer": "projects/XXXX",
      "service": "youtube.googleapis.com"
    },
    "reason": "SERVICE_DISABLED"
  }
]
, accessNotConfigured

So when I simply enabled the YouTube v3 API for my API key it started working.

Think it's a case of error handling and reporting for API responses, to be helpful with outputs to point users towards how to fix it.

So now it works fine, thanks for the tool :)

@pengi
Copy link

pengi commented Oct 3, 2023

@pengi The "ignoring device" log is unrelated. That gets logged when a device is discovered that already has an active connection.

Assumed so :) was thinking if if wasn't multitheaded, it could be helpful to know if the retry code had exited, or something similar

@gabe565
Copy link
Owner

gabe565 commented Oct 3, 2023

I just pushed an update to run the YouTube search and the SponsorBlock queries concurrently so that ad skip doesn't get blocked. It isn't released yet, but it will be soon 🙂

This update will also improve YouTube API logging.

Assumed so :) was thinking if if wasn't multitheaded, it could be helpful to know if the retry code had exited, or something similar

It actually is multithreaded! Discovery and the update flow for each device all run independently of each other.

@gabe565
Copy link
Owner

gabe565 commented Oct 3, 2023

Sorry for the noise. I committed these changes in a single commit then decided to split them up

@gabe565
Copy link
Owner

gabe565 commented Oct 3, 2023

@pengi @schumi4 I just released v0.5.1! When you get a chance, could you update and let me know if it resolves your issues?

@schumi4
Copy link
Author

schumi4 commented Oct 3, 2023

Youtube ads still don't get muted or skipped. In-video ad also didn't get skipped here.

Oct 03 10:33:52 DietPi systemd[1]: Started castsponsorskip.service - Skip YouTube ads and sponsorships on all local Google Cast devices.
Oct 03 10:33:54 DietPi castsponsorskip[422]: 2023/10/03 10:33:54 INFO CastSponsorSkip v0.5.1 (73f3950)
Oct 03 10:33:54 DietPi castsponsorskip[422]: 2023/10/03 10:33:54 INFO Searching for devices...
Oct 03 10:33:55 DietPi castsponsorskip[422]: 2023/10/03 10:33:55 INFO Connected to cast device. device=Küche
Oct 03 10:34:02 DietPi castsponsorskip[422]: 2023/10/03 10:34:02 INFO Connected to cast device. device=Castrop-Rauxel
Oct 03 10:34:02 DietPi castsponsorskip[422]: 2023/10/03 10:34:02 INFO Video ID not found. Searching for video on YouTube... device=Castrop-Rauxel
Oct 03 10:34:25 DietPi castsponsorskip[422]: 2023/10/03 10:34:25 INFO Video ID not found. Searching for video on YouTube... device=Castrop-Rauxel
Oct 03 10:34:38 DietPi castsponsorskip[422]: 2023/10/03 10:34:38 INFO Video ID not found. Searching for video on YouTube... device=Castrop-Rauxel
Oct 03 10:34:38 DietPi castsponsorskip[422]: 2023/10/03 10:34:38 ERROR YouTube search failed. device=Castrop-Rauxel error="search returned no videos"
Oct 03 10:34:39 DietPi castsponsorskip[422]: 2023/10/03 10:34:39 INFO Video ID not found. Searching for video on YouTube... device=Castrop-Rauxel
Oct 03 10:34:39 DietPi castsponsorskip[422]: 2023/10/03 10:34:39 ERROR YouTube search failed. device=Castrop-Rauxel error="search returned no videos"
Oct 03 10:34:41 DietPi castsponsorskip[422]: 2023/10/03 10:34:41 ERROR YouTube search failed. device=Castrop-Rauxel error="search returned no videos"
Oct 03 10:35:26 DietPi castsponsorskip[422]: 2023/10/03 10:35:26 INFO Video ID not found. Searching for video on YouTube... device=Castrop-Rauxel
Oct 03 10:35:39 DietPi castsponsorskip[422]: 2023/10/03 10:35:39 INFO Video ID not found. Searching for video on YouTube... device=Castrop-Rauxel
Oct 03 10:35:39 DietPi castsponsorskip[422]: 2023/10/03 10:35:39 ERROR YouTube search failed. device=Castrop-Rauxel error="search returned no videos"
Oct 03 10:35:39 DietPi castsponsorskip[422]: 2023/10/03 10:35:39 INFO Video ID not found. Searching for video on YouTube... device=Castrop-Rauxel
Oct 03 10:35:40 DietPi castsponsorskip[422]: 2023/10/03 10:35:40 ERROR YouTube search failed. device=Castrop-Rauxel error="search returned no videos"
Oct 03 10:35:43 DietPi castsponsorskip[422]: 2023/10/03 10:35:43 ERROR YouTube search failed. device=Castrop-Rauxel error="search returned no videos"
Oct 03 10:35:46 DietPi castsponsorskip[422]: 2023/10/03 10:35:46 INFO Video ID not found. Searching for video on YouTube... device=Castrop-Rauxel
Oct 03 10:35:46 DietPi castsponsorskip[422]: 2023/10/03 10:35:46 ERROR YouTube search failed. device=Castrop-Rauxel error="search returned no videos"
Oct 03 10:35:46 DietPi castsponsorskip[422]: 2023/10/03 10:35:46 INFO Video ID not found. Searching for video on YouTube... device=Castrop-Rauxel
Oct 03 10:35:47 DietPi castsponsorskip[422]: 2023/10/03 10:35:47 ERROR YouTube search failed. device=Castrop-Rauxel error="search returned no videos"
Oct 03 10:35:49 DietPi castsponsorskip[422]: 2023/10/03 10:35:49 ERROR YouTube search failed. device=Castrop-Rauxel error="search returned no videos"

Can provide debug logs later.

@pengi
Copy link

pengi commented Oct 3, 2023

@pengi @schumi4 I just released v0.5.1! When you get a chance, could you update and let me know if it resolves your issues?

It worked for me in v0.5.0 when I activated the API key actually.

But now on v0.5.1, I get somewhat better error reporting (well, I get the raw output from google API) when I don't have the key active, but I get the same error as @schumi4 when I activate the key again

Oct 03 09:19:21 pengi-dev castsponsorskip[21733]: 2023/10/03 09:19:21 INFO Video ID not found. Searching for video on YouTube... device="Living Room TV"
Oct 03 09:19:21 pengi-dev castsponsorskip[21733]: 2023/10/03 09:19:21 ERROR YouTube search failed. device="Living Room TV" error="search returned no videos"
Oct 03 09:19:23 pengi-dev castsponsorskip[21733]: 2023/10/03 09:19:23 ERROR YouTube search failed. device="Living Room TV" error="search returned no videos"
Oct 03 09:19:23 pengi-dev castsponsorskip[21733]: 2023/10/03 09:19:23 INFO Video ID not found. Searching for video on YouTube... device="Living Room TV"
Oct 03 09:19:25 pengi-dev castsponsorskip[21733]: 2023/10/03 09:19:25 ERROR YouTube search failed. device="Living Room TV" error="search returned no videos"

@pengi
Copy link

pengi commented Oct 3, 2023

Hum... tried to checkout and rebuild from source, and get this, but doesn't work in tag v0.5.1:

pengi@pengi-dev:~/src/CastSponsorSkip(v0.5.1⚡) » ./run.sh                     
time=2023-10-03T09:36:00.315Z level=INFO msg="CastSponsorSkip beta"
time=2023-10-03T09:36:00.315Z level=INFO msg="Searching for devices..."
time=2023-10-03T09:36:00.390Z level=INFO msg="Connected to cast device." device="Living Room TV"
time=2023-10-03T09:36:00.890Z level=DEBUG msg=Update device="Living Room TV"
time=2023-10-03T09:36:10.954Z level=DEBUG msg=Update device="Living Room TV"
time=2023-10-03T09:36:10.983Z level=INFO msg="Video ID not found. Searching for video on YouTube..." device="Living Room TV"
time=2023-10-03T09:36:10.983Z level=DEBUG msg="Searching for video ID" query="\"CHANNEL\"+intitle:\"VIDEO\""
time=2023-10-03T09:36:11.414Z level=DEBUG msg="YouTube search found video ID" device="Living Room TV" video_id=XXXXX
time=2023-10-03T09:36:11.465Z level=DEBUG msg=Update device="Living Room TV"
time=2023-10-03T09:36:11.964Z level=DEBUG msg=Update device="Living Room TV"
time=2023-10-03T09:36:12.464Z level=DEBUG msg=Update device="Living Room TV"
time=2023-10-03T09:36:12.964Z level=DEBUG msg=Update device="Living Room TV"
time=2023-10-03T09:36:13.464Z level=DEBUG msg=Update device="Living Room TV"
time=2023-10-03T09:36:13.964Z level=DEBUG msg=Update device="Living Room TV"
...

But when checking out v0.5.0 I get:

pengi@pengi-dev:~/src/CastSponsorSkip(v0.5.0⚡) » ./run.sh 
time=2023-10-03T09:38:30.995Z level=INFO msg="CastSponsorSkip beta"
time=2023-10-03T09:38:30.996Z level=INFO msg="Searching for devices..."
time=2023-10-03T09:38:33.685Z level=INFO msg="Connected to cast device." device="Living Room TV"
time=2023-10-03T09:38:34.186Z level=DEBUG msg=Update device="Living Room TV"
time=2023-10-03T09:38:35.256Z level=DEBUG msg=Update device="Living Room TV"
time=2023-10-03T09:38:35.435Z level=INFO msg="Video ID not found. Searching for video on YouTube..." device="Living Room TV"
time=2023-10-03T09:38:35.435Z level=DEBUG msg="Searching for video ID" query="\"channel\"+intitle:\"video\""
time=2023-10-03T09:38:35.864Z level=INFO msg="Detected video stream." device="Living Room TV" video_id=XXXX
time=2023-10-03T09:38:35.864Z level=DEBUG msg="Request segments" url="https://sponsor.ajay.app/api/skipSegments/ba88?actionType=skip&actionType=mute&category=sponsor"
time=2023-10-03T09:38:36.127Z level=INFO msg="Found segments for video." device="Living Room TV" segments=1
time=2023-10-03T09:38:36.127Z level=DEBUG msg=Update device="Living Room TV"
time=2023-10-03T09:38:36.326Z level=DEBUG msg=Update device="Living Room TV"
time=2023-10-03T09:38:36.756Z level=DEBUG msg=Update device="Living Room TV"
time=2023-10-03T09:38:39.382Z level=DEBUG msg=Update device="Living Room TV"
time=2023-10-03T09:38:39.469Z level=INFO msg="Skipping to timestamp." device="Living Room TV" category=sponsor from=4m18s to=5m7s
time=2023-10-03T09:38:39.881Z level=DEBUG msg=Update device="Living Room TV"
time=2023-10-03T09:38:39.928Z level=INFO msg="Skipping to timestamp." device="Living Room TV" category=sponsor from=4m18s to=5m7s
time=2023-10-03T09:38:40.382Z level=DEBUG msg=Update device="Living Room TV"

run.sh is just a script that sets up environment and rebuilds

@pengi
Copy link

pengi commented Oct 3, 2023

I did a git bisect, and ended up on this commit introducing the error: a0de9b7

What I noticed is later versions with problems are missing:

time=2023-10-03T09:38:36.127Z level=INFO msg="Found segments for video." device="Living Room TV" segments=1

And that output seems to correspond to when it works or not

@schumi4
Copy link
Author

schumi4 commented Oct 3, 2023

I did a git bisect, and ended up on this commit introducing the error: a0de9b7

What I noticed is later versions with problems are missing:

time=2023-10-03T09:38:36.127Z level=INFO msg="Found segments for video." device="Living Room TV" segments=1

And that output seems to correspond to when it works or not

With "when it works", do you mean skipping in-video sponsors or skipping and muting the pre/mid-roll youtube ads?

@pengi
Copy link

pengi commented Oct 3, 2023

I did a git bisect, and ended up on this commit introducing the error: a0de9b7
What I noticed is later versions with problems are missing:

time=2023-10-03T09:38:36.127Z level=INFO msg="Found segments for video." device="Living Room TV" segments=1

And that output seems to correspond to when it works or not

With "when it works", do you mean skipping in-video sponsors or skipping and muting the pre/mid-roll youtube ads?

Oh right, sorry... I guess I forget about the pre/mid-roll youtube ads, since I have premium. Good call.

I can only test in-video sponsors here, so that works for me. Which means the code for detecting and searching for the videos.

@schumi4
Copy link
Author

schumi4 commented Oct 3, 2023

This might however still be related. Seeing as the evidence (very small sample size i'll admit lol) points to newer devices not having the ads muted. These are also the ones who require the whole API-key ordeal in the first place.

From my testing:
Everything works fine on older devices like OG Chromecast and Chromecast Ultra (both require no API-key).
Muting/skipping never works for Chromecast with Google TV, in-video skips work if the API lookup is successful.

EDIT:
In my testing, video lookup fails:

time=2023-10-03T13:09:53.091+02:00 level=DEBUG msg="Searching for video ID" query="\"\"+intitle:\"\""
time=2023-10-03T13:09:53.388+02:00 level=ERROR msg="YouTube search failed." device=Castrop-Rauxel error="search returned no videos"

Search query is the same regardless of video. Don't see a pattern here. Somethimes it looks up the correct title but looks up only the intitle: during some of the retries.

@gabe565
Copy link
Owner

gabe565 commented Oct 13, 2023

@schumi4 I wish I had one of these newer devices so that I could test some of this strange behavior myself. Instead, you might install vishen/go-chromecast so that you can see what some of the fields are set to that differs from older devices. I'm not sure if it will give all of the data we need yet. I'll keep you posted

@gabe565
Copy link
Owner

gabe565 commented Oct 13, 2023

@schumi4 If you install go-chromecast, can you run the command below, then choose your device and let an ad play? I'd love to see what gets logged. It could also be helpful if you can capture a log when the YouTube search fails.

The command is:

go-chromecast watch --debug

@schumi4
Copy link
Author

schumi4 commented Oct 13, 2023

I certainly can! This case however is at a friend's house so I'll have to remote in sometime next week. Maybe someone else with local access and the same issue can jump in?

Optimistic we can get this fixed though!

@schumi4
Copy link
Author

schumi4 commented Oct 21, 2023

With a heavy heart I have transistioned this case to use iSponsorBlockTV. While I dislike the bloated feel and having to run it with docker, it works for this use case. Sticking with CSS for my local install though.

@gabe565
Copy link
Owner

gabe565 commented Oct 21, 2023

@schumi4 were you ever able to grab the device status with go-chromecast? I believe I know why this is happening but unfortunately I don't have a newer Chromecast to test. I think the status field may be getting set to another number while an ad is playing.

Edit: Oh and for the video lookup, I have a feeling the fields may just be set with different names

@BasVanBoven
Copy link

BasVanBoven commented Oct 25, 2023

Hey @gabe565, maybe I can help with my Chromecast with Google TV. Having the samen problems as reported by schumi4.

Example output from go-chromecast while running below. It does not seem too interesting to me, but maybe it can help you out?

DEBU[1105] (4258)* <- 75783d53-ef11-4cbb-9d89-b780493d8144 [urn:x-cast:com.google.cast.media]: {"requestId":4258,"type":"MEDIA_STATUS","status":[{"mediaSessionId":231,"playerState":"PLAYING","playbackRate":1,"currentTime":2.264,"supportedMediaCommands":207,"volume":{"level":0,"muted":false},"activeTrackIds":[],"shuffle":false,"media":{"contentId":"","streamType":"BUFFERED","metadata":{"metadataType":0,"title":"Pro Bike Mechanic Tests The Cheapest Tools From Wish.com","artist":"Cade Media"},"duration":10.041},"currentItemId":1,"repeatMode":"REPEAT_OFF","items":[{"media":{"contentId":"","streamType":"BUFFERED","metadata":{"metadataType":0,"title":"Pro Bike Mechanic Tests The Cheapest Tools From Wish.com","artist":"Cade Media"},"duration":10.041},"itemId":1,"autoplay":true,"preloadTime":0}]}]} package=cast

Additionally, output from CastSponsorSkip (a different moment/video) when the search fails:

time=2023-10-25T13:34:02.413+02:00 level=DEBUG msg="Searching for video ID" query="\"Epicurious\"+intitle:\"How Joshua Weissman Makes His Perfect Pizza: Every Choice, Every Step | Epicurious\"" time=2023-10-25T13:34:02.753+02:00 level=DEBUG msg="YouTube search found video ID" device="Living room TV" video_id=VqMCH7GosTY time=2023-10-25T13:34:02.899+02:00 level=DEBUG msg=Update device="Living room TV" time=2023-10-25T13:34:03.366+02:00 level=DEBUG msg="Searching for video ID" query="\"\"+intitle:\"\"" time=2023-10-25T13:34:03.399+02:00 level=DEBUG msg=Update device="Living room TV" time=2023-10-25T13:34:03.597+02:00 level=ERROR msg="YouTube search failed." device="Living room TV" error="search returned no videos"

Hope this helps, let me know if I can contribute anything else!

@gabe565
Copy link
Owner

gabe565 commented Oct 25, 2023

@BasVanBoven Thank you so much!

Did you grab that while an ad was playing? There should be a field called customData. Older devices will set "customData":{"playerState":1081} when an ad is playing. I hope that hasn't been removed!

@BasVanBoven
Copy link

I am afraid it has been removed. I just tested again with a larger piece of log attached, but no mention of customData anywhere. When I have more time, I will try and look into the way iSponsorBlockTV handles CCwGTVs (that one is working fine).

rawlog.txt

@taviso
Copy link

taviso commented Oct 31, 2023

I did a git bisect, and ended up on this commit introducing the error: a0de9b7

What I noticed is later versions with problems are missing:

time=2023-10-03T09:38:36.127Z level=INFO msg="Found segments for video." device="Living Room TV" segments=1

And that output seems to correspond to when it works or not

I think I have the same setup as @pengi - Google TV with a Premium subscription. Exactly the same result, 0.5.3 never skips any segments - 0.5.0 does work as expected.

@gabe565
Copy link
Owner

gabe565 commented Nov 1, 2023

@taviso Thanks for bringing that to my attention again. I thought it had been fixed, but seems like there are still some issues. Investigating now!

@gabe565
Copy link
Owner

gabe565 commented Nov 1, 2023

For some reason the search query is being built as "channel"+intitle:"video", which is definitely not right.

Edit: Nevermind. I can't see how that would happen, that may have just been @pengi editing out the actual content. Let me compare logs some more

@gabe565
Copy link
Owner

gabe565 commented Nov 1, 2023

@taviso @pengi Hey! Apologies for the delay, but I believe I've fixed the issue you've been seeing. Could one of you test my latest changes by running the code in main, or by using the beta Docker tag? I'll wait to release this until I hear back confirmation from one of you, but I'm hopeful 🤞

@pengi
Copy link

pengi commented Nov 1, 2023

I unfortunately can't neither deny nor confirm at this point, since I get errors also on my computer. Seems that the sponsorblock API service is down. When checking it manually, I get cloudflare error code 502, at least from my location.

Therefore, I don't know if that happens also to CastSponsorSkip.

The log is at least:

time=2023-11-01T07:45:25.143Z level=INFO msg="CastSponsorSkip beta"
time=2023-11-01T07:45:25.144Z level=INFO msg="Searching for devices..."
time=2023-11-01T07:45:25.446Z level=INFO msg="Connected to cast device." device="Living Room TV"
time=2023-11-01T07:45:25.946Z level=DEBUG msg=Update device="Living Room TV"
time=2023-11-01T07:45:36.023Z level=DEBUG msg=Update device="Living Room TV"
time=2023-11-01T07:45:36.152Z level=INFO msg="Video ID not found. Searching for video on YouTube..." device="Living Room TV"
time=2023-11-01T07:45:36.152Z level=DEBUG msg="Searching for video ID" query="\"Actual channel here)\"+intitle:\"Actual video title here\""
time=2023-11-01T07:45:36.540Z level=DEBUG msg="YouTube search found video ID" device="Living Room TV" video_id=AYouTubeVideoIdHere
time=2023-11-01T07:45:36.644Z level=DEBUG msg=Update device="Living Room TV"
time=2023-11-01T07:45:37.144Z level=DEBUG msg=Update device="Living Room TV"
time=2023-11-01T07:45:37.644Z level=DEBUG msg=Update device="Living Room TV"
time=2023-11-01T07:45:38.145Z level=DEBUG msg=Update device="Living Room TV"

while standing on b182a21

Not that I'm not used to go, so at this point I have to guess a bit of how to build. I checked out that version, then ran:

export CSS_YOUTUBE_API_KEY=My youtube api key here
export CSS_LOG_LEVEL=debug
export CSS_PAUSED_INTERVAL=10s
go clean
go build
go run .

So I hope that should rebuild everything.

That being said, it could equally well just be the sponsorblock api this time.

Unfortunately, this was probably the last time in like 2 months I can check it since I'm moving, and I'll take the TV with chromecast to one spot in an hour, and my computer in the other for a while.

gabe565 added a commit that referenced this issue Nov 2, 2023
@gabe565
Copy link
Owner

gabe565 commented Nov 2, 2023

@pengi Thank you for testing. You helped me realize there was one final issue, but that one has also been fixed! I also tested with a friend's device which requires API lookups, and it's working great after my most recent commit!

@gabe565
Copy link
Owner

gabe565 commented Nov 2, 2023

@pengi @taviso Ok I'm releasing v0.5.4 which fixes the issues you've been seeing!

Still investigating ad skip on newer devices unfortunately, but it's nice to have YouTube queries working again

@654456
Copy link

654456 commented Jan 6, 2024

Can confirm the issue is present on youtube app with Onn 4k tv box, and chromecast HD

@glenstewart
Copy link

I also can confirm the issue still present as of .7.2 build, on youtube app with Onn 4k tv box (Google TV)

@gabe565
Copy link
Owner

gabe565 commented Mar 10, 2024

Can anyone see if this is improved with v0.7.3? I found some cast events which were being filtered, causing CastSponsorSkip to not catch the playing state until after the ad had finished. I'm hoping this fix will help 🤞

@glenstewart
Copy link

Can anyone see if this is improved with v0.7.3?

Sadly, neither mute nor auto-skip are yet working with v0.7.3 when tested with the Onn 4k tv box (Google TV). Thank you for trying - CastSponsorSkip works great on my older Chromecast devices!

@Nightwalker83
Copy link

Nightwalker83 commented Aug 24, 2024

Yeah, the skip and mute functionality does not work with my new chrome cast either. Howvever, ISponsorBlockTv works. Although, it uses the texted based setup and does not say where the device ip/id is stored whereas CSS stores everything in the docker file.

This is what appears in the CSS logs for me when running it via Docker:

2024-08-24 11:19:39 INF CastSponsorSkip version=v0.8.0 commit=9e65ac39
2024-08-24 11:19:39 INF Connecting to configured devices... interface=enp7s0
2024-08-24 11:19:39 INF Connected to cast device. device=10.1.1.34
2024-08-24 11:19:40 INF Video ID not set. Searching YouTube for video ID... device=10.1.1.34
2024-08-24 11:19:41 INF Detected video stream. device=10.1.1.34 video_id=ze_CqdPTyW8
2024-08-24 11:19:42 INF No segments found for video. device=10.1.1.34 video_id=ze_CqdPTyW8

@gabe565
Copy link
Owner

gabe565 commented Aug 30, 2024

Yeah it seems Google has changed something in newer devices so that they don't expose when an ad is playing. I have YouTube Premium, so I haven't tested this much lately, but I'd like to see if I can find a new way to identify when an ad is playing!

@Nightwalker83
Copy link

Nightwalker83 commented Aug 30, 2024

Does your app use the same api as iSponsorBlockTV? If so that app blocks the ads although, unlike yours the ip address for the chromecast does not seem to work.

https://github.com/dmunozv04/iSponsorBlockTV/wiki/Installation

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

8 participants