Date: Fri, 21 Dec 2012 19:37:52 -0800 From: Alfred Perlstein <bright@mu.org> To: Daniel Eischen <deischen@freebsd.org>, Jason Evans <jasone@freebsd.org>, hackers@freebsd.org Subject: malloc+utrace, tracking memory leaks in a running program. Message-ID: <50D52B10.1060205@mu.org>
next in thread | raw e-mail | index | archive | help
This is a multi-part message in MIME format. --------------000103040406040707070503 Content-Type: text/plain; charset=ISO-8859-1; format=flowed Content-Transfer-Encoding: 7bit Hey guys. So the other day in an effort to debug a memory leak I decided to take a look at malloc+utrace(2) and decided to make a tool to debug where leaks are coming from. A few hours later I have: 1) a new version of utrace(2) (utrace2(2)) that uses structured data to prevent overloading of data. (utrace2.diff) 2) changes to ktrace and kdump to decode the new format. (also in utrace2.diff) 3) changes to jemalloc to include the new format AND the function caller so it's easy to get the source of the leaks. (also in utrace2.diff) 4) a program that can take a pipe of kdump(1) and figure out what memory has leaked. (alloctrace.py) 5) simple test program (test_utrace.c) If you want to get a trace now you can do this: gcc -Wall -O ./test_utrace.c env MALLOC_CONF='utrace:true' ktrace ./a.out kdump | ./alloctrace.py Now the problem I am having is making this work on a running program: 1) turning on the "opt_utrace" in a running program is almost impossible. This is because libc is installed stripped. Unfortunately my gdb-foo is weak and I was unable to load the symbol file without a really bad hack. The only way I could get it done was to use a trick from Ed Maste which was to: 1.1) install a debug copy of libc.so over the installed one. <- dislike! 1.2) then launching gdb ./a.out <pid>, 1.3) then set __jemalloc_opt_utrace = 1 1.4) enable ktrace on the running binary: ktrace -p <pid> -t U # this is utrace2 enabled 1.5) run 'cont' in gdb to proceed. There has to be an easier way to access the symbol __jemalloc_opt_utrace besides copying over the installed libc. Is there a workaround for 1.1? Is it time to start installing with some form of debug symbols? This would help us also with dtrace. Ideas? -Alfred --------------000103040406040707070503 Content-Type: text/plain; charset=UTF-8; x-mac-type="0"; x-mac-creator="0"; name="utrace2.diff" Content-Transfer-Encoding: 7bit Content-Disposition: attachment; filename="utrace2.diff" Index: contrib/jemalloc/src/jemalloc.c =================================================================== --- contrib/jemalloc/src/jemalloc.c (revision 244503) +++ contrib/jemalloc/src/jemalloc.c (working copy) @@ -78,20 +78,26 @@ static malloc_mutex_t init_lock = MALLOC_MUTEX_INITIALIZER; #endif +#ifdef JEMALLOC_UTRACE typedef struct { + int ut_type; /* utrace type UTRACE_MALLOC */ + int ut_version; /* utrace malloc version */ void *p; /* Input pointer (as in realloc(p, s)). */ size_t s; /* Request size. */ void *r; /* Result pointer. */ + void *ut_caller; /* Caller */ } malloc_utrace_t; -#ifdef JEMALLOC_UTRACE # define UTRACE(a, b, c) do { \ if (opt_utrace) { \ malloc_utrace_t ut; \ + ut.ut_type = UTRACE_MALLOC; \ + ut.ut_version = 2; \ ut.p = (a); \ ut.s = (b); \ ut.r = (c); \ - utrace(&ut, sizeof(ut)); \ + ut.ut_caller = __builtin_return_address(0); \ + utrace2(&ut, sizeof(ut)); \ } \ } while (0) #else @@ -975,7 +981,6 @@ } if (config_prof && opt_prof && result != NULL) prof_malloc(result, usize, cnt); - UTRACE(0, size, result); return (ret); } @@ -985,6 +990,7 @@ int ret = imemalign(memptr, alignment, size, sizeof(void *)); JEMALLOC_VALGRIND_MALLOC(ret == 0, *memptr, isalloc(*memptr, config_prof), false); + UTRACE(0, size, *memptr); return (ret); } @@ -1000,6 +1006,7 @@ } JEMALLOC_VALGRIND_MALLOC(err == 0, ret, isalloc(ret, config_prof), false); + UTRACE(0, size, ret); return (ret); } @@ -1265,6 +1272,7 @@ void *ret JEMALLOC_CC_SILENCE_INIT(NULL); imemalign(&ret, alignment, size, 1); JEMALLOC_VALGRIND_MALLOC(ret != NULL, ret, size, false); + UTRACE(0, size, ret); return (ret); } #endif @@ -1276,6 +1284,7 @@ void *ret JEMALLOC_CC_SILENCE_INIT(NULL); imemalign(&ret, PAGE, size, 1); JEMALLOC_VALGRIND_MALLOC(ret != NULL, ret, size, false); + UTRACE(0, size, ret); return (ret); } #endif Index: sys/compat/freebsd32/syscalls.master =================================================================== --- sys/compat/freebsd32/syscalls.master (revision 244503) +++ sys/compat/freebsd32/syscalls.master (working copy) @@ -1004,4 +1004,5 @@ int *status, int options, \ struct wrusage32 *wrusage, \ siginfo_t *info); } +533 AUE_NULL STD { int utrace2(const void *addr, size_t len); } Index: sys/kern/init_sysent.c =================================================================== --- sys/kern/init_sysent.c (revision 244503) +++ sys/kern/init_sysent.c (working copy) @@ -567,4 +567,5 @@ { AS(posix_fallocate_args), (sy_call_t *)sys_posix_fallocate, AUE_NULL, NULL, 0, 0, 0, SY_THR_STATIC }, /* 530 = posix_fallocate */ { AS(posix_fadvise_args), (sy_call_t *)sys_posix_fadvise, AUE_NULL, NULL, 0, 0, 0, SY_THR_STATIC }, /* 531 = posix_fadvise */ { AS(wait6_args), (sy_call_t *)sys_wait6, AUE_WAIT6, NULL, 0, 0, 0, SY_THR_STATIC }, /* 532 = wait6 */ + { AS(utrace2_args), (sy_call_t *)sys_utrace2, AUE_NULL, NULL, 0, 0, 0, SY_THR_STATIC }, /* 533 = utrace2 */ }; Index: sys/kern/kern_ktrace.c =================================================================== --- sys/kern/kern_ktrace.c (revision 244503) +++ sys/kern/kern_ktrace.c (working copy) @@ -123,6 +123,7 @@ sizeof(struct ktr_cap_fail), /* KTR_CAPFAIL */ sizeof(struct ktr_fault), /* KTR_FAULT */ sizeof(struct ktr_faultend), /* KTR_FAULTEND */ + 0, /* KTR_USER2 */ }; static STAILQ_HEAD(, ktr_request) ktr_free; @@ -1025,7 +1026,43 @@ #endif /* KTRACE */ } +/* ARGSUSED */ +int +sys_utrace2(td, uap) + struct thread *td; + register struct utrace2_args *uap; +{ + #ifdef KTRACE + struct ktr_request *req; + void *cp; + int error; + + if (!KTRPOINT(td, KTR_USER2)) + return (0); + if (uap->len > KTR_USER_MAXLEN) + return (EINVAL); + cp = malloc(uap->len, M_KTRACE, M_WAITOK); + error = copyin(uap->addr, cp, uap->len); + if (error) { + free(cp, M_KTRACE); + return (error); + } + req = ktr_getrequest(KTR_USER2); + if (req == NULL) { + free(cp, M_KTRACE); + return (ENOMEM); + } + req->ktr_buffer = cp; + req->ktr_header.ktr_len = uap->len; + ktr_submitrequest(td, req); + return (0); +#else /* !KTRACE */ + return (ENOSYS); +#endif /* KTRACE */ +} + +#ifdef KTRACE static int ktrops(td, p, ops, facs, vp) struct thread *td; Index: sys/kern/syscalls.c =================================================================== --- sys/kern/syscalls.c (revision 244503) +++ sys/kern/syscalls.c (working copy) @@ -540,4 +540,5 @@ "posix_fallocate", /* 530 = posix_fallocate */ "posix_fadvise", /* 531 = posix_fadvise */ "wait6", /* 532 = wait6 */ + "utrace2", /* 533 = utrace2 */ }; Index: sys/kern/syscalls.master =================================================================== --- sys/kern/syscalls.master (revision 244503) +++ sys/kern/syscalls.master (working copy) @@ -955,5 +955,6 @@ int *status, int options, \ struct __wrusage *wrusage, \ siginfo_t *info); } +533 AUE_NULL STD { int utrace2(const void *addr, size_t len); } ; Please copy any additions and changes to the following compatability tables: ; sys/compat/freebsd32/syscalls.master Index: sys/kern/systrace_args.c =================================================================== --- sys/kern/systrace_args.c (revision 244503) +++ sys/kern/systrace_args.c (working copy) @@ -3286,6 +3286,14 @@ *n_args = 6; break; } + /* utrace2 */ + case 533: { + struct utrace2_args *p = params; + uarg[0] = (intptr_t) p->addr; /* const void * */ + uarg[1] = p->len; /* size_t */ + *n_args = 2; + break; + } default: *n_args = 0; break; @@ -8745,6 +8753,19 @@ break; }; break; + /* utrace2 */ + case 533: + switch(ndx) { + case 0: + p = "const void *"; + break; + case 1: + p = "size_t"; + break; + default: + break; + }; + break; default: break; }; @@ -10638,6 +10659,11 @@ if (ndx == 0 || ndx == 1) p = "int"; break; + /* utrace2 */ + case 533: + if (ndx == 0 || ndx == 1) + p = "int"; + break; default: break; }; Index: sys/sys/ktrace.h =================================================================== --- sys/sys/ktrace.h (revision 244503) +++ sys/sys/ktrace.h (working copy) @@ -216,6 +216,8 @@ int result; }; +#define KTR_USER2 15 + /* * KTR_DROP - If this bit is set in ktr_type, then at least one event * between the previous record and this record was dropped. @@ -240,6 +242,7 @@ #define KTRFAC_CAPFAIL (1<<KTR_CAPFAIL) #define KTRFAC_FAULT (1<<KTR_FAULT) #define KTRFAC_FAULTEND (1<<KTR_FAULTEND) +#define KTRFAC_USER2 (1<<KTR_USER2) /* * trace flags (also in p_traceflags) @@ -277,8 +280,13 @@ __BEGIN_DECLS int ktrace(const char *, int, int, pid_t); int utrace(const void *, size_t); +int utrace2(const void *, size_t); __END_DECLS +#define UTRACE_MALLOC 0x001 +#define UTRACE_SYSMAX 0x100 +#define UTRACE_APPLICATIONMIN 0x101 + #endif #endif Index: sys/sys/syscall.h =================================================================== --- sys/sys/syscall.h (revision 244503) +++ sys/sys/syscall.h (working copy) @@ -452,4 +452,5 @@ #define SYS_posix_fallocate 530 #define SYS_posix_fadvise 531 #define SYS_wait6 532 -#define SYS_MAXSYSCALL 533 +#define SYS_utrace2 533 +#define SYS_MAXSYSCALL 534 Index: sys/sys/syscall.mk =================================================================== --- sys/sys/syscall.mk (revision 244503) +++ sys/sys/syscall.mk (working copy) @@ -400,4 +400,5 @@ rctl_remove_rule.o \ posix_fallocate.o \ posix_fadvise.o \ - wait6.o + wait6.o \ + utrace2.o Index: sys/sys/sysproto.h =================================================================== --- sys/sys/sysproto.h (revision 244503) +++ sys/sys/sysproto.h (working copy) @@ -1762,6 +1762,10 @@ char wrusage_l_[PADL_(struct __wrusage *)]; struct __wrusage * wrusage; char wrusage_r_[PADR_(struct __wrusage *)]; char info_l_[PADL_(siginfo_t *)]; siginfo_t * info; char info_r_[PADR_(siginfo_t *)]; }; +struct utrace2_args { + char addr_l_[PADL_(const void *)]; const void * addr; char addr_r_[PADR_(const void *)]; + char len_l_[PADL_(size_t)]; size_t len; char len_r_[PADR_(size_t)]; +}; int nosys(struct thread *, struct nosys_args *); void sys_sys_exit(struct thread *, struct sys_exit_args *); int sys_fork(struct thread *, struct fork_args *); @@ -2144,6 +2148,7 @@ int sys_posix_fallocate(struct thread *, struct posix_fallocate_args *); int sys_posix_fadvise(struct thread *, struct posix_fadvise_args *); int sys_wait6(struct thread *, struct wait6_args *); +int sys_utrace2(struct thread *, struct utrace2_args *); #ifdef COMPAT_43 @@ -2840,6 +2845,7 @@ #define SYS_AUE_posix_fallocate AUE_NULL #define SYS_AUE_posix_fadvise AUE_NULL #define SYS_AUE_wait6 AUE_WAIT6 +#define SYS_AUE_utrace2 AUE_NULL #undef PAD_ #undef PADL_ Index: usr.bin/kdump/kdump.c =================================================================== --- usr.bin/kdump/kdump.c (revision 244503) +++ usr.bin/kdump/kdump.c (working copy) @@ -83,6 +83,8 @@ #include "ktrace.h" #include "kdump_subr.h" +struct utrace_malloc_v2; + u_int abidump(struct ktr_header *); int fetchprocinfo(struct ktr_header *, u_int *); int fread_tail(void *, int, int); @@ -96,9 +98,11 @@ void ktrpsig(struct ktr_psig *); void ktrcsw(struct ktr_csw *); void ktrcsw_old(struct ktr_csw_old *); -void ktruser_malloc(unsigned char *); +void ktruser_malloc(struct utrace_malloc_v2 *, int); void ktruser_rtld(int, unsigned char *); -void ktruser(int, unsigned char *); +void ktruser(int, void *); +void ktruser2(size_t, void *); +void ktruser_data(size_t, unsigned char *); void ktrsockaddr(struct sockaddr *); void ktrstat(struct stat *); void ktrstruct(char *, size_t); @@ -321,6 +325,9 @@ case KTR_FAULTEND: ktrfaultend((struct ktr_faultend *)m); break; + case KTR_USER2: + ktruser2(ktrlen, m); + break; default: printf("\n"); break; @@ -469,6 +476,9 @@ case KTR_FAULTEND: type = "PRET"; break; + case KTR_USER2: + type = "USR2"; + break; default: sprintf(unknown, "UNKNOWN(%d)", kth->ktr_type); type = unknown; @@ -1369,51 +1379,117 @@ } } -struct utrace_malloc { - void *p; - size_t s; - void *r; +struct utrace_malloc_old { + void *p; /* Input pointer (as in realloc(p, s)). */ + size_t s; /* Request size. */ + void *r; /* Result pointer. */ }; +struct utrace_malloc_v2 { + int utrace_type; /* utrace type UTRACE_MALLOC */ + int utrace_version; /* utrace malloc version */ + void *p; /* Input pointer (as in realloc(p, s)). */ + size_t s; /* Request size. */ + void *r; /* Result pointer. */ + void *caller; /* Caller */ +}; + void -ktruser_malloc(unsigned char *p) +ktruser_malloc(struct utrace_malloc_v2 *ut, int v2) { - struct utrace_malloc *ut = (struct utrace_malloc *)p; if (ut->p == (void *)(intptr_t)(-1)) - printf("malloc_init()\n"); + printf("malloc_init()"); else if (ut->s == 0) - printf("free(%p)\n", ut->p); + printf("free(%p)", ut->p); else if (ut->p == NULL) - printf("%p = malloc(%zu)\n", ut->r, ut->s); + printf("%p = malloc(%zu)", ut->r, ut->s); else - printf("%p = realloc(%p, %zu)\n", ut->r, ut->p, ut->s); + printf("%p = realloc(%p, %zu)", ut->r, ut->p, ut->s); + if (v2) + printf(", caller %p", ut->caller); + putchar('\n'); } void -ktruser(int len, unsigned char *p) +ktruser_data(size_t len, unsigned char *p) { + printf("%zd ", len); + while (len--) + if (decimal) + printf(" %d", *p++); + else + printf(" %02x", *p++); + printf("\n"); +} + +void +ktruser(int len, void *p) +{ + if (len >= 8 && bcmp(p, "RTLD", 4) == 0) { ktruser_rtld(len, p); return; } - if (len == sizeof(struct utrace_malloc)) { - ktruser_malloc(p); + if (len == sizeof(struct utrace_malloc_old)) { + struct utrace_malloc_old *utm_old; + struct utrace_malloc_v2 utm_v2; + + utm_old = p; + utm_v2.p = utm_old->p; + utm_v2.s = utm_old->s; + utm_v2.r = utm_old->r; + ktruser_malloc(&utm_v2, 0); return; } - printf("%d ", len); - while (len--) - if (decimal) - printf(" %d", *p++); - else - printf(" %02x", *p++); - printf("\n"); + ktruser_data(len, p); } void +ktruser2(size_t len, void *p) +{ + struct ktruser2_header { + int type; + int version; + } *ktru2_hd; + + if (len < sizeof(struct ktruser2_header)) { + warnx("utrace2 size too small: %zd (want: %zd)", + len, sizeof(struct ktruser2_header)); + ktruser_data(len, p); + return; + } + + ktru2_hd = p; + switch (ktru2_hd->type) { + case UTRACE_MALLOC: + if (ktru2_hd->version == 2) { + if (len == sizeof(struct utrace_malloc_v2)) { + ktruser_malloc(p, 1); + return; + } + warnx("ktruser2: UTRACE_MALLOC, version = 2, " + "size incorrect %zd (want: %zd)", + len, sizeof(struct utrace_malloc_v2)); + ktruser_data(len, p); + return; + } else { + warnx("ktruser2: UTRACE_MALLOC, unknown version = %d, " + "(want: %d)", ktru2_hd->version, 2); + ktruser_data(len, p); + return; + } + default: + break; + } + ktruser_data(len, p); + return; +} + +void ktrsockaddr(struct sockaddr *sa) { /* Index: usr.bin/ktrace/ktrace.h =================================================================== --- usr.bin/ktrace/ktrace.h (revision 244503) +++ usr.bin/ktrace/ktrace.h (working copy) @@ -32,7 +32,8 @@ #define DEF_POINTS (KTRFAC_SYSCALL | KTRFAC_SYSRET | KTRFAC_NAMEI | \ KTRFAC_GENIO | KTRFAC_PSIG | KTRFAC_USER | \ - KTRFAC_STRUCT | KTRFAC_SYSCTL | KTRFAC_CAPFAIL) + KTRFAC_STRUCT | KTRFAC_SYSCTL | KTRFAC_CAPFAIL | \ + KTRFAC_USER2) #define PROC_ABI_POINTS (KTRFAC_PROCCTOR | KTRFAC_PROCDTOR) Index: usr.bin/ktrace/subr.c =================================================================== --- usr.bin/ktrace/subr.c (revision 244503) +++ usr.bin/ktrace/subr.c (working copy) @@ -82,6 +82,9 @@ case 'u': facs |= KTRFAC_USER; break; + case 'U': + facs |= KTRFAC_USER2; + break; case 'w': facs |= KTRFAC_CSW; break; --------------000103040406040707070503 Content-Type: text/plain; charset=UTF-8; x-mac-type="0"; x-mac-creator="0"; name="test_utrace.c" Content-Transfer-Encoding: 7bit Content-Disposition: attachment; filename="test_utrace.c" #include <stdio.h> #include <stdlib.h> #include <unistd.h> #define SZ 10 int main(void) { void *allocs[SZ]; int i; volatile int dummy = 0; for (i = 0; i < SZ; i++) allocs[i] = malloc(10); while (dummy) { printf("sleeping...\n"); sleep(1); } for (i = 0; i < SZ; i++) allocs[i] = realloc(allocs[i], 100); for (i = 0; i < SZ; i++) allocs[i] = realloc(allocs[i], 200); for (i = 0; i < SZ; i++) allocs[i] = realloc(allocs[i], 20); //for (i = 0; i < SZ; i++) free(allocs[i]); return 0; } --------------000103040406040707070503--
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?50D52B10.1060205>