Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

constant sound stream overrun on win32 with no sound playing #362

Closed
totaam opened this issue Jun 28, 2013 · 25 comments
Closed

constant sound stream overrun on win32 with no sound playing #362

totaam opened this issue Jun 28, 2013 · 25 comments

Comments

@totaam
Copy link
Collaborator

totaam commented Jun 28, 2013

Issue migrated from trac ticket # 362

component: core | priority: major | resolution: fixed

2013-06-28 10:24:53: antoine created the issue

What I believe is happening is that:

  • we buffer too much in appsrc: empty packets compressed will be very small (a few dozen bytes with the compression header)
  • it takes time to setup the pipeline

By the time we are ready to play, we already have more sound data than the queue element is setup for (200ms by default at present) because although the appsrc buffer is small, it is compressed... and once decompressed this data can be quite big (well over 200ms).

Options:

  • maybe adding timestamps to each sound packet would help?
  • increasing the queue buffer size to 500ms seems to help (but this is an ugly workaround..)
  • maybe we could ignore overruns when the pipeline is starting up and use a leaky queue to recover from this situation
@totaam
Copy link
Collaborator Author

totaam commented Jun 30, 2013

2013-06-30 07:04:48: antoine uploaded file drop-early-overruns.patch (4.1 KiB)

should help avoid repeated overruns

@totaam
Copy link
Collaborator Author

totaam commented Jun 30, 2013

2013-06-30 07:06:17: antoine changed owner from antoine to afarr

@totaam
Copy link
Collaborator Author

totaam commented Jun 30, 2013

2013-06-30 07:06:17: antoine commented

Please try the attachment above and let me know if that fixes the issue.

Also note that I was getting reliable hangs on exit (either via control-C or exit from the tray menu) - this should also be fixed in r3741 (and is in 0.9.6 as of 3742)

@totaam
Copy link
Collaborator Author

totaam commented Jul 2, 2013

2013-07-02 23:54:05: afarr changed status from new to closed

@totaam
Copy link
Collaborator Author

totaam commented Jul 2, 2013

2013-07-02 23:54:05: afarr changed resolution from ** to fixed

@totaam
Copy link
Collaborator Author

totaam commented Jul 2, 2013

2013-07-02 23:54:05: afarr commented

With this patch I'm not seeing the constant start/stop of the speakers anymore.

Also had no issues with Control-C exiting or tray disconnecting.

I guess I'll close this ticket.

@totaam
Copy link
Collaborator Author

totaam commented Jul 5, 2013

2013-07-05 10:40:20: antoine commented

afarr: careful with closing tickets, the code had not been committed yet and I could have forgotten about this (had to search for this closed ticket when I encountered this bug again)

Now done in r3777

@totaam
Copy link
Collaborator Author

totaam commented Jul 31, 2013

2013-07-31 11:21:54: antoine commented

  • timestamps were added to packets in r3799
  • a lot more helpful debugging has been added in r4025 and r4027
  • r4027 also goes back to doing a full stop/start cycle, so this should work on win32

It seems that some of the problems we were having were due to:
''set_state() is only problematic when done from the context
of a GStreamer streaming thread (e.g. a signal callback emitted by an
element, a sync bus watch or a pad probe callback or so).'' (found here)

@totaam
Copy link
Collaborator Author

totaam commented Jul 31, 2013

2013-07-31 12:24:04: antoine commented

r4028 should prevent "early overruns": we only ask the server to start sending sound once the client-side pipeline is ready to receive it.

Please let me know if that works for you.

If not, please provide logs, preferably in non-debug mode but with XPRA_SOUND_DEBUG=1

It is also worth trying to see if no-metadata.patch helps (also for osx)

@totaam
Copy link
Collaborator Author

totaam commented Jul 31, 2013

2013-07-31 16:38:54: antoine uploaded file no-metadata.patch (0.7 KiB)

removes metadata from sound packets

@totaam
Copy link
Collaborator Author

totaam commented Jul 31, 2013

2013-07-31 18:44:46: smo commented

Tested with XPRA_SOUND_DEBUG=1 without removing the metadata I will do this next.

You can hear small blips of sound but nothing constant. Debug log is from win32 client.

2013-07-31 10:32:12,236 sound capabilities: [('sound.pulseaudio.id', *), ('sound.decoders', ['mp3', 'wavpack', 'wav', 'flac', 'speex']), ('sound.pygst.version', (0, 10, 20)), ('sound.send', True), ('sound.encoders', ['mp3', 'wavpack', 'wav', 'flac', 'speex']), ('sound.receive', True), ('sound.pulseaudio.server', *), ('sound.gst.version', (0, 10, 31))]
2013-07-31 10:32:12,266 pulseaudio id=, server=, sound decoders=('mp3', 'wavpack', 'wav', 'flac', 'speex'), sound encoders=('mp3', 'wavpack', 'wav', 'flac', 'speex'), receive=True, send=True
2013-07-31 10:32:12,267 start_receiving_sound() sound sink=None
2013-07-31 10:32:12,267 start_sound_sink(mp3)
2013-07-31 10:32:12,267 starting mp3 sound sink
2013-07-31 10:32:12,269 pipeline elements=['appsrc name=src max-bytes=512', 'mp3parse', 'mad', 'audioconvert', 'audioresample', 'queue name=queue min-threshold-time=50000000 max-size-time=450000000 leaky=2', 'directsoundsink']
2013-07-31 10:32:12,269 pipeline=appsrc name=src max-bytes=512 ! mp3parse ! mad ! audioconvert ! audioresample ! queue name=queue min-threshold-time=50000000 max-size-time=450000000 leaky=2 ! directsoundsink
2013-07-31 10:32:12,308 SoundPipeline.start()
2013-07-31 10:32:12,344 SoundPipeline.start() done
2013-07-31 10:32:12,344 sound sink queue underrun: level=0
2013-07-31 10:32:12,344 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:12,345 mp3 sound sink started
2013-07-31 10:32:12,345 Attached to tcp:10.1.32.93:1300 (press Control-C to detach)

2013-07-31 10:32:12,354 state changed: <gst.Message GstMessageState, old-state=(GstState)GST_STATE_NULL, new-state=(GstState)GST_STATE_READY, pending-state=(GstState)GST_STATE_VOID_PENDING; from directsoundsink0 at 02DDFC08>
2013-07-31 10:32:12,355 state changed: <gst.Message GstMessageState, old-state=(GstState)GST_STATE_NULL, new-state=(GstState)GST_STATE_READY, pending-state=(GstState)GST_STATE_VOID_PENDING; from queue at 02DDFBC8>
2013-07-31 10:32:12,355 state changed: <gst.Message GstMessageState, old-state=(GstState)GST_STATE_NULL, new-state=(GstState)GST_STATE_READY, pending-state=(GstState)GST_STATE_VOID_PENDING; from audioresample0 at 02DDFB88>
2013-07-31 10:32:12,355 state changed: <gst.Message GstMessageState, old-state=(GstState)GST_STATE_NULL, new-state=(GstState)GST_STATE_READY, pending-state=(GstState)GST_STATE_VOID_PENDING; from audioconvert0 at 02DDFB48>
2013-07-31 10:32:12,355 state changed: <gst.Message GstMessageState, old-state=(GstState)GST_STATE_NULL, new-state=(GstState)GST_STATE_READY, pending-state=(GstState)GST_STATE_VOID_PENDING; from mad0 at 02DDFB08>
2013-07-31 10:32:12,355 state changed: <gst.Message GstMessageState, old-state=(GstState)GST_STATE_NULL, new-state=(GstState)GST_STATE_READY, pending-state=(GstState)GST_STATE_VOID_PENDING; from mpegaudioparse0 at 02DDFAC8>
2013-07-31 10:32:12,355 state changed: <gst.Message GstMessageState, old-state=(GstState)GST_STATE_NULL, new-state=(GstState)GST_STATE_READY, pending-state=(GstState)GST_STATE_VOID_PENDING; from src at 02DDFA88>
2013-07-31 10:32:12,355 new-state=READY
2013-07-31 10:32:12,355 sound_sink_state_changed(<xpra.sound.sink.SoundSink object at 0x0249C6D0>, ready) on_sink_ready=<function sink_ready at 0x024977B0>
2013-07-31 10:32:12,357 sink_ready(()) codec=mp3
2013-07-31 10:32:12,357 stream status: <gst.Message GstMessageStreamStatus, type=(GstStreamStatusType)GST_STREAM_STATUS_TYPE_CREATE, owner=(GstElement)"\(GstQueue\)\ queue", object=(GstTask)"\(GstTask\)\ queue:src"; from src at 02DDFA08>
2013-07-31 10:32:12,357 state changed: <gst.Message GstMessageState, old-state=(GstState)GST_STATE_READY, new-state=(GstState)GST_STATE_PAUSED, pending-state=(GstState)GST_STATE_VOID_PENDING; from queue at 02DDFC48>
2013-07-31 10:32:12,358 state changed: <gst.Message GstMessageState, old-state=(GstState)GST_STATE_READY, new-state=(GstState)GST_STATE_PAUSED, pending-state=(GstState)GST_STATE_VOID_PENDING; from audioresample0 at 02DDFC88>
2013-07-31 10:32:12,358 state changed: <gst.Message GstMessageState, old-state=(GstState)GST_STATE_READY, new-state=(GstState)GST_STATE_PAUSED, pending-state=(GstState)GST_STATE_VOID_PENDING; from audioconvert0 at 02DDFCC8>
2013-07-31 10:32:12,358 state changed: <gst.Message GstMessageState, old-state=(GstState)GST_STATE_READY, new-state=(GstState)GST_STATE_PAUSED, pending-state=(GstState)GST_STATE_VOID_PENDING; from mad0 at 02DDFD08>
2013-07-31 10:32:12,358 state changed: <gst.Message GstMessageState, old-state=(GstState)GST_STATE_READY, new-state=(GstState)GST_STATE_PAUSED, pending-state=(GstState)GST_STATE_VOID_PENDING; from mpegaudioparse0 at 02DDFD48>
2013-07-31 10:32:12,358 stream status: <gst.Message GstMessageStreamStatus, type=(GstStreamStatusType)GST_STREAM_STATUS_TYPE_CREATE, owner=(GstElement)"\(GstAppSrc\)\ src", object=(GstTask)"\(GstTask\)\ src:src"; from src at 02DDFD88>
2013-07-31 10:32:12,358 state changed: <gst.Message GstMessageState, old-state=(GstState)GST_STATE_READY, new-state=(GstState)GST_STATE_PAUSED, pending-state=(GstState)GST_STATE_VOID_PENDING; from src at 02DDFDC8>
2013-07-31 10:32:12,358 new-state=PAUSED
2013-07-31 10:32:12,358 sound_sink_state_changed(<xpra.sound.sink.SoundSink object at 0x0249C6D0>, paused) on_sink_ready=None
2013-07-31 10:32:12,358 stream status: <gst.Message GstMessageStreamStatus, type=(GstStreamStatusType)GST_STREAM_STATUS_TYPE_ENTER, owner=(GstElement)"\(GstQueue\)\ queue", object=(GstTask)"\(GstTask\)\ queue:src"; from src at 057D5010>
2013-07-31 10:32:12,358 <gst.Message GstMessageNewClock, clock=(GstClock)"\(GstSystemClock\)\ GstSystemClock"; from pipeline0 at 02DDFE48>
2013-07-31 10:32:12,358 stream status: <gst.Message GstMessageStreamStatus, type=(GstStreamStatusType)GST_STREAM_STATUS_TYPE_ENTER, owner=(GstElement)"\(GstAppSrc\)\ src", object=(GstTask)"\(GstTask\)\ src:src"; from src at 057D5310>
2013-07-31 10:32:12,358 state changed: <gst.Message GstMessageState, old-state=(GstState)GST_STATE_PAUSED, new-state=(GstState)GST_STATE_PLAYING, pending-state=(GstState)GST_STATE_VOID_PENDING; from queue at 02DDFE88>
2013-07-31 10:32:12,359 state changed: <gst.Message GstMessageState, old-state=(GstState)GST_STATE_PAUSED, new-state=(GstState)GST_STATE_PLAYING, pending-state=(GstState)GST_STATE_VOID_PENDING; from audioresample0 at 02DDFEC8>
2013-07-31 10:32:12,359 state changed: <gst.Message GstMessageState, old-state=(GstState)GST_STATE_PAUSED, new-state=(GstState)GST_STATE_PLAYING, pending-state=(GstState)GST_STATE_VOID_PENDING; from audioconvert0 at 02DDFF08>
2013-07-31 10:32:12,359 state changed: <gst.Message GstMessageState, old-state=(GstState)GST_STATE_PAUSED, new-state=(GstState)GST_STATE_PLAYING, pending-state=(GstState)GST_STATE_VOID_PENDING; from mad0 at 02DDFF48>
2013-07-31 10:32:12,359 state changed: <gst.Message GstMessageState, old-state=(GstState)GST_STATE_PAUSED, new-state=(GstState)GST_STATE_PLAYING, pending-state=(GstState)GST_STATE_VOID_PENDING; from mpegaudioparse0 at 02DDFF88>
2013-07-31 10:32:12,359 state changed: <gst.Message GstMessageState, old-state=(GstState)GST_STATE_PAUSED, new-state=(GstState)GST_STATE_PLAYING, pending-state=(GstState)GST_STATE_VOID_PENDING; from src at 057D5610>
2013-07-31 10:32:12,543 sound sink: adding 1044 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:12,543 sound sink: new level=0
2013-07-31 10:32:12,543 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:12,545 sound sink: adding 1044 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:12,545 sound sink: new level=0
2013-07-31 10:32:12,545 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:12,575 sound sink: adding 417 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:12,576 sound sink: new level=0
2013-07-31 10:32:12,578 using audio codec: MPEG 1 Audio, Layer 3 (MP3)
2013-07-31 10:32:12,578 duration changed: (<enum GST_FORMAT_TIME of type GstFormat>, -1L)
2013-07-31 10:32:12,578 sound sink: adding 417 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:12,578 sound sink: new level=0
2013-07-31 10:32:12,584 duration changed: (<enum GST_FORMAT_TIME of type GstFormat>, -1L)
2013-07-31 10:32:12,585 duration changed: (<enum GST_FORMAT_TIME of type GstFormat>, -1L)
2013-07-31 10:32:12,585 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:12,586 stream status: <gst.Message GstMessageStreamStatus, type=(GstStreamStatusType)GST_STREAM_STATUS_TYPE_ENTER, owner=(GstElement)"\(GstDirectSoundSink\)\ directsoundsink0", object=(gpointer)NULL; from audiosinkringbuffer0 at 02DDFD08>
2013-07-31 10:32:12,586 state changed: <gst.Message GstMessageState, old-state=(GstState)GST_STATE_READY, new-state=(GstState)GST_STATE_PAUSED, pending-state=(GstState)GST_STATE_VOID_PENDING; from directsoundsink0 at 057D5050>
2013-07-31 10:32:12,588 <gst.Message (none) from pipeline0 at 057D50D0>
2013-07-31 10:32:12,588 sound sink queue underrun: level=26
2013-07-31 10:32:12,588 state changed: <gst.Message GstMessageState, old-state=(GstState)GST_STATE_PAUSED, new-state=(GstState)GST_STATE_PLAYING, pending-state=(GstState)GST_STATE_VOID_PENDING; from directsoundsink0 at 02DDFCC8>
2013-07-31 10:32:12,588 new-state=PLAYING
2013-07-31 10:32:12,589 sound_sink_state_changed(<xpra.sound.sink.SoundSink object at 0x0249C6D0>, active) on_sink_ready=None
2013-07-31 10:32:12,607 sound sink: adding 522 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:12,608 sound sink: new level=26
2013-07-31 10:32:12,609 duration changed: (<enum GST_FORMAT_TIME of type GstFormat>, -1L)
2013-07-31 10:32:12,609 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:12,625 sound sink queue underrun: level=26
2013-07-31 10:32:12,663 sound sink: adding 1044 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:12,663 sound sink: new level=26
2013-07-31 10:32:12,663 duration changed: (<enum GST_FORMAT_TIME of type GstFormat>, -1L)
2013-07-31 10:32:12,664 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:12,664 sound sink queue underrun: level=26
2013-07-31 10:32:12,720 sound sink: adding 417 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:12,720 sound sink: new level=26
2013-07-31 10:32:12,720 duration changed: (<enum GST_FORMAT_TIME of type GstFormat>, -1L)
2013-07-31 10:32:12,721 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:12,721 sound sink: adding 417 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:12,721 sound sink queue underrun: level=26
2013-07-31 10:32:12,723 sound sink: new level=26
2013-07-31 10:32:12,723 duration changed: (<enum GST_FORMAT_TIME of type GstFormat>, -1L)
2013-07-31 10:32:12,723 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:12,723 sound sink queue underrun: level=26
2013-07-31 10:32:12,769 sound sink: adding 417 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:12,770 sound sink: new level=26
2013-07-31 10:32:12,770 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:12,770 sound sink: new level=26
2013-07-31 10:32:12,770 duration changed: (<enum GST_FORMAT_TIME of type GstFormat>, -1L)
2013-07-31 10:32:12,772 duration changed: (<enum GST_FORMAT_TIME of type GstFormat>, -1L)
2013-07-31 10:32:12,772 sound sink queue underrun: level=26
2013-07-31 10:32:12,773 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:12,773 sound sink queue underrun: level=26
2013-07-31 10:32:12,855 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:12,855 sound sink: new level=26
2013-07-31 10:32:12,855 sound sink: adding 313 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:12,855 sound sink: new level=26
2013-07-31 10:32:12,855 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:12,855 sound sink: new level=26
2013-07-31 10:32:12,855 sound sink queue underrun: level=26
2013-07-31 10:32:12,857 duration changed: (<enum GST_FORMAT_TIME of type GstFormat>, -1L)
2013-07-31 10:32:12,858 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:12,858 sound sink queue underrun: level=26
2013-07-31 10:32:12,859 duration changed: (<enum GST_FORMAT_TIME of type GstFormat>, -1L)
2013-07-31 10:32:12,881 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:12,882 sound sink: new level=26
2013-07-31 10:32:12,882 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:12,882 sound sink queue underrun: level=26
2013-07-31 10:32:12,961 sound sink: adding 417 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:12,963 sound sink: new level=26
2013-07-31 10:32:12,963 sound sink: adding 313 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:12,963 sound sink queue underrun: level=26
2013-07-31 10:32:12,963 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:12,966 sound sink: new level=26
2013-07-31 10:32:12,966 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:12,967 sound sink: new level=26
2013-07-31 10:32:12,967 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:12,967 sound sink: new level=26
2013-07-31 10:32:12,967 duration changed: (<enum GST_FORMAT_TIME of type GstFormat>, -1L)
2013-07-31 10:32:12,967 sound sink queue underrun: level=26
2013-07-31 10:32:12,967 sound sink queue underrun: level=26
2013-07-31 10:32:12,967 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:12,967 sound sink queue underrun: level=26
2013-07-31 10:32:12,987 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:12,987 sound sink: new level=26
2013-07-31 10:32:12,989 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:12,989 sound sink queue underrun: level=26
Exception AssertionError: 'AVFrameWrapper falling out of scope before being freed by avcodec!' in <xpra.codecs.dec_avcodec.decoder.AVFrameWrapper object at 0x024A2F80> ignored
2013-07-31 10:32:13,091 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,092 sound sink: new level=26
2013-07-31 10:32:13,092 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,092 sound sink: new level=26
2013-07-31 10:32:13,092 duration changed: (<enum GST_FORMAT_TIME of type GstFormat>, -1L)
2013-07-31 10:32:13,092 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,092 sound sink queue underrun: level=26
2013-07-31 10:32:13,092 sound sink: new level=26
2013-07-31 10:32:13,094 sound sink queue underrun: level=26
2013-07-31 10:32:13,094 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,094 sound sink queue underrun: level=26
Exception AssertionError: 'AVFrameWrapper falling out of scope before being freed by avcodec!' in <xpra.codecs.dec_avcodec.decoder.AVFrameWrapper object at 0x024A8340> ignored
2013-07-31 10:32:13,118 sound sink: adding 417 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,118 sound sink: new level=26
2013-07-31 10:32:13,119 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,119 sound sink queue underrun: level=26
2013-07-31 10:32:13,134 sound sink: adding 417 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,134 sound sink: new level=26
2013-07-31 10:32:13,134 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,134 sound sink queue underrun: level=26
2013-07-31 10:32:13,191 sound sink: adding 417 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,193 sound sink: new level=26
2013-07-31 10:32:13,193 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,193 sound sink: new level=26
Exception AssertionError2013-07-31 10:32:13,193 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
: 'AVFrameWrapper falling out of scope before being freed by avcodec!' in <xpra.codecs.dec_avcodec.decoder.AVFrameWrapper object at 0x024A83E0> ignored
2013-07-31 10:32:13,194 sound sink queue underrun: level=26
2013-07-31 10:32:13,194 sound sink: new level=26
2013-07-31 10:32:13,194 sound sink queue underrun: level=26
2013-07-31 10:32:13,194 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,194 sound sink queue underrun: level=26
2013-07-31 10:32:13,312 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,313 sound sink: new level=26
Exception AssertionError: 'AVFrameWrapper falling out of scope before being freed by avcodec!'2013-07-31 10:32:13,313 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
 in <xpra.codecs.dec_avcodec.decoder.AVFrameWrapper object at 0x024A81A0> ignored
2013-07-31 10:32:13,315 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,315 sound sink queue underrun: level=26
2013-07-31 10:32:13,315 sound sink: new level=26
2013-07-31 10:32:13,315 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,315 sound sink: new level=26
2013-07-31 10:32:13,315 sound sink: adding 313 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,315 sound sink: new level=26
2013-07-31 10:32:13,315 sound sink queue underrun: level=26
2013-07-31 10:32:13,316 duration changed: (<enum GST_FORMAT_TIME of type GstFormat>, -1L)
2013-07-31 10:32:13,316 sound sink queue underrun: level=26
2013-07-31 10:32:13,316 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,316 sound sink queue underrun: level=26
Exception AssertionError: 'AVFrameWrapper falling out of scope before being freed by avcodec!' in <xpra.codecs.dec_avcodec.decoder.AVFrameWrapper object at 0x024A86A0> ignored
2013-07-31 10:32:13,342 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,342 sound sink: new level=26
2013-07-31 10:32:13,342 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,344 sound sink queue underrun: level=26
2013-07-31 10:32:13,431 sound sink: adding 313 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,433 sound sink: new level=26
Exception AssertionError: 'AVFrameWrapper falling out of scope before being freed by avcodec!' in <xpra.codecs.dec_avcodec.decoder.AVFrameWrapper object at 0x024A85C0> ignored
2013-07-31 10:32:13,433 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,433 sound sink: new level=26
2013-07-31 10:32:13,434 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,434 sound sink queue underrun: level=26
2013-07-31 10:32:13,434 sound sink: new level=26
2013-07-31 10:32:13,434 sound sink queue underrun: level=26
2013-07-31 10:32:13,434 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,434 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,434 sound sink queue underrun: level=26
2013-07-31 10:32:13,436 sound sink: new level=26
2013-07-31 10:32:13,438 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,438 sound sink queue underrun: level=26
Exception AssertionError: 'AVFrameWrapper falling out of scope before being freed by avcodec!' in <xpra.codecs.dec_avcodec.decoder.AVFrameWrapper object at 0x024A8180> ignored
2013-07-31 10:32:13,477 sound sink: adding 417 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,479 sound sink: new level=26
2013-07-31 10:32:13,479 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,480 sound sink queue underrun: level=26
2013-07-31 10:32:13,532 sound sink: adding 417 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,532 sound sink: new level=26
Exception AssertionError: 'AVFrameWrapper falling out of scope before being freed by avcodec!' in <xpra.codecs.dec_avcodec.decoder.AVFrameWrapper object at 0x024A8680> ignored
2013-07-31 10:32:13,532 sound sink: adding 417 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,532 sound sink: new level=26
2013-07-31 10:32:13,532 sound sink queue underrun: level=26
2013-07-31 10:32:13,533 sound sink: adding 417 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,533 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,533 sound sink: new level=26
2013-07-31 10:32:13,533 sound sink queue underrun: level=26
2013-07-31 10:32:13,535 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,535 sound sink queue underrun: level=26
2013-07-31 10:32:13,641 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,642 sound sink: new level=26
Exception AssertionError: 'AVFrameWrapper falling out of scope before being freed by avcodec!' in <xpra.codecs.dec_avcodec.decoder.AVFrameWrapper object at 0x024A80A0>2013-07-31 10:32:13,642 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
 ignored
2013-07-31 10:32:13,642 sound sink: new level=26
2013-07-31 10:32:13,642 sound sink: adding 417 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,642 sound sink: new level=52
2013-07-31 10:32:13,644 sound sink: adding 417 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,644 sound sink: new level=52
2013-07-31 10:32:13,644 sound sink queue underrun: level=26
2013-07-31 10:32:13,644 sound sink queue underrun: level=26
2013-07-31 10:32:13,644 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,644 sound sink queue underrun: level=26
Exception AssertionError: 'AVFrameWrapper falling out of scope before being freed by avcodec!' in <xpra.codecs.dec_avcodec.decoder.AVFrameWrapper object at 0x024A83A0> ignored
2013-07-31 10:32:13,680 sound sink: adding 313 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,680 sound sink: new level=26
2013-07-31 10:32:13,680 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,680 sound sink queue underrun: level=26
2013-07-31 10:32:13,742 sound sink: adding 417 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,743 sound sink: new level=26
Exception AssertionError2013-07-31 10:32:13,743 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
: 'AVFrameWrapper falling out of scope before being freed by avcodec!' in <xpra.codecs.dec_avcodec.decoder.AVFrameWrapper object at 0x024A8240> ignored
2013-07-31 10:32:13,743 sound sink: new level=26
2013-07-31 10:32:13,743 sound sink queue underrun: level=26
2013-07-31 10:32:13,743 sound sink: adding 417 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,743 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,743 sound sink queue underrun: level=26
2013-07-31 10:32:13,743 sound sink: new level=26
2013-07-31 10:32:13,744 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,746 sound sink queue underrun: level=26
Exception AssertionError: 'AVFrameWrapper falling out of scope before being freed by avcodec!' in <xpra.codecs.dec_avcodec.decoder.AVFrameWrapper object at 0x024A8100> ignored
2013-07-31 10:32:13,789 sound sink: adding 417 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,789 sound sink: new level=26
2013-07-31 10:32:13,789 sound sink queue underrun: level=26
2013-07-31 10:32:13,789 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,862 sound sink: adding 417 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,862 sound sink: new level=26
Exception 2013-07-31 10:32:13,862 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
AssertionError: 'AVFrameWrapper falling out of scope before being freed by avcodec!' in <xpra.codecs.dec_avcodec.decoder.AVFrameWrapper object at 0x024A8700> ignored
2013-07-31 10:32:13,864 sound sink: new level=26
2013-07-31 10:32:13,864 sound sink queue underrun: level=26
2013-07-31 10:32:13,864 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,865 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,865 sound sink queue underrun: level=26
2013-07-31 10:32:13,865 sound sink: new level=26
2013-07-31 10:32:13,865 duration changed: (<enum GST_FORMAT_TIME of type GstFormat>, -1L)
2013-07-31 10:32:13,865 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,865 sound sink queue underrun: level=26
Exception AssertionError: 'AVFrameWrapper falling out of scope before being freed by avcodec!' in <xpra.codecs.dec_avcodec.decoder.AVFrameWrapper object at 0x024A86A0> ignored
2013-07-31 10:32:13,891 sound sink: adding 313 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,891 sound sink: new level=26
2013-07-31 10:32:13,897 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,897 sound sink queue underrun: level=26
2013-07-31 10:32:13,982 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,983 sound sink: new level=26
Exception AssertionError: 'AVFrameWrapper falling out of scope before being freed by avcodec!' in <xpra.codecs.dec_avcodec.decoder.AVFrameWrapper object at 0x024A82E0> ignored
2013-07-31 10:32:13,983 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,983 sound sink: new level=52
2013-07-31 10:32:13,983 sound sink queue underrun: level=26
2013-07-31 10:32:13,983 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,983 sound sink: new level=26
2013-07-31 10:32:13,983 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,983 sound sink queue underrun: level=26
2013-07-31 10:32:13,983 sound sink: new level=26
2013-07-31 10:32:13,984 sound sink queue underrun: level=26
2013-07-31 10:32:13,984 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:13,984 sound sink queue underrun: level=26
Exception AssertionError: 'AVFrameWrapper falling out of scope before being freed by avcodec!' in <xpra.codecs.dec_avcodec.decoder.AVFrameWrapper object at 0x024A81E0> ignored
2013-07-31 10:32:14,029 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,029 sound sink: new level=26
2013-07-31 10:32:14,029 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,029 sound sink queue underrun: level=26
2013-07-31 10:32:14,111 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,112 sound sink: new level=26
2013-07-31 10:32:14,112 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
Exception AssertionError: 'AVFrameWrapper falling out of scope before being freed by avcodec!' in <xpra.codecs.dec_avcodec.decoder.AVFrameWrapper object at 0x024A8620> ignored
2013-07-31 10:32:14,112 sound sink: new level=26
2013-07-31 10:32:14,112 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,112 sound sink queue underrun: level=26
2013-07-31 10:32:14,114 sound sink: new level=26
2013-07-31 10:32:14,114 sound sink queue underrun: level=26
2013-07-31 10:32:14,114 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,115 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,115 sound sink queue underrun: level=26
2013-07-31 10:32:14,115 sound sink: new level=26
2013-07-31 10:32:14,118 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,118 sound sink queue underrun: level=26
Exception AssertionError: 'AVFrameWrapper falling out of scope before being freed by avcodec!' in <xpra.codecs.dec_avcodec.decoder.AVFrameWrapper object at 0x024A8580> ignored
2013-07-31 10:32:14,157 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,158 sound sink: new level=26
2013-07-31 10:32:14,160 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,160 sound sink queue underrun: level=26
2013-07-31 10:32:14,211 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,211 sound sink: new level=26
Exception 2013-07-31 10:32:14,213 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
AssertionError: 'AVFrameWrapper falling out of scope before being freed by avcodec!' in <xpra.codecs.dec_avcodec.decoder.AVFrameWrapper object at 0x024A85C0> ignored
2013-07-31 10:32:14,213 sound sink: new level=26
2013-07-31 10:32:14,213 sound sink queue underrun: level=26
2013-07-31 10:32:14,213 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,213 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,213 sound sink queue underrun: level=26
2013-07-31 10:32:14,213 sound sink: new level=26
2013-07-31 10:32:14,214 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,214 sound sink queue underrun: level=26
2013-07-31 10:32:14,322 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,322 sound sink: new level=26
Exception 2013-07-31 10:32:14,322 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
AssertionError: 'AVFrameWrapper falling out of scope before being freed by avcodec!' in <xpra.codecs.dec_avcodec.decoder.AVFrameWrapper object at 0x024A8540> ignored
2013-07-31 10:32:14,322 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,323 sound sink: new level=26
2013-07-31 10:32:14,323 sound sink queue underrun: level=26
2013-07-31 10:32:14,323 sound sink: adding 313 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,325 sound sink: new level=26
2013-07-31 10:32:14,325 sound sink queue underrun: level=26
2013-07-31 10:32:14,325 sound sink: adding 417 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,325 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,325 sound sink: new level=26
2013-07-31 10:32:14,325 sound sink queue underrun: level=26
2013-07-31 10:32:14,328 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,328 sound sink queue underrun: level=26
Exception AssertionError: 'AVFrameWrapper falling out of scope before being freed by avcodec!' in <xpra.codecs.dec_avcodec.decoder.AVFrameWrapper object at 0x024A80E0> ignored
2013-07-31 10:32:14,365 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,365 sound sink: new level=26
2013-07-31 10:32:14,367 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,367 sound sink queue underrun: level=26
Exception 2013-07-31 10:32:14,411 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
AssertionError: 'AVFrameWrapper falling out of scope before being freed by avcodec!' in <xpra.codecs.dec_avcodec.decoder.AVFrameWrapper object at 0x024A8500> ignored
2013-07-31 10:32:14,411 sound sink: new level=26
2013-07-31 10:32:14,411 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,411 sound sink: new level=26
2013-07-31 10:32:14,413 sound sink queue underrun: level=26
2013-07-31 10:32:14,413 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,413 sound sink queue underrun: level=26
2013-07-31 10:32:14,434 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,434 sound sink: new level=26
2013-07-31 10:32:14,434 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,434 sound sink queue underrun: level=26
Exception AssertionError: 'AVFrameWrapper falling out of scope before being freed by avcodec!' in 2013-07-31 10:32:14,503 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
<xpra.codecs.dec_avcodec.decoder.AVFrameWrapper object at 0x024A84C0> ignored
2013-07-31 10:32:14,503 sound sink: new level=26
2013-07-31 10:32:14,503 sound sink: adding 417 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,503 sound sink: new level=26
2013-07-31 10:32:14,503 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,503 sound sink: new level=26
2013-07-31 10:32:14,503 sound sink queue underrun: level=26
2013-07-31 10:32:14,503 sound sink queue underrun: level=26
2013-07-31 10:32:14,505 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,505 sound sink queue underrun: level=26
Exception AssertionError: 'AVFrameWrapper falling out of scope before being freed by avcodec!' in <xpra.codecs.dec_avcodec.decoder.AVFrameWrapper object at 0x024A8380> ignored
Exception AssertionError: 'AVFrameWrapper falling out of scope before being freed by avcodec!' in <xpra.codecs.dec_avcodec.decoder.AVFrameWrapper object at 0x024A8700> ignored
2013-07-31 10:32:14,549 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,549 sound sink: new level=26
2013-07-31 10:32:14,553 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,553 sound sink queue underrun: level=26
2013-07-31 10:32:14,562 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,562 sound sink: new level=26
2013-07-31 10:32:14,563 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,563 sound sink queue underrun: level=26
2013-07-31 10:32:14,651 sound sink: adding 313 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,653 sound sink: new level=26
Exception 2013-07-31 10:32:14,653 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
AssertionError: 'AVFrameWrapper falling out of scope before being freed by avcodec!' in <xpra.codecs.dec_avcodec.decoder.AVFrameWrapper object at 0x024A84A0> ignored
2013-07-31 10:32:14,653 sound sink: new level=26
2013-07-31 10:32:14,654 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,654 sound sink queue underrun: level=26
2013-07-31 10:32:14,654 sound sink: new level=26
2013-07-31 10:32:14,654 sound sink queue underrun: level=26
2013-07-31 10:32:14,654 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,654 sound sink queue underrun: level=26
Exception AssertionError: 'AVFrameWrapper falling out of scope before being freed by avcodec!' in <xpra.codecs.dec_avcodec.decoder.AVFrameWrapper object at 0x024A8440> ignored
2013-07-31 10:32:14,680 sound sink: adding 417 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,681 sound sink: new level=26
2013-07-31 10:32:14,687 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,687 sound sink queue underrun: level=26
2013-07-31 10:32:14,694 sound sink: adding 313 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,694 sound sink: new level=26
2013-07-31 10:32:14,696 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,696 sound sink queue underrun: level=26
2013-07-31 10:32:14,756 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,756 sound sink: new level=26
2013-07-31 10:32:14,757 sound sink: adding 417 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
Exception AssertionError: 'AVFrameWrapper falling out of scope before being freed by avcodec!' in <xpra.codecs.dec_avcodec.decoder.AVFrameWrapper object at 0x024A81E0> ignored
2013-07-31 10:32:14,757 sound sink: new level=26
2013-07-31 10:32:14,757 sound sink queue underrun: level=26
2013-07-31 10:32:14,757 sound sink: adding 417 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,759 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,759 sound sink queue underrun: level=26
2013-07-31 10:32:14,759 sound sink: new level=26
2013-07-31 10:32:14,759 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,759 sound sink queue underrun: level=26
2013-07-31 10:32:14,867 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,867 sound sink: new level=26
Exception AssertionError: 'AVFrameWrapper falling out of scope before being freed by avcodec!'2013-07-31 10:32:14,867 sound sink: adding 417 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
 in <xpra.codecs.dec_avcodec.decoder.AVFrameWrapper object at 0x024A8240> ignored
2013-07-31 10:32:14,868 sound sink: new level=52
2013-07-31 10:32:14,868 sound sink queue underrun: level=26
2013-07-31 10:32:14,868 sound sink: adding 417 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,868 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,868 sound sink queue underrun: level=26
2013-07-31 10:32:14,868 sound sink: new level=26
2013-07-31 10:32:14,868 sound sink: adding 365 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,868 sound sink: new level=26
2013-07-31 10:32:14,869 sound sink queue underrun: level=26
2013-07-31 10:32:14,869 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,869 sound sink queue underrun: level=26
Exception AssertionError: 'AVFrameWrapper falling out of scope before being freed by avcodec!' in <xpra.codecs.dec_avcodec.decoder.AVFrameWrapper object at 0x024A8740> ignored
2013-07-31 10:32:14,904 sound sink: adding 417 bytes to /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,904 sound sink: new level=26
2013-07-31 10:32:14,905 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:14,905 sound sink queue underrun: level=26

got signal SIGINT, exiting
2013-07-31 10:32:14,967 connection closed after 142 packets received (0.7M bytes) and 55 packets sent (14K bytes)
2013-07-31 10:32:14,970 stop_receiving_sound() sound sink=<xpra.sound.sink.SoundSink object at 0x0249C6D0>
2013-07-31 10:32:14,971 UIXpraClient.stop_receiving_sound_thread()
2013-07-31 10:32:14,971 SoundPipeline.cleanup()
2013-07-31 10:32:14,971 SoundPipeline.stop()
2013-07-31 10:32:15,026 need_data: 4096 bytes in /GstPipeline:pipeline0/GstAppSrc:src (__main__.GstAppSrc)
2013-07-31 10:32:15,032 SoundPipeline.stop() done
2013-07-31 10:32:15,033 SoundPipeline.cleanup() done
2013-07-31 10:32:15,033 stop_receiving_sound() sound sink=None
2013-07-31 10:32:15,033 UIXpraClient.stop_receiving_sound_thread() done
2013-07-31 10:32:15,076 speaker is now disabled - dropping packet
2013-07-31 10:32:15,076 speaker is now disabled - dropping packet
2013-07-31 10:32:15,078 Connection lost

@totaam
Copy link
Collaborator Author

totaam commented Jul 31, 2013

2013-07-31 18:55:03: smo commented

Tried with win32 with [/attachment/ticket/362/no-metadata.patch]

No change. Same behavior as the previous comment.

@totaam
Copy link
Collaborator Author

totaam commented Aug 1, 2013

2013-08-01 10:39:44: antoine commented

Argh, well, we don't have any overruns now but we have underruns instead... because we only start pushing buffers when the pipeline is ready to take them, and so it doesn't have time to buffer anything. On some machines/platforms the output device buffer will have enough so this is not a problem, but on others... you get very jittery sound (stops and starts dozens of times per second)
I think it is best to find a way to also deal with the underruns rather than going back to what we had before, which only worked when the pipeline took long enough to setup to avoid underruns.

@totaam
Copy link
Collaborator Author

totaam commented Aug 1, 2013

2013-08-01 14:58:08: antoine uploaded file sound-underrun.patch (13.6 KiB)

ugly patch which fixes win32 and maybe even osx, but breaks linux.. ffs

@totaam
Copy link
Collaborator Author

totaam commented Aug 1, 2013

2013-08-01 15:34:03: antoine commented

Many many hours later... I thought I had it fixed, but see the patch above: it broke Linux support.

@totaam
Copy link
Collaborator Author

totaam commented Aug 1, 2013

2013-08-01 17:03:48: antoine changed status from closed to reopened

@totaam
Copy link
Collaborator Author

totaam commented Aug 1, 2013

2013-08-01 17:03:48: antoine changed resolution from fixed to **

@totaam
Copy link
Collaborator Author

totaam commented Aug 1, 2013

2013-08-01 17:03:48: antoine commented

Please try r4040 (and also on Linux to make sure I haven't broken it)

@totaam
Copy link
Collaborator Author

totaam commented Aug 1, 2013

2013-08-01 17:04:00: antoine changed status from reopened to new

@totaam
Copy link
Collaborator Author

totaam commented Aug 1, 2013

2013-08-01 17:04:00: antoine changed owner from afarr to SmO

@totaam
Copy link
Collaborator Author

totaam commented Aug 1, 2013

2013-08-01 20:12:02: smo commented

I've tried r4040 on 2 different machines running windows 7. So far the sound is working great.

I have not tested this on linux since my desktop is ubuntu 13.04 it can be troublesome to build.

@totaam
Copy link
Collaborator Author

totaam commented Aug 2, 2013

2013-08-02 06:57:46: totaam commented

OK, please stress test on all platforms available by lowering XPRA_SOUND_QUEUE_TIME (anything below 150 should trigger overruns reliably)

Then close this ticket for 0.10, remaining sound work items are now in #400

@totaam
Copy link
Collaborator Author

totaam commented Aug 5, 2013

2013-08-05 23:36:47: smo changed status from new to closed

@totaam
Copy link
Collaborator Author

totaam commented Aug 5, 2013

2013-08-05 23:36:47: smo changed resolution from ** to fixed

@totaam
Copy link
Collaborator Author

totaam commented Aug 5, 2013

2013-08-05 23:36:47: smo commented

Tested with lower XPRA_SOUND_QUEUE_TIME < 150

On windows 7 and linux (fedora 19) with no issues.

@totaam totaam closed this as completed Aug 5, 2013
This was referenced Jan 22, 2021
Closed
Closed
Closed
Closed
@totaam totaam mentioned this issue Jan 22, 2021
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@totaam