plog icon indicating copy to clipboard operation
plog copied to clipboard

Got a __lll_lock_wait when used in multi thread application.

Open fietiger opened this issue 3 years ago • 1 comments

I am using this powerful and easy to use lib in my application. The application is based on Qt 5.12.8 and running on ubuntu 20.04. There is a reproducible phenomenon : my application is frozen sometimes ,I have to kill the process to end application. when I start gdb ann attatch to the process.I found a thread with __lll_lock_wait . here is the stack info:

(gdb) bt
#0  __lll_lock_wait (
    futex=futex@entry=0x7f0767c7a608 <plog::init<plog::TxtFormatter, 0>(plog::Severity, char const*, unsigned long, int)::rollingFileAppender+8>,
    private=0) at lowlevellock.c:52
#1  0x00007f0766b4d0a3 in __GI___pthread_mutex_lock (
    mutex=0x7f0767c7a608 <plog::init<plog::TxtFormatter, 0>(plog::Severity, char const*, unsigned long, int)::rollingFileAppender+8>)
    at ../nptl/pthread_mutex_lock.c:80
#2  0x00007f0767c59530 in plog::util::Mutex::lock (
    this=0x7f0767c7a608 <plog::init<plog::TxtFormatter, 0>(plog::Severity, char const*, unsigned long, int)::rollingFileAppender+8>)
    at /home/upolabs/BoardSLMProj2/thirdparty/include/plog/Util.h:478
#3  0x00007f0767c5958e in plog::util::MutexLock::MutexLock (this=0x7ffd0ddef7e0, mutex=...)
    at /home/upolabs/BoardSLMProj2/thirdparty/include/plog/Util.h:508
#4  0x00007f0767c5bc23 in plog::RollingFileAppender<plog::TxtFormatter, plog::NativeEOLConverter<plog::UTF8Converter> >::write (
    this=0x7f0767c7a600 <plog::init<plog::TxtFormatter, 0>(plog::Severity, char const*, unsigned long, int)::rollingFileAppender>, record=...)
    at /home/upolabs/BoardSLMProj2/thirdparty/include/plog/Appenders/RollingFileAppender.h:38
#5  0x00007f0767c59fcf in plog::Logger<0>::operator+= (this=0x7f0767c7a520 <plog::init<0>(plog::Severity, plog::IAppender*)::logger>, record=...)
    at /home/upolabs/BoardSLMProj2/thirdparty/include/plog/Logger.h:58
#6  0x00007f0767c57f61 in LoggerHelper::Record (this=0x7f0767c7a4e0 <LoggerHelper::Instance()::mainObj>, severity=Level::debug,
    func=0x7f0767c615b0 "AutoLogger::AutoLogger(const string&, Level)", line=53, file=0x7f0767c615ab "", object=0x0,
    msg="Start static void BoardSLMDevice::signal_handler(int, siginfo_t*, void*)")
    at /home/upolabs/BoardSLMProj2/BoardSLMDrv/src/LoggerHelper.cpp:27
#7  0x00007f0767c584cf in AutoLogger::AutoLogger (this=0x7ffd0ddefbf0, func="static void BoardSLMDevice::signal_handler(int, siginfo_t*, void*)",
    lvl=Level::debug) at /home/upolabs/BoardSLMProj2/BoardSLMDrv/src/LoggerHelper.cpp:53
#8  0x00007f0767c39f5a in BoardSLMDevice::signal_handler (signum=12, info=0x7ffd0ddefd70, context=0x7ffd0ddefc40)
    at /home/upolabs/BoardSLMProj2/BoardSLMDrv/src/BoardSLMDevice.cpp:1041
#9  <signal handler called>
#10 __GI___libc_write (nbytes=103, buf=0x55abe5660a70, fd=18) at ../sysdeps/unix/sysv/linux/write.c:26
#11 __GI___libc_write (fd=18, buf=0x55abe5660a70, nbytes=103) at ../sysdeps/unix/sysv/linux/write.c:24
#12 0x00007f0767c593f9 in plog::util::File::write (
    this=0x7f0767c7a630 <plog::init<plog::TxtFormatter, 0>(plog::Severity, char const*, unsigned long, int)::rollingFileAppender+48>,
    buf=0x55abe5660a70, count=103) at /home/upolabs/BoardSLMProj2/thirdparty/include/plog/Util.h:381
#13 0x00007f0767c5c6f3 in plog::util::File::write<char> (
    this=0x7f0767c7a630 <plog::init<plog::TxtFormatter, 0>(plog::Severity, char const*, unsigned long, int)::rollingFileAppender+48>,
    str="2022-09-05 09:09:49.789 DEBUG [51129] [BoardSLMDevice::GetPaddr@752] target:696bde000 for 7f0646bde000\n")
    at /home/upolabs/BoardSLMProj2/thirdparty/include/plog/Util.h:389
#14 0x00007f0767c5bcb7 in plog::RollingFileAppender<plog::TxtFormatter, plog::NativeEOLConverter<plog::UTF8Converter> >::write (
    this=0x7f0767c7a600 <plog::init<plog::TxtFormatter, 0>(plog::Severity, char const*, unsigned long, int)::rollingFileAppender>, record=...)
    at /home/upolabs/BoardSLMProj2/thirdparty/include/plog/Appenders/RollingFileAppender.h:50
#15 0x00007f0767c59fcf in plog::Logger<0>::operator+= (this=0x7f0767c7a520 <plog::init<0>(plog::Severity, plog::IAppender*)::logger>, record=...)
    at /home/upolabs/BoardSLMProj2/thirdparty/include/plog/Logger.h:58
#16 0x00007f0767c57f61 in LoggerHelper::Record (this=0x7f0767c7a4e0 <LoggerHelper::Instance()::mainObj>, severity=Level::debug,
    func=0x7f0767c60720 "resource_size_t BoardSLMDevice::GetPaddr(char*)", line=752, file=0x7f0767c601ca "", object=0x0,
    msg="target:696bde000 for 7f0646bde000") at /home/upolabs/BoardSLMProj2/BoardSLMDrv/src/LoggerHelper.cpp:27
#17 0x00007f0767c380ce in BoardSLMDevice::GetPaddr (this=0x55abe574e830,
    vaddr=0x7f0646bde000 <error: Cannot access memory at address 0x7f0646bde000>)
    at /home/upolabs/BoardSLMProj2/BoardSLMDrv/src/BoardSLMDevice.cpp:752
#18 0x00007f0767c3abfe in BoardSLMDevice::InstantDisplay (this=0x55abe574e830, idx=46, times=1)
    at /home/upolabs/BoardSLMProj2/BoardSLMDrv/src/BoardSLMDevice.cpp:1189
#19 0x00007f0767c3a70a in BoardSLMDevice::InstantDisplay (this=0x55abe574e830, pData=0x55abe5960680, times=1)
    at /home/upolabs/BoardSLMProj2/BoardSLMDrv/src/BoardSLMDevice.cpp:1124
#20 0x000055abe3986cc1 in BoardSLMCache::on_listWidget_Path_SLM1_Cache_currentRowChanged (this=0x55abe4fd2440, arg1=46)
    at /home/upolabs/BoardSLMProj2/BoardSLMQT/boardslmcache.cpp:143
#21 0x000055abe3982c72 in BoardSLMCache::qt_static_metacall (_o=0x55abe4fd2440, _c=QMetaObject::InvokeMetaMethod, _id=11, _a=0x7ffd0ddf1120)
    at BoardSLMQT/BoardSLMQT_autogen/EWIEGA46WW/moc_boardslmcache.cpp:134
#22 0x000055abe3982de8 in BoardSLMCache::qt_metacall (this=0x55abe4fd2440, _c=QMetaObject::InvokeMetaMethod, _id=11, _a=0x7ffd0ddf1120)
    at BoardSLMQT/BoardSLMQT_autogen/EWIEGA46WW/moc_boardslmcache.cpp:179
#23 0x00007f076735d28c in QMetaObject::activate(QObject*, int, int, void**) () from /lib/x86_64-linux-gnu/libQt5Core.so.5
#24 0x00007f076aa99315 in QListWidget::currentRowChanged(int) () from /lib/x86_64-linux-gnu/libQt5Widgets.so.5
#25 0x00007f076aa99cc6 in ?? () from /lib/x86_64-linux-gnu/libQt5Widgets.so.5

fietiger avatar Sep 05 '22 02:09 fietiger

This is expected as you can't do much in a signal handler: you can't allocate memory, use printf or use synchronization primitives. You are allowed to call only async-signal-safe functions: https://man7.org/linux/man-pages/man7/signal-safety.7.html.

So you have 2 options:

  • make you signal handler very lightweight and minimalistic
  • use sigwait in a thread for signal processing like shown in this sample: https://man7.org/linux/man-pages/man3/pthread_sigmask.3.html

The similar issue: https://github.com/ArcticaProject/nx-libs/issues/854

SergiusTheBest avatar Sep 05 '22 08:09 SergiusTheBest