search

gabe565 / CastSponsorSkip

⏭️ Skip YouTube ads and sponsorships on all local Google Cast devices
Apache License 2.0
286 stars 6 forks source link

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

Open schumi4 opened 10 months ago

schumi4 commented 10 months ago

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.

gabe565 commented 10 months ago

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 commented 10 months ago

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

gabe565 commented 10 months ago

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

pengi commented 9 months ago

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 commented 9 months ago

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 commented 9 months ago

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 commented 9 months ago

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 commented 9 months ago

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

pengi commented 9 months ago

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 commented 9 months ago

@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 commented 9 months ago

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 commented 9 months ago

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

gabe565 commented 9 months ago

@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 commented 9 months ago

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 commented 9 months ago

@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 commented 9 months ago

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 commented 9 months ago

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

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 commented 9 months ago

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 commented 9 months ago

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 commented 9 months ago

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 commented 9 months ago

@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 commented 9 months ago

@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 commented 9 months ago

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 commented 9 months ago

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 commented 9 months ago

@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 commented 9 months ago

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 commented 9 months ago

@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 commented 9 months ago

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 commented 8 months ago

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 commented 8 months ago

@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 commented 8 months ago

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 commented 8 months ago

@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 commented 8 months ago

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 b182a214ce07ccaf1899b38e4b24e4ee5c5703ae

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 commented 8 months ago

@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 commented 8 months ago

@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 commented 6 months ago

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

glenstewart commented 5 months ago

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

gabe565 commented 4 months ago

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 commented 4 months ago

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!