diff options
| -rw-r--r-- | CONTRIBUTORS | 2 | ||||
| -rw-r--r-- | HISTORY | 8 | ||||
| -rw-r--r-- | channels.c | 4 | ||||
| -rw-r--r-- | config.h | 10 | ||||
| -rw-r--r-- | epg.c | 4 | ||||
| -rw-r--r-- | recording.c | 4 | ||||
| -rw-r--r-- | thread.c | 175 | ||||
| -rw-r--r-- | timers.c | 4 |
8 files changed, 191 insertions, 20 deletions
diff --git a/CONTRIBUTORS b/CONTRIBUTORS index 140ae533..9f342077 100644 --- a/CONTRIBUTORS +++ b/CONTRIBUTORS @@ -3424,6 +3424,8 @@ Jasmin Jessich <jasmin@anw.at> debugging MTD support for fixing selecting delivery system names in case of undefined indexes for fixing detecting the inclusion of STL header files in tools.h + for help and suggestions when implementing debug output for checking the correct + sequence of locking global lists Martin Schirrmacher <schirrmie@gmail.com> for suggesting to provide a way for skin plugins to get informed about the currently @@ -9055,3 +9055,11 @@ Video Disk Recorder Revision History The newplugin script has also been modified accordingly. - Fixed detecting the inclusion of STL header files in tools.h (thanks to Jasmin Jessich). + +2017-05-28: 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. @@ -4,7 +4,7 @@ * See the main source file 'vdr.c' for copyright information and * how to reach the author. * - * $Id: channels.c 4.3 2015/09/09 10:21:22 kls Exp $ + * $Id: channels.c 4.4 2017/05/26 15:43:54 kls Exp $ */ #include "channels.h" @@ -833,7 +833,7 @@ int cChannels::maxChannelNameLength = 0; int cChannels::maxShortChannelNameLength = 0; cChannels::cChannels(void) -:cConfig<cChannel>("Channels") +:cConfig<cChannel>("2 Channels") { modifiedByUser = 0; } @@ -4,7 +4,7 @@ * See the main source file 'vdr.c' for copyright information and * how to reach the author. * - * $Id: config.h 4.9 2017/04/29 13:33:13 kls Exp $ + * $Id: config.h 4.10 2017/05/28 12:42:49 kls Exp $ */ #ifndef __CONFIG_H @@ -22,13 +22,13 @@ // VDR's own version number: -#define VDRVERSION "2.3.5" -#define VDRVERSNUM 20305 // Version * 10000 + Major * 100 + Minor +#define VDRVERSION "2.3.6" +#define VDRVERSNUM 20306 // Version * 10000 + Major * 100 + Minor // The plugin API's version number: -#define APIVERSION "2.3.5" -#define APIVERSNUM 20305 // Version * 10000 + Major * 100 + Minor +#define APIVERSION "2.3.6" +#define APIVERSNUM 20306 // Version * 10000 + Major * 100 + Minor // When loading plugins, VDR searches them by their APIVERSION, which // may be smaller than VDRVERSION in case there have been no changes to @@ -7,7 +7,7 @@ * Original version (as used in VDR before 1.3.0) written by * Robert Schneider <Robert.Schneider@web.de> and Rolf Hakenes <hakenes@hippomi.de>. * - * $Id: epg.c 4.6 2017/05/09 12:16:36 kls Exp $ + * $Id: epg.c 4.7 2017/05/28 11:30:32 kls Exp $ */ #include "epg.h" @@ -1225,7 +1225,7 @@ char *cSchedules::epgDataFileName = NULL; time_t cSchedules::lastDump = time(NULL); cSchedules::cSchedules(void) -:cList<cSchedule>("Schedules") +:cList<cSchedule>("5 Schedules") { } diff --git a/recording.c b/recording.c index 9f96b73d..7b1d158b 100644 --- a/recording.c +++ b/recording.c @@ -4,7 +4,7 @@ * See the main source file 'vdr.c' for copyright information and * how to reach the author. * - * $Id: recording.c 4.8 2017/04/03 13:34:30 kls Exp $ + * $Id: recording.c 4.9 2017/05/27 15:46:57 kls Exp $ */ #include "recording.h" @@ -1469,7 +1469,7 @@ cVideoDirectoryScannerThread *cRecordings::videoDirectoryScannerThread = NULL; time_t cRecordings::lastUpdate = 0; cRecordings::cRecordings(bool Deleted) -:cList<cRecording>(Deleted ? "DelRecs" : "Recordings") +:cList<cRecording>(Deleted ? "4 DelRecs" : "3 Recordings") { } @@ -4,7 +4,7 @@ * See the main source file 'vdr.c' for copyright information and * how to reach the author. * - * $Id: thread.c 4.2 2016/12/08 10:18:32 kls Exp $ + * $Id: thread.c 4.3 2017/05/28 12:41:03 kls Exp $ */ #include "thread.h" @@ -24,6 +24,7 @@ #define ABORT { dsyslog("ABORT!"); abort(); } // use debugger to trace back the problem //#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 #ifdef DEBUG_LOCKING #define dbglocking(a...) fprintf(stderr, a) @@ -431,6 +432,163 @@ bool cThreadLock::Lock(cThread *Thread) // --- cStateLock ------------------------------------------------------------ +#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) +{ + char *Module = s; + char *Function = NULL; + //char *Offset = NULL; + char *Address = NULL; + // separate the string: + for (char *q = Module; *q; q++) { + if (*q == '(') { + *q = 0; + Function = q + 1; + } + else if (*q == '+') { + *q = 0; + //Offset = q + 1; + } + else if (*q == ')') + *q = 0; + else if (*q == '[') + Address = q + 1; + else if (*q == ']') { + *q = 0; + break; + } + } + // 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); + // determine the file name and line number: + cString cmd = cString::sprintf("addr2line --exe=%s --functions --demangle --basename %s", Module, Address); + 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)) + d = cString::sprintf("%s calling %s", *d, l); + } + else + d = cString::sprintf("%s at %s", *d, l); + n++; + } + p.Close(); + } + free(r); + return d; +} + +static void BackTrace(void) +{ + 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])); + free(s); + } +} + +static void BackTraceCaller(int Level, char *t, int l) +{ + void *b[BT_BUF_SIZE]; + int n = backtrace(b, BT_BUF_SIZE); + if (char **s = backtrace_symbols(b, n)) { + strn0cpy(t, s[Level], l); + free(s); + } +} + +static void DumpStateLockLog(tThreadId ThreadId, const char *Name) +{ + if (!DumpStateLocks) + return; + DumpStateLocks = false; + 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 (++StateLockLogIndex >= SLL_SIZE) + StateLockLogIndex = 0; + } + fprintf(stderr, "%5d invalid lock sequence: %-12s\n", ThreadId, Name); + fprintf(stderr, "full backtrace:\n"); + BackTrace(); +} + +static void CheckStateLockLevel(const char *Name, bool Lock, bool Write = false) +{ + if (Name) { + int n = *Name - '0'; + if (1 <= n && n <= 9) { + int b = 1 << (n - 1); + cMutexLock MutexLock(&StateLockMutex); + tThreadId ThreadId = cThread::ThreadId(); + int Index = StateLockThreadIds.IndexOf(ThreadId); + if (Index < 0) { + if (Lock) { + Index = StateLockThreadIds.Size(); + StateLockThreadIds.Append(ThreadId); + StateLockFlags.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; + if (Lock) { + if ((StateLockFlags[Index] & ~b) < b) + StateLockFlags[Index] |= b; + else if ((StateLockFlags[Index] & b) == 0) + DumpStateLockLog(ThreadId, Name); + } + else + StateLockFlags[Index] &= ~b; + } + } +} +#define dbglockseq(n, l, w) CheckStateLockLevel(n, l, w) +#else +#define dbglockseq(n, l, w) +#endif // DEBUG_LOCKSEQ + cStateLock::cStateLock(const char *Name) :rwLock(true) { @@ -442,7 +600,7 @@ cStateLock::cStateLock(const char *Name) bool cStateLock::Lock(cStateKey &StateKey, bool Write, int TimeoutMs) { - dbglocking("%5d %-10s %10p lock state = %d/%d write = %d timeout = %d\n", cThread::ThreadId(), name, &StateKey, state, StateKey.state, Write, TimeoutMs); + dbglocking("%5d %-12s %10p lock state = %d/%d write = %d timeout = %d\n", cThread::ThreadId(), name, &StateKey, state, StateKey.state, Write, TimeoutMs); StateKey.timedOut = false; if (StateKey.stateLock) { esyslog("ERROR: StateKey already in use in call to cStateLock::Lock() (tid=%d, lock=%s)", StateKey.stateLock->threadId, name); @@ -450,25 +608,27 @@ bool cStateLock::Lock(cStateKey &StateKey, bool Write, int TimeoutMs) return false; } if (rwLock.Lock(Write, TimeoutMs)) { + dbglockseq(name, true, Write); StateKey.stateLock = this; if (Write) { - dbglocking("%5d %-10s %10p locked write\n", cThread::ThreadId(), name, &StateKey); + dbglocking("%5d %-12s %10p locked write\n", cThread::ThreadId(), name, &StateKey); threadId = cThread::ThreadId(); StateKey.write = true; return true; } else if (state != StateKey.state) { - dbglocking("%5d %-10s %10p locked read\n", cThread::ThreadId(), name, &StateKey); + dbglocking("%5d %-12s %10p locked read\n", cThread::ThreadId(), name, &StateKey); return true; } else { - dbglocking("%5d %-10s %10p state unchanged\n", cThread::ThreadId(), name, &StateKey); + dbglocking("%5d %-12s %10p state unchanged\n", cThread::ThreadId(), name, &StateKey); StateKey.stateLock = NULL; + dbglockseq(name, false, false); rwLock.Unlock(); } } else if (TimeoutMs) { - dbglocking("%5d %-10s %10p timeout\n", cThread::ThreadId(), name, &StateKey); + dbglocking("%5d %-12s %10p timeout\n", cThread::ThreadId(), name, &StateKey); StateKey.timedOut = true; } return false; @@ -476,7 +636,7 @@ bool cStateLock::Lock(cStateKey &StateKey, bool Write, int TimeoutMs) void cStateLock::Unlock(cStateKey &StateKey, bool IncState) { - dbglocking("%5d %-10s %10p unlock state = %d/%d inc = %d\n", cThread::ThreadId(), name, &StateKey, state, StateKey.state, IncState); + dbglocking("%5d %-12s %10p unlock state = %d/%d inc = %d\n", cThread::ThreadId(), name, &StateKey, state, StateKey.state, IncState); if (StateKey.stateLock != this) { esyslog("ERROR: cStateLock::Unlock() called with an unused key (tid=%d, lock=%s)", threadId, name); ABORT; @@ -495,6 +655,7 @@ void cStateLock::Unlock(cStateKey &StateKey, bool IncState) threadId = 0; explicitModify = false; } + dbglockseq(name, false, false); rwLock.Unlock(); } @@ -4,7 +4,7 @@ * See the main source file 'vdr.c' for copyright information and * how to reach the author. * - * $Id: timers.c 4.9 2017/04/20 09:15:06 kls Exp $ + * $Id: timers.c 4.10 2017/05/26 15:43:38 kls Exp $ */ #include "timers.h" @@ -714,7 +714,7 @@ cTimers cTimers::timers; int cTimers::lastTimerId = 0; cTimers::cTimers(void) -:cConfig<cTimer>("Timers") +:cConfig<cTimer>("1 Timers") { lastDeleteExpired = 0; } |