GNOME Bugzilla – Bug 761014
h264parse: sends unnecessary caps events/queries for every (unchanging) SPS/PPS when converting to byte-stream (android mediacodec)
Last modified: 2016-02-05 04:27:59 UTC
Files available here http://www.gentil.com/tmp/sdcard-gstreamer-1.7.1.zip can't be played with hardware acceleration with latest git 1.7.2 gstreamer on Android Nexus 7 2013 and Nexus 5x. Those files can be played in hardware acceleration with gstreamer 1.5 and can be played without hardware acceleration with latest. Logs are here: http://www.gentil.com/tmp/log.zip I have provided a gstreamer-1.5 apk file that can play the files in hardware: http://www.gentil.com/tmp/tutorial_5_gstreamer1.5.apk
Can you describe what the different logs are? The only thing really needed here is a log with GST_LEVEL_DEBUG with GIT master and an application that does not link the libav plugin. That should make the problem obvious.
Not working: App: http://www.gentil.comt/tmp/tutorial_5_gstreamer20161023.apk Log: http://www.gentil.comt/tmp/gstreamer-20161023-log-level5-local-fsp25.zip Video: http://www.gentil.comt/tmp/sdcard-gstreamer-1.7.1.zip (local-25fps.mp4) Working: App: http://www.gentil.comt/tmp/tutorial_5_gstreamer1.5.apk Video: http://www.gentil.comt/tmp/sdcard-gstreamer-1.7.1.zip (local-25fps.mp4)
Here are 3 Additional log files that compare the working hardware-accelerated playback on 1.5 and the non working hardware-accelerated playback on 1.7.2.
Created attachment 319622 [details] Working gstreamer1.5
Created attachment 319623 [details] Notworking gstreamer1.7.2
Created attachment 319624 [details] Notworking gstreamer1.7.2 (amc log)
Created attachment 319629 [details] Working gstreamer1.5 (amc log)
And here is the working gstreamer1.5 (amc log). The differences between 1.5 and 1.7.2 follows: *************WORKING 1.5************* 01-24 13:20:47.855: I/OMXClient(21363): Using client-side OMX mux. 01-24 13:20:47.877: D/GStreamer+amcvideodec(21363): 0:00:17.424835205 0x9fcc6f80 gstamcvideodec.c:273:gst_amc_video_dec_open:<amcvideodec-omxqcomvideodecoderavc0> Opened decoder 01-24 13:20:47.880: D/GStreamer+amcvideodec(21363): 0:00:17.427032470 0x9fcc6f80 gstamcvideodec.c:972:gst_amc_video_dec_set_format:<amcvideodec-omxqcomvideodecoderavc0> Setting new caps video/x-h264, stream-format=(string)byte-stream, alignment=(string)au, level=(string)4, profile=(string)baseline, width=(int)1280, height=(int)1440, framerate=(fraction)101/4, pixel-aspect-ratio=(fraction)1/1, parsed=(boolean)true 01-24 13:20:47.880: D/GStreamer+amcvideodec(21363): 0:00:17.427368163 0x9fcc6f80 gstamcvideodec.c:1066:gst_amc_video_dec_set_format:<amcvideodec-omxqcomvideodecoderavc0> Configuring codec with format: {height=1440, width=1280, mime=video/avc} 01-24 13:20:47.881: W/ACodec(21363): do not know color format 0x7fa30c03 = 2141391875 01-24 13:20:48.047: D/GStreamer+amcvideodec(21363): 0:00:17.594451904 0x9f3ebcc0 gstamcvideodec.c:602:gst_amc_video_dec_loop:<amcvideodec-omxqcomvideodecoderavc0> Waiting for available output buffer 01-24 13:20:48.060: D/GStreamer+amcvideodec(21363): 0:00:17.607513427 0x9fcc6f80 gstamcvideodec.c:1164:gst_amc_video_dec_handle_frame:<amcvideodec-omxqcomvideodecoderavc0> Handling frame 01-24 13:20:48.149: D/GStreamer+amcvideodec(21363): 0:00:17.696350097 0x9f3ebcc0 gstamcvideodec.c:667:gst_amc_video_dec_loop:<amcvideodec-omxqcomvideodecoderavc0> Dequeueing output buffer timed out 01-24 13:20:48.149: D/GStreamer+amcvideodec(21363): 0:00:17.696502685 0x9f3ebcc0 gstamcvideodec.c:602:gst_amc_video_dec_loop:<amcvideodec-omxqcomvideodecoderavc0> Waiting for available output buffer 01-24 13:20:48.161: D/GStreamer+amcvideodec(21363): 0:00:17.708099364 0x9fcc6f80 gstamcvideodec.c:1201:gst_amc_video_dec_handle_frame:<amcvideodec-omxqcomvideodecoderavc0> Dequeueing input buffer timed out 01-24 13:20:48.233: D/GStreamer+amcvideodec(21363): 0:00:17.780364991 0x9fcc6f80 gstamcvideodec.c:1272:gst_amc_video_dec_handle_frame:<amcvideodec-omxqcomvideodecoderavc0> Queueing buffer 0: size 61612 time 0 flags 0x00000001 01-24 13:20:48.250: D/GStreamer+amcvideodec(21363): 0:00:17.797180176 0x9f3ebcc0 gstamcvideodec.c:667:gst_amc_video_dec_loop:<amcvideodec-omxqcomvideodecoderavc0> Dequeueing output buffer timed out 01-24 13:20:48.250: D/GStreamer+amcvideodec(21363): 0:00:17.797332764 0x9f3ebcc0 gstamcvideodec.c:602:gst_amc_video_dec_loop:<amcvideodec-omxqcomvideodecoderavc0> Waiting for available output buffer *************NOT WORKING 1.7.2************* 01-24 13:07:59.030: I/OMXClient(20724): Using client-side OMX mux. 01-24 13:07:59.047: D/GStreamer+amcvideodec(20724): 0:00:12.134796144 0x9e27adb0 gstamcvideodec.c:451:gst_amc_video_dec_open:<amcvideodec-omxqcomvideodecoderavc0> Opened decoder 01-24 13:07:59.049: D/GStreamer+amcvideodec(20724): 0:00:12.136169435 0x9e27adb0 gstamcvideodec.c:575:gst_amc_video_dec_change_state:<amcvideodec-omxqcomvideodecoderavc0> changing state: READY => PAUSED 01-24 13:07:59.062: D/GStreamer+amcvideodec(20724): 0:00:12.149291993 0x9e27adb0 gstamcvideodec.c:1757:gst_amc_video_dec_set_format:<amcvideodec-omxqcomvideodecoderavc0> Setting new caps video/x-h264, stream-format=(string)byte-stream, alignment=(string)au, level=(string)4, profile=(string)baseline, width=(int)1280, height=(int)1440, framerate=(fraction)101/4, pixel-aspect-ratio=(fraction)1/1, parsed=(boolean)true 01-24 13:07:59.066: D/GStreamer+amcvideodec(20724): 0:00:12.153564454 0x9e27adb0 gstamcvideodec.c:1864:gst_amc_video_dec_set_format:<amcvideodec-omxqcomvideodecoderavc0> Available downstream caps: video/x-raw(memory:GLMemory), format=(string)RGBA, texture-target=(string)external-oes, width=(int)[ 1, 2147483647 ], height=(int)[ 1, 2147483647 ], framerate=(fraction)[ 0/1, 2147483647/1 ]; video/x-raw, format=(string)NV12, width=(int)[ 1, 2147483647 ], height=(int)[ 1, 2147483647 ], framerate=(fraction)[ 0/1, 2147483647/1 ]; video/x-raw, format=(string)I420, width=(int)[ 1, 2147483647 ], height=(int)[ 1, 2147483647 ], framerate=(fraction)[ 0/1, 2147483647/1 ] 01-24 13:07:59.068: D/GStreamer+amcvideodec(20724): 0:00:12.155517579 0x9e27adb0 gstamcvideodec.c:2437:_find_local_gl_context:<amcvideodec-omxqcomvideodecoderavc0> found local context 0xa077f120 01-24 13:07:59.068: I/GStreamer+amcvideodec(20724): 0:00:12.155670167 0x9e27adb0 gstamcvideodec.c:1933:gst_amc_video_dec_set_format:<amcvideodec-omxqcomvideodecoderavc0> GL output: enabled 01-24 13:07:59.070: D/GStreamer+amcvideodec(20724): 0:00:12.157592774 0x9e27adb0 gstamcvideodec.c:1985:gst_amc_video_dec_set_format:<amcvideodec-omxqcomvideodecoderavc0> Configuring codec with format: {height=1440, width=1280, mime=video/avc} 01-24 13:07:59.071: I/MediaCodec(20724): [OMX.qcom.video.decoder.avc] setting surface generation to 21221377 01-24 13:07:59.072: E/ACodec(20724): [OMX.qcom.video.decoder.avc] storeMetaDataInBuffers failed w/ err -2147483648 01-24 13:07:59.079: D/SurfaceUtils(20724): set up nativeWindow 0x9ece0e08 for 1280x1440, color 0x7fa30c03, rotation 0, usage 0x42002900 01-24 13:07:59.154: D/GStreamer+amcvideodec(20724): 0:00:12.241241456 0x9eea77b0 gstamcvideodec.c:1199:gst_amc_video_dec_loop:<amcvideodec-omxqcomvideodecoderavc0> Waiting for available output buffer 01-24 13:07:59.184: D/GStreamer+amcvideodec(20724): 0:00:12.271392823 0x9e27adb0 gstamcvideodec.c:2077:gst_amc_video_dec_handle_frame:<amcvideodec-omxqcomvideodecoderavc0> Handling frame 01-24 13:07:59.256: D/GStreamer+amcvideodec(20724): 0:00:12.343383790 0x9eea77b0 gstamcvideodec.c:1209:gst_amc_video_dec_loop:<amcvideodec-omxqcomvideodecoderavc0> dequeueOutputBuffer() returned -1 (0xffffffff)
Last important comment, I need libav to play the file WITH hardware acceleration on Gstreamer1.5. I'm 100% that it's hardware decoded. It seems that Libav is only used for a deinterlace plugin. Without libav on Gstreamer1.5, there is no error but the playback is completely jerky. Here is a comparison of the dumpelements between Gstreamer 1.5 with and without libav: DUMPELEMENTS: inputselector1 uridecodebin1 decodebin0 amcvideodec-omxqcomvideodecoderavc1 capsfilter1 h264parse1 multiqueue1 qtdemux1 typefind source playsink vbin vconv conv2 videobalance scale conv identity vqueue glimagesinkbin0 sink glcolorconvertelement0 gluploadelement0 vdbin vdconv streamsynchronizer0 DUMPELEMENTS: inputselector1 uridecodebin1 decodebin0 amcvideodec-omxqcomvideodecoderavc1 capsfilter1 h264parse1 multiqueue1 qtdemux1 typefind source playsink vbin vconv conv2 videobalance scale conv identity vqueue glimagesinkbin0 sink glcolorconvertelement0 gluploadelement0 vdbin deinterlace vdconv streamsynchronizer0 The only difference is the presence of deinterlace in-between vdbin and vdconv.
That might be https://bugzilla.gnome.org/show_bug.cgi?id=720388 and https://bugzilla.gnome.org/show_bug.cgi?id=760553 then. Probably won't have time to look into this more today, but I've half-finished a patch for the deinterlace bugs.
I think that there is some progress if patches of 720388 are applied but it's still not working well. It seems to start really decoding: we might have successfully passed the deinterlace problem. But it's completely jerky with 1 frame every second and a lot of messages. Read log1-after-720388.txt
Created attachment 319803 [details] log #1 after applying 720388
Could you also enable deinterlace:6 in that debug log, additional to what you had before already?
Created attachment 319840 [details] log2 on nexu7-2013
Created attachment 319841 [details] log3 on nexus5x
log2 and log3 with setenv("GST_DEBUG", "*amc*:5,*deinterlace*:6", 1); Note the "DUMPELEMENTS", there is no deinterlace.
Ok, so your problem is something different now and completely independent from the deinterlace bug. What is the remaining problem now, what's your testcase? Just tutorial-5 (which changes?) with your sample file (local-25fps.mp4)?
Correct. I have an untouched tutorial-5 and I'm just trying to play a local file, aka local-25fps.mp4 on either Nexus5x or Nexus7-2013 running Android 6.0.1. All my video test files are in this small archive: http://www.gentil.comt/tmp/sdcard-gstreamer-1.7.1.zip (loc
There was a typo in my link: http://www.gentil.com/tmp/sdcard-gstreamer-1.7.1.zip
With the 720388 fix, on Nexus7-2013, there seems to remain 2 different problems: 1) I have 4 local files in my archive, 2 files work, 2 files don't. * local-25fps and local-50fps don't. There are the same h264 video. * reencode-50fps can play. It's just an avconv reencoding of local-50fps. * stream-21fps-audio can also play. It's a totally similar file than local-25fps but it's muxed differently - it's the exact same h264 video. 2) There is a hang or crash at the termination of a working video, such as reencode-50fps. This happens all the time. It seems a generic bug, not specific to my test case as long as hardware decoding is used. Even if you stop a working video, amc goes crazy in output message and if you want to select another file, it hangs. Not that the default streaming trailer of tutorial-5 doesn't leverage hardware decoding so it's not possible to test with tutorial-5 if you don't use a local file.
Thanks, luckily I also have a Nexus7-2013 here for testing. I'll try to find some time in the next days.
Created attachment 319873 [details] log working but hang at end for stream-25fps
Created attachment 319874 [details] log not working at all for local-25fps
Created attachment 319875 [details] Traces corresponding to log working but hang at end for stream-25fps
I have uploaded here some better and simpler test case videos: http://gentil.com/tmp/videos-test.zip I have provided logs: log working but hang at end for stream-25fps log not working at all for local-25fps Two problems: 1) two files (named local*) are not working while two files (named stream*) are working. For information, local* are generated with "ducatih264enc ! h264parse ! mp4mux ! filesink". stream* are generated with "ducatih264enc ! rtph264pay ! udpsink + udpsrc ! rtph264depay ! h264parse ! mp4mux ! filesink" 2) When a file can be played, there is a hang when exiting the playback as shown in traces.txt
2) The problem seems to occur in gst_amc_video_dec_on_frame_available which is called even when the video is not played any more. A mutex is unhappy about such call. A quick fix is to comment the call of native_onFrameAvailable in the Java part. Perhaps, I don't have the latest of gst-plugins-bad. I'm doing a full CLEAN recompilation.
1) It seems that my local* files are not monotonous. I get a warning if I'm trying to remux them on a PC. I tried different options (asc, dd) in mp4mux but they are failing the same way while playing in tutorial-5.
2) After a full clean recompilation, the problem is still there. I think that it's a generic bug, not specific to my case. Commenting native_onFrameAvailable in Java puts away the problem.
1) I have tried qtmux and also legacyh264parse for the creation of local* but it still doesn't play with tutorial-5. I have just realized that this specific file doesn't play with hardware acceleration on gstreamer-1.5 either :-( But it plays if avdec_h264 is used instead of hardware with any gstreamer version. Is there a problem with non-monotonous stream when hardware decoding is used? I still don't get it why I'm getting this non-monotonous stream with a very simple "ducati264enc ! h264parse ! mp4mux ! filesink" pipeline.
I can play local-25.fps in the photo application and it seems to use hardware acceleration: --------- beginning of main 01-28 01:41:00.625 6692 7069 D skia : --- SkImageDecoder::Factory returned null 01-28 01:41:00.626 6692 7069 D skia : --- SkImageDecoder::Factory returned null 01-28 01:41:00.632 6692 7071 D skia : --- SkImageDecoder::Factory returned null 01-28 01:41:00.632 6692 7071 D skia : --- SkImageDecoder::Factory returned null 01-28 01:41:00.654 1177 1177 I Keyboard.Facilitator: onFinishInput() 01-28 01:41:00.698 195 8818 D NuPlayer: onSetVideoSurface(0xb2c9b700, no video decoder) 01-28 01:41:00.736 195 8818 D NuPlayerDriver: notifyListener_l(0xb37335a0), (5, 1280, 1440) 01-28 01:41:00.736 195 8818 D NuPlayerDriver: notifyListener_l(0xb37335a0), (1, 0, 0) 01-28 01:41:00.761 6692 7053 D OpenGLRenderer: endAllStagingAnimators on 0x994a8900 (RippleDrawable) with handle 0x97e5ba90 01-28 01:41:00.766 6692 6692 W Glide : Load failed for LocalMediaModel{signature=-205777858, localUri=content://media/external/video/media/747} with size [50x50] 01-28 01:41:00.766 6692 6692 W Glide : class aiw: Failed to load resource 01-28 01:41:00.766 6692 6692 W Glide : Cause (1 of 2): class aiw: Failed LoadPath{AutoCloseInputStream->Bitmap->Bitmap}, LOCAL 01-28 01:41:00.766 6692 6692 W Glide : Cause (1 of 1): class aiw: Failed DecodePath{AutoCloseInputStream->Bitmap->Bitmap} 01-28 01:41:00.766 6692 6692 W Glide : Cause (2 of 2): class aiw: Failed LoadPath{ParcelFileDescriptorInner->Bitmap->Bitmap}, LOCAL 01-28 01:41:00.766 6692 6692 W Glide : Cause (1 of 1): class aiw: Failed DecodePath{ParcelFileDescriptorInner->Bitmap->Bitmap} 01-28 01:41:00.766 6692 6692 E Glide : class aiw: Failed to load resource 01-28 01:41:00.769 6692 6692 W Glide : Load failed for LocalMediaModel{signature=-205777858, localUri=content://media/external/video/media/747} with size [313x313] 01-28 01:41:00.769 6692 6692 W Glide : class aiw: Failed to load resource 01-28 01:41:00.769 6692 6692 W Glide : Cause (1 of 2): class aiw: Failed LoadPath{AutoCloseInputStream->Bitmap->Bitmap}, LOCAL 01-28 01:41:00.769 6692 6692 W Glide : Cause (1 of 1): class aiw: Failed DecodePath{AutoCloseInputStream->Bitmap->Bitmap} 01-28 01:41:00.769 6692 6692 W Glide : Cause (2 of 2): class aiw: Failed LoadPath{ParcelFileDescriptorInner->Bitmap->Bitmap}, LOCAL 01-28 01:41:00.769 6692 6692 W Glide : Cause (1 of 1): class aiw: Failed DecodePath{ParcelFileDescriptorInner->Bitmap->Bitmap} 01-28 01:41:00.769 6692 6692 E Glide : class aiw: Failed to load resource 01-28 01:41:00.770 6692 6692 D MediaPlayer: setSubtitleAnchor in MediaPlayer 01-28 01:41:00.772 195 6499 D NuPlayerDriver: seekTo(0xb37335a0) 5713 ms 01-28 01:41:00.772 195 6499 D NuPlayerDriver: notifyListener_l(0xb37335a0), (7, 0, 0) 01-28 01:41:00.773 195 8818 I GenericSource: start 01-28 01:41:00.780 195 8818 D NuPlayerDriver: notifyListener_l(0xb37335a0), (4, 0, 0) 01-28 01:41:00.805 195 8824 I MediaCodec: [OMX.qcom.video.decoder.avc] setting surface generation to 199691 01-28 01:41:00.806 195 8825 E OMX-VDEC-1080P: Extension: OMX.google.android.index.storeANWBufferInMetadata not implemented 01-28 01:41:00.806 195 8825 E OMX-VDEC-1080P: Extension: OMX.google.android.index.storeMetaDataInBuffers not implemented 01-28 01:41:00.806 195 8825 E OMXNodeInstance: getExtensionIndex(13f:qcom.decoder.avc, OMX.google.android.index.storeMetaDataInBuffers) ERROR: NotImplemented(0x80001006) 01-28 01:41:00.806 195 8825 E ACodec : [OMX.qcom.video.decoder.avc] storeMetaDataInBuffers failed w/ err -2147483648 01-28 01:41:00.806 195 8825 E OMX-VDEC-1080P: 01-28 01:41:00.806 195 8825 E OMX-VDEC-1080P: No color conversion required 01-28 01:41:00.806 195 8825 E OMX-VDEC-1080P: 01-28 01:41:00.806 195 8825 E OMX-VDEC-1080P: No color conversion required 01-28 01:41:00.806 195 8825 E OMX-VDEC-1080P: 01-28 01:41:00.806 195 8825 E OMX-VDEC-1080P: No color conversion required 01-28 01:41:00.806 195 8825 E OMX-VDEC-1080P: 01-28 01:41:00.806 195 8825 E OMX-VDEC-1080P: No color conversion required 01-28 01:41:00.806 195 8825 E OMXNodeInstance: setConfig(13f:qcom.decoder.avc, ConfigPriority(0x6f800002)) ERROR: NotImplemented(0x80001006) 01-28 01:41:00.806 195 8825 I ACodec : codec does not support config priority (err -2147483648) 01-28 01:41:00.806 195 8825 E OMXNodeInstance: setConfig(13f:qcom.decoder.avc, ConfigOperatingRate(0x6f800003)) ERROR: NotImplemented(0x80001006) 01-28 01:41:00.806 195 8825 I ACodec : codec does not support config operating rate (err -2147483648) 01-28 01:41:00.806 195 8825 E OMX-VDEC-1080P: 01-28 01:41:00.806 195 8825 E OMX-VDEC-1080P: No color conversion required 01-28 01:41:00.807 195 8824 I MediaCodec: MediaCodec will operate in async mode 01-28 01:41:00.809 195 8825 E OMX-VDEC-1080P: 01-28 01:41:00.809 195 8825 E OMX-VDEC-1080P: No color conversion required 01-28 01:41:00.809 195 8825 E OMX-VDEC-1080P: 01-28 01:41:00.809 195 8825 E OMX-VDEC-1080P: No color conversion required 01-28 01:41:00.809 195 8825 D SurfaceUtils: set up nativeWindow 0xb2c9b708 for 1280x1440, color 0x7fa30c03, rotation 0, usage 0x42002900 01-28 01:41:00.809 195 8825 E OMX-VDEC-1080P: 01-28 01:41:00.809 195 8825 E OMX-VDEC-1080P: No color conversion required 01-28 01:41:00.809 195 8825 E OMX-VDEC-1080P: 01-28 01:41:00.809 195 8825 E OMX-VDEC-1080P: No color conversion required 01-28 01:41:00.816 195 8825 E OMX-VDEC-1080P: 01-28 01:41:00.816 195 8825 E OMX-VDEC-1080P: No color conversion required 01-28 01:41:00.816 195 8825 E OMX-VDEC-1080P: GET_MV_BUFFER_SIZE returned: Size: 491520 and alignment: 8192 01-28 01:41:00.831 195 8825 E OMX-VDEC-1080P: 01-28 01:41:00.831 195 8825 E OMX-VDEC-1080P: No color conversion required 01-28 01:41:00.841 195 8825 E OMX-VDEC-1080P: 01-28 01:41:00.841 195 8825 E OMX-VDEC-1080P: No color conversion required 01-28 01:41:00.851 195 8825 E OMX-VDEC-1080P: 01-28 01:41:00.851 195 8825 E OMX-VDEC-1080P: No color conversion required 01-28 01:41:00.860 195 8825 E OMX-VDEC-1080P: 01-28 01:41:00.860 195 8825 E OMX-VDEC-1080P: No color conversion required 01-28 01:41:00.869 195 8825 E OMX-VDEC-1080P: 01-28 01:41:00.869 195 8825 E OMX-VDEC-1080P: No color conversion required 01-28 01:41:00.876 195 8825 E OMX-VDEC-1080P: 01-28 01:41:00.876 195 8825 E OMX-VDEC-1080P: No color conversion required 01-28 01:41:00.882 195 8825 E OMX-VDEC-1080P: 01-28 01:41:00.882 195 8825 E OMX-VDEC-1080P: No color conversion required 01-28 01:41:00.889 195 8825 E OMX-VDEC-1080P: 01-28 01:41:00.889 195 8825 E OMX-VDEC-1080P: No color conversion required 01-28 01:41:00.897 195 8825 E OMX-VDEC-1080P: 01-28 01:41:00.897 195 8825 E OMX-VDEC-1080P: No color conversion required 01-28 01:41:00.904 195 8825 E OMX-VDEC-1080P: 01-28 01:41:00.904 195 8825 E OMX-VDEC-1080P: No color conversion required 01-28 01:41:00.962 188 188 W SurfaceFlinger: couldn't log to binary event log: overflow. 01-28 01:41:01.064 195 8826 E OMX-VDEC-1080P: 01-28 01:41:01.064 195 8826 E OMX-VDEC-1080P: No color conversion required 01-28 01:41:01.065 195 8825 E OMX-VDEC-1080P: 01-28 01:41:01.065 195 8825 E OMX-VDEC-1080P: No color conversion required 01-28 01:41:01.065 195 8825 E OMX-VDEC-1080P: 01-28 01:41:01.065 195 8825 E OMX-VDEC-1080P: No color conversion required 01-28 01:41:01.065 195 8825 D SurfaceUtils: set up nativeWindow 0xb2c9b708 for 1280x1440, color 0x7fa30c03, rotation 0, usage 0x42002900 01-28 01:41:01.065 195 8825 E OMX-VDEC-1080P: 01-28 01:41:01.065 195 8825 E OMX-VDEC-1080P: No color conversion required 01-28 01:41:01.065 195 8825 E OMX-VDEC-1080P: 01-28 01:41:01.065 195 8825 E OMX-VDEC-1080P: No color conversion required 01-28 01:41:01.087 195 8825 E OMX-VDEC-1080P: 01-28 01:41:01.087 195 8825 E OMX-VDEC-1080P: No color conversion required 01-28 01:41:01.087 195 8825 E OMX-VDEC-1080P: GET_MV_BUFFER_SIZE returned: Size: 491520 and alignment: 8192 01-28 01:41:01.097 195 8825 E OMX-VDEC-1080P: 01-28 01:41:01.097 195 8825 E OMX-VDEC-1080P: No color conversion required 01-28 01:41:01.106 195 8825 E OMX-VDEC-1080P: 01-28 01:41:01.106 195 8825 E OMX-VDEC-1080P: No color conversion required 01-28 01:41:01.113 195 8825 E OMX-VDEC-1080P: 01-28 01:41:01.113 195 8825 E OMX-VDEC-1080P: No color conversion required 01-28 01:41:01.119 195 8825 E OMX-VDEC-1080P: 01-28 01:41:01.119 195 8825 E OMX-VDEC-1080P: No color conversion required 01-28 01:41:01.126 195 8825 E OMX-VDEC-1080P: 01-28 01:41:01.126 195 8825 E OMX-VDEC-1080P: No color conversion required 01-28 01:41:01.133 195 8825 E OMX-VDEC-1080P: 01-28 01:41:01.133 195 8825 E OMX-VDEC-1080P: No color conversion required 01-28 01:41:01.140 195 8825 E OMX-VDEC-1080P: 01-28 01:41:01.140 195 8825 E OMX-VDEC-1080P: No color conversion required 01-28 01:41:01.155 195 8825 E OMX-VDEC-1080P: 01-28 01:41:01.155 195 8825 E OMX-VDEC-1080P: No color conversion required 01-28 01:41:01.169 195 8825 E OMX-VDEC-1080P: 01-28 01:41:01.169 195 8825 E OMX-VDEC-1080P: No color conversion required 01-28 01:41:01.182 195 8825 E OMX-VDEC-1080P: 01-28 01:41:01.182 195 8825 E OMX-VDEC-1080P: No color conversion required 01-28 01:41:01.191 195 8826 E : 01-28 01:41:01.191 195 8826 E : not in avi mode 01-28 01:41:01.233 195 8825 E OMX-VDEC-1080P: 01-28 01:41:01.233 195 8825 E OMX-VDEC-1080P: No color conversion required 01-28 01:41:01.234 195 8818 D NuPlayerDriver: notifyListener_l(0xb37335a0), (5, 1280, 1440) 01-28 01:41:03.858 635 646 I MediaFocusControl: AudioFocus requestAudioFocus() from android.media.AudioManager@58c8eajde@f5d2b89 req=1flags=0x0 01-28 01:41:03.860 195 6499 D NuPlayerDriver: start(0xb37335a0), state is 4, eos is 0 01-28 01:41:03.863 195 8823 I NuPlayerDecoder: [OMX.qcom.video.decoder.avc] resubmitting CSD 01-28 01:41:03.863 195 8823 I NuPlayerDecoder: [OMX.qcom.video.decoder.avc] resubmitting CSD 01-28 01:41:03.864 195 8826 E : 01-28 01:41:03.864 195 8826 E : not in avi mode 01-28 01:41:03.865 195 8826 E : 01-28 01:41:03.865 195 8826 E : not in avi mode 01-28 01:41:03.906 195 8818 D NuPlayerDriver: notifyListener_l(0xb37335a0), (200, 3, 0) 01-28 01:41:03.906 195 8818 D NuPlayerDriver: notifyListener_l(0xb37335a0), (6, 0, 0) 01-28 01:41:03.906 6692 6703 W MediaPlayer: info/warning (3, 0) 01-28 01:41:05.439 195 8823 I NuPlayerDecoder: [video] saw output EOS 01-28 01:41:05.652 195 8818 D NuPlayerDriver: notifyListener_l(0xb37335a0), (2, 0, 0) 01-28 01:41:05.653 635 1295 I MediaFocusControl: AudioFocus requestAudioFocus() from android.media.AudioManager@58c8eajde@f5d2b89 req=1flags=0x0 01-28 01:41:05.655 195 6499 D NuPlayerDriver: start(0xb37335a0), state is 6, eos is 1 01-28 01:41:05.663 195 8823 I NuPlayerDecoder: [OMX.qcom.video.decoder.avc] resubmitting CSD 01-28 01:41:05.663 195 8823 I NuPlayerDecoder: [OMX.qcom.video.decoder.avc] resubmitting CSD 01-28 01:41:05.664 195 8826 E : 01-28 01:41:05.664 195 8826 E : not in avi mode 01-28 01:41:05.666 195 8826 E : 01-28 01:41:05.666 195 8826 E : not in avi mode 01-28 01:41:05.709 195 8818 D NuPlayerDriver: notifyListener_l(0xb37335a0), (6, 0, 0) 01-28 01:41:11.751 195 669 D NuPlayerDriver: notifyListener_l(0xb37335a0), (7, 0, 0) 01-28 01:41:11.753 635 1278 I MediaFocusControl: AudioFocus abandonAudioFocus() from android.media.AudioManager@58c8eajde@f5d2b89
Might be related to B-Frames and timestamp bugs in older version of GStreamer ? Do you still get this issue without B-Frame (e.g. constrained-baseline profile) ?
Thanks for the idea. No, that doesn't seem to be a fix. :-(
Nicolas: is it you this? https://bugs.launchpad.net/ubuntu-omap4-extras-multimedia/+bug/1180378 The patch is applied on my build. I have tried to revert it but it's the same problem. When I inspect my videos on a PC and use avconv, I only get one warning message for all my files: Non-monotonous DTS in output stream 0:0; previous: 167, current: 167; changing to 168. This may result in incorrect timestamps in the output file. The number varies but it's always previous=current. I'm wondering if I could fix and add a +1 somewhere in gstducatividdec.c It would still be better to fix gstreamer during playback for hardware acceleration for non monotonous video as I can play the file with libav and it also plays with hardware acceleration in the photo app.
Forget that last comment. Your problem was for decoding!
Yeah we should fix amcviddec here too. I hope to have some time later today to try reproducing your problem with my Nexus 7 and your video file.
These patches fix the hang and a crash for me and may even fix your streams not playing. Could you test again with the latest master? commit b276de78275b61481384b1edc532a7ebe69079f5 Author: Matthew Waters <matthew@centricular.com> Date: Fri Jan 29 23:28:59 2016 +1100 amcvideodec: guard against not finding a valid frame in loop Fixes sporadic crashes on finishing decoding a video. https://bugzilla.gnome.org/show_bug.cgi?id=761014 commit 1fceac8122293bc33778efc5419f639f8135a02f Author: Matthew Waters <matthew@centricular.com> Date: Fri Jan 29 15:24:36 2016 +1100 amcvideodec: set our data pointer in java to NULL on close The frame available callback can be called after deconfiguring the amc codec. Guard against this by setting the back pointer to NULL on close() and ignoring any NULL data pointer. https://bugzilla.gnome.org/show_bug.cgi?id=761014
(In reply to Gregoire from comment #33) > Nicolas: is it you this? > https://bugs.launchpad.net/ubuntu-omap4-extras-multimedia/+bug/1180378 No, this was not me. I never worked with an OMAP4.
2) Definitely fixed with Waters' commits. I think it was a generic bug affecting everybody. Thanks. 1) Problem is still there. Playback is completely flaky with hardware acceleration for my test files local-*. I don't know if I'm missing anything more. The files local-* plays fine in the native Android photo application.
1) I manage to play my local-* files with a simple MediaCodec java application such as https://github.com/vecio/MediaCodecDemo/blob/master/src/io/vec/demo/mediacodec/DecodeActivity.java. So it's not a hardware problem.
We should clearly fix that before 1.8 then.
For reference and benchmark, here is a small pure Java Android MediaCodec application that can playback any video including my 4 samples: http://gentil.com/tmp/aiMediaCodec.apk Main code source is attached for reference.
Created attachment 320088 [details] Pure Java Android MediaCodec example (benchmark use)
Something's off with the timestamps here: "Frame is too late, dropping (deadline -0:00:32.883610094)" It's also not hardware acceleration specific. Running with the following pipeline: playbin video-sink="capsfilter caps=video/x-raw ! glimagesink" also fails in the same way.
With a slow GPU here I get the same, it's jerky with glimagesink, but fine with xvimagesink. It looks like a regression to me. I fixed this kind of issue in glimagesink (before the split glupload was added) by making sure every uploaded buffer get displayed (prevent drop between prepare() and show_frame()). Otherwise, if the time it takes to upload a frame is larger then the duration of this frame, we would endup with 1 frame per second on screen. Though, moving on with a split glupload, we'll get the same behaviour again. If glupload takes more time then the duration of 1 frame, and the input is live, frames get dropped in the sink before prepare(). For playback case, QoS mechanism should be able to fix that, though for live, QoS will have no impact unless you increase the latency.
(a way to demonstrate, and to check it's the same issue, is to increase max-lateness property on the sink)
It's not a slow GPU issue, my phone can do 4x1080p decode+render without breaking a sweat.
(if you get direct texture rendering, but on comment 43 you had removed the HW acceleration using a caps filter)
It's something unique to tutorial-5. Running the video with a different GStreamer app works flwalessly. Profiling the java side, I see that every 250ms, 100ms of CPU time is taken up by updating the position/slider which is an awful waste of CPU. One can probably reproduce my results by using and changing the pipeline in tutorial-3.
Also, combining prepare() and render() will not help as the buffers are dropped as late before prepare() is even called.
Following comment 48, how do you explain that it's working perfectly fine with gstreamer 1.5 libraries? I have provided a compiled version in the first comment on this page. The problem gets worse if there is more data to decode (50fps vs. 25fps) and if it's a slow device (nexus 7 2013 vs. nexus 5x). But in all cases (any file, any device), there are always warnings "frame is too late". The numbers of warnings and the impact on the visual rendering gets worse to the point local-50fps.mp4 doesn't play on Nexus 7 2013 while it plays perfectly fine with gstreamer 1.5 or with the pure java mediacodec application I also provided. Also, I have just commented the progress bar in tutorial-5 and the problem is still there for me. So perhaps, if you try to strip everything in the code and you also take an octo-core A57 64bit that you overclock to 3GHz with the fastest GPU you can find, you might be able to play the files "correctly", aka. visually speaking. But I think that it's hiding the dirt under the carpet.
1. Hardware decoding was only ever introduced recently into 1.7 which complicates things. One of which is that in order to know a frame has been decoded, we listen to a callback which currently passes through the main thread and if that thread is blocked, stalls occur, removing the position slider, removes that bottleneck. 2. GStreamer 1.5 (into 1.6) was over a year long effort and many changes were made to various elements/libraries so it's very imprecise as to what state your 1.5 application is in. Another interesting point, there are constant caps queries occurring throughout the entire failing video taking a significant amount of time that doesn't seem to occur with the the re-encoded videos.
1. Hardware decoding was working with Gstreamer 1.5 on Android 5.x (at least Nexus 7 2013). Only Android 6.x required gstreamer 1.7 for hardware decoding. You can try the tutorial-5_gstreamer-5 application I uploaded and read the log to check. I have reported this current problem in 1.7 at least since last November 2015 on the mailing list. It's not a problem that has been introduced in a very recent commit. My purpose of the compilation of tutorial-5 against 1.5 was to show that hardware decoding has worked WELL with gstreamer. That being said, it was a very long time ago and way before the new architecture of zero memcpy. I have never seen a smooth playback on 1.7 compared to what I can see on 1.5. The position slider is the wrong discussion as I was try to explain in the last paragraph of comment 50. In a more complex application I have, which runs Android very busy, I see a lot of video hiccups with 1.7 while 1.5 is completely smooth. This happens even on a super fast Nexus 5x. I don't know if your thread explanation is the real problem. It certainly does make sense with what I see. That would sound more like an architecture problem than just a bug.
And those caps queries are from h264parse finding SPS parameters on every frame which seems like a bit of overkill.
Which seems to occur when h264parse is converting from avc to byte-stream format. The following pipeline reproduces the constant caps queries with the local-* files and the fixed number of queries with the reencoded-* and stream-* files. filesrc location=/path/to/file ! qtdemux ! h264parse ! video/x-h264,stream-format=byte-stream ! fakesink -v libav doesn't exhibit this because it can take avc directly.
I still think that we are facing two different issues here: -A) my files local-*.mp4 have some weirdness though they play totally fine in gstreamer 1.5 or in the mediacodec application I provided. -B) those warnings resulting from glupload_delay / thread_architecture_problem / whatever are handicapping playback Thanks for helping on A). Those files are generated with ducatih264enc (gstreamer-0.10) on an OMAP4 board. Though this code is public, I feel bad the community is fixing this problem because it concerns a small population (like almost only myself...) I will re-read the code under the light of your comment 54, try to understand which plugin is the root of this problem (ducatih264enc or h264parse) and see if I can put the local files in the same state as the files stream-*.mp4 I still think that the main problem and the purpose of this bug is B). There is a real issue to the point that it can prevent from playing back videos.
I know Matthew will hate me now, but can you try turning on "qos" property on glupload. For some reason it's turned off by default.
Is comment 56 for me? Can you suggest the pipeline in tutorial-5? playbin videosink=????
Just to make sure that I'm not crazy and I'm not wasting the time of the community, I have tested again stream-*.mp4 on Nexus 7 2013, without any progress bar. The main thread doesn't do anything fancy. It's super jerky with a lot of warning messages - more messages for the 50fps file to the point it can't play. The exact same files play without any problem with my mediacodec application. Problem B) of comment 55 is real... Which doesn't mean that I don't have a separate problem for the files local-*.mp4, aka problem A) and as reported in comment 54. If anyone has a h264 video file and an Android Gstreamer-1.7.2 application that can be played very smoothly with hardware acceleration and without any warning message at all, please share.
Try the .mov files from here http://download.blender.org/peach/bigbuckbunny_movies/
big_buck_bunny_1080p_h264.mov plays "smoothly", visually speaking, but I get hundreds of: 02-03 16:50:07.955: W/GStreamer+amcvideodec(2460): 0:14:32.177246095 0xa0b3c0f0 gstamcvideodec.c:1139:_amc_gl_wait gl_sync 0xa0239690 could not wait for frame, took too long Those exact same messages on stream-50fps.mp4 (I'm not talking about problem A)) make the video unplayable.
Those messages are because the mediacodec api and implementation is extremely suboptimal and means we're essentially performing time-based waits for the next frame as we don't receive a listener callback (for some reason, could honestly be anything causing this). The wait is capped at 30ms after the release of the buffer which plus some processing time gives approximately 30fps which is the recommended encoding framerate according to http://developer.android.com/guide/appendix/media-formats.html. After rendering, the next frame is released in an attempt to keep the rendering smooth. If you're attempting to play a 50fps video and you keep missing listerners, the video will degrade. Combined with the caps processing overhead (between 50-80ms here) as above taking multiple frames, you have a recipe for disaster performance wise. On my phone I never get a frame listener miss with stream-* (the "could not wait" message) however I do with the local-* files (presumably due to the redundant caps processing). You can add more debugging of the listener with *amc*:7 which will tell you what happened and when with regards to the listener. To get the 1.5 behaviour of amcvideocodec, you need to perform the capsfilter pipeline above (playbin video-sink="capsfilter caps=video/x-raw ! glimagesink") which removes the zerocopy path from the decoder and all these waits will disappear. However, you're bottleneck is now probably the texture uploads to glimagesink.
commit 9efdfb1a29b4e5716c46e1f53acb1ebc605b952b Author: Matthew Waters <matthew@centricular.com> Date: Thu Feb 4 15:11:15 2016 +1100 amcvideodec: pass the correct time value to wait_for_sync When we are not waiting, we need to pass -1 to signal that we just want to check that the frame was/n't rendered. Avoids waiting for frames that will never be rendered. https://bugzilla.gnome.org/show_bug.cgi?id=761014 commit 3c29dcaddb0996eac5389adeb9214e03e3593058 Author: Matthew Waters <matthew@centricular.com> Date: Thu Feb 4 15:07:44 2016 +1100 amcvideodec: advance the ready counter ourselves when render=FALSE When not rendering the video frame, e.g. when freeing an unreleased sync frame, we will not receive a frame listener callback. Reduces the amount of 'on_frame_available miss detected' messages when dropping frames. https://bugzilla.gnome.org/show_bug.cgi?id=761014
Created attachment 320402 [details] [review] amcvideodec: use the default accept-caps implementation This removes the double caps query on accept-caps (from videodecoder) and caps query from h264parse every frame.
Created attachment 320403 [details] [review] h264parse: try the current caps before querying downstream This removes the redundant downstream caps queries for caps that end up the same on duplicate SPS/PPS.
Review of attachment 320402 [details] [review]: ::: sys/androidmedia/gstamcvideodec.c @@ +421,3 @@ gst_video_decoder_set_needs_format (GST_VIDEO_DECODER (self), TRUE); + gst_video_decoder_set_use_default_pad_acceptcaps (GST_VIDEO_DECODER (self), + TRUE); The default one will always do a CAPS query downstream. The non-default one will first check against the template, and only do a caps query downstream if the caps are compatible with the template. It might make sense to add a accept_caps vfunc to videodecoder, which will then only check against the caps supported by this very element... without doing any downstream caps queries at all.
Review of attachment 320403 [details] [review]: Makes sense
Review of attachment 320402 [details] [review]: ::: sys/androidmedia/gstamcvideodec.c @@ +421,3 @@ gst_video_decoder_set_needs_format (GST_VIDEO_DECODER (self), TRUE); + gst_video_decoder_set_use_default_pad_acceptcaps (GST_VIDEO_DECODER (self), + TRUE); And with that I mean, this change shouldn't make much of a difference as you will still do downstream caps queries... what will make a difference is adding some accept_caps vfunc.
Created attachment 320408 [details] [review] hs64parse: increase caps equality check for no codec_data And this makes local-50fps.mp4 work for me.
commit 72bc7d7f736a10117fedb8e1d4013a4946cfefbc Author: Matthew Waters <matthew@centricular.com> Date: Thu Feb 4 16:36:28 2016 +1100 h264parse: increase caps equality check for no codec_data When converting from avc to byte-stream, there will not be any codec_data in the src caps. Remove it before the equality check to avoid sending caps events downstream on every SPS/PPS change. https://bugzilla.gnome.org/show_bug.cgi?id=761014 commit f352691a04896d0de3381fe8ee85ada948bd6337 Author: Matthew Waters <matthew@centricular.com> Date: Thu Feb 4 15:34:04 2016 +1100 h264parse: try the current caps before querying downstream If we have a stream that contains an unchanging SPS/PPS for every video frame, we don't need to to constantly query downstream for it's supported caps if the current caps are compatible with the negotiated caps. https://bugzilla.gnome.org/show_bug.cgi?id=761014
Comment on attachment 320402 [details] [review] amcvideodec: use the default accept-caps implementation Let's skip this one then :)
You will want to apply the same changes to h265parse btw :) Keep them in sync What else is missing here now?
commit 2a49811721fca9d412fc73d3544f687efba56f56 Author: Matthew Waters <matthew@centricular.com> Date: Thu Feb 4 18:15:56 2016 +1100 h265parse: avoid sending unnecessary downstream caps queries/events h265 versions of the following commits: f352691a04896d0de3381fe8ee85ada948bd6337 try the current caps before querying downstream 72bc7d7f736a10117fedb8e1d4013a4946cfefbc increase caps equality check for no codec_data https://bugzilla.gnome.org/show_bug.cgi?id=761014
(In reply to Sebastian Dröge (slomo) from comment #71) > What else is missing here now? I think h264parse is sane enough now that all the files work. @Gregoire: if you have any other issues with the decoding performance please open another bug (or clone this one).
First, thanks for all your efforts. I don't want to open a new bug. With the latest commits, *-25fps work well visually speaking though there are still warnings. *-50fps are better but still jerky even on my Nexus 5x. If I change 30ms to 20ms in gstamcvideodec.c, *-50fps start to be better and acceptable visually speaking. Matthew, you said in comment 68 that local-50fps works for you (at 30ms in the code). Which hardware are you running? I'm a little bit confused how it could run as 50fps is 20ms... What's the impact of putting 20ms instead of 30ms?
LG G3. It takes roughly 3ms after release for the listener to fire here. If you're not getting any listener callbacks for any frame, then you need to talk to your hardware/software provider for your decoder. The 30ms is a backup for when the listener is not called at all. Ideally that should never occur but it does so we need to account for it. If you have an issue with the current code, please open a new bug. This is not a support forum.
local-50fps is working at 50fps without a problem on Nexus 7 2013 Android 6.0.1! I had native_onFrameAvailable commented out as mentioned in comment 28. Thanks again for the fixes.