From fe8ade38b893ba02d3d8d9d9c69fd6249a8aa6dd Mon Sep 17 00:00:00 2001 From: Julian Seward Date: Tue, 16 Apr 2002 22:50:32 +0000 Subject: [PATCH] Change --trace-pthread= flag to accept none|some|all, for finer level of pthread event tracing. And allow this info to be passed across to the client, where vg_libpthread.c uses it to also control verbosity. git-svn-id: svn://svn.valgrind.org/valgrind/trunk@91 --- cachegrind/docs/manual.html | 7 +- coregrind/arch/x86-linux/vg_libpthread.c | 98 +++++++++++------------- coregrind/docs/manual.html | 7 +- coregrind/valgrind.in | 7 +- coregrind/vg_include.h | 8 +- coregrind/vg_libpthread.c | 98 +++++++++++------------- coregrind/vg_main.c | 14 ++-- coregrind/vg_scheduler.c | 22 +++--- docs/manual.html | 7 +- memcheck/docs/manual.html | 7 +- valgrind.in | 7 +- vg_include.h | 8 +- vg_libpthread.c | 98 +++++++++++------------- vg_main.c | 14 ++-- vg_scheduler.c | 22 +++--- 15 files changed, 208 insertions(+), 216 deletions(-) diff --git a/cachegrind/docs/manual.html b/cachegrind/docs/manual.html index ab638aff2f..c441db1620 100644 --- a/cachegrind/docs/manual.html +++ b/cachegrind/docs/manual.html @@ -565,9 +565,10 @@ shouldn't need to use them in the normal run of things. Nevertheless:

Enable/disable tracing of thread scheduling events.

-

  • --trace-pthread=no [default]
    - --trace-pthread=yes -

    Enable/disable tracing of pthread-related events.


    • +
  • --trace-pthread=none [default]
    + --trace-pthread=some
    + --trace-pthread=all +

    Specifies amount of trace detail for pthread-related events.


  • --trace-symtab=no [default]
    diff --git a/coregrind/arch/x86-linux/vg_libpthread.c b/coregrind/arch/x86-linux/vg_libpthread.c index ab397457de..11f5200a0d 100644 --- a/coregrind/arch/x86-linux/vg_libpthread.c +++ b/coregrind/arch/x86-linux/vg_libpthread.c @@ -27,29 +27,36 @@ #include #include + /* --------------------------------------------------------------------- - Mini-configuration. + Helpers. We have to be pretty self-sufficient. ------------------------------------------------------------------ */ -/* Set to 1 to see IGNORED debugging messages. */ -static int show_IGNORED = 1; +/* Extract from Valgrind the value of VG_(clo_trace_pthread_level). + Returns 0 (none) if not running on Valgrind. */ +static +int get_pt_trace_level ( void ) +{ + int res; + VALGRIND_MAGIC_SEQUENCE(res, 0 /* default */, + VG_USERREQ__GET_PTHREAD_TRACE_LEVEL, + 0, 0, 0, 0); + return res; +} -/* --------------------------------------------------------------------- - Helpers. We have to be pretty self-sufficient. - ------------------------------------------------------------------ */ static void myexit ( int arg ) { - int __res; + int __res; __asm__ volatile ("movl %%ecx, %%ebx ; int $0x80" : "=a" (__res) : "0" (__NR_exit), "c" (arg) ); - /* We don't bother to mention the fact that this asm trashes %ebx, - since it won't return. If you ever do let it return ... fix - this! */ + /* We don't bother to mention the fact that this asm trashes %ebx, + since it won't return. If you ever do let it return ... fix + this! */ } @@ -95,12 +102,13 @@ void barf ( char* str ) static void ignored ( char* msg ) { - char* ig = "vg_libpthread.so: IGNORED call to: "; - if (!show_IGNORED) return; - write(2, ig, strlen(ig)); - write(2, msg, strlen(msg)); - ig = "\n"; - write(2, ig, strlen(ig)); + if (get_pt_trace_level() >= 1) { + char* ig = "vg_libpthread.so: IGNORED call to: "; + write(2, ig, strlen(ig)); + write(2, msg, strlen(msg)); + ig = "\n"; + write(2, ig, strlen(ig)); + } } @@ -190,8 +198,6 @@ int pthread_mutex_init(pthread_mutex_t *mutex, const pthread_mutexattr_t *mutexattr) { int res; - // char* str = "pthread_mutex_init\n"; - // write(2, str, strlen(str)); ensure_valgrind("pthread_mutex_init"); VALGRIND_MAGIC_SEQUENCE(res, 0 /* default */, VG_USERREQ__PTHREAD_MUTEX_INIT, @@ -214,7 +220,8 @@ int pthread_mutexattr_settype(pthread_mutexattr_t *attr, int type) int pthread_mutex_lock(pthread_mutex_t *mutex) { int res; - if (!(RUNNING_ON_VALGRIND)) { + static int moans = 5; + if (!(RUNNING_ON_VALGRIND) && moans-- > 0) { char* str = "pthread_mutex_lock-NOT-INSIDE-VALGRIND\n"; write(2, str, strlen(str)); return 0; @@ -229,7 +236,8 @@ int pthread_mutex_lock(pthread_mutex_t *mutex) int pthread_mutex_unlock(pthread_mutex_t *mutex) { int res; - if (!(RUNNING_ON_VALGRIND)) { + static int moans = 5; + if (!(RUNNING_ON_VALGRIND) && moans-- > 0) { char* str = "pthread_mutex_unlock-NOT-INSIDE-VALGRIND\n"; write(2, str, strlen(str)); return 0; @@ -256,7 +264,8 @@ pthread_t pthread_self(void) int pthread_mutex_destroy(pthread_mutex_t *mutex) { int res; - if (!(RUNNING_ON_VALGRIND)) { + static int moans = 5; + if (!(RUNNING_ON_VALGRIND) && moans-- > 0) { char* str = "pthread_mutex_destroy-NOT-INSIDE-VALGRIND\n"; write(2, str, strlen(str)); return 0; @@ -335,9 +344,7 @@ int sigaction(int signum, const struct sigaction *act, struct sigaction *oldact) { - // char* str = "sigaction\n"; - // write(2, str, strlen(str)); - return __libc_sigaction(signum, act, oldact); + return __libc_sigaction(signum, act, oldact); } @@ -349,9 +356,7 @@ int connect(int sockfd, const struct sockaddr *serv_addr, socklen_t addrlen) { - // char* str = "connect\n"; - // write(2, str, strlen(str)); - return __libc_connect(sockfd, serv_addr, addrlen); + return __libc_connect(sockfd, serv_addr, addrlen); } @@ -359,9 +364,7 @@ extern int __libc_fcntl(int fd, int cmd, long arg); int fcntl(int fd, int cmd, long arg) { - // char* str = "fcntl\n"; - // write(2, str, strlen(str)); - return __libc_fcntl(fd, cmd, arg); + return __libc_fcntl(fd, cmd, arg); } @@ -369,9 +372,7 @@ extern ssize_t __libc_write(int fd, const void *buf, size_t count); ssize_t write(int fd, const void *buf, size_t count) { - // char* str = "write\n"; - // write(2, str, strlen(str)); - return __libc_write(fd, buf, count); + return __libc_write(fd, buf, count); } @@ -379,9 +380,7 @@ extern ssize_t __libc_read(int fd, void *buf, size_t count); ssize_t read(int fd, void *buf, size_t count) { - // char* str = "read\n"; - // write(2, str, strlen(str)); - return __libc_read(fd, buf, count); + return __libc_read(fd, buf, count); } @@ -389,9 +388,7 @@ extern int __libc_open(const char *pathname, int flags); int open(const char *pathname, int flags) { - // char* str = "open\n"; - // write(2, str, strlen(str)); - return __libc_open(pathname, flags); + return __libc_open(pathname, flags); } @@ -399,9 +396,7 @@ extern int __libc_close(int fd); int close(int fd) { - // char* str = "open\n"; - // write(2, str, strlen(str)); - return __libc_close(fd); + return __libc_close(fd); } @@ -409,9 +404,7 @@ extern int __libc_accept(int s, struct sockaddr *addr, socklen_t *addrlen); int accept(int s, struct sockaddr *addr, socklen_t *addrlen) { - // char* str = "accept\n"; - // write(2, str, strlen(str)); - return __libc_accept(s, addr, addrlen); + return __libc_accept(s, addr, addrlen); } @@ -419,9 +412,7 @@ extern pid_t __libc_fork(void); pid_t fork(void) { - // char* str = "fork\n"; - // write(2, str, strlen(str)); - return __libc_fork(); + return __libc_fork(); } @@ -429,9 +420,7 @@ extern pid_t __libc_waitpid(pid_t pid, int *status, int options); pid_t waitpid(pid_t pid, int *status, int options) { - // char* str = "waitpid\n"; - // write(2, str, strlen(str)); - return __libc_waitpid(pid, status, options); + return __libc_waitpid(pid, status, options); } @@ -446,14 +435,14 @@ extern int __libc_fsync(int fd); int fsync(int fd) { - return __libc_fsync(fd); + return __libc_fsync(fd); } extern off_t __libc_lseek(int fildes, off_t offset, int whence); off_t lseek(int fildes, off_t offset, int whence) { - return __libc_lseek(fildes, offset, whence); + return __libc_lseek(fildes, offset, whence); } extern @@ -470,6 +459,7 @@ int send(int s, const void *msg, size_t len, int flags) return __libc_send(s, msg, len, flags); } + /*--------------------------------------------------*/ /* I've no idea what these are, but they get called quite a lot. @@ -666,7 +656,7 @@ int select ( int n, /* fprintf(stderr, "MY_SELECT: nanosleep\n"); */ /* nanosleep and go round again */ nanosleep_interval.tv_sec = 0; - nanosleep_interval.tv_nsec = 20 * 1000 * 1000; /* 20 milliseconds */ + nanosleep_interval.tv_nsec = 40 * 1000 * 1000; /* 40 milliseconds */ /* It's critical here that valgrind's nanosleep implementation is nonblocking. */ (void)my_do_syscall2(__NR_nanosleep, diff --git a/coregrind/docs/manual.html b/coregrind/docs/manual.html index ab638aff2f..c441db1620 100644 --- a/coregrind/docs/manual.html +++ b/coregrind/docs/manual.html @@ -565,9 +565,10 @@ shouldn't need to use them in the normal run of things. Nevertheless:

    Enable/disable tracing of thread scheduling events.


    • -

  • --trace-pthread=no [default]
    - --trace-pthread=yes -

    Enable/disable tracing of pthread-related events.


    • +
  • --trace-pthread=none [default]
    + --trace-pthread=some
    + --trace-pthread=all +

    Specifies amount of trace detail for pthread-related events.


  • --trace-symtab=no [default]
    diff --git a/coregrind/valgrind.in b/coregrind/valgrind.in index ea7d757326..40bb6c959d 100755 --- a/coregrind/valgrind.in +++ b/coregrind/valgrind.in @@ -87,8 +87,9 @@ do --trace-malloc=no) vgopts="$vgopts $arg"; shift;; --trace-sched=yes) vgopts="$vgopts $arg"; shift;; --trace-sched=no) vgopts="$vgopts $arg"; shift;; - --trace-pthread=yes) vgopts="$vgopts $arg"; shift;; - --trace-pthread=no) vgopts="$vgopts $arg"; shift;; + --trace-pthread=none) vgopts="$vgopts $arg"; shift;; + --trace-pthread=some) vgopts="$vgopts $arg"; shift;; + --trace-pthread=all) vgopts="$vgopts $arg"; shift;; --stop-after=*) vgopts="$vgopts $arg"; shift;; --dump-error=*) vgopts="$vgopts $arg"; shift;; -*) dousage=1; break;; @@ -148,7 +149,7 @@ if [ z"$argopts" = z -o z"$dousage" = z1 ]; then echo " --trace-symtab=no|yes show symbol table details? [no]" echo " --trace-malloc=no|yes show client malloc details? [no]" echo " --trace-sched=no|yes show thread scheduler details? [no]" - echo " --trace-pthread=no|yes show pthread event details? [no]" + echo " --trace-pthread=none|some|all show pthread event details? [no]" echo " --stop-after= switch to real CPU after executing" echo " basic blocks [infinity]" echo " --dump-error= show translation for basic block" diff --git a/coregrind/vg_include.h b/coregrind/vg_include.h index 1fef7dad25..cd831c8d24 100644 --- a/coregrind/vg_include.h +++ b/coregrind/vg_include.h @@ -241,8 +241,9 @@ extern Bool VG_(clo_trace_symtab); extern Bool VG_(clo_trace_malloc); /* DEBUG: print thread scheduling events? default: NO */ extern Bool VG_(clo_trace_sched); -/* DEBUG: print pthread (mutex etc) events? default: NO */ -extern Bool VG_(clo_trace_pthread); +/* DEBUG: print pthread (mutex etc) events? default: 0 (none), 1 + (some), 2 (all) */ +extern Int VG_(clo_trace_pthread_level); /* Stop after this many basic blocks. default: Infinity. */ extern ULong VG_(clo_stop_after); /* Display gory details for the k'th most popular error. default: @@ -405,6 +406,9 @@ extern Bool VG_(is_empty_arena) ( ArenaId aid ); #define VG_USERREQ__PTHREAD_MUTEX_DESTROY 0x3007 #define VG_USERREQ__PTHREAD_CANCEL 0x3008 +/* Cosmetic ... */ +#define VG_USERREQ__GET_PTHREAD_TRACE_LEVEL 0x3101 + /* In vg_constants.h: #define VG_USERREQ__SIGNAL_RETURNS 0x4001 diff --git a/coregrind/vg_libpthread.c b/coregrind/vg_libpthread.c index ab397457de..11f5200a0d 100644 --- a/coregrind/vg_libpthread.c +++ b/coregrind/vg_libpthread.c @@ -27,29 +27,36 @@ #include #include + /* --------------------------------------------------------------------- - Mini-configuration. + Helpers. We have to be pretty self-sufficient. ------------------------------------------------------------------ */ -/* Set to 1 to see IGNORED debugging messages. */ -static int show_IGNORED = 1; +/* Extract from Valgrind the value of VG_(clo_trace_pthread_level). + Returns 0 (none) if not running on Valgrind. */ +static +int get_pt_trace_level ( void ) +{ + int res; + VALGRIND_MAGIC_SEQUENCE(res, 0 /* default */, + VG_USERREQ__GET_PTHREAD_TRACE_LEVEL, + 0, 0, 0, 0); + return res; +} -/* --------------------------------------------------------------------- - Helpers. We have to be pretty self-sufficient. - ------------------------------------------------------------------ */ static void myexit ( int arg ) { - int __res; + int __res; __asm__ volatile ("movl %%ecx, %%ebx ; int $0x80" : "=a" (__res) : "0" (__NR_exit), "c" (arg) ); - /* We don't bother to mention the fact that this asm trashes %ebx, - since it won't return. If you ever do let it return ... fix - this! */ + /* We don't bother to mention the fact that this asm trashes %ebx, + since it won't return. If you ever do let it return ... fix + this! */ } @@ -95,12 +102,13 @@ void barf ( char* str ) static void ignored ( char* msg ) { - char* ig = "vg_libpthread.so: IGNORED call to: "; - if (!show_IGNORED) return; - write(2, ig, strlen(ig)); - write(2, msg, strlen(msg)); - ig = "\n"; - write(2, ig, strlen(ig)); + if (get_pt_trace_level() >= 1) { + char* ig = "vg_libpthread.so: IGNORED call to: "; + write(2, ig, strlen(ig)); + write(2, msg, strlen(msg)); + ig = "\n"; + write(2, ig, strlen(ig)); + } } @@ -190,8 +198,6 @@ int pthread_mutex_init(pthread_mutex_t *mutex, const pthread_mutexattr_t *mutexattr) { int res; - // char* str = "pthread_mutex_init\n"; - // write(2, str, strlen(str)); ensure_valgrind("pthread_mutex_init"); VALGRIND_MAGIC_SEQUENCE(res, 0 /* default */, VG_USERREQ__PTHREAD_MUTEX_INIT, @@ -214,7 +220,8 @@ int pthread_mutexattr_settype(pthread_mutexattr_t *attr, int type) int pthread_mutex_lock(pthread_mutex_t *mutex) { int res; - if (!(RUNNING_ON_VALGRIND)) { + static int moans = 5; + if (!(RUNNING_ON_VALGRIND) && moans-- > 0) { char* str = "pthread_mutex_lock-NOT-INSIDE-VALGRIND\n"; write(2, str, strlen(str)); return 0; @@ -229,7 +236,8 @@ int pthread_mutex_lock(pthread_mutex_t *mutex) int pthread_mutex_unlock(pthread_mutex_t *mutex) { int res; - if (!(RUNNING_ON_VALGRIND)) { + static int moans = 5; + if (!(RUNNING_ON_VALGRIND) && moans-- > 0) { char* str = "pthread_mutex_unlock-NOT-INSIDE-VALGRIND\n"; write(2, str, strlen(str)); return 0; @@ -256,7 +264,8 @@ pthread_t pthread_self(void) int pthread_mutex_destroy(pthread_mutex_t *mutex) { int res; - if (!(RUNNING_ON_VALGRIND)) { + static int moans = 5; + if (!(RUNNING_ON_VALGRIND) && moans-- > 0) { char* str = "pthread_mutex_destroy-NOT-INSIDE-VALGRIND\n"; write(2, str, strlen(str)); return 0; @@ -335,9 +344,7 @@ int sigaction(int signum, const struct sigaction *act, struct sigaction *oldact) { - // char* str = "sigaction\n"; - // write(2, str, strlen(str)); - return __libc_sigaction(signum, act, oldact); + return __libc_sigaction(signum, act, oldact); } @@ -349,9 +356,7 @@ int connect(int sockfd, const struct sockaddr *serv_addr, socklen_t addrlen) { - // char* str = "connect\n"; - // write(2, str, strlen(str)); - return __libc_connect(sockfd, serv_addr, addrlen); + return __libc_connect(sockfd, serv_addr, addrlen); } @@ -359,9 +364,7 @@ extern int __libc_fcntl(int fd, int cmd, long arg); int fcntl(int fd, int cmd, long arg) { - // char* str = "fcntl\n"; - // write(2, str, strlen(str)); - return __libc_fcntl(fd, cmd, arg); + return __libc_fcntl(fd, cmd, arg); } @@ -369,9 +372,7 @@ extern ssize_t __libc_write(int fd, const void *buf, size_t count); ssize_t write(int fd, const void *buf, size_t count) { - // char* str = "write\n"; - // write(2, str, strlen(str)); - return __libc_write(fd, buf, count); + return __libc_write(fd, buf, count); } @@ -379,9 +380,7 @@ extern ssize_t __libc_read(int fd, void *buf, size_t count); ssize_t read(int fd, void *buf, size_t count) { - // char* str = "read\n"; - // write(2, str, strlen(str)); - return __libc_read(fd, buf, count); + return __libc_read(fd, buf, count); } @@ -389,9 +388,7 @@ extern int __libc_open(const char *pathname, int flags); int open(const char *pathname, int flags) { - // char* str = "open\n"; - // write(2, str, strlen(str)); - return __libc_open(pathname, flags); + return __libc_open(pathname, flags); } @@ -399,9 +396,7 @@ extern int __libc_close(int fd); int close(int fd) { - // char* str = "open\n"; - // write(2, str, strlen(str)); - return __libc_close(fd); + return __libc_close(fd); } @@ -409,9 +404,7 @@ extern int __libc_accept(int s, struct sockaddr *addr, socklen_t *addrlen); int accept(int s, struct sockaddr *addr, socklen_t *addrlen) { - // char* str = "accept\n"; - // write(2, str, strlen(str)); - return __libc_accept(s, addr, addrlen); + return __libc_accept(s, addr, addrlen); } @@ -419,9 +412,7 @@ extern pid_t __libc_fork(void); pid_t fork(void) { - // char* str = "fork\n"; - // write(2, str, strlen(str)); - return __libc_fork(); + return __libc_fork(); } @@ -429,9 +420,7 @@ extern pid_t __libc_waitpid(pid_t pid, int *status, int options); pid_t waitpid(pid_t pid, int *status, int options) { - // char* str = "waitpid\n"; - // write(2, str, strlen(str)); - return __libc_waitpid(pid, status, options); + return __libc_waitpid(pid, status, options); } @@ -446,14 +435,14 @@ extern int __libc_fsync(int fd); int fsync(int fd) { - return __libc_fsync(fd); + return __libc_fsync(fd); } extern off_t __libc_lseek(int fildes, off_t offset, int whence); off_t lseek(int fildes, off_t offset, int whence) { - return __libc_lseek(fildes, offset, whence); + return __libc_lseek(fildes, offset, whence); } extern @@ -470,6 +459,7 @@ int send(int s, const void *msg, size_t len, int flags) return __libc_send(s, msg, len, flags); } + /*--------------------------------------------------*/ /* I've no idea what these are, but they get called quite a lot. @@ -666,7 +656,7 @@ int select ( int n, /* fprintf(stderr, "MY_SELECT: nanosleep\n"); */ /* nanosleep and go round again */ nanosleep_interval.tv_sec = 0; - nanosleep_interval.tv_nsec = 20 * 1000 * 1000; /* 20 milliseconds */ + nanosleep_interval.tv_nsec = 40 * 1000 * 1000; /* 40 milliseconds */ /* It's critical here that valgrind's nanosleep implementation is nonblocking. */ (void)my_do_syscall2(__NR_nanosleep, diff --git a/coregrind/vg_main.c b/coregrind/vg_main.c index 7c5ac4062a..06b2e978f1 100644 --- a/coregrind/vg_main.c +++ b/coregrind/vg_main.c @@ -425,7 +425,7 @@ Bool VG_(clo_trace_signals); Bool VG_(clo_trace_symtab); Bool VG_(clo_trace_malloc); Bool VG_(clo_trace_sched); -Bool VG_(clo_trace_pthread); +Int VG_(clo_trace_pthread_level); ULong VG_(clo_stop_after); Int VG_(clo_dump_error); Int VG_(clo_backtrace_size); @@ -508,7 +508,7 @@ static void process_cmd_line_options ( void ) VG_(clo_trace_symtab) = False; VG_(clo_trace_malloc) = False; VG_(clo_trace_sched) = False; - VG_(clo_trace_pthread) = False; + VG_(clo_trace_pthread_level) = 0; VG_(clo_stop_after) = 1000000000000LL; VG_(clo_dump_error) = 0; VG_(clo_backtrace_size) = 4; @@ -777,10 +777,12 @@ static void process_cmd_line_options ( void ) else if (STREQ(argv[i], "--trace-sched=no")) VG_(clo_trace_sched) = False; - else if (STREQ(argv[i], "--trace-pthread=yes")) - VG_(clo_trace_pthread) = True; - else if (STREQ(argv[i], "--trace-pthread=no")) - VG_(clo_trace_pthread) = False; + else if (STREQ(argv[i], "--trace-pthread=none")) + VG_(clo_trace_pthread_level) = 0; + else if (STREQ(argv[i], "--trace-pthread=some")) + VG_(clo_trace_pthread_level) = 1; + else if (STREQ(argv[i], "--trace-pthread=all")) + VG_(clo_trace_pthread_level) = 2; else if (STREQN(13, argv[i], "--stop-after=")) VG_(clo_stop_after) = VG_(atoll)(&argv[i][13]); diff --git a/coregrind/vg_scheduler.c b/coregrind/vg_scheduler.c index 33cb15766e..770fbd3782 100644 --- a/coregrind/vg_scheduler.c +++ b/coregrind/vg_scheduler.c @@ -176,7 +176,7 @@ void add_waiting_fd ( ThreadId tid, Int fd, Int syscall_no ) static void print_sched_event ( ThreadId tid, Char* what ) { - VG_(message)(Vg_DebugMsg, "SCHED[%d]: %s", tid, what ); + VG_(message)(Vg_DebugMsg, " SCHED[%d]: %s", tid, what ); } @@ -555,6 +555,8 @@ Bool maybe_do_trivial_clientreq ( ThreadId tid ) SIMPLE_RETURN(tid); case VG_USERREQ__RUNNING_ON_VALGRIND: SIMPLE_RETURN(1); + case VG_USERREQ__GET_PTHREAD_TRACE_LEVEL: + SIMPLE_RETURN(VG_(clo_trace_pthread_level)); default: /* Too hard; wimp out. */ @@ -1477,7 +1479,7 @@ void initialise_mutex ( ThreadId tid, pthread_mutex_t *mutex ) vg_mutexes[mid].owner = VG_INVALID_THREADID; /* irrelevant */ mutex->__m_reserved = mid; mutex->__m_count = 1; /* initialised */ - if (VG_(clo_trace_pthread)) { + if (VG_(clo_trace_pthread_level) >= 1) { VG_(sprintf)(msg_buf, "(initialise mutex) (%p) -> %d", mutex, mid ); print_pthread_event(tid, msg_buf); @@ -1497,7 +1499,7 @@ void do_pthread_mutex_init ( ThreadId tid, initialise_mutex(tid, mutex); - if (VG_(clo_trace_pthread)) { + if (VG_(clo_trace_pthread_level) >= 1) { VG_(sprintf)(msg_buf, "pthread_mutex_init (%p) -> %d", mutex, mutex->__m_reserved ); print_pthread_event(tid, msg_buf); @@ -1541,7 +1543,7 @@ void do_pthread_mutex_lock( ThreadId tid, pthread_mutex_t *mutex ) return; } - if (VG_(clo_trace_pthread)) { + if (VG_(clo_trace_pthread_level) >= 2) { VG_(sprintf)(msg_buf, "pthread_mutex_lock %d (%p)", mid, mutex ); print_pthread_event(tid, msg_buf); @@ -1562,9 +1564,9 @@ void do_pthread_mutex_lock( ThreadId tid, pthread_mutex_t *mutex ) vg_threads[tid].status = VgTs_WaitMX; vg_threads[tid].waited_on_mid = mid; /* No assignment to %EDX, since we're blocking. */ - if (VG_(clo_trace_pthread)) { - VG_(sprintf)(msg_buf, "pthread_mutex_lock %d (%p): BLOCK", - mid, mutex ); + if (VG_(clo_trace_pthread_level) >= 1) { + VG_(sprintf)(msg_buf, "pthread_mutex_lock %d: BLOCK", + mid ); print_pthread_event(tid, msg_buf); } } else { @@ -1597,7 +1599,7 @@ void do_pthread_mutex_unlock ( ThreadId tid, return; } - if (VG_(clo_trace_pthread)) { + if (VG_(clo_trace_pthread_level) >= 2) { VG_(sprintf)(msg_buf, "pthread_mutex_unlock %d (%p)", mid, mutex ); print_pthread_event(tid, msg_buf); @@ -1633,7 +1635,7 @@ void do_pthread_mutex_unlock ( ThreadId tid, vg_threads[i].status = VgTs_Runnable; vg_threads[i].m_edx = 0; /* pth_lock() success */ - if (VG_(clo_trace_pthread)) { + if (VG_(clo_trace_pthread_level) >= 1) { VG_(sprintf)(msg_buf, "pthread_mutex_lock %d: RESUME", mid ); print_pthread_event(tid, msg_buf); @@ -1664,7 +1666,7 @@ static void do_pthread_mutex_destroy ( ThreadId tid, return; } - if (VG_(clo_trace_pthread)) { + if (VG_(clo_trace_pthread_level) >= 1) { VG_(sprintf)(msg_buf, "pthread_mutex_destroy %d (%p)", mid, mutex ); print_pthread_event(tid, msg_buf); diff --git a/docs/manual.html b/docs/manual.html index ab638aff2f..c441db1620 100644 --- a/docs/manual.html +++ b/docs/manual.html @@ -565,9 +565,10 @@ shouldn't need to use them in the normal run of things. Nevertheless:

    Enable/disable tracing of thread scheduling events.


    • -

  • --trace-pthread=no [default]
    - --trace-pthread=yes -

    Enable/disable tracing of pthread-related events.


    • +
  • --trace-pthread=none [default]
    + --trace-pthread=some
    + --trace-pthread=all +

    Specifies amount of trace detail for pthread-related events.


  • --trace-symtab=no [default]
    diff --git a/memcheck/docs/manual.html b/memcheck/docs/manual.html index ab638aff2f..c441db1620 100644 --- a/memcheck/docs/manual.html +++ b/memcheck/docs/manual.html @@ -565,9 +565,10 @@ shouldn't need to use them in the normal run of things. Nevertheless:

    Enable/disable tracing of thread scheduling events.


    • -

  • --trace-pthread=no [default]
    - --trace-pthread=yes -

    Enable/disable tracing of pthread-related events.


    • +
  • --trace-pthread=none [default]
    + --trace-pthread=some
    + --trace-pthread=all +

    Specifies amount of trace detail for pthread-related events.


  • --trace-symtab=no [default]
    diff --git a/valgrind.in b/valgrind.in index ea7d757326..40bb6c959d 100755 --- a/valgrind.in +++ b/valgrind.in @@ -87,8 +87,9 @@ do --trace-malloc=no) vgopts="$vgopts $arg"; shift;; --trace-sched=yes) vgopts="$vgopts $arg"; shift;; --trace-sched=no) vgopts="$vgopts $arg"; shift;; - --trace-pthread=yes) vgopts="$vgopts $arg"; shift;; - --trace-pthread=no) vgopts="$vgopts $arg"; shift;; + --trace-pthread=none) vgopts="$vgopts $arg"; shift;; + --trace-pthread=some) vgopts="$vgopts $arg"; shift;; + --trace-pthread=all) vgopts="$vgopts $arg"; shift;; --stop-after=*) vgopts="$vgopts $arg"; shift;; --dump-error=*) vgopts="$vgopts $arg"; shift;; -*) dousage=1; break;; @@ -148,7 +149,7 @@ if [ z"$argopts" = z -o z"$dousage" = z1 ]; then echo " --trace-symtab=no|yes show symbol table details? [no]" echo " --trace-malloc=no|yes show client malloc details? [no]" echo " --trace-sched=no|yes show thread scheduler details? [no]" - echo " --trace-pthread=no|yes show pthread event details? [no]" + echo " --trace-pthread=none|some|all show pthread event details? [no]" echo " --stop-after= switch to real CPU after executing" echo " basic blocks [infinity]" echo " --dump-error= show translation for basic block" diff --git a/vg_include.h b/vg_include.h index 1fef7dad25..cd831c8d24 100644 --- a/vg_include.h +++ b/vg_include.h @@ -241,8 +241,9 @@ extern Bool VG_(clo_trace_symtab); extern Bool VG_(clo_trace_malloc); /* DEBUG: print thread scheduling events? default: NO */ extern Bool VG_(clo_trace_sched); -/* DEBUG: print pthread (mutex etc) events? default: NO */ -extern Bool VG_(clo_trace_pthread); +/* DEBUG: print pthread (mutex etc) events? default: 0 (none), 1 + (some), 2 (all) */ +extern Int VG_(clo_trace_pthread_level); /* Stop after this many basic blocks. default: Infinity. */ extern ULong VG_(clo_stop_after); /* Display gory details for the k'th most popular error. default: @@ -405,6 +406,9 @@ extern Bool VG_(is_empty_arena) ( ArenaId aid ); #define VG_USERREQ__PTHREAD_MUTEX_DESTROY 0x3007 #define VG_USERREQ__PTHREAD_CANCEL 0x3008 +/* Cosmetic ... */ +#define VG_USERREQ__GET_PTHREAD_TRACE_LEVEL 0x3101 + /* In vg_constants.h: #define VG_USERREQ__SIGNAL_RETURNS 0x4001 diff --git a/vg_libpthread.c b/vg_libpthread.c index ab397457de..11f5200a0d 100644 --- a/vg_libpthread.c +++ b/vg_libpthread.c @@ -27,29 +27,36 @@ #include #include + /* --------------------------------------------------------------------- - Mini-configuration. + Helpers. We have to be pretty self-sufficient. ------------------------------------------------------------------ */ -/* Set to 1 to see IGNORED debugging messages. */ -static int show_IGNORED = 1; +/* Extract from Valgrind the value of VG_(clo_trace_pthread_level). + Returns 0 (none) if not running on Valgrind. */ +static +int get_pt_trace_level ( void ) +{ + int res; + VALGRIND_MAGIC_SEQUENCE(res, 0 /* default */, + VG_USERREQ__GET_PTHREAD_TRACE_LEVEL, + 0, 0, 0, 0); + return res; +} -/* --------------------------------------------------------------------- - Helpers. We have to be pretty self-sufficient. - ------------------------------------------------------------------ */ static void myexit ( int arg ) { - int __res; + int __res; __asm__ volatile ("movl %%ecx, %%ebx ; int $0x80" : "=a" (__res) : "0" (__NR_exit), "c" (arg) ); - /* We don't bother to mention the fact that this asm trashes %ebx, - since it won't return. If you ever do let it return ... fix - this! */ + /* We don't bother to mention the fact that this asm trashes %ebx, + since it won't return. If you ever do let it return ... fix + this! */ } @@ -95,12 +102,13 @@ void barf ( char* str ) static void ignored ( char* msg ) { - char* ig = "vg_libpthread.so: IGNORED call to: "; - if (!show_IGNORED) return; - write(2, ig, strlen(ig)); - write(2, msg, strlen(msg)); - ig = "\n"; - write(2, ig, strlen(ig)); + if (get_pt_trace_level() >= 1) { + char* ig = "vg_libpthread.so: IGNORED call to: "; + write(2, ig, strlen(ig)); + write(2, msg, strlen(msg)); + ig = "\n"; + write(2, ig, strlen(ig)); + } } @@ -190,8 +198,6 @@ int pthread_mutex_init(pthread_mutex_t *mutex, const pthread_mutexattr_t *mutexattr) { int res; - // char* str = "pthread_mutex_init\n"; - // write(2, str, strlen(str)); ensure_valgrind("pthread_mutex_init"); VALGRIND_MAGIC_SEQUENCE(res, 0 /* default */, VG_USERREQ__PTHREAD_MUTEX_INIT, @@ -214,7 +220,8 @@ int pthread_mutexattr_settype(pthread_mutexattr_t *attr, int type) int pthread_mutex_lock(pthread_mutex_t *mutex) { int res; - if (!(RUNNING_ON_VALGRIND)) { + static int moans = 5; + if (!(RUNNING_ON_VALGRIND) && moans-- > 0) { char* str = "pthread_mutex_lock-NOT-INSIDE-VALGRIND\n"; write(2, str, strlen(str)); return 0; @@ -229,7 +236,8 @@ int pthread_mutex_lock(pthread_mutex_t *mutex) int pthread_mutex_unlock(pthread_mutex_t *mutex) { int res; - if (!(RUNNING_ON_VALGRIND)) { + static int moans = 5; + if (!(RUNNING_ON_VALGRIND) && moans-- > 0) { char* str = "pthread_mutex_unlock-NOT-INSIDE-VALGRIND\n"; write(2, str, strlen(str)); return 0; @@ -256,7 +264,8 @@ pthread_t pthread_self(void) int pthread_mutex_destroy(pthread_mutex_t *mutex) { int res; - if (!(RUNNING_ON_VALGRIND)) { + static int moans = 5; + if (!(RUNNING_ON_VALGRIND) && moans-- > 0) { char* str = "pthread_mutex_destroy-NOT-INSIDE-VALGRIND\n"; write(2, str, strlen(str)); return 0; @@ -335,9 +344,7 @@ int sigaction(int signum, const struct sigaction *act, struct sigaction *oldact) { - // char* str = "sigaction\n"; - // write(2, str, strlen(str)); - return __libc_sigaction(signum, act, oldact); + return __libc_sigaction(signum, act, oldact); } @@ -349,9 +356,7 @@ int connect(int sockfd, const struct sockaddr *serv_addr, socklen_t addrlen) { - // char* str = "connect\n"; - // write(2, str, strlen(str)); - return __libc_connect(sockfd, serv_addr, addrlen); + return __libc_connect(sockfd, serv_addr, addrlen); } @@ -359,9 +364,7 @@ extern int __libc_fcntl(int fd, int cmd, long arg); int fcntl(int fd, int cmd, long arg) { - // char* str = "fcntl\n"; - // write(2, str, strlen(str)); - return __libc_fcntl(fd, cmd, arg); + return __libc_fcntl(fd, cmd, arg); } @@ -369,9 +372,7 @@ extern ssize_t __libc_write(int fd, const void *buf, size_t count); ssize_t write(int fd, const void *buf, size_t count) { - // char* str = "write\n"; - // write(2, str, strlen(str)); - return __libc_write(fd, buf, count); + return __libc_write(fd, buf, count); } @@ -379,9 +380,7 @@ extern ssize_t __libc_read(int fd, void *buf, size_t count); ssize_t read(int fd, void *buf, size_t count) { - // char* str = "read\n"; - // write(2, str, strlen(str)); - return __libc_read(fd, buf, count); + return __libc_read(fd, buf, count); } @@ -389,9 +388,7 @@ extern int __libc_open(const char *pathname, int flags); int open(const char *pathname, int flags) { - // char* str = "open\n"; - // write(2, str, strlen(str)); - return __libc_open(pathname, flags); + return __libc_open(pathname, flags); } @@ -399,9 +396,7 @@ extern int __libc_close(int fd); int close(int fd) { - // char* str = "open\n"; - // write(2, str, strlen(str)); - return __libc_close(fd); + return __libc_close(fd); } @@ -409,9 +404,7 @@ extern int __libc_accept(int s, struct sockaddr *addr, socklen_t *addrlen); int accept(int s, struct sockaddr *addr, socklen_t *addrlen) { - // char* str = "accept\n"; - // write(2, str, strlen(str)); - return __libc_accept(s, addr, addrlen); + return __libc_accept(s, addr, addrlen); } @@ -419,9 +412,7 @@ extern pid_t __libc_fork(void); pid_t fork(void) { - // char* str = "fork\n"; - // write(2, str, strlen(str)); - return __libc_fork(); + return __libc_fork(); } @@ -429,9 +420,7 @@ extern pid_t __libc_waitpid(pid_t pid, int *status, int options); pid_t waitpid(pid_t pid, int *status, int options) { - // char* str = "waitpid\n"; - // write(2, str, strlen(str)); - return __libc_waitpid(pid, status, options); + return __libc_waitpid(pid, status, options); } @@ -446,14 +435,14 @@ extern int __libc_fsync(int fd); int fsync(int fd) { - return __libc_fsync(fd); + return __libc_fsync(fd); } extern off_t __libc_lseek(int fildes, off_t offset, int whence); off_t lseek(int fildes, off_t offset, int whence) { - return __libc_lseek(fildes, offset, whence); + return __libc_lseek(fildes, offset, whence); } extern @@ -470,6 +459,7 @@ int send(int s, const void *msg, size_t len, int flags) return __libc_send(s, msg, len, flags); } + /*--------------------------------------------------*/ /* I've no idea what these are, but they get called quite a lot. @@ -666,7 +656,7 @@ int select ( int n, /* fprintf(stderr, "MY_SELECT: nanosleep\n"); */ /* nanosleep and go round again */ nanosleep_interval.tv_sec = 0; - nanosleep_interval.tv_nsec = 20 * 1000 * 1000; /* 20 milliseconds */ + nanosleep_interval.tv_nsec = 40 * 1000 * 1000; /* 40 milliseconds */ /* It's critical here that valgrind's nanosleep implementation is nonblocking. */ (void)my_do_syscall2(__NR_nanosleep, diff --git a/vg_main.c b/vg_main.c index 7c5ac4062a..06b2e978f1 100644 --- a/vg_main.c +++ b/vg_main.c @@ -425,7 +425,7 @@ Bool VG_(clo_trace_signals); Bool VG_(clo_trace_symtab); Bool VG_(clo_trace_malloc); Bool VG_(clo_trace_sched); -Bool VG_(clo_trace_pthread); +Int VG_(clo_trace_pthread_level); ULong VG_(clo_stop_after); Int VG_(clo_dump_error); Int VG_(clo_backtrace_size); @@ -508,7 +508,7 @@ static void process_cmd_line_options ( void ) VG_(clo_trace_symtab) = False; VG_(clo_trace_malloc) = False; VG_(clo_trace_sched) = False; - VG_(clo_trace_pthread) = False; + VG_(clo_trace_pthread_level) = 0; VG_(clo_stop_after) = 1000000000000LL; VG_(clo_dump_error) = 0; VG_(clo_backtrace_size) = 4; @@ -777,10 +777,12 @@ static void process_cmd_line_options ( void ) else if (STREQ(argv[i], "--trace-sched=no")) VG_(clo_trace_sched) = False; - else if (STREQ(argv[i], "--trace-pthread=yes")) - VG_(clo_trace_pthread) = True; - else if (STREQ(argv[i], "--trace-pthread=no")) - VG_(clo_trace_pthread) = False; + else if (STREQ(argv[i], "--trace-pthread=none")) + VG_(clo_trace_pthread_level) = 0; + else if (STREQ(argv[i], "--trace-pthread=some")) + VG_(clo_trace_pthread_level) = 1; + else if (STREQ(argv[i], "--trace-pthread=all")) + VG_(clo_trace_pthread_level) = 2; else if (STREQN(13, argv[i], "--stop-after=")) VG_(clo_stop_after) = VG_(atoll)(&argv[i][13]); diff --git a/vg_scheduler.c b/vg_scheduler.c index 33cb15766e..770fbd3782 100644 --- a/vg_scheduler.c +++ b/vg_scheduler.c @@ -176,7 +176,7 @@ void add_waiting_fd ( ThreadId tid, Int fd, Int syscall_no ) static void print_sched_event ( ThreadId tid, Char* what ) { - VG_(message)(Vg_DebugMsg, "SCHED[%d]: %s", tid, what ); + VG_(message)(Vg_DebugMsg, " SCHED[%d]: %s", tid, what ); } @@ -555,6 +555,8 @@ Bool maybe_do_trivial_clientreq ( ThreadId tid ) SIMPLE_RETURN(tid); case VG_USERREQ__RUNNING_ON_VALGRIND: SIMPLE_RETURN(1); + case VG_USERREQ__GET_PTHREAD_TRACE_LEVEL: + SIMPLE_RETURN(VG_(clo_trace_pthread_level)); default: /* Too hard; wimp out. */ @@ -1477,7 +1479,7 @@ void initialise_mutex ( ThreadId tid, pthread_mutex_t *mutex ) vg_mutexes[mid].owner = VG_INVALID_THREADID; /* irrelevant */ mutex->__m_reserved = mid; mutex->__m_count = 1; /* initialised */ - if (VG_(clo_trace_pthread)) { + if (VG_(clo_trace_pthread_level) >= 1) { VG_(sprintf)(msg_buf, "(initialise mutex) (%p) -> %d", mutex, mid ); print_pthread_event(tid, msg_buf); @@ -1497,7 +1499,7 @@ void do_pthread_mutex_init ( ThreadId tid, initialise_mutex(tid, mutex); - if (VG_(clo_trace_pthread)) { + if (VG_(clo_trace_pthread_level) >= 1) { VG_(sprintf)(msg_buf, "pthread_mutex_init (%p) -> %d", mutex, mutex->__m_reserved ); print_pthread_event(tid, msg_buf); @@ -1541,7 +1543,7 @@ void do_pthread_mutex_lock( ThreadId tid, pthread_mutex_t *mutex ) return; } - if (VG_(clo_trace_pthread)) { + if (VG_(clo_trace_pthread_level) >= 2) { VG_(sprintf)(msg_buf, "pthread_mutex_lock %d (%p)", mid, mutex ); print_pthread_event(tid, msg_buf); @@ -1562,9 +1564,9 @@ void do_pthread_mutex_lock( ThreadId tid, pthread_mutex_t *mutex ) vg_threads[tid].status = VgTs_WaitMX; vg_threads[tid].waited_on_mid = mid; /* No assignment to %EDX, since we're blocking. */ - if (VG_(clo_trace_pthread)) { - VG_(sprintf)(msg_buf, "pthread_mutex_lock %d (%p): BLOCK", - mid, mutex ); + if (VG_(clo_trace_pthread_level) >= 1) { + VG_(sprintf)(msg_buf, "pthread_mutex_lock %d: BLOCK", + mid ); print_pthread_event(tid, msg_buf); } } else { @@ -1597,7 +1599,7 @@ void do_pthread_mutex_unlock ( ThreadId tid, return; } - if (VG_(clo_trace_pthread)) { + if (VG_(clo_trace_pthread_level) >= 2) { VG_(sprintf)(msg_buf, "pthread_mutex_unlock %d (%p)", mid, mutex ); print_pthread_event(tid, msg_buf); @@ -1633,7 +1635,7 @@ void do_pthread_mutex_unlock ( ThreadId tid, vg_threads[i].status = VgTs_Runnable; vg_threads[i].m_edx = 0; /* pth_lock() success */ - if (VG_(clo_trace_pthread)) { + if (VG_(clo_trace_pthread_level) >= 1) { VG_(sprintf)(msg_buf, "pthread_mutex_lock %d: RESUME", mid ); print_pthread_event(tid, msg_buf); @@ -1664,7 +1666,7 @@ static void do_pthread_mutex_destroy ( ThreadId tid, return; } - if (VG_(clo_trace_pthread)) { + if (VG_(clo_trace_pthread_level) >= 1) { VG_(sprintf)(msg_buf, "pthread_mutex_destroy %d (%p)", mid, mutex ); print_pthread_event(tid, msg_buf); -- 2.47.2