Hi Daniel,

Apologies for the delay in getting back to you - takes a while for me
to find a time where I can reboot a lot!

> > I'm just trying to work out whether this is unique to my system or
> > whether there has been an alsa-lib change and the plugin needs
> > updating.
> 
> Sorry, this got caught in my spam filter for some reason.

All the list e-mails get stuck in my spam filter, because the mailing
list adds a footer onto the bottom of each message.  This causes the
DKIM signature to fail verification so it gets flagged as spam.  I
think the only way to fix this is to change the mailing list so that it
doesn't append a footer or otherwise modify message content.

> Do you have the ability to try the kernel you were on before your
> current one? IIRC Debian keeps the old one in grub for at least one
> upgrade. Buggy ALSA kernel-side is not uncommon.

I'm on Arch Linux and I did have my old kernel still available, so I
have gone back to that (3.18) and the problem still exists there.  So
it must be some other piece of software on my system causing it.  I
tried reverting alsa-lib to the previous version I was using as well,
but that didn't change anything either.

Since my last post I have upgraded my work PC which is also running
Arch Linux, and it does not have the problem.  The main difference
between these two machines is that they have different chips providing
the intel-hda audio interface, but otherwise they are the same
architecture and similar CPU generation.

> Could you try this via the pulse backend and see if the problem
> traverses pulse as well?

Confirming exact same behaviour with pulse output plugin.  However, not
using Pulseaudio normally, I got this warning when loading the PA server:

E: [alsa-source-ALC892 Analog] alsa-util.c: snd_pcm_avail_delay() returned 
strange values: delay 0 is less than avail 4.
E: [alsa-source-ALC892 Analog] alsa-util.c: Most likely this is a bug in the 
ALSA driver 'snd_hda_intel'. Please report this issue to the ALSA developers.
E: [alsa-source-ALC892 Analog] alsa-util.c: snd_pcm_dump():
E: [alsa-source-ALC892 Analog] alsa-util.c: Direct Snoop PCM
E: [alsa-source-ALC892 Analog] alsa-util.c: Its setup is:
E: [alsa-source-ALC892 Analog] alsa-util.c:   stream       : CAPTURE
E: [alsa-source-ALC892 Analog] alsa-util.c:   access       : MMAP_INTERLEAVED
E: [alsa-source-ALC892 Analog] alsa-util.c:   format       : S32_LE
E: [alsa-source-ALC892 Analog] alsa-util.c:   subformat    : STD
E: [alsa-source-ALC892 Analog] alsa-util.c:   channels     : 2
E: [alsa-source-ALC892 Analog] alsa-util.c:   rate         : 48000
E: [alsa-source-ALC892 Analog] alsa-util.c:   exact rate   : 48000 (48000/1)
E: [alsa-source-ALC892 Analog] alsa-util.c:   msbits       : 32
E: [alsa-source-ALC892 Analog] alsa-util.c:   buffer_size  : 16384
E: [alsa-source-ALC892 Analog] alsa-util.c:   period_size  : 1024
E: [alsa-source-ALC892 Analog] alsa-util.c:   period_time  : 21333
E: [alsa-source-ALC892 Analog] alsa-util.c:   tstamp_mode  : ENABLE
E: [alsa-source-ALC892 Analog] alsa-util.c:   period_step  : 1
E: [alsa-source-ALC892 Analog] alsa-util.c:   avail_min    : 15943
E: [alsa-source-ALC892 Analog] alsa-util.c:   period_event : 0
E: [alsa-source-ALC892 Analog] alsa-util.c:   start_threshold  : -1
E: [alsa-source-ALC892 Analog] alsa-util.c:   stop_threshold   : 
4611686018427387904
E: [alsa-source-ALC892 Analog] alsa-util.c:   silence_threshold: 0
E: [alsa-source-ALC892 Analog] alsa-util.c:   silence_size : 0
E: [alsa-source-ALC892 Analog] alsa-util.c:   boundary     : 4611686018427387904
E: [alsa-source-ALC892 Analog] alsa-util.c: Hardware PCM card 1 'HDA Intel PCH' 
device 0 subdevice 0
E: [alsa-source-ALC892 Analog] alsa-util.c: Its setup is:
E: [alsa-source-ALC892 Analog] alsa-util.c:   stream       : CAPTURE
E: [alsa-source-ALC892 Analog] alsa-util.c:   access       : MMAP_INTERLEAVED
E: [alsa-source-ALC892 Analog] alsa-util.c:   format       : S32_LE
E: [alsa-source-ALC892 Analog] alsa-util.c:   subformat    : STD
E: [alsa-source-ALC892 Analog] alsa-util.c:   channels     : 2
E: [alsa-source-ALC892 Analog] alsa-util.c:   rate         : 48000
E: [alsa-source-ALC892 Analog] alsa-util.c:   exact rate   : 48000 (48000/1)
E: [alsa-source-ALC892 Analog] alsa-util.c:   msbits       : 32
E: [alsa-source-ALC892 Analog] alsa-util.c:   buffer_size  : 16384
E: [alsa-source-ALC892 Analog] alsa-util.c:   period_size  : 1024
E: [alsa-source-ALC892 Analog] alsa-util.c:   period_time  : 21333
E: [alsa-source-ALC892 Analog] alsa-util.c:   tstamp_mode  : ENABLE
E: [alsa-source-ALC892 Analog] alsa-util.c:   period_step  : 1
E: [alsa-source-ALC892 Analog] alsa-util.c:   avail_min    : 1024
E: [alsa-source-ALC892 Analog] alsa-util.c:   period_event : 0
E: [alsa-source-ALC892 Analog] alsa-util.c:   start_threshold  : 1
E: [alsa-source-ALC892 Analog] alsa-util.c:   stop_threshold   : 
4611686018427387904
E: [alsa-source-ALC892 Analog] alsa-util.c:   silence_threshold: 0
E: [alsa-source-ALC892 Analog] alsa-util.c:   silence_size : 0
E: [alsa-source-ALC892 Analog] alsa-util.c:   boundary     : 4611686018427387904
E: [alsa-source-ALC892 Analog] alsa-util.c:   appl_ptr     : 0
E: [alsa-source-ALC892 Analog] alsa-util.c:   hw_ptr       : 8236

I'm not quite sure what this means, but I'll report it to the ALSA devs
anyway.

In case it helps, here is a backtrace of all xmms2d threads at the
point where the end of the track has been reached and playback has
stopped.  At this point "xmms2 status" shows the playback time stuck
at the last second, e.g. "1:23 of 1:23".

Pressing Ctrl+C on the daemon causes it to begin to exit but it never
terminates unless I press Ctrl+C a second time, making me suspect a
deadlock somewhere.  Seeing all the threads below stuck in
poll/wait/syscall states seems to confirm this.

Here's the backtrace:

(gdb) thr 1
#0  0x00007ffff70e4e8d in poll () from /usr/lib/libc.so.6
#1  0x00007ffff7812c7c in ?? () from /usr/lib/libglib-2.0.so.0
#2  0x00007ffff7813002 in g_main_loop_run () from /usr/lib/libglib-2.0.so.0
#3  0x000000000040eb15 in main (argc=1, argv=0x7fffffffe108) at 
../src/xmms/main.c:737
(gdb) thr 2
#0  0x00007ffff70e4e8d in poll () from /usr/lib/libc.so.6
#1  0x00007ffff7812c7c in ?? () from /usr/lib/libglib-2.0.so.0
#2  0x00007ffff7813002 in g_main_loop_run () from /usr/lib/libglib-2.0.so.0
#3  0x0000000000427f30 in xmms_ipc_client_thread (data=0x55b6da0) at 
../src/xmms/ipc.c:381
#4  0x00007ffff7839625 in ?? () from /usr/lib/libglib-2.0.so.0
#5  0x00007ffff73af354 in start_thread () from /usr/lib/libpthread.so.0
#6  0x00007ffff70edbfd in clone () from /usr/lib/libc.so.6
(gdb) thr 3
#0  0x00007ffff70e4e8d in poll () from /usr/lib/libc.so.6
#1  0x00007ffff7812c7c in ?? () from /usr/lib/libglib-2.0.so.0
#2  0x00007ffff7813002 in g_main_loop_run () from /usr/lib/libglib-2.0.so.0
#3  0x0000000000427f30 in xmms_ipc_client_thread (data=0x55b6f30) at 
../src/xmms/ipc.c:381
#4  0x00007ffff7839625 in ?? () from /usr/lib/libglib-2.0.so.0
#5  0x00007ffff73af354 in start_thread () from /usr/lib/libpthread.so.0
#6  0x00007ffff70edbfd in clone () from /usr/lib/libc.so.6
(gdb) thr 4
#0  0x00007ffff70e4e8d in poll () from /usr/lib/libc.so.6
#1  0x00007ffff7812c7c in ?? () from /usr/lib/libglib-2.0.so.0
#2  0x00007ffff7813002 in g_main_loop_run () from /usr/lib/libglib-2.0.so.0
#3  0x0000000000427f30 in xmms_ipc_client_thread (data=0x55b76d0) at 
../src/xmms/ipc.c:381
#4  0x00007ffff7839625 in ?? () from /usr/lib/libglib-2.0.so.0
#5  0x00007ffff73af354 in start_thread () from /usr/lib/libpthread.so.0
#6  0x00007ffff70edbfd in clone () from /usr/lib/libc.so.6
(gdb) thr 5
#0  0x00007ffff70e4e8d in poll () from /usr/lib/libc.so.6
#1  0x00007ffff7812c7c in ?? () from /usr/lib/libglib-2.0.so.0
#2  0x00007ffff7813002 in g_main_loop_run () from /usr/lib/libglib-2.0.so.0
#3  0x0000000000427f30 in xmms_ipc_client_thread (data=0x55b8930) at 
../src/xmms/ipc.c:381
#4  0x00007ffff7839625 in ?? () from /usr/lib/libglib-2.0.so.0
#5  0x00007ffff73af354 in start_thread () from /usr/lib/libpthread.so.0
#6  0x00007ffff70edbfd in clone () from /usr/lib/libc.so.6
(gdb) thr 6
#0  0x00007ffff73b83b7 in do_sigwait () from /usr/lib/libpthread.so.0
#1  0x00007ffff73b842d in sigwait () from /usr/lib/libpthread.so.0
#2  0x00000000004396f0 in sigwaiter (data=0x6b7c00) at 
../src/xmms/compat/signal_unix.c:52
#3  0x00007ffff7839625 in ?? () from /usr/lib/libglib-2.0.so.0
#4  0x00007ffff73af354 in start_thread () from /usr/lib/libpthread.so.0
#5  0x00007ffff70edbfd in clone () from /usr/lib/libc.so.6
(gdb) thr 7
#0  0x00007ffff73b7f1d in nanosleep () from /usr/lib/libpthread.so.0
#1  0x00007ffff783ac58 in g_usleep () from /usr/lib/libglib-2.0.so.0
#2  0x000000000041d36c in xmms_output_monitor_volume_thread (data=0x3dc43d0) at 
../src/xmms/output.c:1228
#3  0x00007ffff7839625 in ?? () from /usr/lib/libglib-2.0.so.0
#4  0x00007ffff73af354 in start_thread () from /usr/lib/libpthread.so.0
#5  0x00007ffff70edbfd in clone () from /usr/lib/libc.so.6
(gdb) thr 8
#0  0x00007ffff70e9939 in syscall () from /usr/lib/libc.so.6
#1  0x00007ffff785755f in g_cond_wait () from /usr/lib/libglib-2.0.so.0
#2  0x000000000042c6eb in xmms_ringbuf_wait_used (ringbuf=0x5ed70d0, len=4096, 
mtx=0x3dc4430) at ../src/xmms/ringbuf.c:407
#3  0x000000000041b9cb in xmms_output_read (output=0x3dc43d0, 
buffer=0x7fffcd48af20 "", len=4096) at ../src/xmms/output.c:535
#4  0x00000000004339cd in xmms_output_plugin_writer (data=0x7994c0) at 
../src/xmms/outputplugin.c:453
#5  0x00007ffff7839625 in ?? () from /usr/lib/libglib-2.0.so.0
#6  0x00007ffff73af354 in start_thread () from /usr/lib/libpthread.so.0
#7  0x00007ffff70edbfd in clone () from /usr/lib/libc.so.6
(gdb) thr 9
#0  0x00007ffff70e9939 in syscall () from /usr/lib/libc.so.6
#1  0x00007ffff785755f in g_cond_wait () from /usr/lib/libglib-2.0.so.0
#2  0x000000000042c610 in xmms_ringbuf_wait_free (ringbuf=0x5ed70d0, len=4096, 
mtx=0x3dc4430) at ../src/xmms/ringbuf.c:390
#3  0x000000000041b757 in xmms_output_filler (arg=0x3dc43d0) at 
../src/xmms/output.c:478
#4  0x00007ffff7839625 in ?? () from /usr/lib/libglib-2.0.so.0
#5  0x00007ffff73af354 in start_thread () from /usr/lib/libpthread.so.0
#6  0x00007ffff70edbfd in clone () from /usr/lib/libc.so.6
(gdb) thr 10
#0  0x00007ffff70e9939 in syscall () from /usr/lib/libc.so.6
#1  0x00007ffff785755f in g_cond_wait () from /usr/lib/libglib-2.0.so.0
#2  0x0000000000421c1f in xmms_playlist_updater_loop (updater=0x5ed79e0) at 
../src/xmms/playlist_updater.c:171
#3  0x00007ffff7839625 in ?? () from /usr/lib/libglib-2.0.so.0
#4  0x00007ffff73af354 in start_thread () from /usr/lib/libpthread.so.0
#5  0x00007ffff70edbfd in clone () from /usr/lib/libc.so.6
(gdb) thr 11
#0  0x00007ffff70e9939 in syscall () from /usr/lib/libc.so.6
#1  0x00007ffff785755f in g_cond_wait () from /usr/lib/libglib-2.0.so.0
#2  0x000000000042748d in xmms_coll_sync_loop (udata=0x5ed7ab0) at 
../src/xmms/collsync.c:503
#3  0x00007ffff7839625 in ?? () from /usr/lib/libglib-2.0.so.0
#4  0x00007ffff73af354 in start_thread () from /usr/lib/libpthread.so.0
#5  0x00007ffff70edbfd in clone () from /usr/lib/libc.so.6
(gdb) thr 12
#0  0x00007ffff70e9939 in syscall () from /usr/lib/libc.so.6
#1  0x00007ffff785755f in g_cond_wait () from /usr/lib/libglib-2.0.so.0
#2  0x0000000000410b68 in xmms_mediainfo_reader_thread (data=0x5ed7c50) at 
../src/xmms/mediainfo.c:189
#3  0x00007ffff7839625 in ?? () from /usr/lib/libglib-2.0.so.0
#4  0x00007ffff73af354 in start_thread () from /usr/lib/libpthread.so.0
#5  0x00007ffff70edbfd in clone () from /usr/lib/libc.so.6
(gdb) thr 13
#0  0x00007ffff70e9939 in syscall () from /usr/lib/libc.so.6
#1  0x00007ffff785755f in g_cond_wait () from /usr/lib/libglib-2.0.so.0
#2  0x000000000046c88a in _sync_thread (s4=0x6b7cf0) at 
../src/lib/s4/src/lib/s4.c:399
#3  0x00007ffff7839625 in ?? () from /usr/lib/libglib-2.0.so.0
#4  0x00007ffff73af354 in start_thread () from /usr/lib/libpthread.so.0
#5  0x00007ffff70edbfd in clone () from /usr/lib/libc.so.6
(gdb) thr 14
#0  0x00007ffff70e4e8d in poll () from /usr/lib/libc.so.6
#1  0x00007ffff7812c7c in ?? () from /usr/lib/libglib-2.0.so.0
#2  0x00007ffff7813002 in g_main_loop_run () from /usr/lib/libglib-2.0.so.0
#3  0x00007ffff631c876 in ?? () from /usr/lib/libgio-2.0.so.0
#4  0x00007ffff7839625 in ?? () from /usr/lib/libglib-2.0.so.0
#5  0x00007ffff73af354 in start_thread () from /usr/lib/libpthread.so.0
#6  0x00007ffff70edbfd in clone () from /usr/lib/libc.so.6

If there's any further debugging I can do, please let me know.  I'm not
really sure where to start looking.  I'm guessing it's somewhere in the
buffer flush process since songs play normally and occasionally advance
to the next track correctly, but most of the time they just stop instead
of advancing, at the point where I'd expect the playback buffer to be
emptying.

Thanks,
Adam.

--
_______________________________________________
Xmms2-devel mailing list
Xmms2-devel@lists.xmms2.org
http://lists.xmms2.org/cgi-bin/mailman/listinfo/xmms2-devel

Reply via email to