Android appsrc pipeline / log assistance

kenny kenny at kenny.house
Thu Jan 1 15:29:25 PST 2015


Fair warning, I'm new to gstreamer (been using it for about a little over a
week now).  What a fantastic tool,  I'd like to extend a huge thanks to
everyone who has spent time on it.

In the project I'm currently working on, I would like to use gstreamer in an
Android application to encode some audio using the opus encoder plugin.
Likely we'll also stream the audio via gstreamer as well, but for now I'm
just trying to get the pipeline flowing and playing. The audio data is from
a bluetooth hardware device that only allows access via a Java API. The
device has a fixed sample rate at 4KHz, sending raw 16-bit PCM Audio.

I have successfully setup a pipeline that sourced audio from a file,
converted and resampled, opus encoded, opus decoded, and output to the
autoaudiosink on my android device (Nexus 9). This allowed me to become more
familiar with gstreamer, and get used to gobject some. I did get this
functioning just fine. A big thanks to the folks who have posted updated
versions of the android tutorials to work with the most recent gstreamer
versions.

I have since turned to the task of pushing audio from the hardware device
into my gstreamer pipeline. I am using the appsrc element in "push" mode to
do this. For the time being, I'm simply trying to run a pipeline as such:
appsrc ! audioconvert ! audioresample ! autoaudiosink

I have tried to combine some android examples I've found alongside a few
different appsrc tutorials, but the overall flow is as follows:
1. Setup pipeline and need-data and enough-data callbacks.
2. Start playing the pipeline. The need-data callback makes a call to my
java code that starts up a thread to start pushing data to my JNI code.
3. The java code continues pushing buffers, which are pushed to the appsrc
element, until it receives back a JNI_FALSE. 

In log outputs, I can see the pipeline initially setup. The caps negotiation
seems to work just fine. The pipeline shifts from paused to playing. Things
seem to go alright for a few buffer pushes, then I consistently see an
output from appsrc of "we have buffer" ... "of size 0" . basesrc outputs
"pausing after gst_pad_push() = error" and then follows a "Internal data
flow error." and "streaming task paused, reason error (-5)". At this point
the pipeline appears to start shutting down.

I'm not 100% if this is where my problem is located, but these logs
consistently immediately proceed the internal data flow error.

The full log output is as follows, the "System.out" lines are output when my
java code is pushing buffers. I've bold faced the lines I'm most curious
about:

W/VideoCapabilities﹕ Unsupported mime video/mpeg2
W/AudioCapabilities﹕ Unsupported mime audio/mpeg-L2
W/VideoCapabilities﹕ Unrecognized level 0 for video/x-vnd.on2.vp8
I/VideoCapabilities﹕ Unsupported profile 4 for video/mp4v-es
E/GStreamer+amc﹕ 0:00:00.237551333 0xab6ad640 gstamc.c:2291:scan_codecs
Decoder codec has unknown color formats, ignoring
E/GStreamer+amc﹕ 0:00:00.238114750 0xab6ad640 gstamc.c:2291:scan_codecs
Decoder codec has unknown color formats, ignoring
E/GStreamer+amc﹕ 0:00:00.238939666 0xab6ad640 gstamc.c:2291:scan_codecs
Decoder codec has unknown color formats, ignoring
W/VideoCapabilities﹕ Unsupported mime video/mpeg2
E/GStreamer+amc﹕ 0:00:00.239551416 0xab6ad640 gstamc.c:2291:scan_codecs
Decoder codec has unknown color formats, ignoring
W/AudioCapabilities﹕ Unsupported mime audio/mpeg-L2
E/GStreamer+amc﹕ 0:00:00.240644250 0xab6ad640 gstamc.c:2291:scan_codecs
Decoder codec has unknown color formats, ignoring
W/VideoCapabilities﹕ Unrecognized level 0 for video/x-vnd.on2.vp8
E/GStreamer+amc﹕ 0:00:00.241924916 0xab6ad640 gstamc.c:2291:scan_codecs
Decoder codec has unknown color formats, ignoring
E/GStreamer+amc﹕ 0:00:00.244581666 0xab6ad640 gstamc.c:2291:scan_codecs
Decoder codec has unknown color formats, ignoring
E/GStreamer+amc﹕ 0:00:00.245105833 0xab6ad640 gstamc.c:2291:scan_codecs
Decoder codec has unknown color formats, ignoring
E/GStreamer+amc﹕ 0:00:00.245522333 0xab6ad640 gstamc.c:2291:scan_codecs
Decoder codec has unknown color formats, ignoring
E/GStreamer+amc﹕ 0:00:00.246357083 0xab6ad640 gstamc.c:2291:scan_codecs
Decoder codec has unknown color formats, ignoring
E/GStreamer+amc﹕ 0:00:00.246951416 0xab6ad640 gstamc.c:2291:scan_codecs
Decoder codec has unknown color formats, ignoring
I/VideoCapabilities﹕ Unsupported profile 4 for video/mp4v-es
W/GStreamer+amc﹕ 0:00:00.252245416 0xab6ad640
gstamc.c:3872:gst_amc_codec_info_to_caps Unsupported mimetype 'audio/opus'
W/GStreamer+amc﹕ 0:00:00.252754166 0xab6ad640
gstamc.c:3886:gst_amc_codec_info_to_caps Unknown color format 0x7f420888
W/GStreamer+amc﹕ 0:00:00.252829750 0xab6ad640
gstamc.c:3886:gst_amc_codec_info_to_caps Unknown color format 0x7f000789
W/GStreamer+amc﹕ 0:00:00.253525666 0xab6ad640
gstamc.c:3886:gst_amc_codec_info_to_caps Unknown color format 0x7f420888
W/GStreamer+amc﹕ 0:00:00.253614416 0xab6ad640
gstamc.c:3886:gst_amc_codec_info_to_caps Unknown color format 0x7f000789
W/GStreamer+amc﹕ 0:00:00.253866416 0xab6ad640
gstamc.c:3886:gst_amc_codec_info_to_caps Unknown color format 0x7f420888
W/GStreamer+amc﹕ 0:00:00.253920333 0xab6ad640
gstamc.c:3886:gst_amc_codec_info_to_caps Unknown color format 0x7f000789
W/GStreamer+amc﹕ 0:00:00.254251583 0xab6ad640
gstamc.c:3886:gst_amc_codec_info_to_caps Unknown color format 0x7f420888
W/GStreamer+amc﹕ 0:00:00.254306583 0xab6ad640
gstamc.c:3886:gst_amc_codec_info_to_caps Unknown color format 0x7f000789
W/GStreamer+amc﹕ 0:00:00.255488083 0xab6ad640
gstamc.c:3886:gst_amc_codec_info_to_caps Unknown color format 0x7f420888
W/GStreamer+amc﹕ 0:00:00.255553583 0xab6ad640
gstamc.c:3886:gst_amc_codec_info_to_caps Unknown color format 0x7f000789
W/GStreamer+amc﹕ 0:00:00.255937833 0xab6ad640
gstamc.c:3886:gst_amc_codec_info_to_caps Unknown color format 0x7f420888
W/GStreamer+amc﹕ 0:00:00.255996916 0xab6ad640
gstamc.c:3886:gst_amc_codec_info_to_caps Unknown color format 0x7f000789
I/GStreamer﹕ GStreamer initialization complete
D/OpenGLRenderer﹕ Render dirty regions requested: true
W/BluetoothAdapter﹕ getBluetoothService() called with no
BluetoothManagerCallback
I/OpenGLRenderer﹕ Initialized EGL, version 1.4
D/OpenGLRenderer﹕ Enabling debug mode 0
D/GStreamer+hello-gs﹕ 0:00:02.903022416 0xab710f20
jni/hello-gs.c:244:gst_native_init Created CustomData at 0xab817eb8
D/GStreamer+hello-gs﹕ 0:00:02.903263499 0xab710f20
jni/hello-gs.c:246:gst_native_init Created GlobalRef for app object at
0x20041a
D/GStreamer+hello-gs﹕ 0:00:02.920787499 0xab81c800
jni/hello-gs.c:160:app_function Started the app function thread with
command: This doesn't matter anymore
D/GStreamer+basesrc﹕ 0:00:02.925103916 0xab81c800
gstbasesrc.c:445:gst_base_src_init:<GstBaseSrc at 0xab81e178> creating src pad
D/GStreamer+basesrc﹕ 0:00:02.925807832 0xab81c800
gstbasesrc.c:448:gst_base_src_init:<GstBaseSrc at 0xab81e178> setting functions
on src pad
D/GStreamer+basesrc﹕ 0:00:02.926039832 0xab81c800
gstbasesrc.c:456:gst_base_src_init:<GstBaseSrc at 0xab81e178> adding src pad
D/GStreamer+basesrc﹕ 0:00:02.926250249 0xab81c800
gstbasesrc.c:473:gst_base_src_init:<GstBaseSrc at 0xab81e178> init done
D/GStreamer+audioresample﹕ 0:00:02.927991332 0xab81c800
gstaudioresample.c:1326:gst_audio_resample_set_property:<resample> new
quality 4
D/GStreamer+appsrc﹕ 0:00:02.937325916 0xab81c800
gstappsrc.c:1174:gst_app_src_set_caps:<source> setting caps to audio/x-raw,
format=(string)U16LE, layout=(string)interleaved, rate=(int)4000,
channels=(int)1
D/GStreamer+appsrc﹕ 0:00:02.937539082 0xab81c800
gstappsrc.c:1327:gst_app_src_set_max_bytes:<source> setting max-bytes to
-845390739427819008
W/GLib+GLib-GObject﹕ g_object_set_valist: object class 'GstAppSrc' has no
property named '!'
D/GStreamer+appsrc﹕ 0:00:02.937825499 0xab81c800
gstappsrc.c:601:gst_app_src_internal_get_caps:<source> caps: audio/x-raw,
format=(string)U16LE, layout=(string)interleaved, rate=(int)4000,
channels=(int)1
D/GStreamer+basesrc﹕ 0:00:02.937920916 0xab81c800
gstbasesrc.c:1280:gst_base_src_default_query:<source> query caps returns 1
D/GStreamer+audioconvert﹕ 0:00:02.938323082 0xab81c800
gstaudioconvert.c:331:gst_audio_convert_transform_caps:<convert> transformed
audio/x-raw, format=(string){ S8, U8, S16LE, S16BE, U16LE, U16BE, S24_32LE,
S24_32BE, U24_32LE, U24_32BE, S32LE, S32BE, U32LE, U32BE, S24LE, S24BE,
U24LE, U24BE, S20LE, S20BE, U20LE, U20BE, S18LE, S18BE, U18LE, U18BE, F32LE,
F32BE, F64LE, F64BE }, rate=(int)[ 1, 2147483647 ], channels=(int)[ 1,
2147483647 ], layout=(string)interleaved into audio/x-raw, rate=(int)[ 1,
2147483647 ], layout=(string)interleaved
D/GStreamer+appsrc﹕ 0:00:02.938894999 0xab81c800
gstappsrc.c:601:gst_app_src_internal_get_caps:<source> caps: audio/x-raw,
format=(string)U16LE, layout=(string)interleaved, rate=(int)4000,
channels=(int)1
D/GStreamer+basesrc﹕ 0:00:02.938973249 0xab81c800
gstbasesrc.c:1280:gst_base_src_default_query:<source> query caps returns 1
D/GStreamer+audioconvert﹕ 0:00:02.939226916 0xab81c800
gstaudioconvert.c:331:gst_audio_convert_transform_caps:<convert> transformed
audio/x-raw, format=(string){ S8, U8, S16LE, S16BE, U16LE, U16BE, S24_32LE,
S24_32BE, U24_32LE, U24_32BE, S32LE, S32BE, U32LE, U32BE, S24LE, S24BE,
U24LE, U24BE, S20LE, S20BE, U20LE, U20BE, S18LE, S18BE, U18LE, U18BE, F32LE,
F32BE, F64LE, F64BE }, rate=(int)[ 1, 2147483647 ], channels=(int)[ 1,
2147483647 ], layout=(string)interleaved into audio/x-raw, rate=(int)[ 1,
2147483647 ], layout=(string)interleaved
D/GStreamer+appsrc﹕ 0:00:02.939754166 0xab81c800
gstappsrc.c:601:gst_app_src_internal_get_caps:<source> caps: audio/x-raw,
format=(string)U16LE, layout=(string)interleaved, rate=(int)4000,
channels=(int)1
D/GStreamer+basesrc﹕ 0:00:02.939832499 0xab81c800
gstbasesrc.c:1280:gst_base_src_default_query:<source> query caps returns 1
D/GStreamer+audioconvert﹕ 0:00:02.939981832 0xab81c800
gstaudioconvert.c:331:gst_audio_convert_transform_caps:<convert> transformed
audio/x-raw, format=(string)U16LE, layout=(string)interleaved,
rate=(int)4000, channels=(int)1 into audio/x-raw,
layout=(string)interleaved, rate=(int)4000
D/GStreamer+appsrc﹕ 0:00:02.940559249 0xab81c800
gstappsrc.c:601:gst_app_src_internal_get_caps:<source> caps: audio/x-raw,
format=(string)U16LE, layout=(string)interleaved, rate=(int)4000,
channels=(int)1
D/GStreamer+basesrc﹕ 0:00:02.940630666 0xab81c800
gstbasesrc.c:1280:gst_base_src_default_query:<source> query caps returns 1
D/GStreamer+audioconvert﹕ 0:00:02.940778332 0xab81c800
gstaudioconvert.c:331:gst_audio_convert_transform_caps:<convert> transformed
audio/x-raw, format=(string)U16LE, layout=(string)interleaved,
rate=(int)4000, channels=(int)1 into audio/x-raw,
layout=(string)interleaved, rate=(int)4000
D/GStreamer+hello-gs﹕ 0:00:02.941553082 0xab81c800
jni/hello-gs.c:224:app_function Entering main loop...
(CustomData:0xab817eb8)
D/GStreamer+hello-gs﹕ 0:00:02.941625666 0xab81c800
jni/hello-gs.c:63:attach_current_thread Attaching thread 0xab81c800
D/GStreamer+hello-gs﹕ 0:00:02.945063832 0xab81c800
jni/hello-gs.c:88:check_initialization_complete Initialization complete,
notifying application. env:0xab82ce60,  main_loop:0xab82cdb0 on object:
0x20041a
D/GStreamer+hello-gs﹕ 0:00:02.945768332 0xab81c800
jni/hello-gs.c:295:gst_native_play Setting state to PLAYING
W/libOpenSLES﹕ Leaving Object::GetInterface (SL_RESULT_FEATURE_UNSUPPORTED)
D/GStreamer+basesink﹕ 0:00:02.960647832 0xab81c800
gstbasesink.c:4904:gst_base_sink_change_state:<sink-actual-sink-opensles>
READY to PAUSED
D/GStreamer+basesink﹕ 0:00:02.960761166 0xab81c800
gstbasesink.c:4925:gst_base_sink_change_state:<sink-actual-sink-opensles>
doing async state change
D/GStreamer+basesink﹕ 0:00:02.960861249 0xab81c800
gstbasesink.c:4074:gst_base_sink_pad_activate:<sink-actual-sink-opensles>
Trying pull mode first
D/GStreamer+basesink﹕ 0:00:02.960914666 0xab81c800
gstbasesink.c:4080:gst_base_sink_pad_activate:<sink-actual-sink-opensles>
pull mode disabled
D/GStreamer+basesink﹕ 0:00:02.960966166 0xab81c800
gstbasesink.c:4130:gst_base_sink_pad_activate:<sink-actual-sink-opensles>
Falling back to push mode
D/GStreamer+basesink﹕ 0:00:02.961023916 0xab81c800
gstbasesink.c:4132:gst_base_sink_pad_activate:<sink-actual-sink-opensles>
Success activating push mode
D/GStreamer+basesrc﹕ 0:00:02.961297916 0xab81c800
gstbasesrc.c:3757:gst_base_src_activate_mode:<source:src> activating in mode
1
D/GStreamer+basesrc﹕ 0:00:02.961483999 0xab81c800
gstbasesrc.c:3683:gst_base_src_activate_push:<source> Activating in push
mode
D/GStreamer+appsrc﹕ 0:00:02.961536999 0xab81c800
gstappsrc.c:769:gst_app_src_start:<source> starting
D/GStreamer+basesrc﹕ 0:00:02.961586166 0xab81c800
gstbasesrc.c:3364:gst_base_src_start_complete:<source> starting source
D/GStreamer+basesrc﹕ 0:00:02.961648999 0xab81c800
gstbasesrc.c:3388:gst_base_src_start_complete:<source> format: time, have
size: 0, size: -1, duration: -1
D/GStreamer+basesrc﹕ 0:00:02.961698332 0xab81c800
gstbasesrc.c:3391:gst_base_src_start_complete:<source> is seekable: 0
D/GStreamer+basesrc﹕ 0:00:02.961745666 0xab81c800
gstbasesrc.c:3396:gst_base_src_start_complete:<source> is random_access: 0
D/GStreamer+basesrc﹕ 0:00:02.961795832 0xab81c800
gstbasesrc.c:3559:gst_base_src_set_flushing:<source> flushing 0, live_play 0
D/GStreamer+basesrc﹕ 0:00:02.961854416 0xab81c800
gstbasesrc.c:1565:gst_base_src_perform_seek:<source> doing seek: (NULL)
D/GStreamer+basesrc﹕ 0:00:02.961911499 0xab81c800
gstbasesrc.c:1621:gst_base_src_perform_seek:<source> seek with seqnum 26
D/GStreamer+basesrc﹕ 0:00:02.961964166 0xab81c800
gstbasesrc.c:1658:gst_base_src_perform_seek:<source> segment configured from
0 to -1, position 0
I/GStreamer+basesrc﹕ 0:00:02.962108416 0xab81c800
gstbasesrc.c:1328:gst_base_src_do_seek:<source> seeking: time segment
start=0:00:00.000000000, offset=0:00:00.000000000, stop=99:99:99.999999999,
rate=1.000000, applied_rate=1.000000, flags=0x00, time=0:00:00.000000000,
base=0:00:00.000000000, position 0:00:00.000000000, duration
99:99:99.999999999
D/GStreamer+appsrc﹕ 0:00:02.962165832 0xab81c800
gstappsrc.c:892:gst_app_src_do_seek:<source> seeking to 0, format time
D/GStreamer+basesrc﹕ 0:00:02.962533749 0xab81c800
gstbasesrc.c:3505:gst_base_src_start_wait:<source> got ok
D/GStreamer+basesink﹕ 0:00:02.963378499 0xab81c800
gstbasesink.c:1097:gst_base_sink_query_latency:<sink-actual-sink-opensles>
we are not yet ready for LATENCY query
D/GStreamer+basesink﹕ 0:00:02.963436832 0xab81c800
gstbasesink.c:1107:gst_base_sink_query_latency:<sink-actual-sink-opensles>
latency query failed and we are live
D/GStreamer+basesink﹕ 0:00:02.963760666 0xab81c800
gstbasesink.c:4337:gst_base_sink_send_event:<sink-actual-sink-opensles>
handling event 0xab714360 latency event: 0xab714360, time
99:99:99.999999999, seq-num 33, GstEventLatency, latency=(guint64)0;
D/GStreamer+basesink﹕ 0:00:02.963830749 0xab81c800
gstbasesink.c:4354:gst_base_sink_send_event:<sink-actual-sink-opensles>
latency set to 0:00:00.000000000
D/GStreamer+basesink﹕ 0:00:02.963914916 0xab81c800
gstbasesink.c:4384:gst_base_sink_send_event:<sink-actual-sink-opensles>
handled event 0xab714360 latency event: 0xab714360, time 99:99:99.999999999,
seq-num 33, GstEventLatency, latency=(guint64)0;: 1
D/GStreamer+basesrc﹕ 0:00:02.964409249 0xab81c800
gstbasesrc.c:3792:gst_base_src_change_state:<source> PAUSED->PLAYING
D/GStreamer+basesrc﹕ 0:00:02.964463332 0xab81c800
gstbasesrc.c:3638:gst_base_src_set_playing:<source> unschedule clock
D/GStreamer+basesrc﹕ 0:00:02.964513249 0xab81c800
gstbasesrc.c:3645:gst_base_src_set_playing:<source> live running 1
D/GStreamer+basesrc﹕ 0:00:02.964567916 0xab81c800
gstbasesrc.c:3652:gst_base_src_set_playing:<source> unlock stop
D/GStreamer+appsrc﹕ 0:00:02.964651999 0xab81c800
gstappsrc.c:754:gst_app_src_unlock_stop:<source> unlock stop
D/GStreamer+basesrc﹕ 0:00:02.964703249 0xab81c800
gstbasesrc.c:3666:gst_base_src_set_playing:<source> signal
D/GStreamer+hello-gs﹕ 0:00:02.965069249 0xab81c800
jni/hello-gs.c:105:state_changed_cb State changed message: State changed to
READY
D/GStreamer+hello-gs﹕ 0:00:02.965261332 0xab81c800
jni/hello-gs.c:105:state_changed_cb State changed message: State changed to
PAUSED
D/GStreamer+basesrc﹕ 0:00:02.967795832 0xab829b50
gstbasesrc.c:1280:gst_base_src_default_query:<source> query uri returns 0
D/GStreamer+basesrc﹕ 0:00:02.968239332 0xab829b50
gstbasesrc.c:883:gst_base_src_send_stream_start:<source> Pushing
STREAM_START
D/GStreamer+basesink﹕ 0:00:02.968824249 0xab829b50
gstbasesink.c:3162:gst_base_sink_event:<sink-actual-sink-opensles> received
event 0xab82c510 stream-start event: 0xab82c510, time 99:99:99.999999999,
seq-num 40, GstEventStreamStart,
stream-id=(string)7e0778cb216032b22a9003a117520e1b,
flags=(GstStreamFlags)GST_STREAM_FLAG_NONE, group-id=(uint)0;
D/GStreamer+basesink﹕ 0:00:02.968893999 0xab829b50
gstbasesink.c:3057:gst_base_sink_default_event:<sink-actual-sink-opensles>
Now posting STREAM_START (seqnum:40)
D/GStreamer+basesrc﹕ 0:00:02.969438166 0xab829b50
gstbasesrc.c:3253:gst_base_src_negotiate:<source> starting negotiation
D/GStreamer+audioconvert﹕ 0:00:02.969683249 0xab829b50
gstaudioconvert.c:331:gst_audio_convert_transform_caps:<convert> transformed
audio/x-raw, format=(string)U16LE, layout=(string)interleaved,
rate=(int)4000, channels=(int)1 into audio/x-raw,
layout=(string)interleaved, rate=(int)4000
D/GStreamer+audioconvert﹕ 0:00:02.970605416 0xab829b50
gstaudioconvert.c:331:gst_audio_convert_transform_caps:<convert> transformed
audio/x-raw, layout=(string)interleaved, rate=(int)4000,
format=(string)S16LE, channels=(int)[ 1, 2 ] into audio/x-raw,
format=(string)U16LE, layout=(string)interleaved, rate=(int)4000,
channels=(int)1
D/GStreamer+audioconvert﹕ 0:00:02.970803332 0xab829b50
gstaudioconvert.c:331:gst_audio_convert_transform_caps:<convert> transformed
audio/x-raw, format=(string)U16LE, layout=(string)interleaved,
rate=(int)4000, channels=(int)1 into audio/x-raw,
layout=(string)interleaved, rate=(int)4000
D/GStreamer+audioconvert﹕ 0:00:02.971560499 0xab829b50
gstaudioconvert.c:700:gst_audio_convert_fixate_caps:<convert> trying to
fixate othercaps audio/x-raw, layout=(string)interleaved, rate=(int)4000,
format=(string)S16LE, channels=(int)[ 1, 2 ] based on caps audio/x-raw,
format=(string)U16LE, layout=(string)interleaved, rate=(int)4000,
channels=(int)1
D/GStreamer+audioconvert﹕ 0:00:02.971675499 0xab829b50
gstaudioconvert.c:723:gst_audio_convert_fixate_caps:<convert> now fixating
audio/x-raw, layout=(string)interleaved, rate=(int)4000,
format=(string)S16LE, channels=(int)1
D/GStreamer+audioconvert﹕ 0:00:02.971755499 0xab829b50
gstaudioconvert.c:737:gst_audio_convert_fixate_caps:<convert> fixated
othercaps to audio/x-raw, layout=(string)interleaved, rate=(int)4000,
format=(string)S16LE, channels=(int)1
D/GStreamer+audioconvert﹕ 0:00:02.972660666 0xab829b50
gstaudioconvert.c:751:gst_audio_convert_set_caps:<convert> incaps
audio/x-raw, format=(string)U16LE, layout=(string)interleaved,
rate=(int)4000, channels=(int)1, outcaps audio/x-raw,
layout=(string)interleaved, rate=(int)4000, format=(string)S16LE,
channels=(int)1
I/GStreamer+audioconvert﹕ 0:00:02.972796499 0xab829b50
audioconvert.c:620:audio_convert_prepare_context depth in 16, out 16
I/GStreamer+audioconvert﹕ 0:00:02.972845666 0xab829b50
audioconvert.c:630:audio_convert_prepare_context using dither 2 and noise
shaping 0
D/GStreamer+audioconvert﹕ 0:00:02.972918582 0xab829b50
gstchannelmix.c:641:gst_channel_mix_setup_matrix Matrix for 1 -> 1: { {
1.000000 } }
I/GStreamer+audioconvert﹕ 0:00:02.972966582 0xab829b50
audioconvert.c:650:audio_convert_prepare_context func index in 4, out 5
I/GStreamer+audioconvert﹕ 0:00:02.973004832 0xab829b50
audioconvert.c:655:audio_convert_prepare_context use int mixing
I/GStreamer+audioconvert﹕ 0:00:02.973047332 0xab829b50
audioconvert.c:661:audio_convert_prepare_context unitsizes: 2 -> 2
I/GStreamer+audioconvert﹕ 0:00:02.973091999 0xab829b50
audioconvert.c:671:audio_convert_prepare_context in default 0, mix
passthrough 1, out default 0
I/GStreamer+audioconvert﹕ 0:00:02.973134082 0xab829b50
audioconvert.c:678:audio_convert_prepare_context scale in 16, out 16
D/GStreamer+basesink﹕ 0:00:02.974106082 0xab829b50
gstbasesink.c:4836:gst_base_sink_default_query:<sink-actual-sink-opensles>
Checking if requested caps audio/x-raw, layout=(string)interleaved,
rate=(int)8000, format=(string)S16LE, channels=(int)1 are a subset of pad
caps audio/x-raw, format=(string){ S16LE, U8LE }, rate=(int){ 8000, 11025,
12000, 16000, 22050, 24000, 32000, 44100 }, channels=(int)[ 1, 2 ] result 1
D/GStreamer+basesink﹕ 0:00:02.977252832 0xab829b50
gstbasesink.c:4836:gst_base_sink_default_query:<sink-actual-sink-opensles>
Checking if requested caps audio/x-raw, layout=(string)interleaved,
rate=(int)8000, format=(string)S16LE, channels=(int)1 are a subset of pad
caps audio/x-raw, format=(string){ S16LE, U8LE }, rate=(int){ 8000, 11025,
12000, 16000, 22050, 24000, 32000, 44100 }, channels=(int)[ 1, 2 ] result 1
D/GStreamer+basesink﹕ 0:00:02.979126916 0xab829b50
gstbasesink.c:4836:gst_base_sink_default_query:<sink-actual-sink-opensles>
Checking if requested caps audio/x-raw, layout=(string)interleaved,
rate=(int)8000, format=(string)S16LE, channels=(int)1 are a subset of pad
caps audio/x-raw, format=(string){ S16LE, U8LE }, rate=(int){ 8000, 11025,
12000, 16000, 22050, 24000, 32000, 44100 }, channels=(int)[ 1, 2 ] result 1
D/GStreamer+basesink﹕ 0:00:02.979281416 0xab829b50
gstbasesink.c:3162:gst_base_sink_event:<sink-actual-sink-opensles> received
event 0xab82c5e8 caps event: 0xab82c5e8, time 99:99:99.999999999, seq-num
46, GstEventCaps, caps=(GstCaps)"audio/x-raw\,\
layout\=\(string\)interleaved\,\ rate\=\(int\)8000\,\
format\=\(string\)S16LE\,\ channels\=\(int\)1";
D/GStreamer+basesink﹕ 0:00:02.979454666 0xab829b50
gstbasesink.c:3074:gst_base_sink_default_event:<sink-actual-sink-opensles>
caps 0xab82c5e8
W/AudioTrack﹕ AUDIO_OUTPUT_FLAG_FAST denied by client
D/GStreamer+basesrc﹕ 0:00:02.985901666 0xab829b50
gstbasesrc.c:3130:gst_base_src_prepare_allocation:<source> ALLOCATION (1)
params: allocation query: 0xab83ca30, GstQueryAllocation,
caps=(GstCaps)"audio/x-raw\,\ format\=\(string\)U16LE\,\
layout\=\(string\)interleaved\,\ rate\=\(int\)4000\,\ channels\=\(int\)1",
need-pool=(boolean)true, allocator=(GArray)NULL, pool=(GArray)NULL;
D/GStreamer+basesrc﹕ 0:00:02.986078916 0xab829b50
gstbasesrc.c:2441:gst_base_src_get_range:<source> calling create offset -1
length 4096, time 0
D/GStreamer+hello-gs﹕ 0:00:02.986143749 0xab829b50
jni/hello-gs.c:63:attach_current_thread Attaching thread 0xab829b50
I/System.out﹕ Bytes pushed to native code: 128
D/GStreamer+hello-gs﹕ 0:00:03.333973832 0xab710f20
jni/hello-gs.c:334:gst_native_push_bytes Pushing buffer of samples:64,
size:128, data: �����
D/GStreamer+appsrc﹕ 0:00:03.334027082 0xab710f20
gstappsrc.c:1564:gst_app_src_push_buffer_full:<source> queueing buffer
0xab842650
D/GStreamer+appsrc﹕ 0:00:03.334187916 0xab829b50
gstappsrc.c:1079:gst_app_src_create:<source> we have buffer 0xab842650 of
size 0
D/GStreamer+basesrc﹕ 0:00:03.334243999 0xab829b50
gstbasesrc.c:2187:gst_base_src_do_sync:<source> no latency needed, live 1,
sync 0
D/GStreamer+basesrc﹕ 0:00:03.334296166 0xab829b50
gstbasesrc.c:2300:gst_base_src_do_sync:<source> no sync needed
D/GStreamer+basesrc﹕ 0:00:03.334332499 0xab829b50
gstbasesrc.c:2505:gst_base_src_get_range:<source> buffer ok
D/GStreamer+basesink﹕ 0:00:03.334582582 0xab829b50
gstbasesink.c:3162:gst_base_sink_event:<sink-actual-sink-opensles> received
event 0xab82c630 segment event: 0xab82c630, time 99:99:99.999999999, seq-num
26, GstEventSegment, segment=(GstSegment)"GstSegment,
flags=(GstSegmentFlags)GST_SEGMENT_FLAG_NONE, rate=(double)1,
applied-rate=(double)1, format=(GstFormat)GST_FORMAT_TIME, base=(guint64)0,
offset=(guint64)0, start=(guint64)0, stop=(guint64)-1, time=(guint64)0,
position=(guint64)0, duration=(guint64)-1;";
D/GStreamer+basesink﹕ 0:00:03.334678832 0xab829b50
gstbasesink.c:3097:gst_base_sink_default_event:<sink-actual-sink-opensles>
configured segment time segment start=0:00:00.000000000,
offset=0:00:00.000000000, stop=99:99:99.999999999, rate=1.000000,
applied_rate=1.000000, flags=0x00, time=0:00:00.000000000,
base=0:00:00.000000000, position 0:00:00.000000000, duration
99:99:99.999999999
I/GStreamer+basesrc﹕ 0:00:03.334740999 0xab829b50
gstbasesrc.c:2828:gst_base_src_loop:<source> marking pending DISCONT
I/GStreamer+audioconvert﹕ 0:00:03.334871916 0xab829b50
gstaudioconvert.c:255:gst_audio_convert_get_unit_size:<convert> unit_size =
2
I/GStreamer+audioconvert﹕ 0:00:03.334919332 0xab829b50
gstaudioconvert.c:255:gst_audio_convert_get_unit_size:<convert> unit_size =
2
I/GStreamer+audioresample﹕ 0:00:03.335045166 0xab829b50
gstaudioresample.c:403:gst_audio_resample_init_state:<resample> Using the
full sinc filter table
D/GStreamer+audioresample﹕ 0:00:03.335084749 0xab829b50
gstaudioresample.c:1207:gst_audio_resample_transform:<resample> found
discontinuity; resyncing
D/GStreamer+audioresample﹕ 0:00:03.335146749 0xab829b50
gstaudioresample.c:1221:gst_audio_resample_transform:<resample> ... but new
offset is invalid
D/GStreamer+audioresample﹕ 0:00:03.335183999 0xab829b50
gstaudioresample.c:1226:gst_audio_resample_transform:<resample> marking this
buffer with the DISCONT flag
D/GStreamer+audioresample﹕ 0:00:03.335243582 0xab829b50
gstaudioresample.c:1243:gst_audio_resample_transform:<resample> input =
samples [-1, -1) = [0, -1) ns;  output = samples [-1, -1) = [0, 0) ns
D/GStreamer+basesink﹕ 0:00:03.335314416 0xab829b50
gstbasesink.c:3334:gst_base_sink_chain_unlocked:<sink-actual-sink-opensles>
got times start: 0:00:00.000000000, end: 0:00:00.000000000
D/GStreamer+basesink﹕ 0:00:03.335369249 0xab829b50
gstbasesink.c:1902:gst_base_sink_get_sync_times:<sink-actual-sink-opensles>
got times start: 0:00:00.000000000, stop: 0:00:00.000000000, do_sync 0
D/GStreamer+basesink﹕ 0:00:03.335410666 0xab829b50
gstbasesink.c:2201:gst_base_sink_do_preroll:<sink-actual-sink-opensles>
prerolling object 0xab8421f0
D/GStreamer+basesink﹕ 0:00:03.335453832 0xab829b50
gstbasesink.c:2220:gst_base_sink_do_preroll:<sink-actual-sink-opensles>
preroll buffer 0:00:00.000000000
D/GStreamer+basesink﹕ 0:00:03.335493582 0xab829b50
gstbasesink.c:1455:gst_base_sink_commit_state:<sink-actual-sink-opensles>
commiting state to PAUSED
D/GStreamer+basesink﹕ 0:00:03.335529082 0xab829b50
gstbasesink.c:1480:gst_base_sink_commit_state:<sink-actual-sink-opensles>
posting PAUSED state change message
D/GStreamer+basesink﹕ 0:00:03.335606916 0xab829b50
gstbasesink.c:1486:gst_base_sink_commit_state:<sink-actual-sink-opensles>
posting async-done message
D/GStreamer+basesink﹕ 0:00:03.335772832 0xab829b50
gstbasesink.c:2154:gst_base_sink_wait_preroll:<sink-actual-sink-opensles>
waiting in preroll for flush or PLAYING
D/GStreamer+basesink﹕ 0:00:03.336022332 0xab83ca60
gstbasesink.c:1071:gst_base_sink_query_latency:<sink-actual-sink-opensles>
we are ready for LATENCY query
D/GStreamer+audioresample﹕ 0:00:03.336114582 0xab83ca60
gstaudioresample.c:1282:gst_audio_resample_query:<resample> Peer latency:
min 0:00:00.000000000 max 99:99:99.999999999
D/GStreamer+audioresample﹕ 0:00:03.336173916 0xab83ca60
gstaudioresample.c:1292:gst_audio_resample_query:<resample> Our latency:
0:00:00.008000000
D/GStreamer+audioresample﹕ 0:00:03.336244666 0xab83ca60
gstaudioresample.c:1300:gst_audio_resample_query:<resample> Calculated total
latency : min 0:00:00.008000000 max 99:99:99.999999999
D/GStreamer+basesink﹕ 0:00:03.336309249 0xab83ca60
gstbasesink.c:1114:gst_base_sink_query_latency:<sink-actual-sink-opensles>
latency query: live: 1, have_latency 1, upstream: 1, min 0:00:00.008000000,
max 99:99:99.999999999
D/GStreamer+basesink﹕ 0:00:03.336462582 0xab83ca60
gstbasesink.c:4337:gst_base_sink_send_event:<sink-actual-sink-opensles>
handling event 0xab83db70 latency event: 0xab83db70, time
99:99:99.999999999, seq-num 54, GstEventLatency, latency=(guint64)408000000;
D/GStreamer+basesink﹕ 0:00:03.336510249 0xab83ca60
gstbasesink.c:4354:gst_base_sink_send_event:<sink-actual-sink-opensles>
latency set to 0:00:00.408000000
D/GStreamer+basesrc﹕ 0:00:03.336596166 0xab83ca60
gstbasesrc.c:1971:gst_base_src_default_event:<source> handle event latency
event: 0xab83db70, time 99:99:99.999999999, seq-num 54, GstEventLatency,
latency=(guint64)408000000;
D/GStreamer+basesink﹕ 0:00:03.336672499 0xab83ca60
gstbasesink.c:4384:gst_base_sink_send_event:<sink-actual-sink-opensles>
handled event 0xab83db70 latency event: 0xab83db70, time 99:99:99.999999999,
seq-num 54, GstEventLatency, latency=(guint64)408000000;: 1
D/GStreamer+basesink﹕ 0:00:03.336834249 0xab83ca60
gstbasesink.c:3251:gst_base_sink_needs_preroll:<sink-actual-sink-opensles>
have_preroll: 1, EOS: 0 => needs preroll: 0
D/GStreamer+basesink﹕ 0:00:03.336873582 0xab83ca60
gstbasesink.c:4940:gst_base_sink_change_state:<sink-actual-sink-opensles>
PAUSED to PLAYING, don't need preroll
D/GStreamer+basesink﹕ 0:00:03.336907582 0xab83ca60
gstbasesink.c:4953:gst_base_sink_change_state:<sink-actual-sink-opensles>
signal preroll
D/GStreamer+basesink﹕ 0:00:03.336962166 0xab829b50
gstbasesink.c:2162:gst_base_sink_wait_preroll:<sink-actual-sink-opensles>
continue after preroll
D/GStreamer+basesink﹕ 0:00:03.337001082 0xab829b50
gstbasesink.c:3416:gst_base_sink_chain_unlocked:<sink-actual-sink-opensles>
rendering object 0xab8421f0
D/GStreamer+basesink﹕ 0:00:03.338454749 0xab829b50
gstbasesink.c:3455:gst_base_sink_chain_unlocked:<sink-actual-sink-opensles>
object unref after render 0xab8421f0
D/GStreamer+basesrc﹕ 0:00:03.338573582 0xab829b50
gstbasesrc.c:2441:gst_base_src_get_range:<source> calling create offset -1
length 4096, time 0
D/GStreamer+hello-gs﹕ 0:00:03.339084582 0xab81c800
jni/hello-gs.c:105:state_changed_cb State changed message: State changed to
PLAYING
I/System.out﹕ Bytes pushed to native code: 128
D/GStreamer+hello-gs﹕ 0:00:03.348741332 0xab847840
jni/hello-gs.c:334:gst_native_push_bytes Pushing buffer of samples:128,
size:128, data: �����
D/GStreamer+appsrc﹕ 0:00:03.348792499 0xab847840
gstappsrc.c:1564:gst_app_src_push_buffer_full:<source> queueing buffer
0xab844d20
D/GStreamer+appsrc﹕ 0:00:03.348862416 0xab829b50
gstappsrc.c:1079:gst_app_src_create:<source> we have buffer 0xab844d20 of
size 128
D/GStreamer+basesrc﹕ 0:00:03.348903999 0xab829b50
gstbasesrc.c:2300:gst_base_src_do_sync:<source> no sync needed
D/GStreamer+basesrc﹕ 0:00:03.348939166 0xab829b50
gstbasesrc.c:2505:gst_base_src_get_range:<source> buffer ok
D/GStreamer+audioresample﹕ 0:00:03.350333332 0xab829b50
gstaudioresample.c:1243:gst_audio_resample_transform:<resample> input =
samples [-1, -1) = [-1, -2) ns;  output = samples [-1, -1) = [0, 8000000) ns
D/GStreamer+basesink﹕ 0:00:03.350449916 0xab829b50
gstbasesink.c:3334:gst_base_sink_chain_unlocked:<sink-actual-sink-opensles>
got times start: 0:00:00.000000000, end: 0:00:00.008000000
D/GStreamer+basesink﹕ 0:00:03.350507916 0xab829b50
gstbasesink.c:1902:gst_base_sink_get_sync_times:<sink-actual-sink-opensles>
got times start: 0:00:00.000000000, stop: 0:00:00.008000000, do_sync 0
D/GStreamer+basesink﹕ 0:00:03.350550082 0xab829b50
gstbasesink.c:3416:gst_base_sink_chain_unlocked:<sink-actual-sink-opensles>
rendering object 0xab842330
D/GStreamer+basesink﹕ 0:00:03.350676332 0xab829b50
gstbasesink.c:3455:gst_base_sink_chain_unlocked:<sink-actual-sink-opensles>
object unref after render 0xab842330
D/GStreamer+basesrc﹕ 0:00:03.350733166 0xab829b50
gstbasesrc.c:2441:gst_base_src_get_range:<source> calling create offset -1
length 4096, time 0
*I/System.out﹕ Bytes pushed to native code: 128
D/GStreamer+hello-gs﹕ 0:00:03.374910832 0xab847840
jni/hello-gs.c:334:gst_native_push_bytes Pushing buffer of samples:192,
size:128, data: �����
D/GStreamer+appsrc﹕ 0:00:03.374961249 0xab847840
gstappsrc.c:1564:gst_app_src_push_buffer_full:<source> queueing buffer
0xab844dc0
D/GStreamer+appsrc﹕ 0:00:03.375100749 0xab829b50
gstappsrc.c:1079:gst_app_src_create:<source> we have buffer 0xab844dc0 of
size 0
D/GStreamer+basesrc﹕ 0:00:03.375151999 0xab829b50
gstbasesrc.c:2300:gst_base_src_do_sync:<source> no sync needed
D/GStreamer+basesrc﹕ 0:00:03.375190999 0xab829b50
gstbasesrc.c:2505:gst_base_src_get_range:<source> buffer ok
I/GStreamer+basesrc﹕ 0:00:03.375259416 0xab829b50
gstbasesrc.c:2841:gst_base_src_loop:<source> pausing after gst_pad_push() =
error
D/GStreamer+basesrc﹕ 0:00:03.375296916 0xab829b50
gstbasesrc.c:2884:gst_base_src_loop:<source> pausing task, reason error
W/GStreamer+basesrc﹕ 0:00:03.375353832 0xab829b50
gstbasesrc.c:2933:gst_base_src_loop:<source> error: Internal data flow
error.
W/GStreamer+basesrc﹕ 0:00:03.375388499 0xab829b50
gstbasesrc.c:2933:gst_base_src_loop:<source> error: streaming task paused,
reason error (-5)*
D/GStreamer+basesink﹕ 0:00:03.375589082 0xab829b50
gstbasesink.c:3334:gst_base_sink_chain_unlocked:<sink-actual-sink-opensles>
got times start: 0:00:00.008000000, end: 0:00:00.016000000
D/GStreamer+basesink﹕ 0:00:03.375646999 0xab829b50
gstbasesink.c:1902:gst_base_sink_get_sync_times:<sink-actual-sink-opensles>
got times start: 0:00:00.008000000, stop: 0:00:00.016000000, do_sync 0
D/GStreamer+basesink﹕ 0:00:03.375688916 0xab829b50
gstbasesink.c:3416:gst_base_sink_chain_unlocked:<sink-actual-sink-opensles>
rendering object 0xab8423d0
D/GStreamer+basesink﹕ 0:00:03.375776416 0xab829b50
gstbasesink.c:3455:gst_base_sink_chain_unlocked:<sink-actual-sink-opensles>
object unref after render 0xab8423d0
D/GStreamer+basesink﹕ 0:00:03.375866332 0xab829b50
gstbasesink.c:3162:gst_base_sink_event:<sink-actual-sink-opensles> received
event 0xab82c6c0 eos event: 0xab82c6c0, time 99:99:99.999999999, seq-num 26,
(NULL)
D/GStreamer+basesink﹕ 0:00:03.375911666 0xab829b50
gstbasesink.c:1854:gst_base_sink_get_sync_times:<sink-actual-sink-opensles>
sync times for EOS 99:99:99.999999999
D/GStreamer+basesink﹕ 0:00:03.375953166 0xab829b50
gstbasesink.c:2308:gst_base_sink_wait:<sink-actual-sink-opensles> checking
preroll
D/GStreamer+basesink﹕ 0:00:03.375995416 0xab829b50
gstbasesink.c:2319:gst_base_sink_wait:<sink-actual-sink-opensles> possibly
waiting for clock to reach 0:00:00.016000000
D/GStreamer+hello-gs﹕ 0:00:03.376133332 0xab81c800
jni/hello-gs.c:120:error_cb Error message received: Error received from
element source: Internal data flow error.
D/GStreamer+basesink﹕ 0:00:03.376428832 0xab81c800
gstbasesink.c:4992:gst_base_sink_change_state:<sink-actual-sink-opensles>
PLAYING to PAUSED
D/GStreamer+basesink﹕ 0:00:03.376468249 0xab81c800
gstbasesink.c:5001:gst_base_sink_change_state:<sink-actual-sink-opensles>
got preroll lock
D/GStreamer+basesink﹕ 0:00:03.376511666 0xab81c800
gstbasesink.c:5012:gst_base_sink_change_state:<sink-actual-sink-opensles>
unschedule clock
D/GStreamer+basesink﹕ 0:00:03.376566999 0xab81c800
gstbasesink.c:3251:gst_base_sink_needs_preroll:<sink-actual-sink-opensles>
have_preroll: 0, EOS: 1 => needs preroll: 0
D/GStreamer+basesink﹕ 0:00:03.376604332 0xab81c800
gstbasesink.c:5019:gst_base_sink_change_state:<sink-actual-sink-opensles>
PLAYING to PAUSED, we are prerolled
D/GStreamer+basesink﹕ 0:00:03.376642416 0xab81c800
gstbasesink.c:5040:gst_base_sink_change_state:<sink-actual-sink-opensles>
rendered: 3, dropped: 0
D/GStreamer+basesrc﹕ 0:00:03.376792082 0xab81c800
gstbasesrc.c:3809:gst_base_src_change_state:<source> PLAYING->PAUSED
D/GStreamer+basesrc﹕ 0:00:03.376832582 0xab81c800
gstbasesrc.c:3629:gst_base_src_set_playing:<source> unlock
D/GStreamer+appsrc﹕ 0:00:03.376865166 0xab81c800
gstappsrc.c:739:gst_app_src_unlock:<source> unlock start
D/GStreamer+basesrc﹕ 0:00:03.376899332 0xab81c800
gstbasesrc.c:3638:gst_base_src_set_playing:<source> unschedule clock
D/GStreamer+basesrc﹕ 0:00:03.376932499 0xab81c800
gstbasesrc.c:3645:gst_base_src_set_playing:<source> live running 0
D/GStreamer+basesink﹕ 0:00:03.377147999 0xab81c800
gstbasesink.c:4026:gst_base_sink_set_flushing:<sink-actual-sink-opensles>
flushing out data thread, need preroll to TRUE
D/GStreamer+basesink﹕ 0:00:03.377253332 0xab829b50
gstbasesink.c:2328:gst_base_sink_wait:<sink-actual-sink-opensles> clock
returned 2
D/GStreamer+basesink﹕ 0:00:03.377289416 0xab829b50
gstbasesink.c:2349:gst_base_sink_wait:<sink-actual-sink-opensles> we are
flushing
D/GStreamer+basesink﹕ 0:00:03.377323499 0xab829b50
gstbasesink.c:3039:gst_base_sink_default_event:<sink-actual-sink-opensles>
Now posting EOS
D/GStreamer+basesink﹕ 0:00:03.377357499 0xab829b50
gstbasesink.c:3042:gst_base_sink_default_event:<sink-actual-sink-opensles>
Got seqnum #26
D/GStreamer+basesink﹕ 0:00:03.377464666 0xab81c800
gstbasesink.c:5079:gst_base_sink_change_state:<sink-actual-sink-opensles>
PAUSED to READY, don't need_preroll
I/System.out﹕ Bytes pushed to native code: 128
D/GStreamer+hello-gs﹕ 0:00:03.383102499 0xab84ed00
jni/hello-gs.c:334:gst_native_push_bytes Pushing buffer of samples:256,
size:128, data: �����
D/GStreamer+appsrc﹕ 0:00:03.383164499 0xab84ed00
gstappsrc.c:1577:gst_app_src_push_buffer_full:<source> refuse buffer
0xab84e410, we are flushing
I/System.out﹕ Bytes pushed to native code: 128
D/GStreamer+hello-gs﹕ 0:00:03.411154999 0xab710f20
jni/hello-gs.c:334:gst_native_push_bytes Pushing buffer of samples:320,
size:128, data:
D/GStreamer+appsrc﹕ 0:00:03.411205999 0xab710f20
gstappsrc.c:1577:gst_app_src_push_buffer_full:<source> refuse buffer
0xab8426f0, we are flushing
I/System.out﹕ Bytes pushed to native code: 128
D/GStreamer+hello-gs﹕ 0:00:03.413887499 0xab847840
jni/hello-gs.c:334:gst_native_push_bytes Pushing buffer of samples:384,
size:128, data: �����
D/GStreamer+appsrc﹕ 0:00:03.413942749 0xab847840
gstappsrc.c:1577:gst_app_src_push_buffer_full:<source> refuse buffer
0xab844e60, we are flushing
D/GStreamer+basesrc﹕ 0:00:03.428764499 0xab81c800
gstbasesrc.c:3757:gst_base_src_activate_mode:<source:src> activating in mode
1
D/GStreamer+basesrc﹕ 0:00:03.428822332 0xab81c800
gstbasesrc.c:3691:gst_base_src_activate_push:<source> Deactivating in push
mode
D/GStreamer+basesrc﹕ 0:00:03.428855832 0xab81c800
gstbasesrc.c:3516:gst_base_src_stop:<source> stopping source
D/GStreamer+basesrc﹕ 0:00:03.428897082 0xab81c800
gstbasesrc.c:3559:gst_base_src_set_flushing:<source> flushing 1, live_play 0
D/GStreamer+appsrc﹕ 0:00:03.428935832 0xab81c800
gstappsrc.c:739:gst_app_src_unlock:<source> unlock start
D/GStreamer+appsrc﹕ 0:00:03.428970249 0xab81c800
gstappsrc.c:754:gst_app_src_unlock_stop:<source> unlock stop
D/GStreamer+appsrc﹕ 0:00:03.429099249 0xab81c800
gstappsrc.c:790:gst_app_src_stop:<source> stopping
W/art﹕ Native thread exiting without having called DetachCurrentThread
(maybe it's going to use a pthread_key_create destructor?):
Thread[21,tid=30806,Native,Thread*=0xab84c5e0,peer=0x12c060e0,"Thread-2569"]
D/GStreamer+hello-gs﹕ 0:00:03.929474665 0xab829b50
jni/hello-gs.c:54:detach_current_thread Detaching thread 0xab829b50

The function that pushes the buffers to my appsrc element is as follows:

static jboolean gst_native_push_bytes(JNIEnv* env, jobject thiz, jbyteArray
byteBuffer, jint size){
  CustomData *data = GET_CUSTOM_DATA (env, thiz, custom_data_field_id);
  if (!data) return JNI_FALSE;

  if(!data->playing){
    GST_DEBUG("ERROR: Pipeline not playing");
    return JNI_FALSE;
  }

  pthread_mutex_lock(&data_lock);
  if(data->push_more_data){
    pthread_mutex_unlock(&data_lock);

    int i=0;
    GstBuffer *buffer;
    GstMapInfo map;
    jbyte *bytes;
    gint num_samples = (int)size / 2;
    GstFlowReturn ret;

    buffer = gst_buffer_new_allocate(NULL,size,NULL);
    /*
    GST_BUFFER_TIMESTAMP (buffer) = gst_util_uint64_scale((unsigned
int)data->num_samples, GST_SECOND, SAMPLE_RATE);
    GST_BUFFER_DURATION (buffer) = gst_util_uint64_scale((unsigned
int)num_samples, GST_SECOND, SAMPLE_RATE);
    */
    gst_buffer_map(buffer,&map,GST_MAP_WRITE);

    bytes = (*env)->GetByteArrayElements(env, byteBuffer, 0);

    memcpy((char*)map.data,bytes,(int)size);

    gst_buffer_unmap(buffer,&map);
    data->num_samples += num_samples;

    GST_DEBUG("Pushing buffer of samples:%u, size:%u, data:
%c%c%c%c%c",(unsigned int)data->num_samples,(unsigned
int)size,bytes[0],bytes[1],bytes[2],bytes[3],bytes[4]);
    ret = gst_app_src_push_buffer(data->source,buffer);

    (*env)->ReleaseByteArrayElements(env, byteBuffer,bytes,JNI_ABORT);
    gst_buffer_unref(buffer);
    if(ret == GST_FLOW_OK){
       return JNI_TRUE;
    }
    return JNI_FALSE;
  }
  pthread_mutex_unlock(&data_lock);
  return JNI_FALSE;
}

And my pipeline setup function is as follows:

static void *app_function (void *cusdata){
    JavaVMAttachArgs args;
    GstBus *bus;
    CustomData *data = (CustomData *)cusdata;
    const char *command = data->command;
    GSource *bus_source;
    GError *error = NULL;
    GstAudioInfo info;
    GstCaps *audio_caps;

    gst_debug_set_threshold_for_name("basesrc", GST_LEVEL_DEBUG);
    gst_debug_set_threshold_for_name("appsrc", GST_LEVEL_DEBUG);
    gst_debug_set_threshold_for_name("basesink", GST_LEVEL_DEBUG);
    gst_debug_set_threshold_for_name("autoaudiosink", GST_LEVEL_DEBUG);
    gst_debug_set_threshold_for_name("audioresample", GST_LEVEL_DEBUG);
    gst_debug_set_threshold_for_name("audioconvert", GST_LEVEL_DEBUG);

    GST_DEBUG ("Started the app function thread with command: %s",command);

    data->context = g_main_context_new();
    g_main_context_push_thread_default(data->context);

    data->source = gst_element_factory_make("appsrc", "source");
    data->convert = gst_element_factory_make("audioconvert", "convert");
    data->resample = gst_element_factory_make("audioresample", "resample");
    data->encoder = gst_element_factory_make("opusenc", "encoder");
    data->decoder = gst_element_factory_make("opusdec", "decoder");
    data->sink = gst_element_factory_make("autoaudiosink","sink");

    /* Create empty pipeline */
    data->pipeline = gst_pipeline_new("opus-pipeline");

   
gst_bin_add_many(GST_BIN(data->pipeline),data->source,data->convert,data->resample,data->encoder,data->decoder,data->sink,
NULL);
    gst_audio_info_set_format(&info, GST_AUDIO_FORMAT_U16LE, SAMPLE_RATE, 1,
NULL);
    audio_caps = gst_audio_info_to_caps(&info);
    guint min_percent = 33;
    g_object_set(data->source,"caps",audio_caps,"format",GST_FORMAT_TIME,
"is-live", TRUE, "block",
FALSE,"max-bytes",512,"min-percent",&min_percent,"do-timestamp", TRUE,
NULL);

    /* Try to link all the elements together */
   
if(!gst_element_link_many(data->source,data->convert,data->resample,data->sink,NULL)){
          g_printerr("Not all elements could be linked\n");
          gst_object_unref(data->pipeline);
          return;
    }

    /*Set callback business */
    bus = gst_element_get_bus(data->pipeline);
    bus_source = gst_bus_create_watch(bus);
    g_source_set_callback(bus_source,(GSourceFunc)
gst_bus_async_signal_func,NULL,NULL);
    g_source_attach (bus_source, data->context);
    g_source_unref(bus_source);
    g_signal_connect (G_OBJECT (bus), "message::error",
G_CALLBACK(error_cb), data);
    g_signal_connect (G_OBJECT (bus), "message::state-changed",
G_CALLBACK(state_changed_cb), data);
    g_signal_connect (data->source, "need-data",
G_CALLBACK(start_requesting_data), data);
    g_signal_connect(data->source, "enough-data",
G_CALLBACK(stop_pushing_data),data);
    gst_object_unref (bus);

    /*Start the pipeline*/
    GST_DEBUG ("Entering main loop... (CustomData:%p)", data);
    data->main_loop = g_main_loop_new (data->context, FALSE);
    check_initialization_complete (data);
    g_main_loop_run (data->main_loop);

    /*Block until the pipeline is stopped*/
    GST_DEBUG ("Exited main loop");
    g_main_loop_unref (data->main_loop);
    data->main_loop = NULL;
}

Any help or anything that stands out from the log file that I'm not noticing
would be greatly appreciated.

Thanks so much, 
Kenny



--
View this message in context: http://gstreamer-devel.966125.n4.nabble.com/Android-appsrc-pipeline-log-assistance-tp4670082.html
Sent from the GStreamer-devel mailing list archive at Nabble.com.


More information about the gstreamer-devel mailing list