diff --git a/Services/YouTubeStreamService.cs b/Services/YouTubeStreamService.cs index 54381cc..9844fbf 100644 --- a/Services/YouTubeStreamService.cs +++ b/Services/YouTubeStreamService.cs @@ -178,6 +178,98 @@ public class YouTubeStreamService : null; } + /// One compact log line answering the only question that matters while a + /// stream is running: is the broadcast actually bound to the stream we are pushing + /// to, and has it moved off `ready`? + /// + /// Added 2026-10-04 after two test runs proved the push itself is healthy — ffmpeg + /// delivered 101,229 KiB video + 1,419 KiB audio over 112s with no socket error, + /// yet `enableAutoStart` never fired and close-out 403'd with `invalidTransition`. + /// The config is correct by Google's documentation (boundStreamId is a valid + /// contentDetails field with no restriction against reusable streams), so the only + /// way forward is to observe rather than guess. Everything the API reports about + /// this broadcast and its stream goes in one greppable line: + /// lifeCycleStatus (so the caller can stop asking once it is live), privacyStatus, the boundStreamId + /// *compared against the stream we think we are pushing*, enableAutoStart/Stop, liveChatId + /// presence, the stream's own status.streamStatus, and the CDN settings we declared. + /// Never throws. + public async Task LogBroadcastDiagnosticsAsync(string broadcastId, string? streamId) + { + if (!await EnsureToken()) return null; + + _http.DefaultRequestHeaders.Authorization = new("Bearer", _auth.CurrentChannel!.AccessToken); + + try + { + var broadcast = await GetJsonAsync($"liveBroadcasts?part=status,contentDetails,snippet&id={Uri.EscapeDataString(broadcastId)}"); + var status = Nested(broadcast, "status"); + var details = Nested(broadcast, "contentDetails"); + var snippet = Nested(broadcast, "snippet"); + + var lifeCycle = Text(status, "lifeCycleStatus") ?? "?"; + var bound = Text(details, "boundStreamId"); + JsonElement? stream = string.IsNullOrWhiteSpace(streamId) + ? null + : await GetJsonAsync($"liveStreams?part=status,cdn&id={Uri.EscapeDataString(streamId)}"); + var streamItem = stream is { } present + && present.TryGetProperty("items", out var streamItems) + && streamItems.GetArrayLength() > 0 + ? streamItems[0] + : default(JsonElement); + + AppLog.Write( + $"Broadcast diag: id={broadcastId} lifeCycle={lifeCycle} privacy={Text(status, "privacyStatus") ?? "?"} " + + $"recording={Text(status, "recordingStatus") ?? "?"} bound={bound ?? "NONE"} " + + $"expect={streamId ?? "none"} boundMatches={BoundMatches(bound, streamId)} " + + $"boundLastUpdate={Text(details, "boundStreamLastUpdateTimeMs") ?? "?"} " + + $"autoStart={Flag(details, "enableAutoStart")} autoStop={Flag(details, "enableAutoStop")} " + + $"liveChatId={(string.IsNullOrWhiteSpace(Text(snippet, "liveChatId")) ? "none" : "present")} | " + + $"streamId={Text(streamItem, "id") ?? "none"} streamStatus={Text(Nested(streamItem, "status"), "streamStatus") ?? "?"} " + + $"activeChat={(string.IsNullOrWhiteSpace(Text(Nested(streamItem, "status"), "activeLiveChatId")) ? "none" : "present")} " + + $"cdn={Text(Nested(streamItem, "cdn"), "ingestionType") ?? "?"}/{Text(Nested(streamItem, "cdn"), "resolution") ?? "?"}@{Text(Nested(streamItem, "cdn"), "frameRate") ?? "?"}"); + return lifeCycle; + } + catch (Exception ex) + { + AppLog.Write($"Broadcast diag failed: {ex.Message}"); + return null; + } + } + + /// The bound stream must be the one we are actually feeding. A mismatch is + /// the failure mode where ingest succeeds (the reusable stream happily accepts the + /// bytes) while the broadcast waits forever for a stream that is not sending. + internal static string BoundMatches(string? boundStreamId, string? expectedStreamId) + { + if (string.IsNullOrWhiteSpace(boundStreamId)) return "NO-BINDING"; + if (string.IsNullOrWhiteSpace(expectedStreamId)) return "unknown"; + return boundStreamId == expectedStreamId ? "yes" : "MISMATCH"; + } + + private async Task GetJsonAsync(string pathAndQuery) + { + var response = await _http.GetAsync($"{ApiBase}/{pathAndQuery}"); + if (!response.IsSuccessStatusCode) + { + AppLog.Write($"Broadcast diag GET {pathAndQuery.Split('?')[0]} failed ({(int)response.StatusCode})"); + return default; + } + return JsonSerializer.Deserialize(await response.Content.ReadAsStringAsync()); + } + + private static JsonElement Nested(JsonElement parent, string name) => + parent.ValueKind == JsonValueKind.Object && parent.TryGetProperty(name, out var child) ? child : default; + + private static string? Text(JsonElement parent, string name) => + parent.ValueKind == JsonValueKind.Object && parent.TryGetProperty(name, out var value) && value.ValueKind == JsonValueKind.String + ? value.GetString() + : null; + + private static string Flag(JsonElement parent, string name) => + parent.ValueKind == JsonValueKind.Object && parent.TryGetProperty(name, out var value) + ? (value.ValueKind == JsonValueKind.True ? "true" : value.ValueKind == JsonValueKind.False ? "false" : value.ValueKind.ToString()) + : "unset"; + /// Returns the channel's reusable stream (TASK 5 design decision 2): /// lists existing streams first and reuses the one with cdn.isReusable=true, /// creating it with variable resolution/frame rate on first use. Binding to a diff --git a/ViewModels/MainViewModel.Streaming.Operations.cs b/ViewModels/MainViewModel.Streaming.Operations.cs index f9b7daa..e47253e 100644 --- a/ViewModels/MainViewModel.Streaming.Operations.cs +++ b/ViewModels/MainViewModel.Streaming.Operations.cs @@ -167,6 +167,7 @@ public partial class MainViewModel : ViewModelBase _currentBroadcastId = await _youtubeStream.CreateBroadcast( StreamTitle, StreamDescription, DateTime.UtcNow, stream.Id); + _broadcastSeenLive = false; if (_currentBroadcastId == null) { AppLog.Write("Broadcast creation failed; check the OAuth session"); @@ -236,7 +237,15 @@ public partial class MainViewModel : ViewModelBase /// One liveStreams.list poll (TASK 5 item 3): updates the YouTube /// health state + the report-by-exception banner. Never throws — a poll - /// failure logs and leaves the last state untouched. + /// failure logs and leaves the last state untouched. + /// + /// Also piggybacks the broadcast diagnostic (2026-10-04) — the health poll was + /// already running during a stream but only ever read the STREAM's health, which + /// is why two test runs could push 100MB to YouTube and still leave the app + /// unable to say whether the broadcast had ever left `ready`. Deliberately + /// self-limiting: it only logs while the broadcast has NOT reached `live`, so it + /// shouts exactly when something is wrong and goes quiet once healthy, rather than + /// adding a permanent per-tick line to the log. private async Task PollHealthAsync() { if (_reusableStream == null || !IsLive) return; @@ -254,6 +263,12 @@ public partial class MainViewModel : ViewModelBase CurrentHealth.ConfigurationIssues.AddRange(health.ConfigurationIssues); OnPropertyChanged(nameof(CurrentHealth)); ApplyHealthIssue(health.ConfigurationIssues); + + if (!string.IsNullOrWhiteSpace(_currentBroadcastId) && !_broadcastSeenLive) + { + var lifeCycle = await _youtubeStream.LogBroadcastDiagnosticsAsync(_currentBroadcastId, _reusableStream.Id); + if (lifeCycle is "live" or "liveStarting") _broadcastSeenLive = true; + } } catch (Exception ex) { diff --git a/ViewModels/MainViewModel.Streaming.cs b/ViewModels/MainViewModel.Streaming.cs index d022b65..2cf1cb5 100644 --- a/ViewModels/MainViewModel.Streaming.cs +++ b/ViewModels/MainViewModel.Streaming.cs @@ -21,6 +21,9 @@ public partial class MainViewModel : ViewModelBase private string _streamDescription = string.Empty; private string _streamVisibility = "Private"; private string? _currentBroadcastId; + /// Latches once the broadcast reaches live so the per-poll broadcast + /// diagnostic stops logging (2026-10-04). Reset at broadcast creation. + private bool _broadcastSeenLive; private string? _reusableStreamUrl; private ReusableStream? _reusableStream; private string? _healthIssueBanner; diff --git a/ai.md b/ai.md index 0e58dc8..741332d 100644 --- a/ai.md +++ b/ai.md @@ -1683,6 +1683,33 @@ These are the hard facts behind every decision. Full list in `TASKS.md`. `enableAutoStart=true`, `enableAutoStop=true`, `enableMonitorStream=false`, `selfDeclaredMadeForKids=false`, `latencyPreference=low`. The encoder starting brings YouTube live. `enableMonitorStream=false` is what lets us skip the testing stage. +- **⛔ CORRECTION (2026-10-04): the push is provably healthy — stop investigating it.** The long + test run settles it: `liveBroadcasts.insert` at 14:17:04.577, ffmpeg `Output #0, flv` to + `rtmp://a.rtmp.youtube.com/live2/5f6z-…` at 14:17:05.686, and at 14:18:56.473 ffmpeg's own + muxing summary reads **`video:101229KiB audio:1419KiB`**, `muxing overhead: 0.202949%` — ~99 MB + of real video plus audio over 112s, which is exactly what 8000+128 kb/s should produce. **No + socket error, no 4xx from ingest, no reconnect.** The broadcast *still* never left `ready`, and + close-out earned 403 `invalidTransition` again. An earlier 8s run behaved identically, so + "YouTube needed longer" is disproven — 112s is longer. The break is between *ingest accepted* + and *broadcast told to start*, nowhere in the RTMP path. +- **The binding is the prime suspect, and the app was blind to it.** `contentDetails.boundStreamId` + ("the live stream bound to the broadcast") and `enableAutoStart` ("start automatically when you + start streaming video **on the bound live stream**") are both valid on insert, with no documented + restriction against a reusable stream. But YouTube's migration guide carries the danger: + **"a liveBroadcast must be bound to exactly one stream before the live broadcast can actually + start. The broadcast is not bound to any streams at the time that it's created."** And this + failure mode is *invisible from the RTMP side*, because **a reusable stream accepts bytes for an + unbound broadcast** — ingest succeeding proves nothing. ⇒ `LogBroadcastDiagnosticsAsync` rides + the **existing** stream-health poll (no second timer) and writes one greppable line: + `lifeCycleStatus`, `privacyStatus`, `recordingStatus`, `boundStreamId` **compared against the + stream id we are actually pushing** (`BoundMatches` → `yes`/`MISMATCH`/`NO-BINDING`/`unknown`), + `boundStreamLastUpdateTimeMs`, `enableAutoStart/Stop`, `liveChatId` presence, the stream's own + `status.streamStatus` + `activeLiveChatId`, and the CDN settings we declared. It is + **self-limiting** — `_broadcastSeenLive` latches on `live`/`liveStarting`, so the line shouts only + while the broadcast is stuck and goes quiet once healthy. **The next run reads this line; it is + the whole experiment.** Guarded by `BroadcastBindingTests.BoundMatches_ComparesTheBroadcastAgainstTheStreamWePush`, + which pins `unknown` for a missing expectation so an absent stream id can never be misreported + as a match. - **Visibility picker (TASK 9 item 6) — DELIBERATE TEST-PHASE LOCK, not drift (2026-09-01).** The "always Private" enforcement in `YouTubeStreamService.CreateBroadcast` stays while the creator runs multi-month real-world testing: non-private test streams would clutter the channel with VODs diff --git a/ytLive.Tests/BroadcastBindingTests.cs b/ytLive.Tests/BroadcastBindingTests.cs new file mode 100644 index 0000000..68e3e2f --- /dev/null +++ b/ytLive.Tests/BroadcastBindingTests.cs @@ -0,0 +1,33 @@ +using Xunit; +using ytLive.Services; + +namespace ytLive.Tests; + +/// +/// Broadcast-binding diagnostics (2026-10-04). Two test streams proved the RTMP push +/// is healthy — ffmpeg delivered 101,229 KiB video + 1,419 KiB audio over 112 seconds +/// with no socket error — yet the broadcast never left `ready` and close-out returned +/// 403 `invalidTransition`. Google's docs say enableAutoStart fires "when you +/// start streaming video on the bound live stream", so the one thing worth asserting +/// about the request we send is that we know which stream we think we are bound to. +/// +public class BroadcastBindingTests +{ + /// The comparison that decides whether the broadcast is even watching the + /// feed we are pushing. A reusable stream happily accepts bytes for an unbound + /// broadcast, so ingest succeeding proves nothing on its own — a MISMATCH or + /// NO-BINDING would look identical from the RTMP side and would hang forever. + /// "unknown" is the honest answer when the app has no stream id to compare against, + /// so a missing expectation is never silently reported as a match. + [Theory] + [InlineData("stream-abc", "stream-abc", "yes")] + [InlineData("stream-abc", "stream-xyz", "MISMATCH")] + [InlineData(null, "stream-abc", "NO-BINDING")] + [InlineData("", "stream-abc", "NO-BINDING")] + [InlineData("stream-abc", null, "unknown")] + [InlineData("stream-abc", "", "unknown")] + public void BoundMatches_ComparesTheBroadcastAgainstTheStreamWePush(string? bound, string? expected, string verdict) + { + Assert.Equal(verdict, YouTubeStreamService.BoundMatches(bound, expected)); + } +}