Open nojoking opened 1 year ago
I've been investigating it, but could not fix it. Other youtube streams are ok.
I have no idea why other channels get callbacks but this one doesn't. Looks like a pubsubhubbub thing.
So you guys verified correctness for his youtube URL (or channel id UCUzhSlr-PyawQXk2RzSWO7g) in the streamer profile, and then you witnessed a successful pubsub register for that channel id.
Do you know for a fact that a callback was never received or did it just not show on grafana?
I could try subscribing to him from schlawg.org to troubleshoot further, but I'd need a bit of assistance from him. basically a heads up 30 mins or so before he starts another stream, plus if his inbox blocks unknown he should message me on lichess.
I had manually registered the channel ID in pubsub just in case, and still nothing came - the pubsubVideoId
was never populated in the DB.
I have since added new logging to the pubsub notification endpoint to collect more data about the issue.
Feel free to contact him by PM if you want to dig into this
unrelated (?) but I just checked out the logging output and some (but not all) notifications are sent twice. Not a big deal.
https://gist.github.com/ornicar/a26b1faec73c6a387b3cac9f527044a0
possibly related, we sometimes get notifications without a channelId
or a videoId
field!
561533:2023-05-02 06:19:58,225 INFO streamer onYouTubeVideo e5NN4bKHGYI on channel UCUlStYf1szBrN9gXrpq6r9Q
564998:2023-05-02 06:22:05,238 INFO streamer onYouTubeVideo wZ6h3w3rgH0 on channel UCQNbD2RogfAowOGy0kSzJ8A
565031:2023-05-02 06:22:07,117 INFO streamer onYouTubeVideo wZ6h3w3rgH0 on channel UCQNbD2RogfAowOGy0kSzJ8A
588181:2023-05-02 06:35:18,445 INFO streamer onYouTubeVideo on channel
616392:2023-05-02 06:50:51,633 INFO streamer onYouTubeVideo on channel
620984:2023-05-02 06:53:19,175 INFO streamer onYouTubeVideo zhSqfs9mVQM on channel UC4fZ52BXsCL1e0FG2pjYdPw
621163:2023-05-02 06:53:26,029 INFO streamer onYouTubeVideo zhSqfs9mVQM on channel UC4fZ52BXsCL1e0FG2pjYdPw
632949:2023-05-02 07:00:07,797 INFO streamer onYouTubeVideo 2kt5MJabW7c on channel UCQcndin7vogg1u_yLXPuY-g
we might know more about these later on https://github.com/lichess-org/lila/commit/0663da881f99199f91cbf9a238e568b9e27cc553
Yeah, there's nothing I could add to the work you've already done on this. It sounds like GMTalBaron fell into the wrong bucket at either google or pubsubhubbub.
Chris next time this happens to someone, you could suggest they tweak their channel description (on youtube) or some other field there. Then reapprove their stream (to retrigger the pubsub subscription) and see if it clears up. This could be mildly more effective than prayer.
so here's what's being logged now:
May 13 09:20:11 manta lila[2627402]: WARN streamer - onYouTubeVideo on channel <feed xmlns:at="http://purl.org/atompub/tombstones/1.0" xmlns="http://www.w3.org/2005/Atom"><at:deleted-entry ref="yt:video:Sz_F8etjuWw" when="2023-05-13T09:19:33.07059+00:00">
May 13 09:20:11 manta lila[2627402]: <link href="https://www.youtube.com/watch?v=Sz_F8etjuWw"/>
May 13 09:20:11 manta lila[2627402]: <at:by>
May 13 09:20:11 manta lila[2627402]: <name>Kids Unfold</name>
May 13 09:20:11 manta lila[2627402]: <uri>https://www.youtube.com/channel/UCG4iLBfhsvkAnH3vsxB66Pg</uri>
May 13 09:20:11 manta lila[2627402]: </at:by>
May 13 09:20:11 manta lila[2627402]: </at:deleted-entry></feed>
May 13 09:42:13 manta lila[2627402]: WARN streamer - onYouTubeVideo on channel <feed xmlns:at="http://purl.org/atompub/tombstones/1.0" xmlns="http://www.w3.org/2005/Atom"><at:deleted-entry ref="yt:video:IWKa5zyvab4" when="2023-05-13T09:42:02.59188+00:00">
May 13 09:42:13 manta lila[2627402]: <link href="https://www.youtube.com/watch?v=IWKa5zyvab4"/>
May 13 09:42:13 manta lila[2627402]: <at:by>
May 13 09:42:13 manta lila[2627402]: <name>Combat Chess</name>
May 13 09:42:13 manta lila[2627402]: <uri>https://www.youtube.com/channel/UClozk9c2eiXGd1LgomIkcmw</uri>
May 13 09:42:13 manta lila[2627402]: </at:by>
May 13 09:42:13 manta lila[2627402]: </at:deleted-entry></feed>
May 13 09:42:13 manta lila[2627402]: WARN streamer - onYouTubeVideo on channel <feed xmlns:at="http://purl.org/atompub/tombstones/1.0" xmlns="http://www.w3.org/2005/Atom"><at:deleted-entry ref="yt:video:uroVu6Nv_cM" when="2023-05-13T09:42:02.271888+00:00">
May 13 09:42:13 manta lila[2627402]: <link href="https://www.youtube.com/watch?v=uroVu6Nv_cM"/>
May 13 09:42:13 manta lila[2627402]: <at:by>
May 13 09:42:13 manta lila[2627402]: <name>Combat Chess</name>
May 13 09:42:13 manta lila[2627402]: <uri>https://www.youtube.com/channel/UClozk9c2eiXGd1LgomIkcmw</uri>
May 13 09:42:13 manta lila[2627402]: </at:by>
May 13 09:42:13 manta lila[2627402]: </at:deleted-entry></feed>
documents without a channel or video IDs. Not sure what they're about
so apparently these warnings are about private videos, such as
WARN streamer - onYouTubeVideo deleted-entry yt:video:_v7WG9QIQzg
https://www.youtube.com/watch?v=_v7WG9QIQzg
This is probably unrelated but I worry about how we handle things in subscribeAll. Each subscription request results in a verification challenge sent to a lila endpoint, and it doesn't look like we log those at all. If some are getting lost in the ether (discarded by a proxy, etc) we could probably mitigate that by throttling for a second after each request in subscribeAll.
Subscription lifetime is a suggestion - websub servers are free to ignore it. We should probably run subscribeAll a bit more frequently than every 8 days.
You saw a very specific issue that certainly seems youtube/websub related with GMTalBaron. But we don't know the plethora of failures since then have the same cause.
like this?
It seems that occasionally YouTube streams are not detected for mysterious reasons, the most recent case:
https://lichess.org/@/TalBaron-YouTube https://www.youtube.com/@GMTalBaron
stream not detected several days in a row