kenmirrors/asterisk
1
0
Fork 0
mirror of https://github.com/asterisk/asterisk.git synced 2025-10-04 03:20:33 +00:00
Code Issues Packages Projects Releases Wiki Activity

utils: add lock timestamps for DEBUG_THREADS

Browse Source 
Adds last locked and unlocked timestamps as well as a
counter for the number of times the lock has been
attempted (vs locked/unlocked) to debug output printed
using the DEBUG_THREADS option.

Resolves: #110
(cherry picked from commit 3acdffc17e)
This commit is contained in:
Mike Bradeen
2023-05-23 12:33:55 -06:00
committed by Asterisk Development Team
parent 244e0b69ea
commit 714950bd7c
1 changed files with 39 additions and 6 deletions
Download Patch File Download Diff File Expand all files Collapse all files

45
main/utils.c
View File

@@ -971,6 +971,9 @@ struct thr_lock_info {
const char *lock_name; const char *lock_name;
void *lock_addr; void *lock_addr;
int times_locked; int times_locked;
int times_lock_attempted;
struct timeval last_locked;
struct timeval last_unlocked;
int line_num; int line_num;
enum ast_lock_type type; enum ast_lock_type type;
/*! This thread is waiting on this lock */ /*! This thread is waiting on this lock */
@@ -1063,6 +1066,8 @@ void ast_store_lock_info(enum ast_lock_type type, const char *filename,
for (i = 0; i < lock_info->num_locks; i++) { for (i = 0; i < lock_info->num_locks; i++) {
if (lock_info->locks[i].lock_addr == lock_addr) { if (lock_info->locks[i].lock_addr == lock_addr) {
lock_info->locks[i].times_locked++; lock_info->locks[i].times_locked++;
lock_info->locks[i].times_lock_attempted++;
lock_info->locks[i].last_locked = ast_tvnow();
#ifdef HAVE_BKTR #ifdef HAVE_BKTR
lock_info->locks[i].backtrace = bt; lock_info->locks[i].backtrace = bt;
#endif #endif
@@ -1094,6 +1099,8 @@ void ast_store_lock_info(enum ast_lock_type type, const char *filename,
lock_info->locks[i].lock_name = lock_name; lock_info->locks[i].lock_name = lock_name;
lock_info->locks[i].lock_addr = lock_addr; lock_info->locks[i].lock_addr = lock_addr;
lock_info->locks[i].times_locked = 1; lock_info->locks[i].times_locked = 1;
lock_info->locks[i].times_lock_attempted = 1;
lock_info->locks[i].last_locked = ast_tvnow();
lock_info->locks[i].type = type; lock_info->locks[i].type = type;
lock_info->locks[i].pending = 1; lock_info->locks[i].pending = 1;
#ifdef HAVE_BKTR #ifdef HAVE_BKTR
@@ -1133,6 +1140,7 @@ void ast_mark_lock_failed(void *lock_addr)
if (lock_info->locks[lock_info->num_locks - 1].lock_addr == lock_addr) { if (lock_info->locks[lock_info->num_locks - 1].lock_addr == lock_addr) {
lock_info->locks[lock_info->num_locks - 1].pending = -1; lock_info->locks[lock_info->num_locks - 1].pending = -1;
lock_info->locks[lock_info->num_locks - 1].times_locked--; lock_info->locks[lock_info->num_locks - 1].times_locked--;
lock_info->locks[lock_info->num_locks - 1].last_unlocked = ast_tvnow();
} }
pthread_mutex_unlock(&lock_info->lock); pthread_mutex_unlock(&lock_info->lock);
#endif /* ! LOW_MEMORY */ #endif /* ! LOW_MEMORY */
@@ -1255,6 +1263,7 @@ void ast_remove_lock_info(void *lock_addr, struct ast_bt *bt)
if (lock_info->locks[i].times_locked > 1) { if (lock_info->locks[i].times_locked > 1) {
lock_info->locks[i].times_locked--; lock_info->locks[i].times_locked--;
lock_info->locks[i].last_unlocked = ast_tvnow();
#ifdef HAVE_BKTR #ifdef HAVE_BKTR
lock_info->locks[i].backtrace = bt; lock_info->locks[i].backtrace = bt;
#endif #endif
@@ -1322,16 +1331,36 @@ static void append_lock_information(struct ast_str **str, struct thr_lock_info *
int j; int j;
ast_mutex_t *lock; ast_mutex_t *lock;
struct ast_lock_track *lt; struct ast_lock_track *lt;
struct timeval held_for;
struct timeval now = ast_tvnow();
char lock_time[32], unlock_time[32], held_time[32];
ast_str_append(str, 0, "=== ---> %sLock #%d (%s): %s %d %s %s %p (%d%s)\n", held_for = ast_tvsub(now, lock_info->locks[i].last_locked);
/* format time duration strings */
ast_format_duration_hh_mm_ss(lock_info->locks[i].last_locked.tv_sec,
lock_time, sizeof(lock_time));
ast_format_duration_hh_mm_ss(lock_info->locks[i].last_unlocked.tv_sec,
unlock_time, sizeof(unlock_time));
ast_format_duration_hh_mm_ss(held_for.tv_sec, held_time, sizeof(held_time));
ast_str_append(str, 0, "=== ---> %sLock #%d (%s): %s %d %s %s %p\n"
"=== %s.%06ld, %s.%06ld, %s.%06ld (%d, %d%s)\n",
lock_info->locks[i].pending > 0 ? "Waiting for " : lock_info->locks[i].pending > 0 ? "Waiting for " :
lock_info->locks[i].pending < 0 ? "Tried and failed to get " : "", i, lock_info->locks[i].pending < 0 ? "Tried and failed to get " : "", i,
lock_info->locks[i].file, lock_info->locks[i].file,
locktype2str(lock_info->locks[i].type), locktype2str(lock_info->locks[i].type),
lock_info->locks[i].line_num, lock_info->locks[i].line_num,
lock_info->locks[i].func, lock_info->locks[i].lock_name, lock_info->locks[i].func,
lock_info->locks[i].lock_name,
lock_info->locks[i].lock_addr, lock_info->locks[i].lock_addr,
lock_time,
lock_info->locks[i].last_locked.tv_usec,
unlock_time,
lock_info->locks[i].last_unlocked.tv_usec,
held_time,
held_for.tv_usec,
lock_info->locks[i].times_locked, lock_info->locks[i].times_locked,
lock_info->locks[i].times_lock_attempted,
lock_info->locks[i].suspended ? " - suspended" : ""); lock_info->locks[i].suspended ? " - suspended" : "");
#ifdef HAVE_BKTR #ifdef HAVE_BKTR
append_backtrace_information(str, lock_info->locks[i].backtrace); append_backtrace_information(str, lock_info->locks[i].backtrace);
@@ -1412,20 +1441,24 @@ struct ast_str *ast_dump_locks(void)
#if !defined(LOW_MEMORY) #if !defined(LOW_MEMORY)
struct thr_lock_info *lock_info; struct thr_lock_info *lock_info;
struct ast_str *str; struct ast_str *str;
char print_time[32];
struct timeval now = ast_tvnow();
if (!(str = ast_str_create(4096))) { if (!(str = ast_str_create(4096))) {
return NULL; return NULL;
} }
ast_format_duration_hh_mm_ss(now.tv_sec, print_time, sizeof(print_time));
ast_str_append(&str, 0, "\n" ast_str_append(&str, 0, "\n"
"=======================================================================\n" "=======================================================================\n"
"=== %s\n" "=== %s\n"
"=== Currently Held Locks\n" "=== Currently Held Locks at Time: %s.%06ld =================\n"
"=======================================================================\n" "=======================================================================\n"
"===\n" "===\n"
"=== <pending> <lock#> (<file>): <lock type> <line num> <function> <lock name> <lock addr> (times locked)\n" "=== <pending> <lock#> (<file>): <lock type> <line num> <function> <lock name> <lock addr>\n"
"===\n", ast_get_version()); "=== <locked at>, <failed at>, <held for> (attempts, times locked)\n"
"===\n", ast_get_version(), print_time, now.tv_usec);
if (!str) { if (!str) {
return NULL; return NULL;
} }