/* * File: iowrap.c * CVS: $Id: iowrap.c,v 1.23 2005/06/16 11:18:24 pek Exp $ * Author: Per Ekman * pek@pdc.kth.se * Mods: Philip Mucci * mucci@cs.utk.edu */ #include #include #include "iotrack.h" #include "ops.h" #include "iowrap.h" #ifdef LIBLOAD #include "libload.h" #else #if defined(__i386__) #include "callmacros-x86-linux.h" #elif defined(__ia64__) #include "callmacros-ia64-linux.h" #endif #endif #define RFNAME "iotrack.res" #define LOGENV "IOTRACK_LOGFILE" #define RBASESIZE 1024*16 #define BUFSIZE 1024*16 #define BUFLEFT(x) (sizeof x.buf - (x.p - x.buf)) #define BUFUSED(x) (x.p - x.buf) /***************************/ /* Global variables. These must be initialized in _init for forked and threaded apps to work. */ int logfile_fd; /* Result file */ extern char **environ; struct { char buf[BUFSIZE]; char *p; } bs; char str[STRMAX]; /* Junk buffer */ /* Name of the log file */ static char logname[STRMAX]; /* Options to library. */ /* Do we want to follow forks? */ static int followfork = 0; /* End of global variables */ /***************************/ /* Obtain a backtrace and print it to stdout. (from the glibc manual) */ void print_trace () { void *array[10]; size_t size; char **strings; size_t i; size = backtrace (array, 10); strings = backtrace_symbols (array, size); REAL_FPRINTF (stderr, "Obtained %zd stack frames.\n", size); for (i = 0; i < size; i++) REAL_FPRINTF(stderr, "%s\n", strings[i]); free (strings); } void sigsegv_handler(int sig) { print_trace(); } /* Get time in seconds */ static inline float gettime() { static struct timeval tv; static time_t secbase = 0; if (gettimeofday(&tv, NULL)) perror("Failed gettimeofday()"); if (secbase == 0) secbase = tv.tv_sec; return (float)(tv.tv_sec - secbase) + (tv.tv_usec / 1000000.0); } void logentry(char *op, char *fmt, ...) { va_list ap; int c; #ifdef NOBUFFERING assert ( (c = snprintf(bs.p, BUFLEFT(bs), "%f:%s:", gettime(), op)) >= 0); bs.p += c; va_start(ap, fmt); assert( (c = vsnprintf(bs.p, BUFLEFT(bs), fmt, ap)) >= 0); bs.p += c; va_end(ap); if (BUFLEFT(bs) < 2) { REAL_FPRINTF(stderr, "Short buffer length in logentry() (%d > 2)\n", (int)BUFLEFT(bs)); bs.p -= 2; } *(bs.p)++ = '\n'; *(bs.p) = '\0'; // printf(bs.buf); if (REAL_WRITE(logfile_fd, bs.buf, BUFUSED(bs)) < 0) { perror("iowrap : Failed write to result file"); exit(1); } bs.p = bs.buf; #else int e; e = errno; if (BUFLEFT(bs) < STRMAX) { /* REAL_FPRINTF(stderr, "Flushing %s", bs.buf); */ if (REAL_WRITE(logfile_fd, bs.buf, BUFUSED(bs)) < 0) { perror("iowrap : Failed write to result file"); exit(1); } bs.p = bs.buf; } assert ( (c = snprintf(bs.p, BUFLEFT(bs), "%f:%s:", gettime(), op)) >= 0); bs.p += c; va_start(ap, fmt); assert( (c = vsnprintf(bs.p, BUFLEFT(bs), fmt, ap)) >= 0); bs.p += c; va_end(ap); if (BUFLEFT(bs) < 2) { REAL_FPRINTF(stderr, "Short buffer length in logentry() (%d > 2)\n", (int)BUFLEFT(bs)); bs.p -= 2; } *(bs.p)++ = '\n'; *(bs.p) = '\0'; errno = e; #endif } /* _fini() is run when the DSO is unloaded */ #ifdef __GNUC__ void fini_iowrap() #else void _fini() #endif { if (REAL_WRITE(logfile_fd, bs.buf, BUFUSED(bs)) < 0) { perror("iowrap : Failed write to result file"); exit(1); } REAL_CLOSE(logfile_fd); } /* _init() is run when the DSO is loaded */ #ifdef __GNUC__ void init_iowrap() #else void _init() #endif { char *p, *ptr; char tmp[PATH_MAX], tmp2[ARG_MAX], args[ARG_MAX] = ""; char exename[PATH_MAX] = ""; int myfd, bytes, total, c, i; if ( (p = getenv(LOGENV)) != NULL) strncpy(logname, p, sizeof logname); else strncpy(logname, RFNAME, sizeof logname); p = logname + strlen(logname); p += snprintf(p, sizeof logname - (p - logname), ".%d", getpid()); i = 0; libload(); while ( (logfile_fd = REAL_OPEN(logname, O_RDWR | O_EXCL | O_CREAT, S_IRWXU)) < 0) { if (errno == EEXIST) { snprintf(p, sizeof logname - (p - logname), ".%d", i); i++; } else { REAL_FPRINTF(stderr,"iowrap : Failed to open(%s): %s",logname,strerror(errno)); exit(1); } } bs.p= bs.buf; /* Get the executable name */ sprintf(tmp, "/proc/%d/exe", (int) getpid()); if (readlink(tmp, exename, PATH_MAX) < 0) { REAL_FPRINTF(stderr,"iowrap : Failed to readlink(%s): %s",tmp,strerror(errno)); exit(1); } /* Get the executable args */ sprintf(tmp, "/proc/%d/cmdline", (int) getpid()); if ((myfd = REAL_OPEN(tmp, O_RDONLY, 0)) < 0) { REAL_FPRINTF(stderr,"iowrap : Failed to open(%s): %s",tmp,strerror(errno)); exit(1); } memset(tmp2,0x0,sizeof(tmp2)); bytes = REAL_READ(myfd,&tmp2,ARG_MAX*sizeof(char)); if (bytes < 0) { REAL_FPRINTF(stderr,"iowrap : Failed to read(%s,%d): %s",tmp,(int)(ARG_MAX*sizeof(char)),strerror(errno)); exit(1); } REAL_CLOSE(myfd); ptr = tmp2; total = bytes/sizeof(char); for (c=0;csin6_addr, p, len) == NULL) { perror("Failed to translate IPV6 sockaddr"); return NULL; } return p; #else /* IPV4 */ if (inet_ntop(AF_INET, &((struct sockaddr_in *)sp)->sin_addr, p, len) == NULL) { perror("Failed to translate IPV4 sockaddr"); return NULL; } return p; #endif /* IPV6 */ } /* We need to trap exec in order to flush the logfile buffer before continuing. */ int execve(const char *file, char *const argv[], char *const envp[]) { logentry("EXECVE", "file %s", file); fini_iowrap(); return REAL_EXECVE(file, argv, envp); } int execv(const char *path, char *const argv[]) { logentry("EXECV", "file %s", path); fini_iowrap(); return REAL_EXECV(path, argv); } int execvp(const char *file, char *const argv[]) { logentry("EXECVP", "file %s", file); fini_iowrap(); return REAL_EXECVP(file, argv); } /* Cribbed from glibc posix */ int execl(const char *path, const char *arg, ...) { size_t argv_max = 1024; const char **argv = alloca (argv_max * sizeof (const char *)); unsigned int i; va_list args; argv[0] = arg; va_start (args, arg); i = 0; while (argv[i++] != NULL) { if (i == argv_max) { const char **nptr = alloca ((argv_max *= 2) * sizeof (const char *)); if ((char *) nptr + argv_max == (char *) argv) { /* Stack grows down. */ argv = (const char **) memcpy (nptr, argv, i * sizeof (const char *)); argv_max += i; } else if ((char *) argv + i == (char *) nptr) /* Stack grows up. */ argv_max += i; else /* We have a hole in the stack. */ argv = (const char **) memcpy (nptr, argv, i * sizeof (const char *)); } argv[i] = va_arg (args, const char *); } va_end (args); logentry("EXECL", "file %s", path); fini_iowrap(); return REAL_EXECVE(path, (char **const)argv, environ); } int execlp (const char *file, const char *arg, ...) { size_t argv_max = 1024; const char **argv = alloca (argv_max * sizeof (const char *)); unsigned int i; va_list args; argv[0] = arg; va_start (args, arg); i = 0; while (argv[i++] != NULL) { if (i == argv_max) { const char **nptr = alloca ((argv_max *= 2) * sizeof (const char *)); if ((char *) nptr + argv_max == (char *) argv) { /* Stack grows down. */ argv = (const char **) memcpy (nptr, argv, i * sizeof (const char *)); argv_max += i; } else if ((char *) argv + i == (char *) nptr) /* Stack grows up. */ argv_max += i; else /* We have a hole in the stack. */ argv = (const char **) memcpy (nptr, argv, i * sizeof (const char *)); } argv[i] = va_arg (args, const char *); } va_end (args); logentry("EXECLP", "file %s", file); fini_iowrap(); return REAL_EXECVP(file, (char *const *) argv); } int execle (const char *path, const char *arg, ...) { size_t argv_max = 1024; const char **argv = alloca (argv_max * sizeof (const char *)); const char *const *envp; unsigned int i; va_list args; argv[0] = arg; va_start (args, arg); i = 0; while (argv[i++] != NULL) { if (i == argv_max) { const char **nptr = alloca ((argv_max *= 2) * sizeof (const char *)); if ((char *) nptr + argv_max == (char *) argv) { /* Stack grows down. */ argv = (const char **) memcpy (nptr, argv, i * sizeof (const char *)); argv_max += i; } else if ((char *) argv + i == (char *) nptr) /* Stack grows up. */ argv_max += i; else /* We have a hole in the stack. */ argv = (const char **) memcpy (nptr, argv, i * sizeof (const char *)); } argv[i] = va_arg (args, const char *); } envp = va_arg (args, const char *const *); va_end (args); logentry("EXECLE", "file %s", path); fini_iowrap(); return REAL_EXECVE(path, (char *const *) argv, (char *const *) envp); } /* Captured calls */ int open(const char *pathname, int flags, ...) { va_list ap; mode_t mode; int fd; float t0 = gettime(); if (flags & O_CREAT) { va_start(ap, flags); mode = va_arg(ap, int); va_end(ap); } fd = REAL_OPEN(pathname, flags, mode); logentry("OPEN", "new fd %d:time %f:%s", fd, gettime() - t0, (char *)pathname); return fd; } int open64(const char *pathname, int flags, ...) { va_list ap; mode_t mode; int fd; float t0 = gettime(); if (flags & O_CREAT) { va_start(ap, flags); mode = va_arg(ap, int); va_end(ap); } fd = REAL_OPEN64(pathname, flags, mode); logentry("OPEN", "new fd %d:time %f:%s", fd, gettime() - t0, (char *)pathname); return fd; } int creat(const char *pathname, mode_t mode) { int fd; float t0 = gettime(); fd = REAL_CREAT(pathname, mode); logentry("CREAT", "new fd %d:time %f:%s", fd, gettime() - t0, (char *)pathname); return fd; } int creat64(const char *pathname, mode_t mode) { int fd; float t0 = gettime(); fd = REAL_CREAT64(pathname, mode); logentry("CREAT", "new fd %d:time %f:%s", fd, gettime() - t0, (char *)pathname); return fd; } int dup(int oldfd) { int fd; fd = REAL_DUP(oldfd); logentry("DUP", "old fd %d:new fd %d", oldfd, fd); return fd; } int dup2(int oldfd, int newfd) { newfd = REAL_DUP2(oldfd, newfd); logentry("DUP2", "old fd %d:new fd %d", oldfd, newfd); return newfd; } int close(int fd) { logentry("CLOSE", "fd %d", fd); return REAL_CLOSE(fd); } int socket(int domain, int type, int proto) { int fd; float t0 = gettime(); fd = REAL_SOCKET(domain, type, proto); logentry("SOCKET", "new fd %d:domain %d:type %d:proto %d:time %f", fd, domain, type, proto, gettime() - t0); return fd; } int accept(int s, struct sockaddr *addr, socklen_t *addrlen) { int fd; float t0 = gettime(); fd = REAL_ACCEPT(s, addr, addrlen); logentry("ACCEPT", "new fd %d:listening socket %d:addr %s:time %f", fd, s, sockaddr_to_str(str, sizeof str, addr), gettime() - t0); return fd; } ssize_t send(int s, const void *buf, size_t len, int flags) { ssize_t res; float t0 = gettime(); res = REAL_SEND(s, buf, len, flags); logentry("SEND", "fd %d:request size %d:I/O size %d:flags %x:time %f", s, len, res, flags, gettime() - t0); return res; } ssize_t sendto(int s, const void *buf, size_t len, int flags, const struct sockaddr *to, socklen_t tolen) { ssize_t res; float t0 = gettime(); res = REAL_SENDTO(s, buf, len, flags, to, tolen); logentry("SENDTO", "fd %d:request size %d:I/O size %d:flags %x:addr %s:time %f", s, len, res, flags, sockaddr_to_str(str, sizeof str, to), gettime() - t0); return res; } ssize_t sendmsg(int s, const struct msghdr *msg, int flags) { int i; size_t acc = 0; ssize_t res; struct iovec *vector; float t0 = gettime(); vector = msg->msg_iov; for (i = 0; i < msg->msg_iovlen; i++) acc += vector[i].iov_len; res = REAL_SENDMSG(s, msg, flags); logentry("SENDMSG", "fd %d:request size %d:I/O size %d:flags %x:time %f", s, acc, res, flags, gettime() - t0); return res; } ssize_t recv(int s, void *buf, size_t len, int flags) { ssize_t res; float t0 = gettime(); res = REAL_RECV(s, buf, len, flags); logentry("RECV", "fd %d:request size %d:I/O size %d:flags %x:time %f", s, len, res, flags, gettime() - t0); return res; } ssize_t recvfrom(int s, void *buf, size_t len, int flags, struct sockaddr *from, socklen_t *fromlen) { ssize_t res; float t0 = gettime(); res = REAL_RECVFROM(s, buf, len, flags, from, fromlen); logentry("RECVFROM", "fd %d:request size %d:I/O size %d:flags %x:addr %s:time %f", s, len, res, flags, sockaddr_to_str(str, sizeof str, from), gettime() - t0); return res; } ssize_t recvmsg(int s, struct msghdr *msg, int flags) { int i; size_t acc = 0; ssize_t res; struct iovec *vector; float t0 = gettime(); res = REAL_RECVMSG(s, msg, flags); if (res >= 0) { vector = msg->msg_iov; for (i = 0; i < msg->msg_iovlen; i++) acc += vector[i].iov_len; } logentry("RECVMSG", "fd %d:request size %d:I/O size %d:flags %x:time %f", s, acc, res, flags, gettime() - t0); return res; } ssize_t readv(int fd, const struct iovec *vector, int count) { int i; size_t acc = 0; ssize_t res; float t0 = gettime(); res = REAL_READV(fd, vector, count); if (res >= 0) { for (i = 0; i < count; i++) acc += vector[i].iov_len; } logentry("READV", "fd %d:request size %d:I/O size %d:count %d:time %f", fd, acc, res, count, gettime() - t0); return res; } ssize_t writev(int fd, const struct iovec *vector, int count) { int i; size_t acc = 0; ssize_t res; float t0 = gettime(); for (i = 0; i < count; i++) acc += vector[i].iov_len; res = REAL_WRITEV(fd, vector, count); logentry("WRITEV", "fd %d:request size %d:I/O size %d:count %d:time %f", fd, acc, res, count, gettime() - t0); return res; } ssize_t read(int fd, void *bp, size_t count) { ssize_t res = 0; float t0 = gettime(); res = REAL_READ(fd, bp, count); logentry("READ", "fd %d:request size %d:I/O size %d:time %f", fd, count, res, gettime() - t0); return res; } ssize_t write(int fd, const void *bp, size_t count) { ssize_t res = 0; float t0 = gettime(); res = REAL_WRITE(fd, bp, count); logentry("WRITE", "fd %d:request size %d:I/O size %d:time %f", fd, count, res, gettime() - t0); return res; } int fcntl(int fd, int cmd, ...) { int res; va_list ap; void *arg; switch (cmd) { /* No arg */ case F_GETFD : /* From kernel source fs/fcntl.c:do_fcntl() */ case F_GETFL : #if defined(F_GETOWN) case F_GETOWN : #endif #if defined(F_GETSIG) case F_GETSIG : #endif #if defined(F_GETLEASE) case F_GETLEASE : #endif res = REAL_FCNTL(fd, cmd, 0); break; default : va_start (ap, cmd); arg = va_arg (ap, void *); va_end (ap); res = REAL_FCNTL(fd, cmd, arg); break; } switch (cmd) { case F_DUPFD : logentry("FCNTL", "fd %d:flag F_DUPFD:new fd %d", fd, res); break; case F_SETFD : logentry("FCNTL", "fd %d:flag F_SETFD: res %d", fd, res); break; } return res; } off_t lseek(int fd, off_t offset, int whence) { ssize_t res = 0; float t0 = gettime(); res = REAL_LSEEK(fd, offset, whence); logentry("LSEEK", "fd %d:offset %d:whence %d:new pos %d:time %f", fd, offset, whence, res, gettime() - t0); return res; } off64_t lseek64(int fd, off64_t offset, int whence) { ssize_t res = 0; float t0 = gettime(); res = REAL_LSEEK64(fd, offset, whence); logentry("LSEEK", "fd %d:offset %d:whence %d:new pos %d:time %f", fd, offset, whence, res, gettime() - t0); return res; } FILE *fopen(const char *path, const char *mode) { FILE *res; res = (FILE *)REAL_FOPEN(path, mode); logentry("FOPEN", "fp 0x%lx:mode %s:%s", res, mode, path); return res; } FILE *fopen64(const char *path, const char *mode) { FILE *res; res = (FILE *)REAL_FOPEN64(path, mode); logentry("FOPEN", "fp 0x%lx:mode %s:%s", res, mode, path); return res; } FILE *fdopen(int fd, const char *mode) { FILE *res; res = (FILE *)REAL_FDOPEN(fd, mode); logentry("FDOPEN", "fp 0x%lx:fd %d:mode %s", res, fd, mode); return res; } int fclose(FILE *fp) { logentry("FCLOSE", "fp 0x%lx", fp); return REAL_FCLOSE(fp); } size_t fread(void *ptr, size_t size, size_t nmemb, FILE *stream) { size_t res; float t0 = gettime(); res = REAL_FREAD(ptr, size, nmemb, stream); logentry("FREAD", "fp 0x%lx:request size %d:I/O size %d:time %f", stream, nmemb*size, res, gettime() - t0); return res; } size_t fwrite( const void *ptr, size_t size, size_t nmemb, FILE *stream) { size_t res; float t0 = gettime(); res = REAL_FWRITE(ptr, size, nmemb, stream); logentry("FWRITE", "fp 0x%lx:request size %d:I/O size %d:time %f", stream, nmemb*size, res, gettime() - t0); return res; } int fseek(FILE *stream, long offset, int whence) { int res; float t0 = gettime(); res = REAL_FSEEK(stream, offset, whence); logentry("FSEEK", "fp 0x%lx:offset %l: whence %d:res %d:time %f", stream, offset, whence, res, gettime() - t0); return res; } void rewind(FILE *stream) { logentry("REWIND", "fp 0x%lx", stream); REAL_REWIND(stream); } int fprintf(FILE *stream, const char *format, ...) { va_list arg; int res; float t0 = gettime(); va_start (arg, format); res = REAL_VFPRINTF(stream, format, arg); va_end (arg); logentry("FPRINTF", "fp 0x%lx:I/O size %d:time %f", stream, res, gettime() - t0); return res; } pid_t fork (void) { pid_t pid = REAL_FORK(); if (pid == 0) { if (followfork == 0) init_iowrap(); } return(pid); } #if defined(THREADS) #if defined(linux) typedef struct pc_arg { void * (*start_routine)(void *); void * arg; } pc_arg_t; static void (*probe_thread_init_routine)(void *) = NULL; static void (*probe_thread_exit_routine)(void *) = NULL; static void *probe_thread_init_tramp(void *arg) { void * (*start_routine)(void *) = ((pc_arg_t *)arg)->start_routine; void * real_arg = ((pc_arg_t *)arg)->arg; void *retval; if ((probe_thread_init_routine) && (probe_thread_exit_routine)) { probe_thread_init_routine(real_arg); pthread_cleanup_push(probe_thread_exit_routine,NULL); retval = start_routine(real_arg); pthread_cleanup_pop(1); return(retval); } else abort(); } int pthread_trap_create(void (*arg)(void *)) { probe_thread_init_routine = arg; return(0); } int pthread_trap_exit(void (*arg)(void *)) { probe_thread_exit_routine = arg; return(0); } int pthread_create (pthread_t *__restrict __thread, __const pthread_attr_t *__restrict __attr, void *(*__start_routine) (void *), void *__restrict __arg) { pc_arg_t *pca = NULL; static int (*real_pthread_create) (pthread_t *__restrict __thread, __const pthread_attr_t *__restrict __attr, void *(*__start_routine) (void *), void *__restrict __arg) = NULL; if (__start_routine == NULL) return -1; pca = (pc_arg_t *)malloc(sizeof(pc_arg_t)); memset(pca,0x0,sizeof(pc_arg_t)); pca->start_routine = __start_routine; pca->arg = __arg; if (real_pthread_create == NULL) { char *error; void *handle = dlopen("libpthread.so.0",RTLD_LAZY); real_pthread_create = dlsym(handle,"pthread_create"); if ((error = dlerror()) != NULL) { fputs(error,stderr); exit(1); } } return(real_pthread_create(__thread,__attr,probe_thread_init_tramp,pca)); } #endif #endif