Skip to content

Commit 7c9b8d9

Browse files
CopilotYimingZhanshen
Copilot
and
YimingZhanshen
committed
Add comprehensive debug logging throughout audio pipeline
All log lines prefixed with [DEBUG-*] tags for easy filtering: - [DEBUG-C] Control socket (port 7002): packet types, counts, exit reason - [DEBUG-D] Data socket (port 7003): packet counts, queue/dequeue stats - [DEBUG-FFMPEG] FFmpeg decoder: frame I/O, process health, ALL stderr - [DEBUG-FFMPEG-STDERR] Raw FFmpeg stderr output - [DEBUG-PCM] PCM data delivery with silence detection - [DEBUG-AUDIO] AudioOutputService sample delivery and queue state - [DEBUG-SETUP] AudioListener creation/stop lifecycle - [DEBUG-TEARDOWN] Session teardown with stream type - [DEBUG-UDP] Socket start/stop with port numbers This will show exactly where audio data flow stops. Co-authored-by: YimingZhanshen <76594627+YimingZhanshen@users.noreply.github.com>
1 parent 383b580 commit 7c9b8d9

6 files changed

Lines changed: 184 additions & 35 deletions

File tree

‎AirPlay/AirPlayService.cs‎

Lines changed: 13 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -147,8 +147,21 @@ public async Task StartAsync(CancellationToken cancellationToken)
147147
};
148148

149149
_audiobuf = new List<byte>();
150+
int pcmReceivedCount = 0;
150151
_airPlayReceiver.OnPCMDataReceived += (s, e) =>
151152
{
153+
pcmReceivedCount++;
154+
if (pcmReceivedCount <= 5 || pcmReceivedCount % 500 == 0)
155+
{
156+
bool allZeros = true;
157+
int checkLen = Math.Min(e.Length, 100);
158+
for (int i = 0; i < checkLen; i++)
159+
{
160+
if (e.Data[i] != 0) { allZeros = false; break; }
161+
}
162+
Console.WriteLine($"[DEBUG-PCM] OnPCMDataReceived #{pcmReceivedCount}: len={e.Length}, allZeros={allZeros}");
163+
}
164+
152165
// Play audio through speakers
153166
lock (_audioOutputLock)
154167
{

‎AirPlay/Decoders/Implementations/FFmpegAacEldDecoder.cs‎

Lines changed: 24 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -37,6 +37,8 @@ public class FFmpegAacEldDecoder : IDecoder, IDisposable
3737
private bool _initialized;
3838
private readonly byte[] _adtsHeader = new byte[7];
3939
private int _adtsFreqIdx;
40+
private int _decodeCallCount;
41+
private int _totalFramesDecoded;
4042

4143
public AudioFormat Type => AudioFormat.AAC_ELD;
4244

@@ -83,11 +85,8 @@ public int Config(int sampleRate, int channels, int bitDepth, int frameLength)
8385
string line;
8486
while ((line = reader.ReadLine()) != null)
8587
{
86-
// Only log critical errors, not per-frame decode warnings
87-
if (line.Contains("error", StringComparison.OrdinalIgnoreCase))
88-
{
89-
Console.WriteLine($"FFmpeg: {line}");
90-
}
88+
// Log all FFmpeg stderr output for debugging
89+
Console.WriteLine($"[DEBUG-FFMPEG-STDERR] {line}");
9190
}
9291
}
9392
catch { /* ignore */ }
@@ -115,10 +114,17 @@ public int GetOutputStreamLength()
115114
public int DecodeFrame(byte[] input, ref byte[] output, int length)
116115
{
117116
if (!_initialized || _ffmpegProcess == null || _ffmpegProcess.HasExited)
117+
{
118+
_decodeCallCount++;
119+
if (_decodeCallCount <= 3 || _decodeCallCount % 500 == 0)
120+
Console.WriteLine($"[DEBUG-FFMPEG] DecodeFrame called but process not ready: initialized={_initialized}, process={_ffmpegProcess != null}, hasExited={_ffmpegProcess?.HasExited}");
118121
return -1;
122+
}
119123

120124
try
121125
{
126+
_decodeCallCount++;
127+
122128
// Wrap the raw AAC frame in an ADTS header for FFmpeg to parse.
123129
// ADTS profile is set to AAC-LC (profile=2) since ADTS only has a 2-bit
124130
// profile field and cannot represent AAC-ELD. FFmpeg's decoder handles
@@ -131,6 +137,9 @@ public int DecodeFrame(byte[] input, ref byte[] output, int length)
131137
_ffmpegInput.Write(input, 0, input.Length);
132138
_ffmpegInput.Flush();
133139

140+
if (_decodeCallCount <= 3)
141+
Console.WriteLine($"[DEBUG-FFMPEG] Wrote frame #{_decodeCallCount}: inputLen={input.Length}, adtsFrameLen={frameLen}, expecting {_pcmOutputSize} bytes PCM output");
142+
134143
// Read decoded PCM from FFmpeg stdout
135144
int bytesToRead = _pcmOutputSize;
136145
int totalRead = 0;
@@ -148,16 +157,25 @@ public int DecodeFrame(byte[] input, ref byte[] output, int length)
148157
totalRead += read;
149158
}
150159

160+
_totalFramesDecoded++;
161+
162+
if (_decodeCallCount <= 5 || _decodeCallCount % 500 == 0)
163+
Console.WriteLine($"[DEBUG-FFMPEG] Frame #{_decodeCallCount}: read {totalRead}/{bytesToRead} bytes (attemptsLeft={maxAttempts}), totalDecoded={_totalFramesDecoded}");
164+
151165
if (totalRead < bytesToRead)
152166
{
153167
// Partial read - zero fill the rest
154168
Array.Clear(output, totalRead, bytesToRead - totalRead);
169+
if (_decodeCallCount <= 10)
170+
Console.WriteLine($"[DEBUG-FFMPEG] WARNING: Partial read! Only {totalRead} of {bytesToRead} bytes, zero-filled remainder");
155171
}
156172

157173
return 0;
158174
}
159-
catch (Exception)
175+
catch (Exception ex)
160176
{
177+
if (_decodeCallCount <= 5 || _decodeCallCount % 500 == 0)
178+
Console.WriteLine($"[DEBUG-FFMPEG] DecodeFrame exception #{_decodeCallCount}: {ex.GetType().Name}: {ex.Message}");
161179
return -1;
162180
}
163181
}

‎AirPlay/Listeners/AirTunesListener.cs‎

Lines changed: 8 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -454,14 +454,17 @@ public override async Task OnDataReceivedAsync(Request request, Response respons
454454
// (ports 7002/7003 must be released first)
455455
if (session.AudioControlListener != null)
456456
{
457+
Console.WriteLine("[DEBUG-SETUP] Stopping existing AudioListener before creating new one...");
457458
try { await session.AudioControlListener.StopAsync(); }
458-
catch (Exception ex) { Console.WriteLine($"Error stopping old audio listener: {ex.Message}"); }
459+
catch (Exception ex) { Console.WriteLine($"[DEBUG-SETUP] Error stopping old audio listener: {ex.Message}"); }
459460
session.AudioControlListener = null;
460461
}
461462

463+
Console.WriteLine($"[DEBUG-SETUP] Creating new AudioListener: format={session.AudioFormat}, ct={session.AudioCompressionType}, spf={session.AudioSamplesPerFrame}, mirroring={session.MirroringSession}");
462464
// Start 'AudioListener' (handle PCM/AAC/ALAC data received from iOS/macOS
463465
var control = new AudioListener(_receiver, session.SessionId, 7002, 7003, _dumpConfig);
464466
await control.StartAsync(cancellationToken).ConfigureAwait(false);
467+
Console.WriteLine("[DEBUG-SETUP] AudioListener started successfully");
465468

466469
session.AudioControlListener = control;
467470
}
@@ -564,6 +567,7 @@ public override async Task OnDataReceivedAsync(Request request, Response respons
564567
}
565568
if (request.Type == RequestType.TEARDOWN)
566569
{
570+
Console.WriteLine("[DEBUG-TEARDOWN] TEARDOWN request received");
567571
var plistReader = new BinaryPlistReader();
568572
using (var mem = new MemoryStream(request.Body))
569573
{
@@ -574,10 +578,12 @@ public override async Task OnDataReceivedAsync(Request request, Response respons
574578
// Always one foreach request
575579
var stream = (Dictionary<object, object>)((object[])plist["streams"]).Last();
576580
var type = (short)stream["type"];
581+
Console.WriteLine($"[DEBUG-TEARDOWN] Stream type: {type}");
577582

578583
// If screen Mirroring
579584
if (type == 110)
580585
{
586+
Console.WriteLine("[DEBUG-TEARDOWN] Stopping mirroring session");
581587
// Stop mirroring session
582588
if (session.MirroringListener != null)
583589
{
@@ -592,6 +598,7 @@ public override async Task OnDataReceivedAsync(Request request, Response respons
592598
// If audio session
593599
if (type == 96)
594600
{
601+
Console.WriteLine("[DEBUG-TEARDOWN] Stopping audio session");
595602
// Stop audio session
596603
if (session.AudioControlListener != null)
597604
{

0 commit comments

Comments
 (0)