WIP

.claude/settings.local.json

@@ -141,7 +141,8 @@
       "Bash(if [ -f build.log ])",
       "Bash(then grep -E \"(ShouldEnableAsyncMode|Async mode|AsyncHandler)\" build.log)",
       "Bash(else echo \"No build log\")",
-      "Bash(fi)"
+      "Bash(fi)",
+      "Bash(ninja)"
     ],
     "deny": [],
     "ask": []

todo30.txt

@@ -314,4 +314,68 @@
 
 
 
+● 완벽합니다! 로그를 분석한 결과, 매우 중요한 진전이 있었습니다. 다양한 관점에서 진단하겠습니다:
+
+● MediaCodec Async 동작 진단 - 다각적 분석
+
+  🎉 중요한 성과:
+
+  1. Codec Private Data 문제 완전 해결 (Line 45, 139)
+  Line 45: "Stored AV1 codec private data: 21 bytes"
+  Line 139: "Set AV1 codec specific data (csd-0): 21 bytes"
+  ✅ AV1 sequence header가 MediaCodec에 성공적으로 전달됨
+
+  2. 중복 등록 문제 해결 (Line 19-20)
+  Line 19: "[VideoDecoderFactory] Total registered decoders for AV1: 1"
+  ✅ 이전 2개에서 1개로 감소 - 코드 최적화 성공
+
+  3. 출력 콜백 드디어 호출됨! (Line 346-347) 🔥
+  Line 346: "OnAsyncOutputAvailable: index=0"
+  Line 347: "OnAsyncOutputAvailable: Calling onOutputBufferAvailable lambda"
+  ✅ MediaCodec가 프레임을 디코딩하고 출력 콜백 호출 성공!
+
+  ---
+  ❌ 새로운 문제 발견:
+
+  WaitForAsyncFrame 동기화 문제 (Line 348)
+  Line 348: "DecodeFrameAsync: WaitForAsyncFrame timed out after 500ms"
+
+  출력 콜백이 호출되었지만, WaitForAsyncFrame이 이를 감지하지 못하고 타임아웃됨.
+
+  ---
+  🔍 다각적 진단
+
+  관점 1: 타임라인 분석
+
+  Line 296: queueInputBuffer 호출 (13:51:14.384)
+  Line 298: queueInputBuffer 성공 (status=0) (13:51:14.388) - 4ms 후
+  Line 346: OnAsyncOutputAvailable 호출 (13:51:14.398) - 14ms 후
+  Line 348: WaitForAsyncFrame 타임아웃 (13:51:14.888) - 504ms 후
+
+  문제: OnAsyncOutputAvailable이 14ms 후에 호출되었지만, WaitForAsyncFrame은 504ms 동안 대기하다가 타임아웃됨.
+
+  근본 원인: 콜백과 WaitForAsyncFrame 간의 동기화 문제
+
+  ---
+  관점 2: 콜백 체인 분석
+
+  OnAsyncOutputAvailable (Line 346-347)
+    ↓
+  onOutputBufferAvailable lambda 호출
+    ↓
+  ??? (프레임 큐에 추가되어야 함)
+    ↓
+  WaitForAsyncFrame (condition variable 대기)
+
+  가설: onOutputBufferAvailable 람다가 호출되지만, 프레임이 async frame queue에 추가되지 않거나 condition variable이 notify되지 않음.
+
+  ---
+  관점 3: MediaCodecAsyncHandler 구조 분석
+
+  MediaCodecAsyncHandler.cpp를 읽어서 WaitForAsyncFrame 구현을 확인해야 합니다:
+
+
+
+
+
 

vav2/platforms/android/applications/vav2player/vavcore/build.gradle

@@ -76,55 +76,25 @@ dependencies {
     androidTestImplementation 'androidx.test.espresso:espresso-core:3.5.1'
 }
 
-// Custom task to build standalone VavCore library
+// Custom task to copy latest VavCore library (always runs before build)
 task buildStandaloneVavCore {
-    description = "Build standalone VavCore library for Android"
+    description = "Copy latest VavCore library for Android (or build if not exists)"
     group = "build"
 
     doLast {
         def standaloneVavCoreDir = file("../../../../android/vavcore")
-        def buildScript = new File(standaloneVavCoreDir, "build_vavcore_android.bat")
 
-        if (!buildScript.exists()) {
-            logger.warn("VavCore build script not found: ${buildScript.absolutePath}")
-            logger.warn("Attempting to use existing prebuilt library...")
-            return
-        }
-
-        // Detect build type from task name (configureCMakeDebug vs configureCMakeRelease)
-        def buildType = "Debug"  // Default to Debug for development
-        tasks.matching { it.name.contains("configureCMake") }.each { task ->
-            if (task.name.contains("Release")) {
-                buildType = "Release"
-            }
-        }
-        logger.lifecycle("Building VavCore in ${buildType} mode")
-
-        // Build for all configured ABIs
+        // Copy for all configured ABIs
         def abis = android.defaultConfig.ndk.abiFilters
+        def anyLibraryCopied = false
+
         abis.each { abi ->
-            def arch = (abi == "arm64-v8a") ? "arm64" : "arm32"
-            logger.lifecycle("Building VavCore for ${abi} (${arch})...")
+            // Check for prebuilt library first
+            def vavCoreLib = new File(standaloneVavCoreDir, "lib/android-${abi}/libVavCore.so")
 
-            // CRITICAL FIX: Copy entire environment and add our variables
-            def env = System.getenv().collect { k, v -> "$k=$v" }
-            env.add("VAVCORE_BUILD_TYPE=${buildType}")
-
-            def proc = ["cmd", "/c", buildScript.absolutePath, arch].execute(
-                env as String[],
-                standaloneVavCoreDir
-            )
-
-            proc.waitForProcessOutput(System.out, System.err)
-
-            if (proc.exitValue() != 0) {
-                logger.warn("Failed to build VavCore for ${abi}")
-                logger.warn("Attempting to use existing prebuilt library...")
-            } else {
-                logger.lifecycle("VavCore built successfully for ${abi}")
-
-                // Copy to both prebuilt location AND jniLibs (Gradle uses jniLibs)
-                def vavCoreLib = new File(standaloneVavCoreDir, "lib/android-${abi}/libVavCore.so")
+            if (vavCoreLib.exists()) {
+                def timestamp = new Date(vavCoreLib.lastModified()).format("yyyy-MM-dd HH:mm:ss")
+                logger.lifecycle("Found VavCore for ${abi} (built: ${timestamp})")
 
                 // Location 1: Project-wide prebuilt directory
                 def prebuiltDir = file("../../../../../../lib/android-${abi}/vavcore")
@@ -134,23 +104,37 @@ task buildStandaloneVavCore {
                 def jniLibsDir = file("src/main/jniLibs/${abi}")
                 def jniLibsLib = new File(jniLibsDir, "libVavCore.so")
 
-                if (vavCoreLib.exists()) {
-                    // Copy to prebuilt location
-                    prebuiltDir.mkdirs()
-                    copy {
-                        from vavCoreLib
-                        into prebuiltDir
-                    }
-                    logger.lifecycle("Copied VavCore to: ${prebuiltLib.absolutePath}")
-
-                    // Copy to jniLibs (Gradle actually uses this)
-                    jniLibsDir.mkdirs()
-                    copy {
-                        from vavCoreLib
-                        into jniLibsDir
-                    }
-                    logger.lifecycle("Copied VavCore to jniLibs: ${jniLibsLib.absolutePath}")
+                // Always copy to ensure latest version
+                prebuiltDir.mkdirs()
+                copy {
+                    from vavCoreLib
+                    into prebuiltDir
                 }
+                logger.lifecycle("✓ Copied latest VavCore to: ${prebuiltLib.absolutePath}")
+
+                jniLibsDir.mkdirs()
+                copy {
+                    from vavCoreLib
+                    into jniLibsDir
+                }
+                logger.lifecycle("✓ Copied latest VavCore to jniLibs: ${jniLibsLib.absolutePath}")
+
+                anyLibraryCopied = true
+            } else {
+                logger.warn("VavCore not found for ${abi}: ${vavCoreLib.absolutePath}")
+                logger.warn("Please build VavCore first using: build_vavcore_android.bat")
+            }
+        }
+
+        if (!anyLibraryCopied) {
+            def buildScript = new File(standaloneVavCoreDir, "build_vavcore_android.bat")
+            if (buildScript.exists()) {
+                logger.warn("===============================================")
+                logger.warn("VavCore library not found!")
+                logger.warn("Please run the build script first:")
+                logger.warn("  cd ${standaloneVavCoreDir.absolutePath}")
+                logger.warn("  .\\build_vavcore_android.bat arm64")
+                logger.warn("===============================================")
             }
         }
     }

vav2/platforms/windows/vavcore/src/Decoder/MediaCodecAV1Decoder.cpp

@@ -67,6 +67,18 @@ bool MediaCodecAV1Decoder::ValidateInitializationParams(const VideoMetadata& met
     m_width = metadata.width;
     m_height = metadata.height;
 
+    // Store codec private data (AV1 sequence header from WebM)
+    if (metadata.codec_private_data && metadata.codec_private_size > 0) {
+        m_codec_private_data.assign(
+            metadata.codec_private_data,
+            metadata.codec_private_data + metadata.codec_private_size
+        );
+        LogInfo("Stored AV1 codec private data: " + std::to_string(m_codec_private_data.size()) + " bytes");
+    } else {
+        LogWarning("No codec private data provided - MediaCodec may fail to decode");
+        m_codec_private_data.clear();
+    }
+
     return true;
 }
 
@@ -694,6 +706,17 @@ bool MediaCodecAV1Decoder::InitializeMediaCodec() {
     AMediaFormat_setInt32(m_format, AMEDIAFORMAT_KEY_WIDTH, m_width);
     AMediaFormat_setInt32(m_format, AMEDIAFORMAT_KEY_HEIGHT, m_height);
 
+    // Set codec specific data (csd-0) - CRITICAL for AV1 decoding
+    // This contains the AV1 sequence header from WebM CodecPrivate
+    if (!m_codec_private_data.empty()) {
+        AMediaFormat_setBuffer(m_format, "csd-0",
+                              m_codec_private_data.data(),
+                              m_codec_private_data.size());
+        LogInfo("Set AV1 codec specific data (csd-0): " + std::to_string(m_codec_private_data.size()) + " bytes");
+    } else {
+        LogWarning("No codec private data available - MediaCodec may fail to decode AV1 frames");
+    }
+
     // Configure MediaCodec
     if (!ConfigureDecoder(VideoMetadata{})) {
         LogError("Failed to configure MediaCodec");

vav2/platforms/windows/vavcore/src/Decoder/MediaCodecAV1Decoder.h

@@ -170,6 +170,9 @@ private:
     int32_t m_width;
     int32_t m_height;
 
+    // Codec configuration (AV1 sequence header from WebM)
+    std::vector<uint8_t> m_codec_private_data;
+
     // Component management (REFACTORED: Phase 2-5 modularization)
     std::unique_ptr<MediaCodecBufferProcessor> m_buffer_processor;
     std::unique_ptr<MediaCodecHardwareDetector> m_hardware_detector;

vav2/platforms/windows/vavcore/src/Decoder/MediaCodecAsyncHandler.cpp

@@ -258,6 +258,10 @@ bool MediaCodecAsyncHandler::DecodeFrameAsync(const uint8_t* packet_data, size_t
 
     LogInfo("DecodeFrameAsync: Got input buffer successfully, capacity=" + std::to_string(buffer_capacity));
 
+    // Log packet size
+    LogInfo("DecodeFrameAsync: Checking packet size: packet_size=" + std::to_string(packet_size) +
+            ", buffer_capacity=" + std::to_string(buffer_capacity));
+
     if (packet_size > buffer_capacity) {
         LogError("DecodeFrameAsync: Packet size exceeds buffer capacity");
         AMediaCodec_queueInputBuffer(m_codec, input_index, 0, 0, 0, 0);
@@ -265,22 +269,40 @@ bool MediaCodecAsyncHandler::DecodeFrameAsync(const uint8_t* packet_data, size_t
     }
 
     // Copy packet data
+    LogInfo("DecodeFrameAsync: Copying packet data (" + std::to_string(packet_size) + " bytes)...");
     memcpy(input_buffer, packet_data, packet_size);
+    LogInfo("DecodeFrameAsync: Packet data copied successfully");
 
     // Queue input buffer
     int64_t timestamp_us = std::chrono::duration_cast<std::chrono::microseconds>(
         std::chrono::steady_clock::now().time_since_epoch()).count();
 
+    LogInfo("DecodeFrameAsync: Calling queueInputBuffer with index=" + std::to_string(input_index) +
+            ", size=" + std::to_string(packet_size) + ", timestamp=" + std::to_string(timestamp_us));
+
     media_status_t status = AMediaCodec_queueInputBuffer(
         m_codec, input_index, 0, packet_size, timestamp_us, 0);
 
+    LogInfo("DecodeFrameAsync: queueInputBuffer returned status=" + std::to_string(status));
+
     if (status != AMEDIA_OK) {
         LogError("DecodeFrameAsync: Failed to queue input buffer: " + std::to_string(status));
         return false;
     }
 
+    LogInfo("DecodeFrameAsync: Input buffer queued successfully, now waiting for output...");
+
     // Wait for async output frame
-    return WaitForAsyncFrame(output_frame, 100);  // 100ms timeout
+    // First frame may take longer to decode (codec initialization, I-frame processing)
+    bool result = WaitForAsyncFrame(output_frame, 500);  // 500ms timeout for first frame
+
+    if (!result) {
+        LogWarning("DecodeFrameAsync: WaitForAsyncFrame timed out after 500ms");
+    } else {
+        LogInfo("DecodeFrameAsync: Frame decoded successfully");
+    }
+
+    return result;
 }
 
 bool MediaCodecAsyncHandler::WaitForAsyncFrame(VideoFrame& output_frame, int timeout_ms) {
@@ -360,8 +382,13 @@ void MediaCodecAsyncHandler::ReturnAndClearInputBuffers() {
 }
 
 bool MediaCodecAsyncHandler::ProcessAsyncOutputFrame(int32_t output_index, AMediaCodecBufferInfo* buffer_info, VideoFrame& output_frame) {
+    LogInfo("ProcessAsyncOutputFrame: ENTRY - output_index=" + std::to_string(output_index));
+
     if (!m_codec || output_index < 0 || !buffer_info) {
-        LogError("ProcessAsyncOutputFrame: Invalid parameters");
+        LogError("ProcessAsyncOutputFrame: Invalid parameters - codec=" +
+                std::to_string(reinterpret_cast<uintptr_t>(m_codec)) +
+                ", output_index=" + std::to_string(output_index) +
+                ", buffer_info=" + std::to_string(reinterpret_cast<uintptr_t>(buffer_info)));
         return false;
     }
 
@@ -371,9 +398,16 @@ bool MediaCodecAsyncHandler::ProcessAsyncOutputFrame(int32_t output_index, AMedi
         return false;
     }
 
+    LogInfo("ProcessAsyncOutputFrame: Getting output buffer...");
+
     // Get output buffer (for validation, not actually used in surface mode)
     size_t buffer_size = 0;
     uint8_t* output_buffer = AMediaCodec_getOutputBuffer(m_codec, output_index, &buffer_size);
+
+    LogInfo("ProcessAsyncOutputFrame: getOutputBuffer returned: buffer=" +
+            std::to_string(reinterpret_cast<uintptr_t>(output_buffer)) +
+            ", size=" + std::to_string(buffer_size));
+
     if (!output_buffer) {
         LogError("ProcessAsyncOutputFrame: Failed to get output buffer");
         AMediaCodec_releaseOutputBuffer(m_codec, output_index, false);
@@ -387,7 +421,12 @@ bool MediaCodecAsyncHandler::ProcessAsyncOutputFrame(int32_t output_index, AMedi
 
     // Step 1: Release MediaCodec buffer to ImageReader surface (render=true)
     // This triggers MediaCodec to render the frame to ImageReader's Surface
+    LogInfo("ProcessAsyncOutputFrame: Releasing output buffer to ImageReader (render=true)...");
+
     media_status_t status = AMediaCodec_releaseOutputBuffer(m_codec, output_index, true);
+
+    LogInfo("ProcessAsyncOutputFrame: releaseOutputBuffer returned status=" + std::to_string(status));
+
     if (status != AMEDIA_OK) {
         LogError("ProcessAsyncOutputFrame: Failed to release output buffer: " + std::to_string(status));
         return false;
@@ -395,20 +434,32 @@ bool MediaCodecAsyncHandler::ProcessAsyncOutputFrame(int32_t output_index, AMedi
 
     // Step 2: Acquire AHardwareBuffer from ImageReader
     // Get SurfaceManager from decoder
+    LogInfo("ProcessAsyncOutputFrame: Getting SurfaceManager from decoder...");
+
     MediaCodecSurfaceManager* surface_manager = m_decoder->GetSurfaceManager();
     if (!surface_manager) {
         LogError("ProcessAsyncOutputFrame: SurfaceManager not available");
         return false;
     }
 
+    LogInfo("ProcessAsyncOutputFrame: SurfaceManager obtained successfully");
+
     // Acquire latest image from ImageReader
+    LogInfo("ProcessAsyncOutputFrame: Calling AcquireLatestImage...");
+
     AHardwareBuffer* ahb = surface_manager->AcquireLatestImage();
+
+    LogInfo("ProcessAsyncOutputFrame: AcquireLatestImage returned: ahb=" +
+            std::to_string(reinterpret_cast<uintptr_t>(ahb)));
+
     if (!ahb) {
         // This is normal during initial buffering - no image ready yet
-        LogWarning("ProcessAsyncOutputFrame: No image available from ImageReader (buffering)");
+        LogWarning("ProcessAsyncOutputFrame: No image available from ImageReader (buffering) - THIS IS THE FAILURE POINT!");
         return false;
     }
 
+    LogInfo("ProcessAsyncOutputFrame: AHardwareBuffer acquired successfully");
+
     // Step 3: Convert AHardwareBuffer to VkImage (zero-copy GPU pipeline)
     void* vk_device = surface_manager->GetVulkanDevice();
     void* vk_instance = surface_manager->GetVulkanInstance();
@@ -448,6 +499,7 @@ bool MediaCodecAsyncHandler::ProcessAsyncOutputFrame(int32_t output_index, AMedi
 
     LogInfo("ProcessAsyncOutputFrame: Frame acquired successfully (timestamp=" +
             std::to_string(buffer_info->presentationTimeUs) + "us)");
+    LogInfo("ProcessAsyncOutputFrame: EXIT - SUCCESS - returning true");
     return true;
 }
 
@@ -469,8 +521,19 @@ void MediaCodecAsyncHandler::OnAsyncInputAvailable(AMediaCodec* codec, void* use
 
 void MediaCodecAsyncHandler::OnAsyncOutputAvailable(AMediaCodec* codec, void* userdata, int32_t index, AMediaCodecBufferInfo* bufferInfo) {
     auto* handler = static_cast<MediaCodecAsyncHandler*>(userdata);
-    if (handler && handler->m_async_callbacks.onOutputBufferAvailable) {
-        handler->m_async_callbacks.onOutputBufferAvailable(index, bufferInfo);
+    if (handler) {
+        // Log output callback entry
+        handler->LogInfo("OnAsyncOutputAvailable: index=" + std::to_string(index) +
+                        ", callback_codec=" + std::to_string(reinterpret_cast<uintptr_t>(codec)) +
+                        ", stored_codec=" + std::to_string(reinterpret_cast<uintptr_t>(handler->m_codec)) +
+                        ", bufferInfo=" + std::to_string(reinterpret_cast<uintptr_t>(bufferInfo)));
+
+        if (handler->m_async_callbacks.onOutputBufferAvailable) {
+            handler->LogInfo("OnAsyncOutputAvailable: Calling onOutputBufferAvailable lambda");
+            handler->m_async_callbacks.onOutputBufferAvailable(index, bufferInfo);
+        } else {
+            handler->LogError("OnAsyncOutputAvailable: onOutputBufferAvailable callback is null!");
+        }
     }
 }
 

vav2/platforms/windows/vavcore/src/Decoder/MediaCodecSelector.h

@@ -59,10 +59,10 @@ public:
     // Codec information queries
     std::string GetSelectedCodecName() const { return m_selected_codec_name; }
     std::vector<CodecInfo> GetAvailableCodecs();
+    std::vector<std::string> GetAvailableCodecNames();  // Public for MediaCodecAV1Decoder delegation
 
 private:
     // Codec enumeration helpers
-    std::vector<std::string> GetAvailableCodecNames();
     bool IsAV1Codec(const std::string& codec_name) const;
 
     // Priority-based selection