savonet / liquidsoap

Liquidsoap is a statically typed scripting general-purpose language with dedicated operators and backend for all thing media, streaming, file generation, automation, HTTP backend and more.
http://liquidsoap.info
GNU General Public License v2.0
1.4k stars 130 forks source link

Liquidsoap hanging during shutdown #843

Closed AxisNL closed 4 years ago

AxisNL commented 5 years ago

Describe the bug We're using liquidsoap 1.3.6, as a part of Cast-Control's MediaCP package. It works fine, but we have an issue where incidentally a customer will choose to restart liquidsoap, and it will hang during shutdown. An admin has to log in to the server and do a kill -9. The problem is that we cannot seem to reproduce it. I can restart liquidsoap hundreds of times without a problem.

Funny thing is that a succesful shutdown logs this (grepping for main in liquidsoap.log):

2019/06/20 20:25:36 [main:3] Shutdown started!
2019/06/20 20:25:36 [main:3] Waiting for threads to terminate...
2019/06/20 20:25:36 [clock.wallclock_main:3] Streaming loop stopped.
2019/06/20 20:25:36 [main:3] Threads terminated.
2019/06/20 20:25:36 [main:3] Cleaning downloaded files...
2019/06/20 20:25:36 [main:3] Freeing memory...

And an unsuccesful shutdown logs:

2019/06/20 20:26:51 [main:3] Shutdown started!
2019/06/20 20:26:51 [main:3] Waiting for threads to terminate...
2019/06/20 20:26:51 [clock.wallclock_main:3] Streaming loop stopped.
2019/06/20 20:26:51 [main:3] Threads terminated.

After this it becomes zombie and doesn't do anything anymore.

To Reproduce Can't reproduce myself. Our customers do thousands of autodj restarts a week, and sometimes this issue pops up.

Expected behavior I expect liquidsoap to shutdown nice and cleanly when it is asked to do so.

Version details

Install method Installed using yum by mediacp (liquidsoap-1.3.6-80.4.x86_64), logs show:

2019/06/20 20:49:03 [main:3] Liquidsoap 1.3.6
2019/06/20 20:49:03 [main:3] Using: bytes=[distributed with OCaml 4.02 or above] pcre=7.3.4 dtools=0.4.1 duppy=0.8.0 cry=0.6.2 mm=0.4.0 xmlplaylist=0.1.4 ogg=0.5.2 vorbis=0.7.1 opus=0.1.2 speex=0.2.1 mad=0.4.5 flac=0.1.4 flac.ogg=0.1.4 dynlink=[distributed with Ocaml] lame=0.3.3 theora=0.3.1 bjack=0.1.5 alsa=0.2.3 samplerate=0.1.4 taglib=0.3.5 magic=0.7.3 inotify=2.3 yojson=1.1.8 soundtouch=0.1.8 ladspa=0.1.5

I hope you guys have an idea what the problem could be.. (known issue I overlooked?)

smimram commented 5 years ago

Without a reproduction case, it is very difficult to answer (and if we were aware of such problems we would already have fixed those :)). The only recent related issue I can think of is #769, but it is related to jack and I suspect that you are not likely to use that?

smimram commented 5 years ago

I am going to close this for now since we really don't have enough information. Feel free to reopen if you have a reproducible test case or at least a track, we'll be glad to help!

crocket commented 5 years ago

Upgrade ocaml-duppy to 0.8.0, and recompile liquidsoap. A lower version of ocaml-duppy caused the issue.

smimram commented 5 years ago

Thanks @crocket, feel free to reopen if this was another bug.

crocket commented 5 years ago

I found a simple fix for liquidsoap-1.3.7. It may apply to liquidsoap-1.3.6, too.

  1. Upgrade ocaml-duppy to 0.8.0
  2. Apply the following patch to ocaml-gstreamer-0.3.0 if you use ocaml-gstreamer
diff -ur a/src/gstreamer_stubs.c b/src/gstreamer_stubs.c
--- a/src/gstreamer_stubs.c 2018-09-10 00:43:43.000000000 +0900
+++ b/src/gstreamer_stubs.c 2019-07-26 09:30:52.714156364 +0900
@@ -586,18 +586,30 @@

   caml_release_runtime_system();
   g_main_loop_run(loop);
+  g_main_loop_unref(loop);
   caml_acquire_runtime_system();

   CAMLreturn(Val_unit);
 }

+gboolean gstreamer_loop_quit_helper(gpointer user_data)
+{
+  GMainLoop* loop = user_data;
+  g_main_loop_quit(loop);
+  return FALSE;
+}
+
 CAMLprim value ocaml_gstreamer_loop_quit(value l)
 {
   CAMLparam1(l);
   GMainLoop* loop = Loop_val(l);
+  GSource* idle_source;

   caml_release_runtime_system();
-  g_main_loop_quit(loop);
+  idle_source=g_idle_source_new();
+  g_source_set_callback(idle_source, gstreamer_loop_quit_helper, loop, NULL);
+  g_source_attach(idle_source, NULL);
+  g_source_unref(idle_source);
   caml_acquire_runtime_system();

   CAMLreturn(Val_unit);
  1. Compile liquidsoap-1.3.6 or liquidsoap-1.3.7 against ocaml-duppy-0.8.0 and ocaml-gstreamer-0.3.0
AxisNL commented 4 years ago

I still have liquidsoap (now 1.3.7) dying on me on shutdown. It might have to do something with a fast subsequent restart (which a client perhaps should not do, but can't prevent it).

A grep for main:3 in the logs show the following:

A successful restart:

2020/02/05 22:20:42 [main:3] Shutdown started!
2020/02/05 22:20:42 [main:3] Waiting for threads to terminate...
2020/02/05 22:20:42 [clock.wallclock_main:3] Streaming loop stopped.
2020/02/05 22:20:42 [main:3] Threads terminated.
2020/02/05 22:20:42 [main:3] Cleaning downloaded files...
2020/02/05 22:20:42 [main:3] Freeing memory...
2020/02/05 22:20:43 [main:3] Liquidsoap 1.3.7
2020/02/05 22:20:43 [main:3] Using: bytes=[distributed with OCaml 4.02 or above] pcre=7.4.1 dtools=0.4.1 duppy=0.8.0 cry=0.6.4 mm=0.4.1 ogg=0.5.2 vorbis=0.7.1 mad=0.4.5 flac=0.1.4 flac.ogg=0.1.4 dynlink=[distributed with Ocaml] lame=0.3.3 fdkaac=0.2.1 theora=0.3.1 samplerate=0.1.4 taglib=0.3.6 camomile=1.0.2 faad=0.4.0
2020/02/05 22:20:44 [clock.wallclock_main:3] Streaming loop starts, synchronized with wallclock.

Another succesful restart:

2020/02/08 21:02:00 [main:3] Shutdown started!
2020/02/08 21:02:00 [main:3] Waiting for threads to terminate...
2020/02/08 21:02:01 [clock.wallclock_main:3] Streaming loop stopped.
2020/02/08 21:02:01 [main:3] Threads terminated.
2020/02/08 21:02:01 [main:3] Cleaning downloaded files...
2020/02/08 21:02:01 [main:3] Freeing memory...
2020/02/08 21:02:04 [main:3] Liquidsoap 1.3.7
2020/02/08 21:02:04 [main:3] Using: bytes=[distributed with OCaml 4.02 or above] pcre=7.4.1 dtools=0.4.1 duppy=0.8.0 cry=0.6.4 mm=0.4.1 ogg=0.5.2 vorbis=0.7.1 mad=0.4.5 flac=0.1.4 flac.ogg=0.1.4 dynlink=[distributed with Ocaml] lame=0.3.3 fdkaac=0.2.1 theora=0.3.1 samplerate=0.1.4 taglib=0.3.6 camomile=1.0.2 faad=0.4.0
2020/02/08 21:02:04 [clock.wallclock_main:3] Streaming loop starts, synchronized with wallclock.

And the next one fails. Liquidsoap zombies out and has to be killed manually and is started the next morning:

2020/02/08 21:02:09 [main:3] Shutdown started!
2020/02/08 21:02:09 [main:3] Waiting for threads to terminate...
2020/02/08 21:02:09 [clock.wallclock_main:3] Streaming loop stopped.
2020/02/08 21:02:09 [main:3] Threads terminated.

2020/02/09 11:42:49 [main:3] Liquidsoap 1.3.7
2020/02/09 11:42:49 [main:3] Using: bytes=[distributed with OCaml 4.02 or above] pcre=7.4.1 dtools=0.4.1 duppy=0.8.0 cry=0.6.4 mm=0.4.1 ogg=0.5.2 vorbis=0.7.1 mad=0.4.5 flac=0.1.4 flac.ogg=0.1.4 dynlink=[distributed with Ocaml] lame=0.3.3 fdkaac=0.2.1 theora=0.3.1 samplerate=0.1.4 taglib=0.3.6 camomile=1.0.2 faad=0.4.0
2020/02/09 11:42:50 [clock.wallclock_main:3] Streaming loop starts, synchronized with wallclock.

Any more ideas?

crocket commented 4 years ago

Did you compile liquidsoap against ocaml-duppy-0.8.0 or above? Did you follow my instructions?

AxisNL commented 4 years ago

Did you compile liquidsoap against ocaml-duppy-0.8.0 or above? Did you follow my instructions?

Crocket, yes, thank you, I tried so much stuff that I forget what I tried and what I did not try on so many systems :) The above output shows 'duppy=0.8.0' in the compiler flags, so I am pretty sure it's compiled against ocaml-duppy 0.8.0.

crocket commented 4 years ago

Did you also patch ocaml-streamer?

Jookia commented 4 years ago

As part of reproducing #1045 I've found this issue and I think I'm hitting the same bug. on ocaml-duppy master (0207fdffa34d78e64ec8f98c7cdbc11c2bf49e65)

Massive debug dump:

(gdb) r                                                                                                                       
Starting program: /home/liquidsoap/.opam/default/bin/liquidsoap test.liq --debug 
[Thread debugging using libthread_db enabled]                                                                                 
Using host libthread_db library "/usr/lib/libthread_db.so.1".                                                                 
2020/03/09 21:30:09 >>> LOG START                                                                                             
[New Thread 0x7fffee3c4700 (LWP 40543)]                                                                                       
[New Thread 0x7fffedbc3700 (LWP 40544)]                                                                                       
[Detaching after vfork from child process 405452020/03/09 21:30:09 [main:3] Liquidsoap 1.5.0+git@818d67ea                     
]                                                              
2020/03/09 21:30:09 [main:3] Using: bytes=[distributed with OCaml 4.02 or above] pcre=7.4.3 sedlex=2.1 menhirLib=20200211 dtoo
ls=1b1fa5b duppy=0.8.1 cry=0.6.5 mm=0.6.0 ogg=0.6.0 opus=0.1.3 dynlink=[distributed with Ocaml] ffmpeg-avutil=0.5.0 ffmpeg-avc
odec=0.5.0 ffmpeg-av=0.5.0 ffmpeg-avfilter=0.5.0 ffmpeg-swresample=0.5.0 ffmpeg-swscale=0.5.0 ssl=0.5.9 camomile=1.0.2     
2020/03/09 21:30:09 [main:3]                                   
2020/03/09 21:30:09 [main:3] DISCLAIMER: This version of Liquidsoap has been                                                  
2020/03/09 21:30:09 [main:3] compiled from a snapshot of the development code.                                                
2020/03/09 21:30:09 [main:3] As such, it should not be used in production                                                     
2020/03/09 21:30:09 [main:3] unless you know what you are doing!                                                              
2020/03/09 21:30:09 [main:3]                                                                                                  
2020/03/09 21:30:09 [main:3] We are, however, very interested in any feedback           
2020/03/09 21:30:09 [main:3] about our development code and committed to fix                                                  
2020/03/09 21:30:09 [main:3] issues as soon as possible.                                                                      
2020/03/09 21:30:09 [main:3]                                                                                                  
2020/03/09 21:30:09 [main:3] If you are interested in collaborating to              
2020/03/09 21:30:09 [main:3] the development of Liquidsoap, feel free to                                                      
2020/03/09 21:30:09 [main:3] drop us a mail at <savonet-devl@lists.sf.net>          
2020/03/09 21:30:09 [main:3] or to join the slack chat at <http://slack.liquidsoap.info>.                                     
2020/03/09 21:30:09 [main:3]                                   
2020/03/09 21:30:09 [main:3] Please send any bug report or feature request                                                    
2020/03/09 21:30:09 [main:3] at <https://github.com/savonet/liquidsoap/issues>.                                               
2020/03/09 21:30:09 [main:3]                                                                                                  
2020/03/09 21:30:09 [main:3] We hope you enjoy this snapshot build of Liquidsoap!               
2020/03/09 21:30:09 [main:3]                                                                                                  
2020/03/09 21:30:09 [dynamic.loader:3] Could not find dynamic module for lame encoder.           
2020/03/09 21:30:09 [dynamic.loader:3] Could not find dynamic module for fdkaac encoder.                                      
2020/03/09 21:30:09 [frame:3] Using 44100Hz audio, 25Hz video, 44100Hz master.                                      
2020/03/09 21:30:09 [frame:3] Frame size must be a multiple of 1764 ticks = 1764 audio samples = 1 video samples.             
2020/03/09 21:30:09 [frame:3] Targetting 'frame.duration': 0.04s = 1764 audio samples = 1764 ticks.                           
2020/03/09 21:30:09 [frame:3] Frames last 0.04s = 1764 audio samples = 1 video samples = 1764 ticks.    
2020/03/09 21:30:09 [request.dynamic_17310:4] Reloading playlist.                                                             
2020/03/09 21:30:09 [request.dynamic_17310:4] Playlist is a directory.
[New Thread 0x7fffed3c2700 (LWP 40547)]                                                                                       
2020/03/09 21:30:09 [sandbox:3] Sandboxing disabled                                                                           
2020/03/09 21:30:09 [video.converter:3] Couldn't find preferred video converter: gavl.                                        
[New Thread 0x7fffecbc1700 (LWP 40548)] 
[New Thread 0x7fffe7fff700 (LWP 40549)]                                                                             [141/1852]
[New Thread 0x7fffe77fe700 (LWP 40550)]                
[New Thread 0x7fffe6ffd700 (LWP 40551)]                                                                                       
2020/03/09 21:30:09 [audio.converter:3] Using samplerate converter: ffmpeg.
2020/03/09 21:30:09 [threads:4] Created thread "generic queue #1" (1 total).     
2020/03/09 21:30:09 [threads:4] Created thread "generic queue #2" (2 total).                                 
2020/03/09 21:30:09 [threads:4] Created thread "non-blocking queue #1" (3 total).           
2020/03/09 21:30:09 [threads:4] Created thread "non-blocking queue #2" (4 total).                      
2020/03/09 21:30:09 [clock:4] Currently 1 clocks allocated.                                                                   
2020/03/09 21:30:09 [clock.main:4] Starting 1 sources...                                                                      
2020/03/09 21:30:09 [source:4] Source output.icecast_17319 gets up.                                                           
2020/03/09 21:30:09 [source:4] Source mksafe gets up.
2020/03/09 21:30:09 [source:4] Source request.dynamic_17310 gets up.      
2020/03/09 21:30:09 [request.dynamic_17310:4] Content kind is {audio=2;video=0;midi=0}.                         
2020/03/09 21:30:09 [request.dynamic_17310:4] Activations changed: static=[], dynamic=[mksafe:/test(dot)mp3:/test(dot)mp3].
2020/03/09 21:30:09 [source:4] Source safe_blank gets up.  
2020/03/09 21:30:09 [safe_blank:4] Content kind is {audio=2;video=0;midi=0}.                                                  
2020/03/09 21:30:09 [safe_blank:4] Activations changed: static=[], dynamic=[mksafe:/test(dot)mp3:/test(dot)mp3].              
2020/03/09 21:30:09 [mksafe:4] Activations changed: static=[/test(dot)mp3:/test(dot)mp3], dynamic=[].                         
2020/03/09 21:30:09 [/test(dot)mp3:4] Activations changed: static=[/test(dot)mp3], dynamic=[].                                
2020/03/09 21:30:09 [/test(dot)mp3:4] Enabling caching mode: active source.                                                   
2020/03/09 21:30:09 [/test(dot)mp3:3] Connecting mount /test.mp3 for source@localhost...
[New Thread 0x7fffe53f5700 (LWP 40552)]                                                                                       
2020/03/09 21:30:10 [/test(dot)mp3:2] Connection failed: could not connect to host: Connection refused in connect()
2020/03/09 21:30:10 [/test(dot)mp3:3] Will try again in 3.00 sec.                  
2020/03/09 21:30:10 [threads:4] Created thread "clock_main" (1 total).              
2020/03/09 21:30:10 [clock:4] Main phase starts.                                                                              
2020/03/09 21:30:10 [clock.main:3] Streaming loop starts in auto-sync mode          
2020/03/09 21:30:10 [clock.main:3] Delegating synchronisation to CPU clock                                                    
2020/03/09 21:30:10 [mksafe:3] Switch to safe_blank.           
2020/03/09 21:30:10 [safe_blank:4] Activations changed: static=[mksafe:/test(dot)mp3:/test(dot)mp3], dynamic=[mksafe:/test(dot
)mp3:/test(dot)mp3].                                                                                                          
2020/03/09 21:30:10 [decoder:4] Trying method "META" for "/home/liquidsoap/musics/5_2_11.opus"...                             
2020/03/09 21:30:10 [decoder:4] Trying method "WAV" for "/home/liquidsoap/musics/5_2_11.opus"...
2020/03/09 21:30:10 [decoder.wav/aiff:4] Invalid file extension for "/home/liquidsoap/musics/5_2_11.opus"!                    
2020/03/09 21:30:10 [decoder:4] Trying method "AIFF" for "/home/liquidsoap/musics/5_2_11.opus"...
2020/03/09 21:30:10 [decoder.wav/aiff:4] Invalid file extension for "/home/liquidsoap/musics/5_2_11.opus"!                    
2020/03/09 21:30:10 [decoder:4] Trying method "MIDI" for "/home/liquidsoap/musics/5_2_11.opus"...                   
2020/03/09 21:30:10 [decoder:4] Trying method "IMAGE" for "/home/liquidsoap/musics/5_2_11.opus"...                            
2020/03/09 21:30:10 [decoder:4] Trying method "FFMPEG" for "/home/liquidsoap/musics/5_2_11.opus"...                           
2020/03/09 21:30:10 [decoder.ffmpeg:4] Invalid file extension for "/home/liquidsoap/musics/5_2_11.opus"!
2020/03/09 21:30:10 [decoder:4] Trying method "OGG" for "/home/liquidsoap/musics/5_2_11.opus"...                              
^C2020/03/09 21:30:10 [main:3] Shutdown started!
2020/03/09 21:30:10 [main:3] Waiting for main threads to terminate...                                                         
2020/03/09 21:30:10 [threads:4] Waiting for thread clock_main to shutdown                                                     
2020/03/09 21:30:10 [/test(dot)mp3:4] Activations changed: static=[], dynamic=[].                                             
2020/03/09 21:30:10 [source:4] Source /test(dot)mp3 gets down.
2020/03/09 21:30:10 [mksafe:4] Activations changed: static=[], dynamic=[].  
2020/03/09 21:30:10 [source:4] Source mksafe gets down.
2020/03/09 21:30:10 [request.dynamic_17310:4] Activations changed: static=[], dynamic=[].                                     
2020/03/09 21:30:10 [source:4] Source request.dynamic_17310 gets down.     
2020/03/09 21:30:10 [request.dynamic_17310:4] Waiting for feeding task to stop...
2020/03/09 21:30:10 [decoder.ogg:4] File "/home/liquidsoap/musics/5_2_11.opus" recognized as audio=2 video=0.
2020/03/09 21:30:10 [decoder:3] Method "OGG" accepted "/home/liquidsoap/musics/5_2_11.opus".
2020/03/09 21:30:10 [decoder.id3v2:4] Invalid file extension for "/home/liquidsoap/musics/5_2_11.opus"!
2020/03/09 21:30:10 [request.dynamic_17310:4] Remaining: 0.0s, queued: 0.0s, adding: 30.0s (RID 0)                            
[Thread 0x7fffe53f5700 (LWP 40552) exited]                                                                                    
[Thread 0x7fffecbc1700 (LWP 40548) exited]                                                                                    
[Thread 0x7fffed3c2700 (LWP 40547) exited]           
2020/03/09 21:30:10 [request.dynamic_17310:4] Cleaning up request queue...
2020/03/09 21:30:10 [safe_blank:4] Activations changed: static=[mksafe:/test(dot)mp3:/test(dot)mp3], dynamic=[].
2020/03/09 21:30:10 [safe_blank:4] Activations changed: static=[], dynamic=[].                                             
2020/03/09 21:30:10 [source:4] Source safe_blank gets down.
2020/03/09 21:30:10 [clock.main:3] Streaming loop stopped.                                                                    
2020/03/09 21:30:10 [threads:4] Thread "clock_main" terminated (0 remaining).                                                 
2020/03/09 21:30:10 [main:3] Threads terminated.                                                                              
2020/03/09 21:30:10 [threads:3] Shutting down scheduler...                                                                    
2020/03/09 21:30:10 [threads:3] Scheduler shut down.                                                                          
2020/03/09 21:30:10 [threads:3] Waiting for queue threads to terminate...               
2020/03/09 21:30:10 [threads:4] Waiting for thread generic queue #1 to shutdown                                               
2020/03/09 21:30:10 [threads:4] Thread "generic queue #2" terminated (3 remaining).                                
2020/03/09 21:30:10 [threads:4] Thread "generic queue #1" terminated (2 remaining).
2020/03/09 21:30:10 [threads:4] Waiting for thread non-blocking queue #1 to shutdown
2020/03/09 21:30:10 [threads:4] Thread "non-blocking queue #1" terminated (1 remaining).                                      
2020/03/09 21:30:10 [threads:4] Waiting for thread non-blocking queue #2 to shutdown
[Thread 0x7fffe7fff700 (LWP 40549) exited]                                                                                    
^Z                                                             
Thread 1 "liquidsoap" received signal SIGTSTP, Stopped (user).                                                                
0x00007ffff5e88cf5 in pthread_cond_wait@@GLIBC_2.3.2 () from /usr/lib/libpthread.so.0
(gdb) info threads
  Id   Target Id                                      Frame 
* 1    Thread 0x7fffef5a0080 (LWP 40542) "liquidsoap" 0x00007ffff5e88cf5 in pthread_cond_wait@@GLIBC_2.3.2 ()
   from /usr/lib/libpthread.so.0
  2    Thread 0x7fffee3c4700 (LWP 40543) "liquidsoap" 0x00007ffff5e88cf5 in pthread_cond_wait@@GLIBC_2.3.2 ()
   from /usr/lib/libpthread.so.0
  3    Thread 0x7fffedbc3700 (LWP 40544) "liquidsoap" 0x00007ffff5c5cf0b in select () from /usr/lib/libc.so.6
  7    Thread 0x7fffe77fe700 (LWP 40550) "liquidsoap" 0x00007ffff5e88cf5 in pthread_cond_wait@@GLIBC_2.3.2 ()
   from /usr/lib/libpthread.so.0
  8    Thread 0x7fffe6ffd700 (LWP 40551) "liquidsoap" 0x00007ffff5e88cf5 in pthread_cond_wait@@GLIBC_2.3.2 ()
   from /usr/lib/libpthread.so.0
(gdb) thread 3
[Switching to thread 3 (Thread 0x7fffedbc3700 (LWP 40544))]
#0  0x00007ffff5c5cf0b in select () from /usr/lib/libc.so.6
(gdb) bt
#0  0x00007ffff5c5cf0b in select () from /usr/lib/libc.so.6
#1  0x0000555555c9d6e9 in caml_thread_tick ()
#2  0x00007ffff5e8246f in start_thread () from /usr/lib/libpthread.so.0
#3  0x00007ffff5c653d3 in clone () from /usr/lib/libc.so.6
(gdb) frame 1
#1  0x0000555555c9d6e9 in caml_thread_tick ()
(gdb) disas
Dump of assembler code for function caml_thread_tick:
   0x0000555555c9d680 <+0>:     push   %rbp
   0x0000555555c9d681 <+1>:     push   %rbx
   0x0000555555c9d682 <+2>:     sub    $0xa8,%rsp
   0x0000555555c9d689 <+9>:     mov    %fs:0x28,%rax
   0x0000555555c9d692 <+18>:    mov    %rax,0x98(%rsp)
   0x0000555555c9d69a <+26>:    xor    %eax,%eax
   0x0000555555c9d69c <+28>:    lea    0x10(%rsp),%rbp
   0x0000555555c9d6a1 <+33>:    mov    %rbp,%rdi
   0x0000555555c9d6a4 <+36>:    callq  0x55555591ae10 <sigfillset@plt>
   0x0000555555c9d6a9 <+41>:    xor    %edx,%edx
   0x0000555555c9d6ab <+43>:    mov    %rbp,%rsi
   0x0000555555c9d6ae <+46>:    xor    %edi,%edi
   0x0000555555c9d6b0 <+48>:    callq  0x55555591bd80 <pthread_sigmask@plt>
   0x0000555555c9d6b5 <+53>:    mov    0x3f28d5(%rip),%eax        # 0x55555608ff90 <caml_tick_thread_stop>
   0x0000555555c9d6bb <+59>:    test   %eax,%eax
   0x0000555555c9d6bd <+61>:    jne    0x555555c9d6fd <caml_thread_tick+125>
   0x0000555555c9d6bf <+63>:    mov    %rsp,%rbx
   0x0000555555c9d6c2 <+66>:    nopw   0x0(%rax,%rax,1)
   0x0000555555c9d6c8 <+72>:    mov    %rbx,%r8
   0x0000555555c9d6cb <+75>:    xor    %ecx,%ecx
   0x0000555555c9d6cd <+77>:    xor    %edx,%edx
   0x0000555555c9d6cf <+79>:    xor    %esi,%esi
   0x0000555555c9d6d1 <+81>:    xor    %edi,%edi
   0x0000555555c9d6d3 <+83>:    movq   $0x0,(%rsp)
   0x0000555555c9d6db <+91>:    movq   $0xc350,0x8(%rsp)
   0x0000555555c9d6e4 <+100>:   callq  0x55555591a140 <select@plt>
=> 0x0000555555c9d6e9 <+105>:   mov    $0x1a,%edi
   0x0000555555c9d6ee <+110>:   callq  0x555555ca7420 <caml_record_signal>
   0x0000555555c9d6f3 <+115>:   mov    0x3f2897(%rip),%eax        # 0x55555608ff90 <caml_tick_thread_stop>
   0x0000555555c9d6f9 <+121>:   test   %eax,%eax
   0x0000555555c9d6fb <+123>:   je     0x555555c9d6c8 <caml_thread_tick+72>
   0x0000555555c9d6fd <+125>:   mov    0x98(%rsp),%rax
   0x0000555555c9d705 <+133>:   xor    %fs:0x28,%rax
   0x0000555555c9d70e <+142>:   jne    0x555555c9d71c <caml_thread_tick+156>
   0x0000555555c9d710 <+144>:   add    $0xa8,%rsp
   0x0000555555c9d717 <+151>:   xor    %eax,%eax
   0x0000555555c9d719 <+153>:   pop    %rbx
   0x0000555555c9d71a <+154>:   pop    %rbp
   0x0000555555c9d71b <+155>:   retq   
   0x0000555555c9d71c <+156>:   callq  0x55555591a660 <__stack_chk_fail@plt>

It doesn't look like it really wants to respond to SIGTERM:

(gdb) signal 15
Note:
  Thread 1 previously stopped with signal SIGTSTP, Stopped (user).
Continuing thread 3 (the current thread) with specified signal will
still deliver the signals noted above to their respective threads.
Continue anyway? (y or n) y
Continuing with signal SIGTERM.

Thread 2 "liquidsoap" received signal SIGTSTP, Stopped (user).
[Switching to Thread 0x7fffee3c4700 (LWP 40543)]
0x00007ffff5e88cf5 in pthread_cond_wait@@GLIBC_2.3.2 () from /usr/lib/libpthread.so.0
(gdb) c
Continuing.

Thread 8 "liquidsoap" received signal SIGTSTP, Stopped (user).
[Switching to Thread 0x7fffe6ffd700 (LWP 40551)]
0x00007ffff5e88cf5 in pthread_cond_wait@@GLIBC_2.3.2 () from /usr/lib/libpthread.so.0
(gdb) c
Continuing.

Thread 7 "liquidsoap" received signal SIGTSTP, Stopped (user).
[Switching to Thread 0x7fffe77fe700 (LWP 40550)]
0x00007ffff5e88cf5 in pthread_cond_wait@@GLIBC_2.3.2 () from /usr/lib/libpthread.so.0
(gdb) c
Continuing.

Thread 3 "liquidsoap" received signal SIGTSTP, Stopped (user).
[Switching to Thread 0x7fffedbc3700 (LWP 40544)]
0x00007ffff5c5cf0b in select () from /usr/lib/libc.so.6
(gdb) c
Continuing.

Thread 1 "liquidsoap" received signal SIGTSTP, Stopped (user).
[Switching to Thread 0x7fffef5a0080 (LWP 40542)]
0x00007ffff5e88cf5 in pthread_cond_wait@@GLIBC_2.3.2 () from /usr/lib/libpthread.so.0
(gdb) c
(gdb) c
Continuing.
^C^Z
Thread 1 "liquidsoap" received signal SIGTSTP, Stopped (user).
0x00007ffff5e88cf5 in pthread_cond_wait@@GLIBC_2.3.2 () from /usr/lib/libpthread.so.0
(gdb) info threads
  Id   Target Id                                      Frame 
* 1    Thread 0x7fffef5a0080 (LWP 40542) "liquidsoap" 0x00007ffff5e88cf5 in pthread_cond_wait@@GLIBC_2.3.2 ()
   from /usr/lib/libpthread.so.0
  2    Thread 0x7fffee3c4700 (LWP 40543) "liquidsoap" 0x00007ffff5e88cf5 in pthread_cond_wait@@GLIBC_2.3.2 ()
   from /usr/lib/libpthread.so.0
  3    Thread 0x7fffedbc3700 (LWP 40544) "liquidsoap" 0x00007ffff5c5cf0b in select () from /usr/lib/libc.so.6
  7    Thread 0x7fffe77fe700 (LWP 40550) "liquidsoap" 0x00007ffff5e88cf5 in pthread_cond_wait@@GLIBC_2.3.2 ()
   from /usr/lib/libpthread.so.0
  8    Thread 0x7fffe6ffd700 (LWP 40551) "liquidsoap" 0x00007ffff5e88cf5 in pthread_cond_wait@@GLIBC_2.3.2 ()
   from /usr/lib/libpthread.so.0
(gdb) 

Linux confirms this is a signal issue:

[liquidsoap@liquidsoap ocaml-duppy]$ grep '^Sig' /proc/40542/task/40544/status 
SigQ:   19/15413
SigPnd: 0000000000004000
SigBlk: fffffffe7ffbfeff
SigIgn: 0000000000001000
SigCgt: 0000000182004602
AxisNL commented 4 years ago

Did you also patch ocaml-streamer?

I'm still getting this confirmed by our control panel's technician, I have too little knowledge about ocaml. I see Jookia is seeing issues as well, I wonder if that will help the case.

stale[bot] commented 4 years ago

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

stale[bot] commented 4 years ago

This issue was closed for lack of activity. If you believe that it is still relevant, please confirm that it applies to the latest released version of liquidsoap and re-open the ticket. Thanks!