diff options
| -rw-r--r-- | CONTRIBUTORS | 2 | ||||
| -rw-r--r-- | HISTORY | 20 | ||||
| -rw-r--r-- | Make.config.template | 8 | ||||
| -rw-r--r-- | thread.c | 246 | ||||
| -rw-r--r-- | thread.h | 33 |
5 files changed, 224 insertions, 85 deletions
diff --git a/CONTRIBUTORS b/CONTRIBUTORS index a3d593f3..6e228afe 100644 --- a/CONTRIBUTORS +++ b/CONTRIBUTORS @@ -3429,6 +3429,8 @@ Jasmin Jessich <jasmin@anw.at> for help and suggestions when implementing debug output for checking the correct sequence of locking global lists for suggesting to use $(Q) to control Makefile verbosity + for adding handling DEBUG to the Make.config.template file, in order to control + code optimization Martin Schirrmacher <schirrmie@gmail.com> for suggesting to provide a way for skin plugins to get informed about the currently @@ -9058,11 +9058,21 @@ Video Disk Recorder Revision History 2017-05-31: Version 2.3.6 -- Added debug output for checking the correct sequence of locking global lists - (with help and suggestions from Jasmin Jessich). To activate this, define the - macro DEBUG_LOCKSEQ in thread.c. At the first occurrence of an invalid locking - sequence, the 20 most recent locks will be printed to stderr, followed by a - backtrace that led to the call in question. +- Added backtrace functions for debugging (see cBackTrace in thread.h). +- Added checking the correct sequence of locking global lists (with help and + suggestions from Jasmin Jessich). At the first occurrence of an invalid locking + sequence, the 20 most recent locks will be written to the log file, followed by a + backtrace that led to the call in question. This code can be activated by defining + the macro DEBUG_LOCKSEQ in thread.c (which is on by default). + When debugging an actual invalid locking sequence, you can additionally define + the macro DEBUG_LOCKCALL in thread.c, which will add information about the caller + of each lock. Note that this may cause some stress on the CPU, therefore it is off + by default. +- The file Make.config.template now reacts on DEBUG=1 in the 'make' command line, + and disables code optimizations by setting -O0 (thanks to Jasmin Jessich). + This can be helpful when backtracing highly optimized code. You may want to + 'make distclean' before running 'make' with a modified setting of DEBUG, to make + sure all object files are newly compiled. - Fixed the locking sequence when dumping EPG data. - Fixed the locking sequence when starting a recording. - The Makefiles now use the macro $(Q) instead of a plain '@' in front of their diff --git a/Make.config.template b/Make.config.template index 8768f3b9..82d55617 100644 --- a/Make.config.template +++ b/Make.config.template @@ -6,7 +6,7 @@ # See the main source file 'vdr.c' for copyright information and # how to reach the author. # -# $Id: Make.config.template 3.4 2015/02/09 09:58:45 kls Exp $ +# $Id: Make.config.template 4.1 2017/06/02 09:29:54 kls Exp $ ### The C compiler and options: @@ -16,6 +16,12 @@ CFLAGS = -g -O3 -Wall CXX = g++ CXXFLAGS = -g -O3 -Wall -Werror=overloaded-virtual -Wno-parentheses +# Use 'make DEBUG=1 ...' to build a debug version of VDR and plugins: +ifdef DEBUG +CFLAGS += -O0 +CXXFLAGS += -O0 +endif + # Use 'make M32=1 ...' to build a 32-bit version of VDR on a 64-bit machine: ifdef M32 CFLAGS += -m32 @@ -4,27 +4,31 @@ * See the main source file 'vdr.c' for copyright information and * how to reach the author. * - * $Id: thread.c 4.3 2017/05/28 12:41:03 kls Exp $ + * $Id: thread.c 4.4 2017/06/03 12:43:22 kls Exp $ */ #include "thread.h" +#include <cxxabi.h> +#include <dlfcn.h> #include <errno.h> +#include <execinfo.h> #include <linux/unistd.h> #include <malloc.h> #include <stdarg.h> #include <stdlib.h> +#include <sys/prctl.h> #include <sys/resource.h> #include <sys/syscall.h> #include <sys/time.h> #include <sys/wait.h> -#include <sys/prctl.h> #include <unistd.h> #include "tools.h" -#define ABORT { dsyslog("ABORT!"); abort(); } // use debugger to trace back the problem +#define ABORT { dsyslog("ABORT!"); cBackTrace::BackTrace(); abort(); } -//#define DEBUG_LOCKING // uncomment this line to activate debug output for locking -//#define DEBUG_LOCKSEQ // uncomment this line to activate debug output for locking sequence +//#define DEBUG_LOCKING // uncomment this line to activate debug output for locking +#define DEBUG_LOCKSEQ // uncomment this line to activate debug output for invalid locking sequence +//#define DEBUG_LOCKCALL // uncomment this line to activate caller information with DEBUG_LOCKSEQ (WARNING: expensive operation, use only when actually debugging the locking sequence!) #ifdef DEBUG_LOCKING #define dbglocking(a...) fprintf(stderr, a) @@ -430,27 +434,15 @@ bool cThreadLock::Lock(cThread *Thread) return false; } -// --- cStateLock ------------------------------------------------------------ +// --- cBackTrace ------------------------------------------------------------ -#ifdef DEBUG_LOCKSEQ -#include <cxxabi.h> -#include <execinfo.h> -static cVector<tThreadId> StateLockThreadIds; -static cVector<int> StateLockFlags; -static cMutex StateLockMutex; -#define SLL_SIZE 20 // the number of log entries -#define SLL_LENGTH 256 // the maximum length of log entries -#define SLL_DELIM '#' // delimiter for caller info -static char StateLockLog[SLL_SIZE][SLL_LENGTH] = { 0 }; -static int StateLockLogIndex = 0; -static bool DumpStateLocks = true; #define BT_BUF_SIZE 100 -static cString Demangle(char *s, char *Prefix = NULL) +cString cBackTrace::Demangle(char *s) { char *Module = s; char *Function = NULL; - //char *Offset = NULL; + char *Offset = NULL; char *Address = NULL; // separate the string: for (char *q = Module; *q; q++) { @@ -460,7 +452,7 @@ static cString Demangle(char *s, char *Prefix = NULL) } else if (*q == '+') { *q = 0; - //Offset = q + 1; + Offset = q + 1; } else if (*q == ')') *q = 0; @@ -472,20 +464,46 @@ static cString Demangle(char *s, char *Prefix = NULL) } } // demangle the function name: - int status; - char *r = abi::__cxa_demangle(Function, NULL, 0, &status); - if (r) - Function = r; - cString d = cString::sprintf("%s %s %s", Prefix ? Prefix : "", Module, Function); + char *DemangledFunction = NULL; + if (Function) { + int status; + DemangledFunction = abi::__cxa_demangle(Function, NULL, 0, &status); + if (DemangledFunction) + Function = DemangledFunction; + if (!*Function) + Function = NULL; + } + cString d = cString::sprintf("%s%s%s", Module, Function ? " " : "", Function ? Function : ""); + // convert string address to numbers: + unsigned long long addr = Address ? strtoull(Address, NULL, 0) : 0; + unsigned long long offs = Offset ? strtoull(Offset, NULL, 0) : 0; + // for shared libraries we need get the offset inside the library: + if (Function) { + // check whether the module name ends with ".so*": + char *e = Module; + char *p = NULL; + while (e = strstr(e, ".so")) + p = e++; + if (p && !strchr(p, '/')) { + Dl_info dlinfo; + if (dladdr(reinterpret_cast<void*>(addr), &dlinfo)) { + if ((strcmp(Module, dlinfo.dli_fname) == 0) && dlinfo.dli_fbase) { + unsigned long long base = reinterpret_cast<unsigned long long>(dlinfo.dli_fbase); + addr -= base; + addr &= 0x0FFFFFFFF; // to make it work on both 32 and 64 bit systems + } + } + } + } // determine the file name and line number: - cString cmd = cString::sprintf("addr2line --exe=%s --functions --demangle --basename %s", Module, Address); + cString cmd = cString::sprintf("addr2line --functions --demangle --inlines --basename --exe=%s 0x%llx", Module, Function ? addr : offs); cPipe p; if (p.Open(cmd, "r")) { int n = 0; cReadLine rl; while (char *l = rl.Read(p)) { if (n == 0) { - if (!isempty(Function) && strcmp(l, Function)) + if (Function && strcmp(l, Function)) d = cString::sprintf("%s calling %s", *d, l); } else @@ -494,101 +512,173 @@ static cString Demangle(char *s, char *Prefix = NULL) } p.Close(); } - free(r); + free(DemangledFunction); return d; } -static void BackTrace(void) +void cBackTrace::BackTrace(cStringList &StringList, int Level, bool Mangled) { void *b[BT_BUF_SIZE]; int n = backtrace(b, BT_BUF_SIZE); if (char **s = backtrace_symbols(b, n)) { - for (int i = 5; i < n; i++) - fprintf(stderr, "%s\n", *Demangle(s[i])); + for (int i = max(Level, 0) + 1; i < n; i++) // 1 is the call to this function itself + StringList.Append(strdup(Mangled ? s[i] : *Demangle(s[i]))); free(s); } } -static void BackTraceCaller(int Level, char *t, int l) +void cBackTrace::BackTrace(FILE *f, int Level, bool Mangled) { + cStringList sl; + BackTrace(sl, Level + 1, Mangled); // 1 is the call to this function itself + for (int i = 0; i < sl.Size(); i++) { + if (f) + fprintf(f, "%s\n", sl[i]); + else + dsyslog("%s", sl[i]); + } +} + +cString cBackTrace::GetCaller(int Level, bool Mangled) +{ + cString Caller; + Level = max(Level, 0) + 1; // 1 is the call to this function itself void *b[BT_BUF_SIZE]; int n = backtrace(b, BT_BUF_SIZE); if (char **s = backtrace_symbols(b, n)) { - strn0cpy(t, s[Level], l); + if (Level < n) + Caller = Mangled ? s[Level] : *Demangle(s[Level]); free(s); } + return Caller; } -static void DumpStateLockLog(tThreadId ThreadId, const char *Name) -{ - if (!DumpStateLocks) - return; - DumpStateLocks = false; +// --- cStateLockLog --------------------------------------------------------- + +#ifdef DEBUG_LOCKSEQ +#define SLL_SIZE 20 // the number of log entries +#define SLL_LENGTH 256 // the maximum length of log entries +#define SLL_MAX_LIST 9 // max. number of lists to log +#define SLL_WRITE_FLAG 0x80000000 + +class cStateLockLog { +private: + cMutex mutex; + cVector<tThreadId> threadIds; + cVector<int> flags; + tThreadId logThreadIds[SLL_SIZE]; + int logFlags[SLL_SIZE]; + char logCaller[SLL_SIZE][SLL_LENGTH]; + int logIndex; + bool dumped; + void Dump(const char *Name, tThreadId ThreadId); +public: + cStateLockLog(void); + void Check(const char *Name, bool Lock, bool Write = false); + }; + +cStateLockLog::cStateLockLog(void) +{ + memset(logThreadIds, 0, sizeof(logThreadIds)); + memset(logFlags, 0, sizeof(logFlags)); + memset(logCaller, 0, sizeof(logCaller)); + logIndex = 0; + dumped = false; +} + +void cStateLockLog::Dump(const char *Name, tThreadId ThreadId) +{ + dsyslog("--- begin invalid lock sequence report"); + int LastFlags = 0; for (int i = 0; i < SLL_SIZE; i++) { - char *s = StateLockLog[StateLockLogIndex]; - if (*s) { - if (char *Delim = strchr(s, SLL_DELIM)) { - *Delim = 0; - fprintf(stderr, "%s\n", *Demangle(Delim + 1, s)); + if (tThreadId tid = logThreadIds[logIndex]) { + char msg[SLL_LENGTH]; + char *q = msg; + q += sprintf(q, "%5d", tid); + int Flags = logFlags[logIndex]; + bool Write = Flags & SLL_WRITE_FLAG; + Flags &= ~SLL_WRITE_FLAG; + int Changed = LastFlags ^ Flags; + LastFlags = Flags; + bool Lock = (Flags & Changed) != 0; + for (int i = 0; i <= SLL_MAX_LIST; i++) { + char c = '-'; + int b = 1 << i; + if ((Flags & b) != 0) + c = '*'; + if ((Changed & b) != 0) + c = Lock ? Write ? 'W' : 'R' : '-'; + q += sprintf(q, " %c", c); + } + q += sprintf(q, " %c", Lock ? 'L' : 'U'); + if (*logCaller[logIndex]) { + *q++ = ' '; + strn0cpy(q, *cBackTrace::Demangle(logCaller[logIndex]), sizeof(msg) - (q - msg)); } + dsyslog("%s", msg); } - if (++StateLockLogIndex >= SLL_SIZE) - StateLockLogIndex = 0; + if (++logIndex >= SLL_SIZE) + logIndex = 0; } - fprintf(stderr, "%5d invalid lock sequence: %-12s\n", ThreadId, Name); - fprintf(stderr, "full backtrace:\n"); - BackTrace(); + dsyslog("%5d invalid lock sequence: %s", ThreadId, Name); + dsyslog("full backtrace:"); + cBackTrace::BackTrace(NULL, 2); + dsyslog("--- end invalid lock sequence report"); + fprintf(stderr, "invalid lock sequence at %s\n", *DayDateTime(time(NULL))); } -static void CheckStateLockLevel(const char *Name, bool Lock, bool Write = false) +void cStateLockLog::Check(const char *Name, bool Lock, bool Write) { - if (Name) { + if (!dumped && Name) { int n = *Name - '0'; - if (1 <= n && n <= 9) { + if (1 <= n && n <= SLL_MAX_LIST) { int b = 1 << (n - 1); - cMutexLock MutexLock(&StateLockMutex); + cMutexLock MutexLock(&mutex); tThreadId ThreadId = cThread::ThreadId(); - int Index = StateLockThreadIds.IndexOf(ThreadId); + int Index = threadIds.IndexOf(ThreadId); if (Index < 0) { if (Lock) { - Index = StateLockThreadIds.Size(); - StateLockThreadIds.Append(ThreadId); - StateLockFlags.Append(0); + Index = threadIds.Size(); + threadIds.Append(ThreadId); + flags.Append(0); } else return; } - char *p = StateLockLog[StateLockLogIndex]; - char *q = p; - q += sprintf(q, "%5d", ThreadId); - for (int i = 0; i <= 9; i++) { - char c = '-'; - if (StateLockFlags[Index] & (1 << i)) - c = '*'; - if (i == n - 1) - c = Lock ? Write ? 'W' : 'R' : '-'; - q += sprintf(q, " %c", c); - } - q += sprintf(q, " %c%c", Lock ? 'L' : 'U', SLL_DELIM); - BackTraceCaller(Lock ? 5 : 3, q, SLL_LENGTH - (q - p)); - if (++StateLockLogIndex >= SLL_SIZE) - StateLockLogIndex = 0; + bool DoDump = false; if (Lock) { - if ((StateLockFlags[Index] & ~b) < b) - StateLockFlags[Index] |= b; - else if ((StateLockFlags[Index] & b) == 0) - DumpStateLockLog(ThreadId, Name); + if ((flags[Index] & ~b) < b) // thread holds only "smaller" locks -> OK + ; + else if ((flags[Index] & b) == 0) // thread already holds "bigger" locks, so it may only re-lock one that it already has! + DoDump = true; + flags[Index] |= b; } else - StateLockFlags[Index] &= ~b; + flags[Index] &= ~b; + logThreadIds[logIndex] = ThreadId; + logFlags[logIndex] = flags[Index] | (Write ? SLL_WRITE_FLAG : 0); +#ifdef DEBUG_LOCKCALL + strn0cpy(logCaller[logIndex], cBackTrace::GetCaller(Lock ? 5 : 3, true), SLL_LENGTH); +#endif + if (++logIndex >= SLL_SIZE) + logIndex = 0; + if (DoDump) { + Dump(Name, ThreadId); + dumped = true; + } } } } -#define dbglockseq(n, l, w) CheckStateLockLevel(n, l, w) + +static cStateLockLog StateLockLog; + +#define dbglockseq(n, l, w) StateLockLog.Check(n, l, w) #else #define dbglockseq(n, l, w) #endif // DEBUG_LOCKSEQ +// --- cStateLock ------------------------------------------------------------ + cStateLock::cStateLock(const char *Name) :rwLock(true) { @@ -4,7 +4,7 @@ * See the main source file 'vdr.c' for copyright information and * how to reach the author. * - * $Id: thread.h 4.2 2016/12/08 10:18:32 kls Exp $ + * $Id: thread.h 4.3 2017/06/03 12:43:22 kls Exp $ */ #ifndef __THREAD_H @@ -291,6 +291,37 @@ public: int Close(void); }; +// cBackTrace can be used for debugging. + +class cStringList; +class cString; + +class cBackTrace { +public: + static cString Demangle(char *s); + ///< Demangles the function name in the given string and returns the converted + ///< version of s. s must be one of the strings returned by a call to + ///< BackTrace() or GetCaller(). + ///< Note that this function works on the given string by inserting '\0' + ///< characters to separate the individual parts. Therefore the string + ///< will be modified upon return. + static void BackTrace(cStringList &StringList, int Level = 0, bool Mangled = false); + ///< Produces a backtrace and stores it in the given StringList. + ///< If Level is given, only calls up to the given value are listed. + ///< If Mangled is true, the raw backtrace will be returned and you can use + ///< Demangle() to make the function names readable. + static void BackTrace(FILE *f = NULL, int Level = 0, bool Mangled = false); + ///< Produces a backtrace beginning at the given Level, and + ///< writes it to the given file. If no file is given, the backtrace is + ///< written to the logfile. If Mangled is true, the raw backtrace will + ///< be printed/logged. + static cString GetCaller(int Level = 0, bool Mangled = false); + ///< Returns the caller at the given Level (or the immediate caller, + ///< if Level is 0). + ///< If Mangled is true, the raw backtrace will be returned and you can use + ///< Demangle() to make the function name readable. + }; + // SystemExec() implements a 'system()' call that closes all unnecessary file // descriptors in the child process. // With Detached=true, calls command in background and in a separate session, |