ravelox / pimidi

Raspberry Pi RTP MIDI
164 stars 38 forks source link

Potential threading issue during shutdown #55

Closed mganss closed 4 years ago

mganss commented 4 years ago

Repro: Compile with -fsanitize=thread (works only on x86 I believe), start raveloxmidi (ALSA input and output configured) and run python/send_quit.py. Output:

[1577626719]    [tid=139689132979072]   NORMAL: Shutdown request received on local socket
==================
WARNING: ThreadSanitizer: data race (pid=4629)
  Read of size 4 at 0x5597b133d3f8 by thread T2:
    #0 net_socket_alsa_listener /home/mganss/pimidi/raveloxmidi/src/net_socket.c:622 (raveloxmidi+0xae4b)
    #1 <null> <null> (libtsan.so.0+0x296ad)

  Previous write of size 4 at 0x5597b133d3f8 by main thread (mutexes: write M39):
    #0 set_shutdown_lock /home/mganss/pimidi/raveloxmidi/src/net_socket.c:448 (raveloxmidi+0xac05)
    #1 net_socket_read /home/mganss/pimidi/raveloxmidi/src/net_socket.c:352 (raveloxmidi+0xac05)
    #2 net_socket_fd_loop /home/mganss/pimidi/raveloxmidi/src/net_socket.c:508 (raveloxmidi+0xb817)
    #3 main /home/mganss/pimidi/raveloxmidi/src/raveloxmidi.c:118 (raveloxmidi+0x3aae)

  Location is global 'net_socket_shutdown' of size 4 at 0x5597b133d3f8 (raveloxmidi+0x00000021f3f8)

  Mutex M39 (0x5597b133d320) created at:
    #0 pthread_mutex_init <null> (libtsan.so.0+0x2c5ad)
    #1 net_socket_loop_init /home/mganss/pimidi/raveloxmidi/src/net_socket.c:465 (raveloxmidi+0xaeff)
    #2 main /home/mganss/pimidi/raveloxmidi/src/raveloxmidi.c:104 (raveloxmidi+0x3a1e)

  Thread T2 (tid=4633, running) created by main thread at:
    #0 pthread_create <null> (libtsan.so.0+0x2bcee)
    #1 net_socket_alsa_loop /home/mganss/pimidi/raveloxmidi/src/net_socket.c:633 (raveloxmidi+0xb56d)
    #2 main /home/mganss/pimidi/raveloxmidi/src/raveloxmidi.c:116 (raveloxmidi+0x3aa9)

SUMMARY: ThreadSanitizer: data race /home/mganss/pimidi/raveloxmidi/src/net_socket.c:622 in net_socket_alsa_listener
==================
[1577626745]    [tid=139688985487104]   DEBUG: net_socket_alsa_listener: Thread stopped
==================
WARNING: ThreadSanitizer: lock-order-inversion (potential deadlock) (pid=4629)
  Cycle in lock order graph: M24 (0x7b0c00000930) => M33 (0x7b0c00000c60) => M24

  Mutex M33 acquired here while holding mutex M24 in main thread:
    #0 pthread_mutex_lock <null> (libtsan.so.0+0x3fadb)
    #1 <null> <null> (libdbus-1.so.3+0x1082f)
    #2 main /home/mganss/pimidi/raveloxmidi/src/raveloxmidi.c:98 (raveloxmidi+0x3a15)

    Hint: use TSAN_OPTIONS=second_deadlock_stack=1 to get more informative warning message

  Mutex M24 acquired here while holding mutex M33 in main thread:
    #0 pthread_mutex_lock <null> (libtsan.so.0+0x3fadb)
    #1 <null> <null> (libdbus-1.so.3+0x2892c)
    #2 dns_service_publisher_stop /home/mganss/pimidi/raveloxmidi/src/dns_service_publisher.c:283 (raveloxmidi+0x46af)
    #3 main /home/mganss/pimidi/raveloxmidi/src/raveloxmidi.c:126 (raveloxmidi+0x3a56)

SUMMARY: ThreadSanitizer: lock-order-inversion (potential deadlock) (/usr/lib/x86_64-linux-gnu/libtsan.so.0+0x3fadb) in __interceptor_pthread_mutex_lock
==================
ravelox commented 4 years ago

I've added some protection around the shutdown status but there's the lock-order-inversion report that I can't fix as it's inside the avahi code.

mganss commented 4 years ago

Verified.