diag: log what the broadcast is actually bound to while a stream runs

The logs answered the question and closed off a whole branch of investigation.

The long run: broadcast inserted 14:17:04.577, ffmpeg to
rtmp://a.rtmp.youtube.com/live2/5f6z-... at 14:17:05.686, and ffmpeg's own
muxing summary at 14:18:56.473 reads

  video:101229KiB audio:1419KiB  muxing overhead: 0.202949%

~99MB of real video plus audio over 112s, which is what 8000+128 kb/s is
supposed to produce. No socket error, no 4xx from ingest, no reconnect. And the
broadcast still never left `ready`; close-out 403'd invalidTransition again. The
8s run behaved the same way, so "YouTube needed longer" is disproven — 112s is
longer.

So the RTMP path is provably healthy. That is the finding worth keeping: it
kills the entire "the push is broken" theory, which is where this had been
heading for a week. The break is between ingest being accepted and the broadcast
being told to start.

Which puts the binding in frame, and the app was structurally blind to it.
Google documents contentDetails.boundStreamId and says enableAutoStart fires
"when you start streaming video on the bound live stream" — both valid on
insert, neither restricted against reusable streams. But the migration guide
also says a broadcast "is not bound to any streams at the time that it's
created", and the failure that produces is invisible from the RTMP side
precisely because a reusable stream will happily accept bytes for an unbound
broadcast. Ingest succeeding proves nothing.

Hence LogBroadcastDiagnosticsAsync, riding the existing health poll rather than
adding a timer. One greppable line: lifecycle status, privacy, recording,
boundStreamId *compared against the stream id we are actually pushing*
(BoundMatches: yes / MISMATCH / NO-BINDING / unknown), boundStreamLastUpdate-
TimeMs, autoStart/Stop, liveChatId presence, the stream's own streamStatus and
activeLiveChatId, and the CDN settings we declared.

Deliberately self-limiting: _broadcastSeenLive latches on live/liveStarting so
the diagnostic shouts only while the broadcast is stuck and goes quiet once it
is healthy. A permanent per-tick log line would be noise; this is the opposite.

One test, per the Good Dog rule: BroadcastBindingTests pins the matrix and
specifically pins `unknown` when there is no stream id to compare against, so a
missing expectation can never be misreported as a match — that is the failure
that would make this diagnostic lie.

Suite 387/387, 0 warnings.
This commit is contained in:
2026-10-04 14:47:09 -07:00
parent 048cab79f8
commit 5ad0106502
5 changed files with 171 additions and 1 deletions
+92
View File
@@ -178,6 +178,98 @@ public class YouTubeStreamService
: null;
}
/// <summary>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.</summary>
public async Task<string?> 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;
}
}
/// <summary>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.</summary>
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<JsonElement> 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<JsonElement>(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";
/// <summary>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
@@ -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
/// <summary>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.</summary>
/// 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.</summary>
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)
{
+3
View File
@@ -21,6 +21,9 @@ public partial class MainViewModel : ViewModelBase
private string _streamDescription = string.Empty;
private string _streamVisibility = "Private";
private string? _currentBroadcastId;
/// <summary>Latches once the broadcast reaches live so the per-poll broadcast
/// diagnostic stops logging (2026-10-04). Reset at broadcast creation.</summary>
private bool _broadcastSeenLive;
private string? _reusableStreamUrl;
private ReusableStream? _reusableStream;
private string? _healthIssueBanner;
+27
View File
@@ -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
+33
View File
@@ -0,0 +1,33 @@
using Xunit;
using ytLive.Services;
namespace ytLive.Tests;
/// <summary>
/// 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 <c>enableAutoStart</c> 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.
/// </summary>
public class BroadcastBindingTests
{
/// <summary>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.</summary>
[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));
}
}