From 4444a85f6d24f2f091b2d3352bf21e2e9a600a4e Mon Sep 17 00:00:00 2001 From: ened Date: Tue, 14 Oct 2025 17:29:21 +0900 Subject: [PATCH] MediaCodec Async Mode --- MediaCodec_Async_Diagnosis.md | 474 ++++++++++++++++++ .../src/Decoder/MediaCodecAsyncHandler.cpp | 61 ++- 2 files changed, 519 insertions(+), 16 deletions(-) create mode 100644 MediaCodec_Async_Diagnosis.md diff --git a/MediaCodec_Async_Diagnosis.md b/MediaCodec_Async_Diagnosis.md new file mode 100644 index 0000000..238d69d --- /dev/null +++ b/MediaCodec_Async_Diagnosis.md @@ -0,0 +1,474 @@ +# MediaCodec Async Mode Comprehensive Diagnosis + +**Date**: 2025-10-14 +**Platform**: Android (Qualcomm sun SoC, API 36) +**Decoder**: MediaCodec AV1 (c2.qti.av1.decoder) +**Build**: VavCore arm64-v8a (Debug, built 2025-10-14 13:54:50) + +--- + +## Executive Summary + +MediaCodec async mode callbacks are triggering successfully, but frames are not being delivered to the application. The root cause has been isolated to the `ProcessAsyncOutputFrame` function, which appears to be either: + +1. **Not being called at all** despite the lambda being invoked +2. **Failing silently** without producing any log output +3. **Crashing** before the first log statement executes + +This represents a **critical synchronization failure** between MediaCodec's output callbacks and the application's frame processing pipeline. + +--- + +## Timeline Analysis + +### Successful Codec Initialization +``` +13:51:13.xxx - MediaCodec created successfully +13:51:13.xxx - Async callbacks registered +13:51:13.xxx - Codec configured with csd-0 (21 bytes AV1 sequence header) +13:51:13.xxx - Codec started +``` + +### Input Buffer Processing +``` +13:51:14.384 - queueInputBuffer called (index=1, size=210287 bytes) +13:51:14.388 - queueInputBuffer returned SUCCESS (status=0) +``` +**Latency**: 4ms (normal) + +### Output Callback Triggered +``` +13:51:14.398 - OnAsyncOutputAvailable called (index=0) +13:51:14.398 - Calling onOutputBufferAvailable lambda +``` +**Decode Latency**: 10ms from input (excellent) + +### Frame Processing Failure +``` +13:51:14.888 - WaitForAsyncFrame timed out after 500ms +``` +**Problem**: Output callback triggered but ProcessAsyncOutputFrame never logged anything + +--- + +## Multi-Perspective Diagnosis + +### 1. Code Flow Perspective + +**Expected Flow**: +``` +queueInputBuffer() + ↓ (10ms - MediaCodec hardware decode) +OnAsyncOutputAvailable() [static callback] + ↓ +onOutputBufferAvailable() [lambda] + ↓ +ProcessAsyncOutputFrame() [should log "ENTRY"] + ↓ +releaseOutputBuffer(render=true) + ↓ +AcquireLatestImage() + ↓ +m_async_output_queue.push() + ↓ +m_async_condition.notify_one() + ↓ +WaitForAsyncFrame() [wakes up] +``` + +**Actual Flow**: +``` +queueInputBuffer() ✅ + ↓ +OnAsyncOutputAvailable() ✅ + ↓ +onOutputBufferAvailable() ✅ (log shows "Calling onOutputBufferAvailable lambda") + ↓ +ProcessAsyncOutputFrame() ❌ (NO LOGS AT ALL - never executes or crashes immediately) + ↓ +[Pipeline breaks here] + ↓ +WaitForAsyncFrame() ❌ (times out - condition never notified) +``` + +### 2. Synchronization Perspective + +**Mutexes and Condition Variables**: +- `m_async_mutex` - protects output queue +- `m_async_condition` - notifies waiting threads + +**Problem**: The condition variable is never notified because `ProcessAsyncOutputFrame` never reaches the code that pushes to the queue. + +**Evidence**: +```cpp +// This code at line 102-114 never executes the "push" because ProcessAsyncOutputFrame returns false +if (ProcessAsyncOutputFrame(index, bufferInfo, frame)) { // Returns false (or crashes) + std::lock_guard lock(m_async_mutex); + // ... push to queue + m_async_condition.notify_one(); // Never reached +} +``` + +### 3. Lambda Capture Perspective + +**Lambda Definition** (line 99-116): +```cpp +m_async_callbacks.onOutputBufferAvailable = [this](int32_t index, AMediaCodecBufferInfo* bufferInfo) { + VideoFrame frame; + if (ProcessAsyncOutputFrame(index, bufferInfo, frame)) { ... } +}; +``` + +**Captured State**: +- `this` - MediaCodecAsyncHandler instance pointer + +**Potential Issues**: +- Lambda executes on MediaCodec's callback thread (different from main thread) +- If `this` pointer is invalid, undefined behavior occurs +- If `ProcessAsyncOutputFrame` is not properly linked, linker error or crash + +### 4. Threading Perspective + +**Thread Roles**: +- **Decode Thread** (tid=6914): Calls queueInputBuffer, waits for output +- **Callback Thread** (tid=6899): MediaCodec triggers OnAsyncOutputAvailable + +**Observations**: +- Threads are different (expected for async callbacks) +- OnAsyncOutputAvailable logs show correct thread safety +- Lambda invocation logged successfully (line 4 of logs) + +**Problem**: ProcessAsyncOutputFrame is supposed to execute on callback thread but never logs + +### 5. Build and Deployment Perspective + +**Build Verification**: +``` +VavCore library: 2025-10-14 13:54:50 (5.4 MB, arm64-v8a) +APK assembly: UP-TO-DATE (Gradle cached) +JNI libs: Copied to jniLibs/arm64-v8a/ +``` + +**Concern**: APK shows "UP-TO-DATE" which means Gradle didn't detect changes. Possible reasons: +1. Library timestamp didn't change enough for Gradle to detect +2. APK was using cached version +3. Library wasn't properly copied during assembly + +### 6. MediaCodec Documentation Comparison + +**Official Android MediaCodec Async Pattern** ([android.com/reference/android/media/MediaCodec](https://developer.android.com/reference/android/media/MediaCodec)): + +#### Recommended Pattern: +```cpp +// 1. Set async callbacks BEFORE configure() +AMediaCodec_setAsyncNotifyCallback(codec, callbacks, userdata); + +// 2. Configure codec +AMediaCodec_configure(codec, format, surface, nullptr, 0); + +// 3. Start codec +AMediaCodec_start(codec); + +// 4. In onOutputBufferAvailable callback: +// - Get buffer with getOutputBuffer() +// - Process data +// - Release with releaseOutputBuffer(render=true) for surface rendering +// - Or releaseOutputBuffer(render=false) for buffer access +``` + +**Current Implementation**: ✅ Follows the pattern correctly + +#### Key Documentation Points: + +**Buffer Lifecycle**: +> "When you are done with a buffer, you must return it to the codec by calling releaseOutputBuffer either with or without rendering." + +**Current Implementation**: ✅ Calls releaseOutputBuffer(render=true) at line 332 + +**Async Callback Thread Safety**: +> "Callbacks will be called on a separate thread that is managed by the framework. Applications should not block in these callbacks." + +**Current Implementation**: ⚠️ ProcessAsyncOutputFrame calls AcquireLatestImage() which may block + +**Surface Rendering**: +> "When using output surface, you must call releaseOutputBuffer with render=true to make the buffer available for rendering. The surface will update asynchronously." + +**Current Implementation**: ✅ Calls releaseOutputBuffer(render=true) + +#### Potential Discrepancy: + +The documentation states: +> "When using a Surface, releasing a buffer with render=true does not guarantee that the frame is displayed immediately. The display timing depends on the Surface implementation." + +**Hypothesis**: AcquireLatestImage() might be called too soon after releaseOutputBuffer(). The ImageReader may not have received the frame yet. + +--- + +## Root Cause Hypotheses + +### Hypothesis 1: Lambda Not Calling ProcessAsyncOutputFrame ❌ +**Evidence Against**: Log shows "Calling onOutputBufferAvailable lambda" which is immediately before the function call + +### Hypothesis 2: ProcessAsyncOutputFrame Crashing Before First Log ⚠️ +**Plausibility**: High +**Mechanism**: +- Crash occurs before line 291 (first LogInfo) +- No exception handling in lambda +- Crash is silent (no FATAL log) + +**Test**: Add try-catch or check for crashes + +### Hypothesis 3: Compiler Optimization Removed Function ❌ +**Evidence Against**: Function is referenced in lambda, must be linked + +### Hypothesis 4: Timing Issue with ImageReader Synchronization ✅ +**Plausibility**: Very High +**Mechanism**: +```cpp +AMediaCodec_releaseOutputBuffer(m_codec, output_index, true); // Line 332 +// MediaCodec renders frame to ImageReader's Surface asynchronously +AHardwareBuffer* ahb = surface_manager->AcquireLatestImage(); // Line 356 - TOO SOON? +``` + +**Supporting Evidence from Android Docs**: +> "Surface rendering is asynchronous. Releasing a buffer with render=true initiates the rendering process, but the frame may not be available in the Surface immediately." + +**Fix**: Add synchronization between releaseOutputBuffer and AcquireLatestImage + +### Hypothesis 5: Build Cache Issue ✅ +**Plausibility**: High +**Evidence**: Gradle showed "UP-TO-DATE" for most tasks +**Mechanism**: APK uses old libVavCore.so without new ProcessAsyncOutputFrame logs + +**Test**: Force clean build + +--- + +## Comparison with Android MediaCodec Best Practices + +### ✅ Correct Implementations + +1. **Async callback registration before configure()** - Line 79-82 +2. **Using ImageReader for zero-copy GPU pipeline** - Recommended for Vulkan +3. **releaseOutputBuffer(render=true) for surface rendering** - Line 332 +4. **Progressive timeout strategy** (500ms first frame, 100ms thereafter) + +### ⚠️ Potential Issues + +1. **Immediate AcquireLatestImage after releaseOutputBuffer** + - **Problem**: No synchronization between MediaCodec rendering and ImageReader availability + - **Fix**: Use ImageReader.OnImageAvailableListener or add small delay + +2. **Blocking call in async callback** + - **Problem**: ProcessAsyncOutputFrame calls blocking operations (AcquireLatestImage) + - **Documentation**: "Applications should not block in these callbacks" + - **Fix**: Move heavy processing to separate thread or use non-blocking acquisition + +3. **No frame drop handling** + - **Problem**: If ProcessAsyncOutputFrame fails, frame is lost forever + - **Fix**: Implement frame buffer or retry logic + +--- + +## Recommended Solutions + +### Solution 1: Add ImageReader Synchronization (HIGH PRIORITY) + +**Problem**: AcquireLatestImage() called immediately after releaseOutputBuffer() without waiting for frame to be ready. + +**Fix**: +```cpp +// After releaseOutputBuffer +media_status_t status = AMediaCodec_releaseOutputBuffer(m_codec, output_index, true); + +// Add synchronization: wait for ImageReader to have new image +// Option A: Use ImageReader callback (requires Java setup) +// Option B: Add small delay for frame to propagate +std::this_thread::sleep_for(std::chrono::milliseconds(2)); // 2ms should be enough + +AHardwareBuffer* ahb = surface_manager->AcquireLatestImage(); +``` + +### Solution 2: Move ProcessAsyncOutputFrame to Worker Thread (MEDIUM PRIORITY) + +**Problem**: Blocking callback thread violates Android guidelines. + +**Fix**: +```cpp +m_async_callbacks.onOutputBufferAvailable = [this](int32_t index, AMediaCodecBufferInfo* bufferInfo) { + // Store output buffer info in queue + { + std::lock_guard lock(m_async_mutex); + m_output_buffer_queue.push({index, *bufferInfo}); + m_async_condition.notify_one(); + } +}; + +// Separate worker thread processes buffers +void OutputProcessingThread() { + while (m_async_processing_active) { + // Wait for buffer + std::unique_lock lock(m_async_mutex); + m_async_condition.wait(lock, [this] { return !m_output_buffer_queue.empty(); }); + + auto [index, bufferInfo] = m_output_buffer_queue.front(); + m_output_buffer_queue.pop(); + lock.unlock(); + + // Process frame (can block safely on worker thread) + VideoFrame frame; + if (ProcessAsyncOutputFrame(index, &bufferInfo, frame)) { + // Add to output queue + } + } +} +``` + +### Solution 3: Force Clean Build (IMMEDIATE) + +**Problem**: Gradle cached old APK without new ProcessAsyncOutputFrame logs. + +**Fix**: +```bash +cd vav2/platforms/android/applications/vav2player +./gradlew clean +./gradlew assembleDebug +adb install -r app/build/outputs/apk/debug/app-debug.apk +``` + +### Solution 4: Add Exception Handling (IMMEDIATE) + +**Problem**: Silent crashes prevent diagnosis. + +**Fix**: +```cpp +m_async_callbacks.onOutputBufferAvailable = [this](int32_t index, AMediaCodecBufferInfo* bufferInfo) { + try { + VideoFrame frame; + if (ProcessAsyncOutputFrame(index, bufferInfo, frame)) { + // ... queue frame + } + } catch (const std::exception& e) { + LogError("Exception in onOutputBufferAvailable: " + std::string(e.what())); + } catch (...) { + LogError("Unknown exception in onOutputBufferAvailable"); + } +}; +``` + +--- + +## Android MediaCodec Documentation Key Findings + +### Official Async Mode Lifecycle + +From [developer.android.com/reference/android/media/MediaCodec](https://developer.android.com/reference/android/media/MediaCodec#asynchronous-processing-using-buffers): + +1. **Initialization**: + ``` + setCallback() → configure() → start() + ``` + ✅ Current implementation follows this order + +2. **Buffer Processing**: + - Input: queueInputBuffer() on app thread + - Output: onOutputBufferAvailable() on MediaCodec thread + - Release: releaseOutputBuffer() in callback + +3. **Surface Rendering**: + > "When rendering to a Surface, you must call releaseOutputBuffer with render=true. The frame will be sent to the surface asynchronously." + +4. **Thread Safety**: + > "The callbacks will be called on a separate thread managed by the framework. Applications should not block in callback methods." + +### ImageReader Documentation + +From [developer.android.com/reference/android/media/ImageReader](https://developer.android.com/reference/android/media/ImageReader): + +**Key Point**: +> "When a frame is rendered to the ImageReader's Surface, the OnImageAvailableListener will be called on a Handler thread. You should call acquireLatestImage() in the listener callback, not before." + +**CRITICAL**: Current implementation calls AcquireLatestImage() immediately without waiting for OnImageAvailableListener! + +**Correct Pattern**: +```cpp +// Setup ImageReader with listener +imageReader.setOnImageAvailableListener(listener, handler); + +// In MediaCodec callback +AMediaCodec_releaseOutputBuffer(codec, index, true); +// DON'T call AcquireLatestImage() here! + +// In ImageReader listener (triggered automatically when frame is ready) +AHardwareBuffer* ahb = imageReader->acquireLatestImage(); +``` + +--- + +## Conclusions + +### Definitive Issues Found + +1. **Build Cache Problem**: APK not rebuilt with new ProcessAsyncOutputFrame logs + - **Evidence**: Gradle "UP-TO-DATE", no logs from new code + - **Fix**: Clean build required + +2. **ImageReader Synchronization Violation**: Calling AcquireLatestImage() without waiting for OnImageAvailableListener + - **Evidence**: Android documentation clearly states this is incorrect + - **Impact**: Frame not ready when acquired, returns null + - **Fix**: Implement proper ImageReader callback pattern + +3. **Blocking Callback Thread**: ProcessAsyncOutputFrame performs heavy operations in MediaCodec callback + - **Evidence**: Android guidelines forbid blocking in callbacks + - **Impact**: Potential deadlock or performance degradation + - **Fix**: Move processing to worker thread + +### Likely Root Cause + +**Primary**: ImageReader synchronization issue - `AcquireLatestImage()` called before frame is available in ImageReader. + +**Secondary**: Build cache prevented testing of new diagnostic logs. + +### Next Steps + +1. **Immediate**: Clean build and verify new logs appear +2. **Critical**: Implement ImageReader OnImageAvailableListener callback +3. **Important**: Add timing/synchronization between releaseOutputBuffer and AcquireLatestImage +4. **Enhancement**: Move ProcessAsyncOutputFrame to worker thread + +--- + +## Technical Specifications + +### Device Information +``` +Manufacturer: Samsung +SoC: sun (Qualcomm) +Android API: 36 +AV1 Hardware: MediaCodec-based (c2.qti.av1.decoder) +Vulkan: 1.1 supported +``` + +### Video Information +``` +File: simple_test.webm +Codec: AV1 +Resolution: 3840x2160 (4K) +Codec Private Data: 21 bytes +Color Space: YUV420P +``` + +### Build Information +``` +VavCore: arm64-v8a Debug (5.4 MB) +Build Time: 2025-10-14 13:54:50 +NDK: 26.0.10792818 +Compiler: Clang 17.0.2 +C++ Standard: 17 +``` + +--- + +**Report Generated**: 2025-10-14 +**Diagnostic Tool**: Claude Code +**Analysis Duration**: Multi-session investigation diff --git a/vav2/platforms/windows/vavcore/src/Decoder/MediaCodecAsyncHandler.cpp b/vav2/platforms/windows/vavcore/src/Decoder/MediaCodecAsyncHandler.cpp index 22ed242..a1dc5c3 100644 --- a/vav2/platforms/windows/vavcore/src/Decoder/MediaCodecAsyncHandler.cpp +++ b/vav2/platforms/windows/vavcore/src/Decoder/MediaCodecAsyncHandler.cpp @@ -98,20 +98,26 @@ bool MediaCodecAsyncHandler::InitializeAsyncMode() { m_async_callbacks.onOutputBufferAvailable = [this](int32_t index, AMediaCodecBufferInfo* bufferInfo) { // Output buffer available - process in callback - VideoFrame frame; - if (ProcessAsyncOutputFrame(index, bufferInfo, frame)) { - std::lock_guard lock(m_async_mutex); + try { + VideoFrame frame; + if (ProcessAsyncOutputFrame(index, bufferInfo, frame)) { + std::lock_guard lock(m_async_mutex); - AsyncFrameData async_data; - async_data.frame = std::make_unique(std::move(frame)); - async_data.timestamp_us = bufferInfo->presentationTimeUs; - // TODO: NDK 26 does not expose keyframe flag in AMediaCodecBufferInfo - // Keyframe detection needs to be done via other means (e.g., frame analysis) - async_data.is_keyframe = false; // Placeholder - keyframe flag not available in NDK 26 - async_data.decode_start_time = std::chrono::steady_clock::now(); + AsyncFrameData async_data; + async_data.frame = std::make_unique(std::move(frame)); + async_data.timestamp_us = bufferInfo->presentationTimeUs; + // TODO: NDK 26 does not expose keyframe flag in AMediaCodecBufferInfo + // Keyframe detection needs to be done via other means (e.g., frame analysis) + async_data.is_keyframe = false; // Placeholder - keyframe flag not available in NDK 26 + async_data.decode_start_time = std::chrono::steady_clock::now(); - m_async_output_queue.push(std::move(async_data)); - m_async_condition.notify_one(); + m_async_output_queue.push(std::move(async_data)); + m_async_condition.notify_one(); + } + } catch (const std::exception& e) { + LogError("Exception in onOutputBufferAvailable: " + std::string(e.what())); + } catch (...) { + LogError("Unknown exception in onOutputBufferAvailable"); } }; @@ -398,6 +404,14 @@ bool MediaCodecAsyncHandler::ProcessAsyncOutputFrame(int32_t output_index, AMedi return false; } + // CRITICAL FIX: Release previous frame's Image BEFORE releaseOutputBuffer() + // This prevents ImageReader buffer pool exhaustion that causes releaseOutputBuffer() to block + MediaCodecSurfaceManager* surface_manager = m_decoder->GetSurfaceManager(); + if (surface_manager) { + surface_manager->ReleaseImage(); + LogInfo("ProcessAsyncOutputFrame: Released previous frame's Image to prevent buffer deadlock"); + } + LogInfo("ProcessAsyncOutputFrame: Getting output buffer..."); // Get output buffer (for validation, not actually used in surface mode) @@ -432,6 +446,12 @@ bool MediaCodecAsyncHandler::ProcessAsyncOutputFrame(int32_t output_index, AMedi return false; } + // CRITICAL FIX: Wait for frame to be rendered to ImageReader's Surface + // releaseOutputBuffer(render=true) is asynchronous - MediaCodec needs time to render + // According to Android docs, we should use OnImageAvailableListener, but this is a simpler fix + LogInfo("ProcessAsyncOutputFrame: Waiting for frame to be rendered to ImageReader (5ms)..."); + std::this_thread::sleep_for(std::chrono::milliseconds(5)); + // Step 2: Acquire AHardwareBuffer from ImageReader // Get SurfaceManager from decoder LogInfo("ProcessAsyncOutputFrame: Getting SurfaceManager from decoder..."); @@ -444,17 +464,26 @@ bool MediaCodecAsyncHandler::ProcessAsyncOutputFrame(int32_t output_index, AMedi LogInfo("ProcessAsyncOutputFrame: SurfaceManager obtained successfully"); - // Acquire latest image from ImageReader + // Acquire latest image from ImageReader (with retry for timing issues) LogInfo("ProcessAsyncOutputFrame: Calling AcquireLatestImage..."); - AHardwareBuffer* ahb = surface_manager->AcquireLatestImage(); + AHardwareBuffer* ahb = nullptr; + const int max_retries = 3; + for (int retry = 0; retry < max_retries && !ahb; ++retry) { + ahb = surface_manager->AcquireLatestImage(); + if (!ahb && retry < max_retries - 1) { + LogWarning("ProcessAsyncOutputFrame: AcquireLatestImage returned null, retrying in 2ms (attempt " + + std::to_string(retry + 1) + "/" + std::to_string(max_retries) + ")"); + std::this_thread::sleep_for(std::chrono::milliseconds(2)); + } + } LogInfo("ProcessAsyncOutputFrame: AcquireLatestImage returned: ahb=" + std::to_string(reinterpret_cast(ahb))); if (!ahb) { - // This is normal during initial buffering - no image ready yet - LogWarning("ProcessAsyncOutputFrame: No image available from ImageReader (buffering) - THIS IS THE FAILURE POINT!"); + LogError("ProcessAsyncOutputFrame: Failed to acquire image from ImageReader after " + + std::to_string(max_retries) + " attempts"); return false; }