[Solved][LibVLC] Video not playing on some devices

[Fradow]

Hello,

I have a problem using LibVLC. Here are the observations I made so far using the exact same video, using 2 different test devices (working on Nexus 7 2013, not working on Wiko Cink Five) :
- works on VLC for both
- works only on the Nexus for my custom app using LibVLC
- does NOT crash, the video just isn't playing, and there is no sound either
- the filepath is correct on the Wiko, and I can even see LibVLC started decoding it in the logs
- setSurfaceSize is implemented and called on the Nexus, but not called on the Wiko
- after investigating above point, indeed, the video start-up doesn't reach vout on the Wiko (no log with tag vout at all), while it does on the Nexus

I narrowed my investigation to those lines, but I have no clue what they really mean, how to solve that, and if there is any possibility to get a notification in the Java code to handle the case :

Log from non-working device :

Code: Select all

02-20 13:57:12.551: D/VLC(3365): core demux: using demux module "mp4" 02-20 13:57:12.552: D/VLC(3365): core input: looking for a subtitle file in /storage/sdcard0/Movies/ 02-20 13:57:12.557: D/VLC(3365): core decoder: looking for decoder module matching "mediacodec,iomx,all": 32 candidates 02-20 13:57:12.559: D/dalvikvm(3365): threadid=18: interp stack at 0x5653b000 02-20 13:57:12.567: D/VLC(3365): mediacodec decoder: using OMX.MTK.VIDEO.DECODER.AVC 02-20 13:57:12.568: D/ACodec(3365): Now uninitialized 02-20 13:57:12.570: I/OMXClient(3365): Using client-side OMX mux. 02-20 13:57:12.572: D/dalvikvm(3365): GC_EXPLICIT freed 207K, 8% free 14507K/15683K, paused 3ms+8ms, total 54ms 02-20 13:57:12.581: I/SurfaceView(3365): Changes: creating=true format=true size=true visible=true left=true top=true mUpdateWindowNeeded=false mReportDrawNeeded=false redrawNeeded=false forceSizeChanged=true mVisible=false mRequestedVisible=true 02-20 13:57:12.584: I/SurfaceView(3365): Cur surface: Surface(name=null, identity=-1) 02-20 13:57:12.589: I/SurfaceView(3365): New surface: Surface(name=null, identity=73), vis=true, frame=Rect(180, 101 - 1076, 526) 02-20 13:57:12.590: I/SurfaceView(3365): visibleChanged -- surfaceCreated 02-20 13:57:12.590: I/SurfaceView(3365): surfaceChanged -- format=2 w=400 h=400 02-20 13:57:12.590: D/VideoPlayer(3365): Pixel format is RGBX_8888 02-20 13:57:12.591: I/SurfaceView(3365): surfaceRedrawNeeded 02-20 13:57:12.591: I/SurfaceView(3365): finishedDrawing 02-20 13:57:12.593: V/SurfaceView(3365): Layout: x=180 y=101 w=896 h=425, frame=Rect(0, 0 - 896,

There is absolutely no more logs after that. The line "ACodec(3365): Now uninitialized" really seem to indicate something is off.

Here is what I get when executing VLC on the same device :

Code: Select all

02-20 14:11:29.672: D/VLC(3814): core demux: using demux module "mp4" 02-20 14:11:29.673: D/VLC(3814): core input: looking for a subtitle file in /storage/sdcard0/Movies/ 02-20 14:11:29.674: D/VLC(3814): core decoder: looking for decoder module matching "any": 33 candidates 02-20 14:11:29.706: D/VLC(3814): avcodec decoder: trying to use direct rendering 02-20 14:11:29.712: D/VLC(3814): avcodec decoder: allowing 1 thread(s) for decoding 02-20 14:11:29.714: D/VLC(3814): avcodec decoder: avcodec codec (H264 - MPEG-4 AVC (part 10)) started 02-20 14:11:29.716: D/VLC(3814): core decoder: using decoder module "avcodec" 02-20 14:11:29.718: I/SurfaceView(3814): Changes: creating=true format=true size=true visible=true left=true top=true mUpdateWindowNeeded=false mReportDrawNeeded=false redrawNeeded=false forceSizeChanged=true mVisible=false mRequestedVisible=true 02-20 14:11:29.720: I/SurfaceView(3814): Cur surface: Surface(name=null, identity=-1) 02-20 14:11:29.724: I/SurfaceView(3814): New surface: Surface(name=null, identity=101), vis=true, frame=Rect(359, 639 - 361, 641) 02-20 14:11:29.724: I/SurfaceView(3814): visibleChanged -- surfaceCreated 02-20 14:11:29.724: I/SurfaceView(3814): surfaceChanged -- format=2 w=2 h=2 02-20 14:11:29.725: D/VLC/VideoPlayerActivity(3814): Pixel format is RGBX_8888 02-20 14:11:29.725: I/SurfaceView(3814): surfaceRedrawNeeded 02-20 14:11:29.725: I/SurfaceView(3814): finishedDrawing 02-20 14:11:29.728: V/SurfaceView(3814): Layout: x=359 y=639 w=2 h=2, frame=Rect(0, 0 - 2, 2) 02-20 14:11:29.729: I/SurfaceView(3814): Changes: creating=true format=true size=true visible=false left=true top=true mUpdateWindowNeeded=false mReportDrawNeeded=false redrawNeeded=false forceSizeChanged=true mVisible=false mRequestedVisible=false 02-20 14:11:29.730: D/VLC(3814): core decoder: looking for decoder module matching "any": 33 candidates 02-20 14:11:29.737: I/SurfaceView(3814): Cur surface: Surface(name=null, identity=-1) 02-20 14:11:29.740: I/SurfaceView(3814): New surface: Surface(name=null, identity=-1), vis=false, frame=Rect(359, 639 - 361, 641) 02-20 14:11:29.740: I/SurfaceView(3814): finishedDrawing 02-20 14:11:29.742: V/SurfaceView(3814): Layout: x=359 y=639 w=2 h=2, frame=Rect(0, 0 - 2, 2) 02-20 14:11:29.761: D/VLC(3814): avcodec decoder: avcodec codec (MPEG AAC Audio) started 02-20 14:11:29.761: D/VLC(3814): core decoder: using decoder module "avcodec" 02-20 14:11:29.762: D/VLC(3814): core demux meta: looking for meta reader module matching "any": 1 candidates 02-20 14:11:29.765: D/VLC(3814): core demux meta: no meta reader modules matched 02-20 14:11:29.765: D/VLC(3814): core input: `file:///storage/sdcard0/Movies/videoplayback.mp4' successfully opened02-20 14:11:29.765: D/dalvikvm(3814): threadid=12: interp stack at 0x53529000 02-20 14:11:29.766: D/dalvikvm(3814): threadid=12: bye! 02-20 14:11:29.766: D/VLC(3814): mp4 demux: track[Id 0x1] using Sync Sample Box (stss) 02-20 14:11:29.766: D/VLC(3814): mp4 demux: stts gives 0 --> 0 (sample number) 02-20 14:11:29.766: D/VLC(3814): mp4 demux: track[Id 0x2] does not provide Sync Sample Box (stss) 02-20 14:11:29.766: D/VLC(3814): core input: Buffering 0% 02-20 14:11:29.767: D/VLC(3814): core input: Buffering 0% 02-20 14:11:29.767: D/VLC(3814): core input: Buffering 33% 02-20 14:11:29.767: D/VLC(3814): avcodec decoder: available software decoder output format 0 (yuv420p) 02-20 14:11:29.768: D/VLC(3814): core generic: creating audio output 02-20 14:11:29.768: D/VLC(3814): core input: Buffering 66% 02-20 14:11:29.768: D/VLC(3814): core audio output: looking for audio output module matching "opensles": 4 candidates 02-20 14:11:29.769: W/libOpenSLES(3814): class OutputMix interface 0 requested but unavailable MPH=43 02-20 14:11:29.769: D/VLC(3814): core audio output: using audio output module "opensles_android" 02-20 14:11:29.769: D/VLC(3814): core input: Buffering 100% 02-20 14:11:29.769: D/VLC(3814): core input: Stream buffering done (400 ms in 2 ms) 02-20 14:11:29.770: D/VLC(3814): core spu text: looking for text renderer module matching "any": 1 candidates 02-20 14:11:29.770: D/VLC(3814): freetype spu text: Using /system/fonts/DroidSans-Bold.ttf as font from file /system/fonts/DroidSans-Bold.ttf 02-20 14:11:29.770: D/VLC(3814): freetype spu text: Using /system/fonts/DroidSansMono.ttf as mono-font from file /system/fonts/DroidSansMono.ttf 02-20 14:11:29.770: D/dalvikvm(3814): threadid=12: interp stack at 0x549eb000 02-20 14:11:29.771: D/VLC(3814): freetype spu text: using fontsize: 2 02-20 14:11:29.771: D/VLC(3814): core spu text: using text renderer module "freetype" 02-20 14:11:29.771: D/VLC(3814): core scale: looking for video filter2 module matching "any": 35 candidates 02-20 14:11:29.773: D/VLC(3814): swscale scale: 32x32 (32x32) chroma: YUVA -> 16x16 (16x16) chroma: RGBA with scaling using Bicubic (good quality) 02-20 14:11:29.773: D/VLC(3814): core scale: using video filter2 module "swscale" 02-20 14:11:29.773: D/VLC(3814): core scale: looking for video filter2 module matching "any": 35 candidates 02-20 14:11:29.773: D/VLC(3814): yuvp scale: YUVP to YUVA converter 02-20 14:11:29.773: D/VLC(3814): core scale: using video filter2 module "yuvp" 02-20 14:11:29.774: D/VLC(3814): core video output: Deinterlacing available 02-20 14:11:29.774: D/VLC(3814): core video output: deinterlace 0, mode blend, is_needed 0 02-20 14:11:29.775: D/VLC(3814): core video output: Opening vout display wrapper 02-20 14:11:29.775: D/VLC(3814): core vout display: looking for vout display module matching "androidsurface": 4 candidates 02-20 14:11:29.775: D/VLC(3814): android_surface vout display: Pixel format RV32 02-20 14:11:29.776: D/VLC(3814): core vout display: VoutDisplayEvent 'fullscreen' 0 02-20 14:11:29.776: D/VLC(3814): core vout display: using vout display module "android_surface" 02-20 14:11:29.776: D/VLC(3814): core vout display: A filter to adapt decoder to display is needed 02-20 14:11:29.776: D/VLC(3814): core filter: looking for video filter2 module matching "any": 35 candidates 02-20 14:11:29.776: D/VLC(3814): yuv_rgb_neon filter: I420(640x360) to RV32(640x360) 02-20 14:11:29.777: D/VLC(3814): core filter: using video filter2 module "yuv_rgb_neon" 02-20 14:11:29.777: D/VLC(3814): core vout display: Filter 'yuv_rgb_neon' (0x54a106b4) appended to chain 02-20 14:11:29.777: I/SurfaceView(3814): Changes: creating=false format=false size=false visible=false left=false top=false mUpdateWindowNeeded=false mReportDrawNeeded=true redrawNeeded=false forceSizeChanged=false mVisible=true mRequestedVisible=true 02-20 14:11:29.778: I/SurfaceView(3814): Cur surface: Surface(name=null, identity=101) 02-20 14:11:29.781: D/dalvikvm(3814): threadid=12: bye!

There is obviously more going on after that.

Does anyone have an idea of what's going on and why the video is not playing ?

[flx42]

Which VLC version did you use?

In your first log you are trying to use HW acceleration (mediacodec) but with the second log SW decoding is used (avcodec).

Could you try with a nightly build and HW acceleration enabled and give us the log?

Thanks

[Fradow]

That seems to be the problem, thanks flx42. The video is indeed not playing with Full Hardware Acceleration enabled.

I'm using a fresh version of VLC pulled from repo and built earlier today :
02-20 14:11:26.309: D/VLC(3814): core libvlc: VLC media player - 2.2.0-git Weatherwax
02-20 14:11:26.309: D/VLC(3814): core libvlc: Copyright � 1996-2014 the VideoLAN team
02-20 14:11:26.310: D/VLC(3814): core libvlc: revision 2.1.0-git-2296-g75cc1f0

The LibVLC version on my ap is a little older :
02-20 13:57:12.503: D/VLC(3365): core libvlc: VLC media player - 2.2.0-git Weatherwax
02-20 13:57:12.503: D/VLC(3365): core libvlc: Copyright � 1996-2014 the VideoLAN team
02-20 13:57:12.503: D/VLC(3365): core libvlc: revision 2.1.0-git-2045-g2dbc664

Here is the log with Full Hardware Acceleration enabled on VLC :

Code: Select all

02-20 15:03:37.929: D/VLC(5024): core demux: using demux module "mp4" 02-20 15:03:37.930: D/VLC(5024): core input: looking for a subtitle file in /storage/sdcard0/Movies/ 02-20 15:03:37.931: D/VLC(5024): core decoder: looking for decoder module matching "mediacodec,iomx,all": 33 candidates 02-20 15:03:37.932: D/dalvikvm(5024): threadid=11: interp stack at 0x53b5a000 02-20 15:03:37.940: I/OMXClient(5024): Using client-side OMX mux. 02-20 15:03:37.968: I/SurfaceView(5024): Changes: creating=true format=true size=true visible=true left=true top=true mUpdateWindowNeeded=false mReportDrawNeeded=false redrawNeeded=false forceSizeChanged=true mVisible=false mRequestedVisible=true 02-20 15:03:37.970: I/SurfaceView(5024): Cur surface: Surface(name=null, identity=-1) 02-20 15:03:37.974: I/SurfaceView(5024): New surface: Surface(name=null, identity=161), vis=true, frame=Rect(359, 639 - 361, 641) 02-20 15:03:37.975: I/SurfaceView(5024): visibleChanged -- surfaceCreated 02-20 15:03:37.976: I/SurfaceView(5024): surfaceChanged -- format=2 w=2 h=2 02-20 15:03:37.976: D/VLC/VideoPlayerActivity(5024): Pixel format is RGBX_8888 02-20 15:03:37.976: I/SurfaceView(5024): surfaceRedrawNeeded 02-20 15:03:37.976: I/SurfaceView(5024): finishedDrawing 02-20 15:03:37.979: V/SurfaceView(5024): Layout: x=359 y=639 w=2 h=2, frame=Rect(0, 0 - 2, 2) 02-20 15:03:37.980: I/SurfaceView(5024): Changes: creating=true format=true size=true visible=true left=true top=true mUpdateWindowNeeded=false mReportDrawNeeded=false redrawNeeded=false forceSizeChanged=true mVisible=false mRequestedVisible=true 02-20 15:03:37.981: I/SurfaceView(5024): Cur surface: Surface(name=null, identity=-1) 02-20 15:03:37.985: I/SurfaceView(5024): New surface: Surface(name=null, identity=162), vis=true, frame=Rect(359, 639 - 361, 641) 02-20 15:03:37.985: I/SurfaceView(5024): visibleChanged -- surfaceCreated 02-20 15:03:37.985: I/SurfaceView(5024): surfaceChanged -- format=1 w=2 h=2 02-20 15:03:37.986: I/SurfaceView(5024): surfaceRedrawNeeded 02-20 15:03:37.986: I/SurfaceView(5024): finishedDrawing 02-20 15:03:37.989: V/SurfaceView(5024): Layout: x=359 y=639 w=2 h=2, frame=Rect(0, 0 - 2, 2) 02-20 15:03:38.007: I/SurfaceView(5024): Changes: creating=false format=false size=false visible=false left=false top=false mUpdateWindowNeeded=false mReportDrawNeeded=true redrawNeeded=false forceSizeChanged=false mVisible=true mRequestedVisible=true 02-20 15:03:38.008: I/SurfaceView(5024): Cur surface: Surface(name=null, identity=161) 02-20 15:03:38.010: I/SurfaceView(5024): New surface: Surface(name=null, identity=161), vis=true, frame=Rect(359, 639 - 361, 641) 02-20 15:03:38.010: I/SurfaceView(5024): surfaceRedrawNeeded 02-20 15:03:38.010: I/SurfaceView(5024): finishedDrawing 02-20 15:03:38.011: V/SurfaceView(5024): Layout: x=359 y=639 w=2 h=2, frame=Rect(0, 0 - 2, 2) 02-20 15:03:38.012: I/SurfaceView(5024): Changes: creating=false format=false size=false visible=false left=false top=false mUpdateWindowNeeded=false mReportDrawNeeded=true redrawNeeded=false forceSizeChanged=false mVisible=true mRequestedVisible=true 02-20 15:03:38.012: I/SurfaceView(5024): Cur surface: Surface(name=null, identity=162) 02-20 15:03:38.016: I/SurfaceView(5024): New surface: Surface(name=null, identity=162), vis=true, frame=Rect(359, 639 - 361, 641) 02-20 15:03:38.017: I/SurfaceView(5024): surfaceRedrawNeeded 02-20 15:03:38.017: I/SurfaceView(5024): finishedDrawing 02-20 15:03:38.018: V/SurfaceView(5024): Layout: x=359 y=639 w=2 h=2, frame=Rect(0, 0 - 2, 2) 02-20 15:03:38.062: V/InputMethodManager(5024): onWindowFocus: null softInputMode=288 first=true flags=#1810580 02-20 15:03:38.062: V/InputMethodManager(5024): Starting input: view=com.android.internal.policy.impl.PhoneWindow$DecorView@42d28cb0 02-20 15:03:38.062: V/InputMethodManager(5024): Starting input: tba=android.view.inputmethod.EditorInfo@42d0e8a8 ic=null 02-20 15:03:38.062: V/InputMethodManager(5024): START INPUT: com.android.internal.policy.impl.PhoneWindow$DecorView@42d28cb0 ic=null tba=android.view.inputmethod.EditorInfo@42d0e8a8 controlFlags=#104 02-20 15:03:38.082: V/InputMethodManager(5024): Starting input: Bind result=InputBindResult{com.android.internal.view.IInputMethodSession$Stub$Proxy@42c758d0 com.android.inputmethod.latin/.LatinIME #60} 02-20 15:03:38.082: D/VLC/AudioServiceContoller(5024): Service Connected 02-20 15:03:38.103: D/OpenGLRenderer(5024): Flushing caches (mode 0)

The problem is : I don't remember doing anything to enable Hardware Acceleration. The only thing I did was to enable time stretching (which is mandatory for my application).

What should I look for in the Java code ?

Edit : solved, I was missing instance.setHardwareAcceleration(-1); in updateLibVlcSettings (which I modified to fit my needs), it seems it defaulted to hardware acceleration for an unknown reason.

[flx42]

With Full HW acceleration, the mediacodec decoder will attempt to get the existing SurfaceView object with jni_LockAndGetAndroidJavaSurface. In our VLC app if the Java code do not send the SurfaceView object to the core (using function attachSurface from VideoPlayerActivity) then the decoder will wait indefinitely. This might be your problem, try to set variable mediacodec-dr to false and try again.

Given the following line from the log
02-20 15:03:37.931: D/VLC(5024): core decoder: looking for decoder module matching "mediacodec,iomx,all": 33 candidates
It looks like you've requested HW acceleration.