Android Internal data flow error + logcat debug
Lee Matthews
lma at spaceapplications.com
Mon May 19 05:25:36 PDT 2014
Thanks Sebastian,
Adding gst_debug_set_threshold_for_name("basesrc", GST_LEVEL_DEBUG); produced a more detailed debug output.
The debug log is as follows :
I/GStreamer(22986): GStreamer initialization complete
W/System.err(22986): java.io.FileNotFoundException: fontconfig/fonts.conf
W/System.err(22986): at android.content.res.AssetManager.openAsset(Native Method)
W/System.err(22986): at android.content.res.AssetManager.open(AssetManager.java:316)
W/System.err(22986): at android.content.res.AssetManager.open(AssetManager.java:290)
W/System.err(22986): at com.gstreamer.GStreamer.copyFile(GStreamer.java:51)
W/System.err(22986): at com.gstreamer.GStreamer.copyFonts(GStreamer.java:31)
W/System.err(22986): at com.gstreamer.GStreamer.init(GStreamer.java:17)
W/System.err(22986): at com.mobinet.mobinetbootapp.MainActivity.onCreate(MainActivity.java:43)
W/System.err(22986): at android.app.Activity.performCreate(Activity.java:5231)
W/System.err(22986): at android.app.Instrumentation.callActivityOnCreate(Instrumentation.java:1087)
W/System.err(22986): at android.app.ActivityThread.performLaunchActivity(ActivityThread.java:2159)
W/System.err(22986): at android.app.ActivityThread.handleLaunchActivity(ActivityThread.java:2245)
W/System.err(22986): at android.app.ActivityThread.access$800(ActivityThread.java:135)
W/System.err(22986): at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1196)
W/System.err(22986): at android.os.Handler.dispatchMessage(Handler.java:102)
W/System.err(22986): at android.os.Looper.loop(Looper.java:136)
W/System.err(22986): at android.app.ActivityThread.main(ActivityThread.java:5017)
W/System.err(22986): at java.lang.reflect.Method.invokeNative(Native Method)
W/System.err(22986): at java.lang.reflect.Method.invoke(Method.java:515)
W/System.err(22986): at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:779)
W/System.err(22986): at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:595)
W/System.err(22986): at dalvik.system.NativeStart.main(Native Method)
D/LOG_TAG (22986): +mobinetStart
D/LOG_TAG (22986): -mobinetStart
D/LOG_TAG (22986): mobinet : init
D/LOG_TAG (22986): Starting mobinet infrastructure
D/LOG_TAG (22986): mobinet : new channel
D/LOG_TAG (22986): mobinet : Registering fd (45) at position 0
D/LOG_TAG (22986): mobinet : main loop
D/LOG_TAG (22986): +audio-sink
D/LOG_TAG (22986): -audio-sink
I/GLib+stdout(22986): +init_pipeline_stream.
D/GStreamer+basesrc(22986): 0:00:00.068806355 0x75638b00 gstbasesrc.c:435:gst_base_src_init:<GstBaseSrc at 0x75842490> creating src pad
D/LOG_TAG (22986): +audio-source
D/GStreamer+basesrc(22986): 0:00:00.069050365 0x75638b00 gstbasesrc.c:438:gst_base_src_init:<GstBaseSrc at 0x75842490> setting functions on src pad
D/GStreamer+basesrc(22986): 0:00:00.069184115 0x75638b00 gstbasesrc.c:446:gst_base_src_init:<GstBaseSrc at 0x75842490> adding src pad
D/LOG_TAG (22986): -audio-source
D/GStreamer+basesrc(22986): 0:00:00.069310990 0x75638b00 gstbasesrc.c:463:gst_base_src_init:<GstBaseSrc at 0x75842490> init done
I/GLib+stdout(22986): +init_pipeline_stream.
D/GStreamer+basesrc(22986): 0:00:00.069545417 0x75638b00 gstbasesrc.c:435:gst_base_src_init:<GstBaseSrc at 0x7594a090> creating src pad
D/GStreamer+basesrc(22986): 0:00:00.069765157 0x75638b00 gstbasesrc.c:438:gst_base_src_init:<GstBaseSrc at 0x7594a090> setting functions on src pad
D/GStreamer+basesrc(22986): 0:00:00.069874011 0x75638b00 gstbasesrc.c:446:gst_base_src_init:<GstBaseSrc at 0x7594a090> adding src pad
D/GStreamer+basesrc(22986): 0:00:00.070030625 0x75638b00 gstbasesrc.c:463:gst_base_src_init:<GstBaseSrc at 0x7594a090> init done
D/GStreamer+basesrc(22986): 0:00:00.070126927 0x7563c9c0 gstbasesrc.c:435:gst_base_src_init:<GstBaseSrc at 0x7594c0e0> creating src pad
D/GStreamer+basesrc(22986): 0:00:00.070956772 0x7563c9c0 gstbasesrc.c:438:gst_base_src_init:<GstBaseSrc at 0x7594c0e0> setting functions on src pad
D/GStreamer+basesrc(22986): 0:00:00.071483386 0x7563c9c0 gstbasesrc.c:446:gst_base_src_init:<GstBaseSrc at 0x7594c0e0> adding src pad
D/GStreamer+basesrc(22986): 0:00:00.071582188 0x7563c9c0 gstbasesrc.c:463:gst_base_src_init:<GstBaseSrc at 0x7594c0e0> init done
I/GLib+stdout(22986): -init_pipeline_stream.
W/libOpenSLES(22986): Leaving Object::GetInterface (SL_RESULT_FEATURE_UNSUPPORTED)
E/GStreamer+opensles_sink(22986): 0:00:00.075455730 0x75638b00 openslessink.c:126:_opensles_query_capabilities:<GstOpenSLESSink at 0x75953f10> engine.GetInterface(IODeviceCapabilities) failed(0x0000000c)
D/AUDIO-SINK(22986): All stream elements created.
I/GLib+stdout(22986): -init_pipeline_stream.
I/GLib+stdout(22986): +config_pipeline_stream.
D/GStreamer+basesrc(22986): 0:00:00.075927449 0x75638b00 gstbasesrc.c:1248:gst_base_src_default_query:<source> query caps returns 1
D/GStreamer+basesrc(22986): 0:00:00.076077292 0x75638b00 gstbasesrc.c:1248:gst_base_src_default_query:<source> query caps returns 1
D/AUDIO-SINK(22986): Elements linked.
I/GLib+stdout(22986): -config_pipeline_stream.
D/LOG_TAG (22986): Starting mobinet infrastructure
D/LOG_TAG (22986): mobinet : Registering fd (54) at position 0
D/LOG_TAG (22986): mobinet : Registering fd (56) at position 1
D/GStreamer+basesrc(22986): 0:00:00.077948855 0x7563c9c0 gstbasesrc.c:435:gst_base_src_init:<GstBaseSrc at 0x7594c380> creating src pad
D/GStreamer+basesrc(22986): 0:00:00.078050625 0x7563c9c0 gstbasesrc.c:438:gst_base_src_init:<GstBaseSrc at 0x7594c380> setting functions on src pad
D/GStreamer+basesrc(22986): 0:00:00.078120209 0x7563c9c0 gstbasesrc.c:446:gst_base_src_init:<GstBaseSrc at 0x7594c380> adding src pad
D/GStreamer+basesrc(22986): 0:00:00.078186823 0x7563c9c0 gstbasesrc.c:463:gst_base_src_init:<GstBaseSrc at 0x7594c380> init done
I/GLib+stdout(22986): -init_pipeline_file.
I/GLib+stdout(22986): +config_pipeline_stream.
D/GStreamer+basesrc(22986): 0:00:00.079505000 0x7563c9c0 gstbasesrc.c:1248:gst_base_src_default_query:<source> query caps returns 1
D/GStreamer+basesrc(22986): 0:00:00.079810573 0x7563c9c0 gstbasesrc.c:1248:gst_base_src_default_query:<source> query caps returns 1
D/GStreamer+basesrc(22986): 0:00:00.080527761 0x7563c9c0 gstbasesrc.c:1248:gst_base_src_default_query:<source> query caps returns 1
D/GStreamer+basesrc(22986): 0:00:00.080833855 0x7563c9c0 gstbasesrc.c:1248:gst_base_src_default_query:<source> query caps returns 1
D/GStreamer+basesrc(22986): 0:00:00.081168595 0x7563c9c0 gstbasesrc.c:1248:gst_base_src_default_query:<source> query caps returns 1
W/GLib+GLib-GObject(22986): g_object_set_valist: object class 'GstOggMux' has no property named 'rate'
W/GLib+GLib-GObject(22986): g_object_set_valist: object class 'GstOggMux' has no property named 'rate'
I/GLib+stdout(22986): -config_pipeline_stream.
I/GLib+stdout(22986): +config_pipeline_file.
D/GStreamer+basesrc(22986): 0:00:00.082872553 0x7563c9c0 gstbasesrc.c:1248:gst_base_src_default_query:<source> query caps returns 1
D/GStreamer+basesrc(22986): 0:00:00.083096147 0x7563c9c0 gstbasesrc.c:1248:gst_base_src_default_query:<source> query caps returns 1
D/GStreamer+basesrc(22986): 0:00:00.083400522 0x7563c9c0 gstbasesrc.c:1248:gst_base_src_default_query:<source> query caps returns 1
D/GStreamer+basesrc(22986): 0:00:00.083715886 0x7563c9c0 gstbasesrc.c:1248:gst_base_src_default_query:<source> query caps returns 1
D/GStreamer+basesrc(22986): 0:00:00.084010938 0x7563c9c0 gstbasesrc.c:1248:gst_base_src_default_query:<source> query caps returns 1
I/GLib+stdout(22986): -config_pipeline_file.
D/LOG_TAG (22986): Starting mobinet infrastructure
D/LOG_TAG (22986): mobinet : Registering fd (62) at position 0
D/LOG_TAG (22986): mobinet : Registering fd (64) at position 1
I/Adreno-EGL(22986): <qeglDrvAPI_eglInitialize:320>: EGL 1.4 QUALCOMM Build: I0404c4692afb8623f95c43aeb6d5e13ed4b30ddbDate: 11/06/13
D/OpenGLRenderer(22986): Enabling debug mode 0
I/ActivityManager( 770): Displayed com.mobinet.mobinetbootapp/.MainActivity: +301ms
D/dalvikvm( 1342): GC_CONCURRENT freed 1435K, 10% free 18415K/20360K, paused 12ms+2ms, total 35ms
D/dalvikvm( 1342): WAIT_FOR_CONCURRENT_GC blocked 2ms
D/LOG_TAG (22986): ++ Accepting Connection on server 0x75965b68
D/LOG_TAG (22986): mobinet : Registering fd (69) at position 1
D/LOG_TAG (22986): Adding client 0x77954730 to server 0x75965b68
D/LOG_TAG (22986): ++ Accepting Connection on server 0x7595a5c0
D/LOG_TAG (22986): mobinet : Registering fd (74) at position 1
D/LOG_TAG (22986): Adding client 0x77954730 to server 0x7595a5c0
D/AUDIO-SINK(22986): START STREAM COMMAND
W/libOpenSLES(22986): Leaving OutputMix::GetDestinationOutputDeviceIDs (SL_RESULT_BUFFER_INSUFFICIENT)
I/GLib+stdout(22986): network :
I/GLib+stdout(22986): gstreamer : Element audiosink changed state from NULL to READY.
D/AUDIO-SINK(22986): gstreamer : Element audiosink changed state from NULL to READY.
I/GLib+stdout(22986): network :
I/GLib+stdout(22986): gstreamer : Element convert changed state from NULL to READY.
D/AUDIO-SINK(22986): gstreamer : Element convert changed state from NULL to READY.
I/GLib+stdout(22986): network :
I/GLib+stdout(22986): gstreamer : Element opus changed state from NULL to READY.
D/AUDIO-SINK(22986): gstreamer : Element opus changed state from NULL to READY.
D/GStreamer+basesrc(22986): 0:00:39.489548944 0x75846d60 gstbasesrc.c:3561:gst_base_src_activate_push:<source> Activating in push mode
I/GLib+stdout(22986): network :
I/GLib+stdout(22986): gstreamer : Element source changed state from NULL to READY.
D/AUDIO-SINK(22986): gstreamer : Element source changed state from NULL to READY.
I/GLib+stdout(22986): network :
I/GLib+stdout(22986): gstreamer : Element audio-stream changed state from NULL to READY.
D/AUDIO-SINK(22986): gstreamer : Element audio-stream changed state from NULL to READY.
I/GLib+stdout(22986): network :
I/GLib+stdout(22986): gstreamer : Element convert changed state from READY to PAUSED.
D/AUDIO-SINK(22986): gstreamer : Element convert changed state from READY to PAUSED.
I/GLib+stdout(22986): network :
I/GLib+stdout(22986): gstreamer : Element opus changed state from READY to PAUSED.
D/AUDIO-SINK(22986): gstreamer : Element opus changed state from READY to PAUSED.
D/GStreamer+basesrc(22986): 0:00:39.521825923 0x75846d60 gstbasesrc.c:3261:gst_base_src_start_complete:<source> starting source
D/GStreamer+basesrc(22986): 0:00:39.522360663 0x75846d60 gstbasesrc.c:3274:gst_base_src_start_complete:<source> setting size -1
D/GStreamer+basesrc(22986): 0:00:39.557699204 0x75846d60 gstbasesrc.c:3285:gst_base_src_start_complete:<source> format: bytes, have size: 0, size: -1, duration: -1
D/GStreamer+basesrc(22986): 0:00:39.557785506 0x75846d60 gstbasesrc.c:3288:gst_base_src_start_complete:<source> is seekable: 0
D/GStreamer+basesrc(22986): 0:00:39.558596548 0x75846d60 gstbasesrc.c:3293:gst_base_src_start_complete:<source> is random_access: 0
D/GStreamer+basesrc(22986): 0:00:39.558814569 0x75846d60 gstbasesrc.c:3442:gst_base_src_set_flushing:<source> flushing 0, live_play 0
D/GStreamer+basesrc(22986): 0:00:39.559071444 0x75846d60 gstbasesrc.c:1533:gst_base_src_perform_seek:<source> doing seek: (NULL)
D/GStreamer+basesrc(22986): 0:00:39.559206704 0x75846d60 gstbasesrc.c:1589:gst_base_src_perform_seek:<source> seek with seqnum 54
D/GStreamer+basesrc(22986): 0:00:39.559853423 0x75846d60 gstbasesrc.c:1626:gst_base_src_perform_seek:<source> segment configured from 0 to -1, position 0
I/GStreamer+basesrc(22986): 0:00:39.560089829 0x75846d60 gstbasesrc.c:1296:gst_base_src_do_seek:<source> seeking: bytes segment start=0, stop=-1, rate=1.000000, applied_rate=1.000000, flags=0x00, time=0, base=0, position 0, duration -1
I/GLib+stdout(22986): network :
I/GLib+stdout(22986): gstreamer : Element src : stream-status message
D/AUDIO-SINK(22986): gstreamer : Element src : stream-status message
D/GStreamer+basesrc(22986): 0:00:39.561296288 0x75846d60 gstbasesrc.c:3388:gst_base_src_start_wait:<source> got ok
I/GLib+stdout(22986): network :
I/GLib+stdout(22986): gstreamer : Element source changed state from READY to PAUSED.
D/AUDIO-SINK(22986): gstreamer : Element source changed state from READY to PAUSED.
D/AUDIO-SINK(22986): Set the pipeline to the playing state
I/GLib+stdout(22986): network :
I/GLib+stdout(22986): gstreamer : Element src : stream-status message
D/AUDIO-SINK(22986): gstreamer : Element src : stream-status message
D/GStreamer+basesrc(22986): 0:00:39.564081600 0x759650c0 gstbasesrc.c:1248:gst_base_src_default_query:<source> query uri returns 0
D/GStreamer+basesrc(22986): 0:00:39.564236236 0x759650c0 gstbasesrc.c:851:gst_base_src_send_stream_start:<source> Pushing STREAM_START
I/GLib+stdout(22986): network :
I/GLib+stdout(22986): gstreamer : Element audio-stream : stream-start message
D/AUDIO-SINK(22986): gstreamer : Element audio-stream : stream-start message
D/GStreamer+basesrc(22986): 0:00:39.565484517 0x759650c0 gstbasesrc.c:3151:gst_base_src_negotiate:<source> starting negotiation
D/GStreamer+basesrc(22986): 0:00:39.565636444 0x759650c0 gstbasesrc.c:1248:gst_base_src_default_query:<source> query caps returns 1
D/GStreamer+basesrc(22986): 0:00:39.565889048 0x759650c0 gstbasesrc.c:3081:gst_base_src_default_negotiate:<source> caps of src: ANY
D/GStreamer+basesrc(22986): 0:00:39.566019100 0x759650c0 gstbasesrc.c:3127:gst_base_src_default_negotiate:<source> no negotiation needed
D/GStreamer+basesrc(22986): 0:00:39.566680923 0x759650c0 gstbasesrc.c:3033:gst_base_src_prepare_allocation:<source> ALLOCATION (1) params: allocation query: 0x778ce400, GstQueryAllocation, caps=(GstCaps)NULL, need-pool=(boolean)true, allocator=(GArray)NULL, pool=(GArray)NULL;
D/GStreamer+basesrc(22986): 0:00:39.566827017 0x759650c0 gstbasesrc.c:2290:gst_base_src_update_length:<source> reading offset 0, length 4096, size -1, segment.stop -1, maxsize -1
D/GStreamer+basesrc(22986): 0:00:39.567100767 0x759650c0 gstbasesrc.c:2388:gst_base_src_get_range:<source> calling create offset 0 length 4096, time 0
D/GStreamer+basesrc(22986): 0:00:39.567775454 0x759650c0 gstbasesrc.c:2432:gst_base_src_get_range:<source> setting first timestamp to 0
D/GStreamer+basesrc(22986): 0:00:39.568026652 0x759650c0 gstbasesrc.c:2247:gst_base_src_do_sync:<source> we have no clock
D/GStreamer+basesrc(22986): 0:00:39.568153527 0x759650c0 gstbasesrc.c:2451:gst_base_src_get_range:<source> buffer ok
I/GStreamer+basesrc(22986): 0:00:39.568716288 0x759650c0 gstbasesrc.c:2772:gst_base_src_loop:<source> marking pending DISCONT
I/GStreamer+basesrc(22986): 0:00:39.568867069 0x759650c0 gstbasesrc.c:2785:gst_base_src_loop:<source> pausing after gst_pad_push() = error
D/GStreamer+basesrc(22986): 0:00:39.569113683 0x759650c0 gstbasesrc.c:2826:gst_base_src_loop:<source> pausing task, reason error
W/GStreamer+basesrc(22986): 0:00:39.569263944 0x759650c0 gstbasesrc.c:2865:gst_base_src_loop:<source> error: Internal data flow error.
W/GStreamer+basesrc(22986): 0:00:39.569893579 0x759650c0 gstbasesrc.c:2865:gst_base_src_loop:<source> error: streaming task paused, reason error (-5)
I/GLib+stdout(22986): network :
I/GLib+stdout(22986): gstreamer : Error: Internal data flow error.
D/AUDIO-SINK(22986): gstreamer : Error: Internal data flow error.
I/GLib+stdout(22986): network :
I/GLib+stdout(22986): gstreamer : Element audiosink changed state from PLAYING to PAUSED.
D/AUDIO-SINK(22986): gstreamer : Element audiosink changed state from PLAYING to PAUSED.
I/GLib+stdout(22986): network :
I/GLib+stdout(22986): gstreamer : Element audiosink changed state from READY to READY.
D/AUDIO-SINK(22986): gstreamer : Element audiosink changed state from READY to READY.
I/GLib+stdout(22986): network :
I/GLib+stdout(22986): gstreamer : Element audiosink changed state from READY to NULL.
D/AUDIO-SINK(22986): gstreamer : Element audiosink changed state from READY to NULL.
I/GLib+stdout(22986): network :
I/GLib+stdout(22986): gstreamer : Element convert changed state from PAUSED to READY.
D/AUDIO-SINK(22986): gstreamer : Element convert changed state from PAUSED to READY.
I/GLib+stdout(22986): network :
I/GLib+stdout(22986): gstreamer : Element convert changed state from READY to NULL.
D/AUDIO-SINK(22986): gstreamer : Element convert changed state from READY to NULL.
I/GLib+stdout(22986): network :
I/GLib+stdout(22986): gstreamer : Element opus changed state from PAUSED to READY.
D/AUDIO-SINK(22986): gstreamer : Element opus changed state from PAUSED to READY.
I/GLib+stdout(22986): network :
I/GLib+stdout(22986): gstreamer : Element opus changed state from READY to NULL.
D/AUDIO-SINK(22986): gstreamer : Element opus changed state from READY to NULL.
D/GStreamer+basesrc(22986): 0:00:39.576026496 0x75638b00 gstbasesrc.c:3569:gst_base_src_activate_push:<source> Deactivating in push mode
D/GStreamer+basesrc(22986): 0:00:39.576316079 0x75638b00 gstbasesrc.c:3399:gst_base_src_stop:<source> stopping source
D/GStreamer+basesrc(22986): 0:00:39.576895402 0x75638b00 gstbasesrc.c:3442:gst_base_src_set_flushing:<source> flushing 1, live_play 0
I/GLib+stdout(22986): network :
I/GLib+stdout(22986): gstreamer : Element src : stream-status message
D/AUDIO-SINK(22986): gstreamer : Element src : stream-status message
I/GLib+stdout(22986): network :
I/GLib+stdout(22986): gstreamer : Element source changed state from PAUSED to READY.
D/AUDIO-SINK(22986): gstreamer : Element source changed state from PAUSED to READY.
--
Thanks.
Lee
----- Original Message -----
From: "Sebastian Dröge" <sebastian at centricular.com>
To: "Discussion of the development of and with GStreamer" <gstreamer-devel at lists.freedesktop.org>
Sent: Friday, 16 May, 2014 8:00:38 PM
Subject: Re: Android Internal data flow error + logcat debug
On Fr, 2014-05-16 at 16:15 +0200, Lee Matthews wrote:
> Hi
>
> I'm trying to read an audio stream from an android phone using gstreamer. My application is based on the gstreamer android tutorials.
>
> My audio pipeline on the phone is
>
> tcpclientsrc ! opusdec ! audioconvert ! openslessink
>
> In logcat I get the following error message.
>
> D/AUDIO-SINK(31971): gstreamer : Element audio-stream : stream-start message
> W/GStreamer+basesrc(31971): 0:00:16.055237494 0x75962ac0 gstbasesrc.c:2865:gst_base_src_loop:<source> error: Internal data flow error.
> W/GStreamer+basesrc(31971): 0:00:16.056187963 0x75962ac0 gstbasesrc.c:2865:gst_base_src_loop:<source> error: streaming task paused, reason error (-5)
> I/GLib+stdout(31971): network :
>
> Does anyone know what is reason error -5 ?
>
> Does anyone know how I can increase the verbosity of the debug information in logcat ? I have tried setting gst_debug_set_default_threshold (GST_LEVEL_DEBUG) just after gst_init but this does not seem to do anything.
Is your code based on the gstreamer_android.c that is generated by the
ndk-build magic included in the GStreamer Android binaries? Please check
if after the gst_init() call there's no other call to
gst_debug_set_default_threshold() than your own.
Also try if calling
gst_debug_set_threshold_for_name("basesrc", GST_LEVEL_DEBUG);
makes any difference. If it does, then some code elsewhere is overriding
the default threshold you set again afterwards.
Hope this helps... apart from that your pipeline should work in theory
and we can only know why not from the debug logs.
--
Sebastian Dröge, Centricular Ltd - http://www.centricular.com
Expertise, Straight from the Source
_______________________________________________
gstreamer-devel mailing list
gstreamer-devel at lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/gstreamer-devel
More information about the gstreamer-devel
mailing list