Looped playback hangs when two simsyns are connected, then one reconnected

[dlbeswick]

This is a weird one -- I create a simple setup like the following with an 8 tick loop:

Song file: bug-freeze-additive.zip

Both "simsyn" and "simsyn 00" play a single note on each loop. "pulsesrc" is used as output.

This is what I find:

• The machines play fine if left alone.

• If "simsyn" is disconnected and reconnected during playback, then the current loop will complete, but when the next loop finishes then playback will hang. UI is still responsive, playback can be stopped and restarted to get it going again. Log says:

  0:05:00.982676214 84559 0x5555567478c0 INFO                 basesrc gstbasesrc.c:2989:gst_base_src_loop:<simsyn 00:simsyn 00> pausing after end of segment
  0:05:00.982738313 84559 0x5555567478c0 INFO               GST_EVENT gstevent.c:2130:gst_event_new_segment_done: creating segment-done event
  0:05:00.982788895 84559 0x5555567478c0 INFO                    task gsttask.c:312:gst_task_func:<simsyn 00:simsyn 00:src> Task going to paused
  

• If you try to disconnect "simsyn" after playback has hung as above, then the whole app seems to deadlock (UI hung, etc.) A backtrace is below:

• If "simsyn 00" is instead given an empty pattern, and "simsyn" is then disconnected and reconnected, then sometimes the loop will continue as expected without hanging, i.e. it doesn't show the above issue.

• If this experiment is repeated with a Buzzmachine instead of audiosynths like simsyn (I used FSM Kick XP) then this issue doesn't happen. Buzzmachines work fine.

• If you try this with a Buzzmachine playing a pattern and a simsyn playing a pattern, then only disconnecting and reconnecting the simsyn will cause the issue. Reconnecting the Buzzmachine works fine.

Please let me know where you think the issue might be and I can help investigate.

I have tried this with master (805810e) and also with a much older commit 4f46520 to make sure it wasn't my recent changes that caused this; the same issue happens with both.

Backtrace from full app deadlock, in the simsyn thread (disconnect when playback hung:)

  64   Thread 0x7fff9a7fc700 (LWP 85022) "simsyn:simsyn:s" syscall ()
    at ../sysdeps/unix/sysv/linux/x86_64/syscall.S:38

(gdb) thread 64
[Switching to thread 64 (Thread 0x7fff9a7fc700 (LWP 85022))]

(gdb) bt
#0  syscall () at ../sysdeps/unix/sysv/linux/x86_64/syscall.S:38
#1  0x00007ffff6e61623 in g_cond_wait (cond=0x5555560d7578, mutex=0x5555560d7550)
    at ../../../glib/gthread-posix.c:1540
#2  0x00007fffac09940e in  () at /usr/lib/x86_64-linux-gnu/gstreamer-1.0/libgstcoreelements.so
#3  0x00007ffff7baaeff in  () at /usr/lib/x86_64-linux-gnu/libgstreamer-1.0.so.0
#4  0x00007ffff7bacf61 in  () at /usr/lib/x86_64-linux-gnu/libgstreamer-1.0.so.0
#5  0x00007ffff7bb3d73 in gst_pad_push () at /usr/lib/x86_64-linux-gnu/libgstreamer-1.0.so.0
#6  0x00007ffff7b99c9b in gst_proxy_pad_chain_default ()
    at /usr/lib/x86_64-linux-gnu/libgstreamer-1.0.so.0
#7  0x00007ffff7baaeff in  () at /usr/lib/x86_64-linux-gnu/libgstreamer-1.0.so.0
#8  0x00007ffff7bacf61 in  () at /usr/lib/x86_64-linux-gnu/libgstreamer-1.0.so.0
#9  0x00007ffff7bb3d73 in gst_pad_push () at /usr/lib/x86_64-linux-gnu/libgstreamer-1.0.so.0
#10 0x00007ffff7b99c9b in gst_proxy_pad_chain_default ()
    at /usr/lib/x86_64-linux-gnu/libgstreamer-1.0.so.0
#11 0x00007ffff7baaeff in  () at /usr/lib/x86_64-linux-gnu/libgstreamer-1.0.so.0
#12 0x00007ffff7bacf61 in  () at /usr/lib/x86_64-linux-gnu/libgstreamer-1.0.so.0
#13 0x00007ffff7bb3d73 in gst_pad_push () at /usr/lib/x86_64-linux-gnu/libgstreamer-1.0.so.0
#14 0x00007fffac0a75a2 in  () at /usr/lib/x86_64-linux-gnu/gstreamer-1.0/libgstcoreelements.so
#15 0x00007fffac0a774d in  () at /usr/lib/x86_64-linux-gnu/gstreamer-1.0/libgstcoreelements.so
#16 0x00007ffff7baaeff in  () at /usr/lib/x86_64-linux-gnu/libgstreamer-1.0.so.0
#17 0x00007ffff7bacf61 in  () at /usr/lib/x86_64-linux-gnu/libgstreamer-1.0.so.0
#18 0x00007ffff7bb3d73 in gst_pad_push () at /usr/lib/x86_64-linux-gnu/libgstreamer-1.0.so.0
#19 0x00007ffff7e0e440 in  () at /usr/lib/x86_64-linux-gnu/libgstbase-1.0.so.0
#20 0x00007ffff7baaeff in  () at /usr/lib/x86_64-linux-gnu/libgstreamer-1.0.so.0
#21 0x00007ffff7bacf61 in  () at /usr/lib/x86_64-linux-gnu/libgstreamer-1.0.so.0
#22 0x00007ffff7bb3d73 in gst_pad_push () at /usr/lib/x86_64-linux-gnu/libgstreamer-1.0.so.0
#23 0x00007ffff7e0e440 in  () at /usr/lib/x86_64-linux-gnu/libgstbase-1.0.so.0
#24 0x00007ffff7baaeff in  () at /usr/lib/x86_64-linux-gnu/libgstreamer-1.0.so.0
#25 0x00007ffff7bacf61 in  () at /usr/lib/x86_64-linux-gnu/libgstreamer-1.0.so.0
#26 0x00007ffff7bb3d73 in gst_pad_push () at /usr/lib/x86_64-linux-gnu/libgstreamer-1.0.so.0
#27 0x00007ffff7e09f95 in  () at /usr/lib/x86_64-linux-gnu/libgstbase-1.0.so.0
#28 0x00007ffff7be2107 in  () at /usr/lib/x86_64-linux-gnu/libgstreamer-1.0.so.0
#29 0x00007ffff6e3e374 in g_thread_pool_thread_proxy (data=<optimized out>)
    at ../../../glib/gthreadpool.c:354
#30 0x00007ffff6e3dad1 in g_thread_proxy (data=0x555555ae1400) at ../../../glib/gthread.c:807
#31 0x00007ffff6da8609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#32 0x00007ffff6ccd293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

[dlbeswick]

I've found that when "STOP_PLAYBACK_FOR_UPDATES" is defined in setup.c then this problem doesn't happen.

[ensonic]

Yeah, this is yet-another-problem-with-adder. Reconfiguring the graph while playing is causing troubles. The buzzmachines and the simsyns should be based on the same baseclass. If it really never ever happens with a buzzmachine, it could make sense to carefully compare the code.

[dlbeswick]

I thought I had better check again; I have now also reproduced the problem with the buzzmachines. Subjectively, it seems to happen way less often than with the simsyn. Simsyn may be 1 in 5 reconnections, buzzmachines are more like 1 in 20. It still might just be luck.

Previously I had tried comparing the source files. There are some small differences, but matching them up didn't seem to make a difference to the behaviour. One difference I can see is that simsyn uses S16 format while the buzzmachines are using F32, but no idea why this would be a problem. I think you're right and it is some issue lurking in a Gstreamer component such as adder.

[ensonic]

The TL;DR is that the code is using pad probes when changing the wiring while playing. Very unfortunately there is no way in gstreamer to tell it to just ignore push or pulls to/from unconnected pads, this is always a critical failure. The more critical part is that newly connected pads need some initialization. Doing this all properly is what the pad probes try to do, but apparently either there is a bug in the probes or some of the elements do it wrong.

In the past I've spent many hours on this and I believe the probes are wrong. My best guess it again is adder that is doing it wrong. The best option for fixing 90% of the issues would be to write our own audio mixing element, that actual mixing code can be taken from audiomixer/adder, the tricky part is handling the state of the pads and complying with the rest of the framework.

This is serious amount of work though :/ The gstreamer community unfortunately does not have a lot of people that care about audio on this level and there is not much support for this and that ultimately made me giving up some time ago. If we want to retry this, the code had the experimental path that would plug audiomixer. I think the first step would be to fork the audiomixer code into the repo and adding the 'caps' property back to be interface compatible with adder. Then I could see if I still have my never submitted changes somewhere and I could try to apply them again.

[dlbeswick]

Thanks Stefan. It sounds like you're right, if you're not having any luck upstream then this is the way to go. If there's anything you'd like me to help out with, then please let me know.