Android video transcoding: end of stream (eos) frames not flushing from hardware encoder (amcvidenc-omxsecavcenc)

Tue Feb 25 03:52:04 PST 2014

Hello,

Below is my video transcoding pipeline.This pipeline uses h/w encoder and decoder from Samsung S3 device. I'm able to build and run this pipeline without any error,however number frames of output/transcod file not matching with input/original file. I mean input file has 670 frames approximately 22 seconds of video after transcoding output file has 558 frames.I done comparison of both streams and found encoder not flushing the frames once eos event posted on bus. I'm sure this is not frame drop issue but issue with flushing frames from encoder element. Input video encoded with 30fps and transcod video file encoded with 25 fps. 
Thanks,
-Umashankar

gst_parse_launch("filesrc location=/mnt/sdcard/Test_case_1280x720_22sec.mp4 ! qtdemux name=demux demux.audio_0 ! queue  max-size-time=5000000000    ! audio/mpeg,mpegversion=4 ! mp4mux name=mux ! filesink location=/mnt/sdcard/transcode.mp4  demux.video_0 !  h264parse !  amcviddec-omxsecavcdec ! queue ! videoparse format=nv12 width=1280 height=720 ! amcvidenc-omxsecavcenc bitrate=12000000 i-frame-interval=20 ! video/x-h264,profile=high ! queue max-size-time=5000000000 ! h264parse ! mux.video_0",&error);

Please find below adb logcat messages. Here I can see gstamc.c:416:gst_amc_codec_flush Failed to call Java method message also "Stopping encoder" and "Closing encoder"message and no flush message from encoder  

D/GStreamer+bin(14891): 0:23:41.689500804 0x59615f60 gstbin.c:2322:gst_bin_element_set_state:<pipeline1> setting element amcvideoenc-omxsecavcenc1 to NULL, base_time 0:00:00.000000000
D/GStreamer+GST_STATES(14891): 0:23:41.689604346 0x59615f60 gstelement.c:2479:gst_element_set_state_func:<amcvideoenc-omxsecavcenc1> set_state to NULL
D/GStreamer+GST_STATES(14891): 0:23:41.689710387 0x59615f60 gstelement.c:2504:gst_element_set_state_func:<amcvideoenc-omxsecavcenc1> setting target state to NULL
D/GStreamer+GST_STATES(14891): 0:23:41.689823637 0x59615f60 gstelement.c:2517:gst_element_set_state_func:<amcvideoenc-omxsecavcenc1> current PAUSED, old_pending VOID_PENDING, next VOID_PENDING, old return SUCCESS
D/GStreamer+GST_STATES(14891): 0:23:41.689934179 0x59615f60 gstelement.c:2551:gst_element_set_state_func:<amcvideoenc-omxsecavcenc1> intermediate: setting state from PAUSED to READY
E/GStreamer+amc(14891): 0:23:41.690272512 0x59615f60 gstamc.c:416:gst_amc_codec_flush Failed to call Java method
V/GStreamer+GST_STATES(14891): 0:23:41.690392762 0x59615f60 gstelement.c:2797:gst_element_change_state_func:<amcvideoenc-omxsecavcenc1> default handler tries setting state from PAUSED to READY (001a)
D/GStreamer+GST_ELEMENT_PADS(14891): 0:23:41.690502762 0x59615f60 gstelement.c:2740:gst_element_pads_activate:<amcvideoenc-omxsecavcenc1> deactivate pads
V/GStreamer+GST_REFCOUNTING(14891): 0:23:41.690628929 0x59615f60 gstobject.c:256:gst_object_ref:<amcvideoenc-omxsecavcenc1> 0x5a454170 ref 3->4
D/GStreamer+GST_PADS(14891): 0:23:41.690740804 0x59615f60 gstpad.c:971:gst_pad_set_active:<amcvideoenc-omxsecavcenc1:src> deactivating pad from push mode
V/GStreamer+GST_REFCOUNTING(14891): 0:23:41.690856054 0x59615f60 gstobject.c:256:gst_object_ref:<amcvideoenc-omxsecavcenc1> 0x5a454170 ref 4->5
D/GStreamer+GST_PADS(14891): 0:23:41.690965346 0x59615f60 gstpad.c:864:pre_activate:<amcvideoenc-omxsecavcenc1:src> setting PAD_MODE NONE, set flushing
D/GStreamer+GST_PADS(14891): 0:23:41.691083304 0x59615f60 gstpad.c:910:post_activate:<amcvideoenc-omxsecavcenc1:src> stopped streaming
D/GStreamer+GST_PADS(14891): 0:23:41.691199554 0x59615f60 gstpad.c:1096:gst_pad_activate_mode:<amcvideoenc-omxsecavcenc1:src> deactivated in push mode
V/GStreamer+GST_REFCOUNTING(14891): 0:23:41.691314804 0x59615f60 gstobject.c:282:gst_object_unref:<amcvideoenc-omxsecavcenc1> 0x5a454170 unref 5->4
V/GStreamer+GST_REFCOUNTING(14891): 0:23:41.691428721 0x59615f60 gstobject.c:282:gst_object_unref:<amcvideoenc-omxsecavcenc1> 0x5a454170 unref 4->3
V/GStreamer+GST_REFCOUNTING(14891): 0:23:41.691554512 0x59615f60 gstobject.c:256:gst_object_ref:<amcvideoenc-omxsecavcenc1> 0x5a454170 ref 3->4
D/GStreamer+GST_PADS(14891): 0:23:41.691667221 0x59615f60 gstpad.c:971:gst_pad_set_active:<amcvideoenc-omxsecavcenc1:sink> deactivating pad from push mode
V/GStreamer+GST_REFCOUNTING(14891): 0:23:41.691782346 0x59615f60 gstobject.c:256:gst_object_ref:<amcvideoenc-omxsecavcenc1> 0x5a454170 ref 4->5
D/GStreamer+GST_PADS(14891): 0:23:41.691890512 0x59615f60 gstpad.c:864:pre_activate:<amcvideoenc-omxsecavcenc1:sink> setting PAD_MODE NONE, set flushing
D/GStreamer+GST_PADS(14891): 0:23:41.692004387 0x59615f60 gstpad.c:910:post_activate:<amcvideoenc-omxsecavcenc1:sink> stopped streaming
V/GStreamer+GST_REFCOUNTING(14891): 0:23:41.692113012 0x59615f60 gstminiobject.c:440:gst_mini_object_unref 0x5984fb18 unref 11->10
D/GStreamer+GST_PADS(14891): 0:23:41.692211221 0x59615f60 gstpad.c:384:remove_events:<amcvideoenc-omxsecavcenc1:sink> notify caps
V/GStreamer+GST_REFCOUNTING(14891): 0:23:41.692345970 0x59615f60 gstobject.c:256:gst_object_ref:<amcvideoenc-omxsecavcenc1> 0x5a454170 ref 5->6
V/GStreamer+GST_PROPERTIES(14891): 0:23:41.692463012 0x59615f60 gstobject.c:465:gst_object_dispatch_properties_changed:<amcvideoenc-omxsecavcenc1> deep notification from sink (caps)
V/GStreamer+GST_REFCOUNTING(14891): 0:23:41.692580345 0x59615f60 gstobject.c:256:gst_object_ref:<pipeline1> 0x595880e8 ref 2->3
V/GStreamer+GST_REFCOUNTING(14891): 0:23:41.692691137 0x59615f60 gstobject.c:282:gst_object_unref:<amcvideoenc-omxsecavcenc1> 0x5a454170 unref 6->5
V/GStreamer+GST_PROPERTIES(14891): 0:23:41.692800512 0x59615f60 gstobject.c:465:gst_object_dispatch_properties_changed:<pipeline1> deep notification from sink (caps)
V/GStreamer+GST_REFCOUNTING(14891): 0:23:41.692912137 0x59615f60 gstobject.c:282:gst_object_unref:<pipeline1> 0x595880e8 unref 3->2
V/GStreamer+GST_REFCOUNTING(14891): 0:23:41.693016304 0x59615f60 gstminiobject.c:440:gst_mini_object_unref 0x5988c980 unref 2->1
V/GStreamer+GST_REFCOUNTING(14891): 0:23:41.693113720 0x59615f60 gstminiobject.c:440:gst_mini_object_unref 0x5984f998 unref 11->10
V/GStreamer+GST_REFCOUNTING(14891): 0:23:41.693208429 0x59615f60 gstminiobject.c:440:gst_mini_object_unref 0x5984f918 unref 11->10
V/GStreamer+GST_REFCOUNTING(14891): 0:23:41.693302470 0x59615f60 gstminiobject.c:440:gst_mini_object_unref 0x5987fda0 unref 4->3
D/GStreamer+GST_PADS(14891): 0:23:41.693452887 0x59615f60 gstpad.c:1096:gst_pad_activate_mode:<amcvideoenc-omxsecavcenc1:sink> deactivated in push mode
V/GStreamer+GST_REFCOUNTING(14891): 0:23:41.693571471 0x59615f60 gstobject.c:282:gst_object_unref:<amcvideoenc-omxsecavcenc1> 0x5a454170 unref 5->4
V/GStreamer+GST_REFCOUNTING(14891): 0:23:41.693683971 0x59615f60 gstobject.c:282:gst_object_unref:<amcvideoenc-omxsecavcenc1> 0x5a454170 unref 4->3
D/GStreamer+GST_ELEMENT_PADS(14891): 0:23:41.693801512 0x59615f60 gstelement.c:2759:gst_element_pads_activate:<amcvideoenc-omxsecavcenc1> pad deactivation successful
V/GStreamer+GST_REFCOUNTING(14891): 0:23:41.693912429 0x59615f60 gstminiobject.c:440:gst_mini_object_unref 0x5984f998 unref 10->9
V/GStreamer+GST_REFCOUNTING(14891): 0:23:41.694009221 0x59615f60 gstminiobject.c:440:gst_mini_object_unref 0x5984f918 unref 10->9
V/GStreamer+GST_REFCOUNTING(14891): 0:23:41.694106679 0x59615f60 gstminiobject.c:440:gst_mini_object_unref 0x5984fb18 unref 10->9
V/GStreamer+GST_REFCOUNTING(14891): 0:23:41.694203762 0x59615f60 gstminiobject.c:440:gst_mini_object_unref 0x598800c0 unref 1->0
V/GStreamer+structure(14891): 0:23:41.694290429 0x59615f60 gststructure.c:392:gst_structure_free free structure 0x5983f2b0
D/GStreamer+amcvideoenc(14891): 0:23:41.694382262 0x59615f60 gstamcvideoenc.c:1142:gst_amc_video_enc_stop:<amcvideoenc-omxsecavcenc1> Stopping encoder
D/GStreamer+GST_PADS(14891): 0:23:41.694489387 0x59615f60 gstpad.c:5526:gst_pad_stop_task:<amcvideoenc-omxsecavcenc1:src> stop task
D/GStreamer+GST_PADS(14891): 0:23:41.694596596 0x59615f60 gstpad.c:5548:gst_pad_stop_task:<amcvideoenc-omxsecavcenc1:src> no task
D/GStreamer+amcvideoenc(14891): 0:23:41.694700262 0x59615f60 gstamcvideoenc.c:1172:gst_amc_video_enc_stop:<amcvideoenc-omxsecavcenc1> Stopped encoder
D/GStreamer+GST_STATES(14891): 0:23:41.694802012 0x59615f60 gstelement.c:2636:gst_element_change_state:<amcvideoenc-omxsecavcenc1> element changed state SUCCESS
I/GStreamer+GST_STATES(14891): 0:23:41.694916554 0x59615f60 gstelement.c:2303:gst_element_continue_state:<amcvideoenc-omxsecavcenc1> committing state from PAUSED to READY, pending NULL, next NULL
I/GStreamer+GST_STATES(14891): 0:23:41.695029346 0x59615f60 gstelement.c:2233:_priv_gst_element_state_changed:<amcvideoenc-omxsecavcenc1> notifying about state-changed PAUSED to READY (NULL pending)
V/GStreamer+structure(14891): 0:23:41.695123179 0x59615f60 gststructure.c:154:gst_structure_new_id_empty_with_size created structure 0x59c1b770
V/GStreamer+GST_MESSAGE(14891): 0:23:41.695231929 0x59615f60 gstmessage.c:284:gst_message_new_custom source amcvideoenc-omxsecavcenc1: creating new message 0x5987ae18 state-changed
V/GStreamer+GST_REFCOUNTING(14891): 0:23:41.695338429 0x59615f60 gstobject.c:256:gst_object_ref:<amcvideoenc-omxsecavcenc1> 0x5a454170 ref 2->3
V/GStreamer+GST_REFCOUNTING(14891): 0:23:41.695455137 0x59615f60 gstobject.c:256:gst_object_ref:<bus2> 0x59551c28 ref 15->16
D/GStreamer+GST_BUS(14891): 0:23:41.695652012 0x59615f60 gstbus.c:312:gst_bus_post:<bus2> [msg 0x5987ae18] posting on bus state-changed message: 0x5987ae18, time 99:99:99.999999999, seq-num 420, element 'amcvideoenc-omxsecavcenc1', GstMessageStateChanged, old-state=(GstState)GST_STATE_PAUSED, new-state=(GstState)GST_STATE_READY, pending-state=(GstState)GST_STATE_NULL;
D/GStreamer+bin(14891): 0:23:41.695767262 0x59615f60 gstbin.c:3396:gst_bin_handle_message_func:<pipeline1> [msg 0x5987ae18] handling child amcvideoenc-omxsecavcenc1 message of type state-changed
D/GStreamer+bin(14891): 0:23:41.695861596 0x59615f60 gstbin.c:3729:gst_bin_handle_message_func:<pipeline1> posting message upward
V/GStreamer+GST_REFCOUNTING(14891): 0:23:41.695971096 0x59615f60 gstobject.c:256:gst_object_ref:<bus3> 0x59551cb8 ref 2->3
D/GStreamer+GST_BUS(14891): 0:23:41.696156054 0x59615f60 gstbus.c:312:gst_bus_post:<bus3> [msg 0x5987ae18] posting on bus state-changed message: 0x5987ae18, time 99:99:99.999999999, seq-num 420, element 'amcvideoenc-omxsecavcenc1', GstMessageStateChanged, old-state=(GstState)GST_STATE_PAUSED, new-state=(GstState)GST_STATE_READY, pending-state=(GstState)GST_STATE_NULL;
D/GStreamer+GST_BUS(14891): 0:23:41.696262304 0x59615f60 gstbus.c:347:gst_bus_post:<bus3> [msg 0x5987ae18] pushing on async queue
D/GStreamer+GST_BUS(14891): 0:23:41.696364679 0x59615f60 gstbus.c:350:gst_bus_post:<bus3> [msg 0x5987ae18] pushed on async queue
V/GStreamer+GST_REFCOUNTING(14891): 0:23:41.696471221 0x59615f60 gstobject.c:282:gst_object_unref:<bus3> 0x59551cb8 unref 3->2
D/GStreamer+GST_BUS(14891): 0:23:41.696574221 0x59615f60 gstbus.c:343:gst_bus_post:<bus2> [msg 0x5987ae18] dropped
V/GStreamer+GST_REFCOUNTING(14891): 0:23:41.696680346 0x59615f60 gstobject.c:282:gst_object_unref:<bus2> 0x59551c28 unref 16->15
I/GStreamer+GST_STATES(14891): 0:23:41.696792012 0x59615f60 gstelement.c:2310:gst_element_continue_state:<amcvideoenc-omxsecavcenc1> continue state change READY to NULL, final NULL
V/GStreamer+GST_STATES(14891): 0:23:41.696908971 0x59615f60 gstelement.c:2797:gst_element_change_state_func:<amcvideoenc-omxsecavcenc1> default handler tries setting state from READY to NULL (0011)
D/GStreamer+GST_ELEMENT_PADS(14891): 0:23:41.697015929 0x59615f60 gstelement.c:2740:gst_element_pads_activate:<amcvideoenc-omxsecavcenc1> deactivate pads
V/GStreamer+GST_REFCOUNTING(14891): 0:23:41.697140637 0x59615f60 gstobject.c:256:gst_object_ref:<amcvideoenc-omxsecavcenc1> 0x5a454170 ref 4->5
D/GStreamer+GST_PADS(14891): 0:23:41.697251512 0x59615f60 gstpad.c:967:gst_pad_set_active:<amcvideoenc-omxsecavcenc1:src> pad was inactive
V/GStreamer+GST_REFCOUNTING(14891): 0:23:41.697365429 0x59615f60 gstobject.c:282:gst_object_unref:<amcvideoenc-omxsecavcenc1> 0x5a454170 unref 5->4
V/GStreamer+GST_REFCOUNTING(14891): 0:23:41.697491720 0x59615f60 gstobject.c:256:gst_object_ref:<amcvideoenc-omxsecavcenc1> 0x5a454170 ref 4->5
D/GStreamer+GST_PADS(14891): 0:23:41.697599929 0x59615f60 gstpad.c:967:gst_pad_set_active:<amcvideoenc-omxsecavcenc1:sink> pad was inactive
V/GStreamer+GST_REFCOUNTING(14891): 0:23:41.697715554 0x59615f60 gstobject.c:282:gst_object_unref:<amcvideoenc-omxsecavcenc1> 0x5a454170 unref 5->4
D/GStreamer+GST_ELEMENT_PADS(14891): 0:23:41.697830262 0x59615f60 gstelement.c:2759:gst_element_pads_activate:<amcvideoenc-omxsecavcenc1> pad deactivation successful
D/GStreamer+amcvideoenc(14891): 0:23:41.697927554 0x59615f60 gstamcvideoenc.c:575:gst_amc_video_enc_close:<amcvideoenc-omxsecavcenc1> Closing encoder
D/GStreamer+amcvideoenc(14891): 0:23:41.698029054 0x59615f60 gstamcvideoenc.c:584:gst_amc_video_enc_close:<amcvideoenc-omxsecavcenc1> Closed encoder
D/GStreamer+GST_STATES(14891): 0:23:41.698131095 0x59615f60 gstelement.c:2636:gst_element_change_state:<amcvideoenc-omxsecavcenc1> element changed state SUCCESS
I/GStreamer+GST_STATES(14891): 0:23:41.698234595 0x59615f60 gstelement.c:2328:gst_element_continue_state:<amcvideoenc-omxsecavcenc1> completed state change to NULL
I/GStreamer+GST_STATES(14891): 0:23:41.698380512 0x59615f60 gstelement.c:2233:_priv_gst_element_state_changed:<amcvideoenc-omxsecavcenc1> notifying about state-changed READY to NULL (VOID_PENDING pending)
V/GStreamer+structure(14891): 0:23:41.698481471 0x59615f60 gststructure.c:154:gst_structure_new_id_empty_with_size created structure 0x59c1b8c0
V/GStreamer+GST_MESSAGE(14891): 0:23:41.698591887 0x59615f60 gstmessage.c:284:gst_message_new_custom source amcvideoenc-omxsecavcenc1: creating new message 0x5987ae70 state-changed
V/GStreamer+GST_REFCOUNTING(14891): 0:23:41.698699096 0x59615f60 gstobject.c:256:gst_object_ref:<amcvideoenc-omxsecavcenc1> 0x5a454170 ref 3->4
V/GStreamer+GST_REFCOUNTING(14891): 0:23:41.698815262 0x59615f60 gstobject.c:256:gst_object_ref:<bus2> 0x59551c28 ref 15->16
D/GStreamer+GST_BUS(14891): 0:23:41.699009971 0x59615f60 gstbus.c:312:gst_bus_post:<bus2> [msg 0x5987ae70] posting on bus state-changed message: 0x5987ae70, time 99:99:99.999999999, seq-num 421, element 'amcvideoenc-omxsecavcenc1', GstMessageStateChanged, old-state=(GstState)GST_STATE_READY, new-state=(GstState)GST_STATE_NULL, pending-state=(GstState)GST_STATE_VOID_PENDING;
D/GStreamer+bin(14891): 0:23:41.699122471 0x59615f60 gstbin.c:3396:gst_bin_handle_message_func:<pipeline1> [msg 0x5987ae70] handling child amcvideoenc-omxsecavcenc1 message of type state-changed
D/GStreamer+bin(14891): 0:23:41.699214096 0x59615f60 gstbin.c:3729:gst_bin_handle_message_func:<pipeline1> posting message upward
V/GStreamer+GST_REFCOUNTING(14891): 0:23:41.699322887 0x59615f60 gstobject.c:256:gst_object_ref:<bus3> 0x59551cb8 ref 2->3
D/GStreamer+GST_BUS(14891): 0:23:41.699506512 0x59615f60 gstbus.c:312:gst_bus_post:<bus3> [msg 0x5987ae70] posting on bus state-changed message: 0x5987ae70, time 99:99:99.999999999, seq-num 421, element 'amcvideoenc-omxsecavcenc1', GstMessageStateChanged, old-state=(GstState)GST_STATE_READY, new-state=(GstState)GST_STATE_NULL, pending-state=(GstState)GST_STATE_VOID_PENDING;
D/GStreamer+GST_BUS(14891): 0:23:41.699613804 0x59615f60 gstbus.c:347:gst_bus_post:<bus3> [msg 0x5987ae70] pushing on async queue
D/GStreamer+GST_BUS(14891): 0:23:41.699715346 0x59615f60 gstbus.c:350:gst_bus_post:<bus3> [msg 0x5987ae70] pushed on async queue
V/GStreamer+GST_REFCOUNTING(14891): 0:23:41.699822721 0x59615f60 gstobject.c:282:gst_object_unref:<bus3> 0x59551cb8 unref 3->2
D/GStreamer+GST_BUS(14891): 0:23:41.699925887 0x59615f60 gstbus.c:343:gst_bus_post:<bus2> [msg 0x5987ae70] dropped
V/GStreamer+GST_REFCOUNTING(14891): 0:23:41.700034221 0x59615f60 gstobject.c:282:gst_object_unref:<bus2> 0x59551c28 unref 16->15
V/GStreamer+GST_STATES(14891): 0:23:41.700144346 0x59615f60 gstelement.c:2652:gst_element_change_state:<amcvideoenc-omxsecavcenc1> exit state change 1
V/GStreamer+GST_STATES(14891): 0:23:41.700246846 0x59615f60 gstelement.c:2652:gst_element_change_state:<amcvideoenc-omxsecavcenc1> exit state change 1
D/GStreamer+GST_STATES(14891): 0:23:41.700351262 0x59615f60 gstelement.c:2563:gst_element_set_state_func:<amcvideoenc-omxsecavcenc1> returned SUCCESS
I/GStreamer+GST_STATES(14891): 0:23:41.700464471 0x59615f60 gstbin.c:2656:gst_bin_change_state_func:<pipeline1> child 'amcvideoenc-omxsecavcenc1' changed state to 1(NULL) successfully
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.freedesktop.org/archives/gstreamer-devel/attachments/20140225/7723fcb3/attachment-0001.html>