Hi,
This patch adds a simple profiler to Wine. Charles has added some fixes since I last posted this, so it should work properly now. I have just updated for Alexandre's latest commits, and changed the way we protect pthread functions from being profiled (now uses a Makefile hack instead of a function attribute).
Profiles are generated in /tmp/wmon.out.<pid>, and can be examined with the wprof tool from wine/libs/wprof/wprof.
I haven't tested this, but it is working in the Crossover tree, where I merged it from. Let me know of any success or failures.
Mike
ChangeLog: Charles Loep <charles@codeweavers.com> Mike McCormack <mike@codeweavers.com> * add a profiler
Index: configure.ac =================================================================== RCS file: /home/wine/wine/configure.ac,v retrieving revision 1.171 diff -u -r1.171 configure.ac --- configure.ac 13 Aug 2003 01:27:48 -0000 1.171 +++ configure.ac 15 Aug 2003 05:15:46 -0000 @@ -20,6 +20,25 @@ AC_ARG_WITH(curses, AC_HELP_STRING([--without-curses],[do not use curses])) AC_ARG_WITH(nptl, AC_HELP_STRING([--with-nptl],[use glibc NPTL threading support])) AC_ARG_WITH(wine-tools,AC_HELP_STRING([--with-wine-tools=<dir>],[use Wine tools from directory <dir>])) +AC_ARG_WITH(profiler,AC_HELP_STRING([--with-profiler],[build the profiler])) + +if test "x$with_profiler" = "xyes" +then + GLIBC_THREAD_CFLAGS=`glib-config --cflags gthread` + GLIBC_THREAD_LIBS=`glib-config --libs gthread` + if test "x$GLIBC_THREAD_CFLAGS" != x + then + PROFILE_CFLAGS="-finstrument-functions -D__NO_STRING_INLINES -DWINE_NO_PROFILE=\"__attribute__((no_instrument_function))\"" + PROFILE_LIBS="-L\$(TOPOBJDIR)/libs/wprof -lwineprof -lm" + PROFILE_LIBNAME="libwineprof" + AC_DEFINE(HAVE_PROFILER,1,[Define to use glibc NPTL threading support.]) + fi +fi +AC_SUBST(PROFILE_CFLAGS) +AC_SUBST(PROFILE_LIBS) +AC_SUBST(PROFILE_LIBNAME) +AC_SUBST(GLIBC_THREAD_CFLAGS) +AC_SUBST(GLIBC_THREAD_LIBS) AC_SUBST(WIN16_FILES,"\$(WIN16_FILES)") AC_SUBST(WIN16_INSTALL,"\$(WIN16_INSTALL)") @@ -1543,6 +1564,7 @@ libs/uuid/Makefile libs/wine/Makefile libs/wpp/Makefile +libs/wprof/Makefile miscemu/Makefile programs/Makefile programs/avitools/Makefile Index: Make.rules.in =================================================================== RCS file: /home/wine/wine/Make.rules.in,v retrieving revision 1.159 diff -u -r1.159 Make.rules.in --- Make.rules.in 21 Jul 2003 22:01:07 -0000 1.159 +++ Make.rules.in 15 Aug 2003 05:15:46 -0000 @@ -54,7 +54,7 @@ LINTFLAGS = @LINTFLAGS@ INCLUDES = -I$(SRCDIR) -I. -I$(TOPSRCDIR)/include -I$(TOPOBJDIR)/include $(EXTRAINCL) EXTRACFLAGS = @EXTRACFLAGS@ -ALLCFLAGS = $(INCLUDES) $(DEFS) $(EXTRACFLAGS) $(CPPFLAGS) $(CFLAGS) +ALLCFLAGS = $(INCLUDES) $(DEFS) $(EXTRACFLAGS) $(CPPFLAGS) $(CFLAGS) $(PROFILE_CFLAGS) ALLLINTFLAGS = $(INCLUDES) $(DEFS) $(LINTFLAGS) MKINSTALLDIRS= $(TOPSRCDIR)/tools/mkinstalldirs -m 755 WINAPI_CHECK = $(TOPSRCDIR)/tools/winapi_check/winapi_check Index: dlls/Makedll.rules.in =================================================================== RCS file: /home/wine/wine/dlls/Makedll.rules.in,v retrieving revision 1.56 diff -u -r1.56 Makedll.rules.in --- dlls/Makedll.rules.in 13 Jun 2003 23:26:02 -0000 1.56 +++ dlls/Makedll.rules.in 15 Aug 2003 05:15:46 -0000 @@ -9,13 +9,16 @@ # plus all variables required by the global Make.rules.in # +PROFILE_LIBS = @PROFILE_LIBS@ +PROFILE_CFLAGS = @PROFILE_CFLAGS@ + DEFS = @DLLFLAGS@ -D__WINESRC__ $(EXTRADEFS) DLLEXT = @DLLEXT@ MAINSPEC = $(MODULE:%.dll=%).spec SPEC_DEF = $(MAINSPEC).def WIN16_FILES = $(SPEC_SRCS16:.spec=.spec.o) $(C_SRCS16:.c=.o) $(EXTRA_OBJS16) ALL_OBJS = @WIN16_FILES@ $(OBJS) $(MODULE).dbg.o -ALL_LIBS = $(LIBWINE) $(EXTRALIBS) $(LIBPORT) $(LDFLAGS) $(LIBS) +ALL_LIBS = $(LIBWINE) $(EXTRALIBS) $(LIBPORT) $(LDFLAGS) $(LIBS) $(PROFILE_LIBS) IMPORTLIBS = $(DELAYIMPORTS:%=$(DLLDIR)/lib%.$(IMPLIBEXT)) $(IMPORTS:%=$(DLLDIR)/lib%.$(IMPLIBEXT)) all: $(MODULE)$(DLLEXT) $(SUBDIRS) Index: libs/Makefile.in =================================================================== RCS file: /home/wine/wine/libs/Makefile.in,v retrieving revision 1.5 diff -u -r1.5 Makefile.in --- libs/Makefile.in 1 May 2003 03:16:21 -0000 1.5 +++ libs/Makefile.in 15 Aug 2003 05:15:47 -0000 @@ -4,12 +4,15 @@ VPATH = @srcdir@ MODULE = none +PROFILE_LIBNAME = @PROFILE_LIBNAME@ + SUBDIRS = \ port \ unicode \ uuid \ wine \ - wpp + wpp \ + wprof INSTALLSUBDIRS = \ unicode \ @@ -21,7 +24,8 @@ libwine_port.a \ libwine_unicode.$(LIBEXT) \ libwine_uuid.a \ - libwpp.a + libwpp.a \ + $(PROFILE_LIBNAME:%=%.$(LIBEXT)) @MAKE_RULES@ @@ -51,6 +55,9 @@ libwpp.a: wpp/libwpp.a $(RM) $@ && $(LN_S) wpp/$@ $@ + +libwineprof.so libwineprof.so.1 libwineprof.a: wprof/libwineprof.$(LIBEXT) + $(RM) $@ && $(LN_S) wprof/$@ $@ # Directory dependencies Index: miscemu/Makefile.in =================================================================== RCS file: /home/wine/wine/miscemu/Makefile.in,v retrieving revision 1.21 diff -u -r1.21 Makefile.in --- miscemu/Makefile.in 22 May 2003 03:40:41 -0000 1.21 +++ miscemu/Makefile.in 15 Aug 2003 05:15:47 -0000 @@ -11,10 +11,13 @@ @MAKE_RULES@ +PROFILE_CFLAGS = @PROFILE_CFLAGS@ +PROFILE_LIBS = @PROFILE_LIBS@ + LDEXECFLAGS = @LDEXECFLAGS@ $(MODULE): $(OBJS) Makefile.in $(DLLDIR)/libntdll.dll.$(LIBEXT) - $(CC) -o $@ $(LDEXECFLAGS) $(OBJS) -L$(DLLDIR) -lntdll.dll $(LIBWINE) $(LIBUNICODE) $(LIBPORT) $(LDFLAGS) + $(CC) -o $@ $(LDEXECFLAGS) $(OBJS) -L$(DLLDIR) -lntdll.dll $(LIBWINE) $(LIBUNICODE) $(LIBPORT) $(LDFLAGS) $(PROFILE_LIBS) install:: $(MODULE) $(MKINSTALLDIRS) $(bindir) Index: programs/Makeprog.rules.in =================================================================== RCS file: /home/wine/wine/programs/Makeprog.rules.in,v retrieving revision 1.29 diff -u -r1.29 Makeprog.rules.in --- programs/Makeprog.rules.in 13 Jun 2003 23:26:01 -0000 1.29 +++ programs/Makeprog.rules.in 15 Aug 2003 05:15:47 -0000 @@ -9,10 +9,13 @@ # plus all variables required by the global Make.rules.in # +PROFILE_LIBS = @PROFILE_LIBS@ +PROFILE_CFLAGS = @PROFILE_CFLAGS@ + DEFS = @DLLFLAGS@ $(EXTRADEFS) LDDLLFLAGS = @LDDLLFLAGS@ ALL_OBJS = $(OBJS) $(MODULE).dbg.o -ALL_LIBS = $(LIBWINE) $(EXTRALIBS) $(LIBPORT) $(LDFLAGS) $(LIBS) +ALL_LIBS = $(LIBWINE) $(EXTRALIBS) $(LIBPORT) $(LDFLAGS) $(LIBS) $(PROFILE_LIBS) BASEMODULE = $(MODULE:.exe=) TESTIMPORTS = $(DELAYIMPORTS) $(IMPORTS) RUNTESTFLAGS= -q -P wine -T $(TOPOBJDIR) $(PLTESTPROGRAM:%=-p %) Index: dlls/ntdll/Makefile.in =================================================================== RCS file: /home/wine/wine/dlls/ntdll/Makefile.in,v retrieving revision 1.70 diff -u -r1.70 Makefile.in --- dlls/ntdll/Makefile.in 27 Jun 2003 04:08:05 -0000 1.70 +++ dlls/ntdll/Makefile.in 15 Aug 2003 05:15:47 -0000 @@ -107,6 +107,12 @@ @MAKE_DLL_RULES@ +#explicit rule for building pthread.c without profiling flags +ALLCFLAGSNOPROFILE = $(INCLUDES) $(DEFS) $(EXTRACFLAGS) $(CPPFLAGS) $(CFLAGS) + +$(TOPOBJDIR)/scheduler/pthread.o: $(TOPOBJDIR)/scheduler/pthread.c + $(CC) -c $(ALLCFLAGSNOPROFILE) -o $@ $< + relay16.s: $(WINEBUILD) $(WINEBUILD) $(DEFS) -o $@ --relay16 --- /dev/null 1994-07-18 08:46:18.000000000 +0900 +++ libs/wprof/Makefile.in 2003-05-30 18:04:36.000000000 +0900 @@ -0,0 +1,39 @@ +# Makefile for wineprof + +TOPSRCDIR = @top_srcdir@ +TOPOBJDIR = ../.. +SRCDIR = @srcdir@ +VPATH = @srcdir@ +MODULE = none + +PROFILE_LIBNAME = @PROFILE_LIBNAME@ + +@MAKE_RULES@ + +TARGETS=$(PROFILE_LIBNAME:%=%.$(LIBEXT)) + +CFLAGS += -ggdb @GLIBC_THREAD_CFLAGS@ -fPIC #-DDEBUG +LIBS += @GLIBC_THREAD_LIBS@ + +all: $(TARGETS) + +$(TARGETS): wprof + +proftest: proftest.c + $(CC) -O2 -ggdb proftest.c -o proftest -finstrument-functions $(LIBS) \ + -lwineprof -lpthread + +proftest_pg: proftest.c + $(CC) -O2 -ggdb -pg proftest.c -o proftest_pg $(LIBS) + +wprof: wineprof.o + $(CC) wineprof.o -o wprof $(LIBS) + +LIBWPROF_OBJ = profiler.o wrappers.o string.o + +$(PROFILE_LIBNAME).$(LIBEXT): $(LIBWPROF_OBJ) + $(CC) -static --shared $< -o $@ -Wl,-soname,libwineprof.so + +clean:: + rm -f wprof proftest proftest_pg + --- /dev/null 1994-07-18 08:46:18.000000000 +0900 +++ libs/wprof/atomicity.h 2003-05-30 17:19:45.000000000 +0900 @@ -0,0 +1,57 @@ +/* Low-level functions for atomic operations. ix86 version, x >= 4. + Copyright (C) 1997, 2000 Free Software Foundation, Inc. + This file is part of the GNU C Library. + + The GNU C Library is free software; you can redistribute it and/or + modify it under the terms of the GNU Library General Public License as + published by the Free Software Foundation; either version 2 of the + License, or (at your option) any later version. + + The GNU C Library is distributed in the hope that it will be useful, + but WITHOUT ANY WARRANTY; without even the implied warranty of + MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU + Library General Public License for more details. + + You should have received a copy of the GNU Library General Public + License along with the GNU C Library; see the file COPYING.LIB. If not, + write to the Free Software Foundation, Inc., 59 Temple Place - Suite 330, + Boston, MA 02111-1307, USA. */ + +#ifndef _ATOMICITY_H +#define _ATOMICITY_H 1 + +#include <inttypes.h> + + +static inline uint32_t +__attribute__ ((unused)) +exchange_and_add (volatile uint32_t *mem, uint32_t val) +{ + register uint32_t result; + __asm__ __volatile__ ("lock; xaddl %0,%2" + : "=r" (result) : "0" (val), "m" (*mem) : "memory"); + return result; +} + +static inline void +__attribute__ ((unused)) +atomic_add (volatile uint32_t *mem, int val) +{ + __asm__ __volatile__ ("lock; addl %0,%1" + : : "ir" (val), "m" (*mem) : "memory"); +} + +static inline char +__attribute__ ((unused)) +compare_and_swap (volatile long int *p, long int oldval, long int newval) +{ + char ret; + long int readval; + + __asm__ __volatile__ ("lock; cmpxchgl %3, %1; sete %0" + : "=q" (ret), "=m" (*p), "=a" (readval) + : "r" (newval), "m" (*p), "a" (oldval)); + return ret; +} + +#endif /* atomicity.h */ --- /dev/null 1994-07-18 08:46:18.000000000 +0900 +++ libs/wprof/profiler.c 2003-08-15 11:27:31.000000000 +0900 @@ -0,0 +1,555 @@ +/* Wine Profiler + * + * Copyright 2000-2003 Codeweavers, Charles Loep + * + * This library is free software; you can redistribute it and/or + * modify it under the terms of the GNU Lesser General Public + * License as published by the Free Software Foundation; either + * version 2.1 of the License, or (at your option) any later version. + * + * This library is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU + * Lesser General Public License for more details. + * + * You should have received a copy of the GNU Lesser General Public + * License along with this library; if not, write to the Free Software + * Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111-1307 USA + */ + +/* + * It's unlikely that this works on anything other than linux/i386 + */ + +#include <stdio.h> +#include <stdlib.h> +#include <string.h> +#include <fcntl.h> +#include <unistd.h> +#include <sys/mman.h> +#include <sys/resource.h> +#include <sys/types.h> +#include <sys/stat.h> + +#include "atomicity.h" +#include "profiler.h" + + +#define WPROF_MAX_CALL_DEPTH 1024 +#define WPROF_MAX_ARC 1000000 + +#define WPROF_CURRENT getpid() +#define WPROF_WMON_PREFIX "/tmp/wmon.out." + + +#define DEBUG + +#ifdef DEBUG +#define db_printf(args...) printf(args) +#else +#define db_printf(args...) +#endif + + +typedef struct cstack_s { + arc_t *current; + counter64_t entry_time; +} cstack_t; + + +typedef struct ptinfo_s { + pid_t pid; + arc_t *root; + int map_fd; + int map_size; + wprof_header_t *header; + cstack_t cstack[WPROF_MAX_CALL_DEPTH]; + int cstackp; + long state; + struct ptinfo_s *next; +} ptinfo_t; + + +#define PTINFO_FINALIZED ((void *)-1) +#define PTINFO_TOTAL 32768 +static ptinfo_t *ptinfo_map[PTINFO_TOTAL]; + + +typedef enum { + WPROF_STATE_OFF = 0, + WPROF_STATE_ON, + WPROF_STATE_BUSY +} WPROF_STATE; + + +/* global data */ +static pid_t wprof_master = 0; +static counter32_t wprof_cpu_hz = 0; +static long wprof_global_state; +static int wprof_thread_count = 0; + +void __attribute__ ((constructor)) wprof_init(); +void __attribute__ ((destructor)) wprof_exit(); + + +static void wprof_finalize_thread(ptinfo_t *pt); +static arc_t *wprof_alloc_arc(ptinfo_t *pt, address32_t addr); + + +/* + * determine the number of ticks per second + */ +static unsigned long wprof_get_hz() +{ + FILE *fp; + double ticks = 0.0; + + fp = fopen("/proc/cpuinfo", "r"); + while(!feof(fp)) + { + + char line[1024]; + + if(!fgets(line, 1024, fp)) + break; + if(sscanf(line, "cpu MHz : %lf", &ticks) != 1) + continue; + db_printf("WPROF: ticks per second: %.0lf\n", (ticks * 1000000.0)); + break; + } + fclose(fp); + + if(ticks == 0.0) + { + printf("WPROF: unable to determine HZ (%lf)\n", ticks); + _exit(1); + } + + return (unsigned long)(ticks * 1000000.0); +} + +static counter64_t get_tsc() +{ + counter64_t value; + __asm__ __volatile__("rdtsc" : "=A" (value)); + return value; +} + + + +/* + * constructor + */ +void wprof_init() +{ + wprof_master = WPROF_CURRENT; + wprof_cpu_hz = wprof_get_hz(); + + db_printf("WPROF: initialized!\n"); + + wprof_global_state = WPROF_STATE_ON; +} + +/* + * destructor + */ +void wprof_exit() +{ + int i; + + wprof_global_state = WPROF_STATE_OFF; + db_printf("WPROF: unloading %d (%d threads)\n", WPROF_CURRENT, wprof_thread_count); + +#if 1 + // finalize any threads that didnt we didn't catch before + for(i = 0; i < PTINFO_TOTAL; i++) { + if(ptinfo_map[i]) { + ptinfo_t *pt = ptinfo_map[i]; + + if(pt == PTINFO_FINALIZED) { + db_printf("WPROF: finalizing %d (skipped)\n", i); + continue; + } + + db_printf("WPROF: finalizing %d\n", pt->pid); + wprof_finalize_thread(pt); + ptinfo_map[i] = 0; + } + } +#endif + +} + + +static char digits[] = { '0', '1', '2', '3', '4', '5', '6', '7', '8', '9' }; +static void strintcat(char *str, int i) +{ + int pos = 11; + char buf[12]; + + buf[11] = 0; + do { + buf[--pos] = digits[i % 10]; + i = i / 10; + } while(i != 0); + + strcat(str, &buf[pos]); +} + + +/* + * map the profile output file for the current thread + */ +static ptinfo_t *wprof_map_output() +{ + ptinfo_t *pt = NULL; + char filename[256] = WPROF_WMON_PREFIX; + void *addr; + int map_size, map_fd; + + map_size = sizeof(wprof_header_t) + (WPROF_MAX_ARC * sizeof(arc_t)) + sizeof(ptinfo_t); + + strintcat(filename, WPROF_CURRENT); + db_printf("WPROF: creating %s\n", filename); + + map_fd = open(filename, O_RDWR|O_CREAT|O_TRUNC, 0664); + ftruncate(map_fd, map_size); + addr = mmap(NULL, map_size, PROT_READ|PROT_WRITE, MAP_SHARED, map_fd, 0); + + pt = (ptinfo_t *)(addr + map_size - sizeof(ptinfo_t)); + pt->map_size = map_size; + pt->map_fd = map_fd; + pt->header = (wprof_header_t *)addr; + pt->header->vaddr = (unsigned int)addr; + + return pt; +} + +/* + * allocate a thread info struct + */ +static ptinfo_t *wprof_alloc_ptinfo() +{ + ptinfo_t *pt; + arc_t *arc; + pid_t current = WPROF_CURRENT; + + db_printf("WPROF: new thread; pid %d\n", current); + + pt = wprof_map_output(); + pt->pid = current; + pt->root = NULL; + pt->next = NULL; + + pt->header->magic = WPROF_MAGIC; + pt->header->version = WPROF_VERSION; + pt->header->pid = pt->pid; + pt->header->cpu_hz = wprof_cpu_hz; + gettimeofday(&pt->header->time_start, NULL); + gettimeofday(&pt->header->time_stop, NULL); + + arc = wprof_alloc_arc(pt, 0); + pt->root = arc; + pt->cstackp = 0; + pt->cstack[pt->cstackp].current = pt->root; + pt->cstack[pt->cstackp].entry_time = get_tsc(); + + ptinfo_map[current] = pt; + pt->state = WPROF_STATE_ON; + + wprof_thread_count++; + + return pt; +} + + +/* + * retrieve or allocate a thread info struct + */ +static ptinfo_t *wprof_get_ptinfo() +{ + ptinfo_t *pt; + pid_t current = WPROF_CURRENT; + + pt = ptinfo_map[current]; + + if(pt == PTINFO_FINALIZED) + return NULL; + + if(!pt) + pt = wprof_alloc_ptinfo(); + return pt; +} + + +static void wprof_unlink_ptinfo(ptinfo_t *ptrem) +{ + ptinfo_map[ptrem->pid] = PTINFO_FINALIZED; +} + +static int wprof_has_ptinfo() +{ + pid_t current = WPROF_CURRENT; + + if(ptinfo_map[current]) + return 1; + return 0; +} + +/* + * allocate new arc + * FIXME: make sure there's enough free space left for the allocation + */ +static arc_t *wprof_alloc_arc(ptinfo_t *pt, address32_t addr) +{ + arc_t *arc; + + arc = &pt->header->root[pt->header->arc_count++]; + arc->addr = addr; + + //db_printf("WPROF: allocating arc for %x\n", addr); + return arc; +} + + +/* + * append arc to the list + */ +static arc_t *wprof_arc_list_append(arc_t *root, arc_t *arc) +{ + arc_t *tmp; + + if(!root) + return arc; + + tmp = root; + while(tmp->next) + tmp = tmp->next; + tmp->next = arc; + + return root; +} + + +/* + * find arc with address addr or allocate a new one + */ +static arc_t *wprof_find_arc(ptinfo_t *pt, arc_t *current, address32_t addr) +{ + arc_t *arc; + + for(arc = current->children; arc; arc = arc->next) + { + if(arc->addr == addr) + return arc; + } + + arc = wprof_alloc_arc(pt, addr); + current->children = wprof_arc_list_append(current->children, arc); + + return arc; +} + +#define CHECKPT(pt) do { if(!pt) return; if(pt == PTINFO_FINALIZED) return; } while(0) + + +/* + * profile entry point + * this is called first thing in a profiled function + */ +void __cyg_profile_func_enter(address32_t this_fn, address32_t call_site) +{ + ptinfo_t *pt; + cstack_t *top; + arc_t *arc; + + pt = wprof_get_ptinfo(); + CHECKPT(pt); + + if(pt->state == WPROF_STATE_OFF) + return; + + /* FIXME + * what to do when a signal arrives in the middle of this? + * for now we'll just ignore it and return + */ + if(!compare_and_swap(&pt->state, WPROF_STATE_ON, WPROF_STATE_BUSY)) + { + db_printf("WPROF: warning; re-entry in __menter (state=%ld)\n", pt->state); + return; + } + + top = &pt->cstack[pt->cstackp++]; + arc = wprof_find_arc(pt, top->current, this_fn); + arc->count++; + + top++; + top->current = arc; + top->entry_time = get_tsc(); + + compare_and_swap(&pt->state, WPROF_STATE_BUSY, WPROF_STATE_ON); +} + + +/* + * called at exit of a profiled function + */ +void __cyg_profile_func_exit(address32_t this_fn, address32_t call_site) +{ + counter64_t after; + ptinfo_t *pt; + cstack_t *top; + arc_t *arc; + + after = get_tsc(); + pt = wprof_get_ptinfo(); + CHECKPT(pt); + + if(pt->state == WPROF_STATE_OFF) + return; + + /* + * this happens when __menter was re-entered (by a signal) + * ignore the signal handler exit + */ + if(pt->state == WPROF_STATE_BUSY) + { + db_printf("WPROF: warning; BUSY in __mexit\n"); + return; + } + top = &pt->cstack[pt->cstackp]; + arc = top->current; + arc->ticks += (after - top->entry_time); + + pt->cstackp--; +} + + +static void sim_func_exit(ptinfo_t *pt) +{ + counter64_t after; + cstack_t *top; + arc_t *arc; + + after = get_tsc(); + + top = &pt->cstack[pt->cstackp]; + arc = top->current; + arc->ticks += (after - top->entry_time); + + pt->cstackp--; +} + + + +/* + * grab a copy of /proc/self/maps and save the relevant entries to + * the profile output file. + * FIXME: cant use /proc/self/.. since this may be called from a different process + */ +static void wprof_write_maps(ptinfo_t *pt, char *addr) +{ + FILE *fp; + + fp = fopen("/proc/self/maps", "r"); + if(!fp) + return; + + while(!feof(fp)) + { + wprof_map_t map; + char tmp[1024], soname[256], perm[16]; + int start, end, offset, res; + + if(!fgets(tmp, 1024, fp)) + break; + + res = sscanf(tmp, "%x-%x %s %x %*s %*d %[^\n]\n", + &start, &end, perm, &offset, soname); + if(res != 5) + continue; + + /* only save entries mapped as executable */ + if(!strstr(perm, "x")) + continue; + + memset(&map, 0, sizeof(wprof_map_t)); + map.addr_from = start; + map.addr_to = end; + map.offset = offset; + strncpy(map.filename, soname, sizeof(map.filename)); + + memcpy(addr, &map, sizeof(wprof_map_t)); + addr += sizeof(wprof_map_t); + pt->header->map_count++; + } + + fclose(fp); +} + + +/* + * finalize a threads output file + */ +static void wprof_finalize_thread(ptinfo_t *pt) +{ + size_t end; + + CHECKPT(pt); + + while(pt->cstackp > 0) + { + //db_printf("WPROF: unwind cstack %d\n", pt->cstackp); + sim_func_exit(pt); + } + + pt->state = WPROF_STATE_OFF; + + db_printf("[%d] profile_exit\n", pt->pid); + db_printf("[%d] arc_count=%d (mem=%d)\n", + pt->pid, pt->header->arc_count, + pt->header->arc_count * sizeof(arc_t)); + + end = sizeof(wprof_header_t) + (pt->header->arc_count * sizeof(arc_t)); + + if(lseek(pt->map_fd, end, SEEK_SET) != -1) { + void *addr = (void *)pt->header; + int map_fd = pt->map_fd; + int map_size = pt->map_size; + + wprof_write_maps(pt, (char *)(pt->header->vaddr + end)); + pt->header->flags |= WFLAG_CLOSED; + wprof_unlink_ptinfo(pt); + + ftruncate(map_fd, end + (pt->header->map_count * sizeof(wprof_map_t))); + + munmap(addr, map_size); + close(map_fd); + } else { + printf("WPROF: lseek failed\n"); + } +} + + +/* + * exit the CURRENT thread + */ +void wprof_exit_thread(int status) +{ + ptinfo_t *pt; + + db_printf("WPROF: wprof_exit_thread(%d)\n", status); + + pt = wprof_get_ptinfo(); + CHECKPT(pt); + + /* record exit code */ + pt->header->exitcode = status; + + /* store some useful info */ + pt->header->flags |= WFLAG_HAS_RUSAGE; + getrusage(RUSAGE_SELF, &pt->header->rusage); + gettimeofday(&pt->header->time_stop, NULL); + + wprof_finalize_thread(pt); +} --- /dev/null 1994-07-18 08:46:18.000000000 +0900 +++ libs/wprof/profiler.h 2003-05-30 17:19:45.000000000 +0900 @@ -0,0 +1,87 @@ +/* Wine Profiler + * + * Copyright 2000-2003 Codeweavers, Charles Loep + * + * This library is free software; you can redistribute it and/or + * modify it under the terms of the GNU Lesser General Public + * License as published by the Free Software Foundation; either + * version 2.1 of the License, or (at your option) any later version. + * + * This library is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU + * Lesser General Public License for more details. + * + * You should have received a copy of the GNU Lesser General Public + * License along with this library; if not, write to the Free Software + * Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111-1307 USA + */ + +#ifndef __WPROF_H__ +#define __WPROF_H__ + +#include <unistd.h> +#include <sys/time.h> +#include <sys/resource.h> + +#define XSTDCALL __attribute((__stdcall__)) +#define XNOPROF __attribute((no_instrument_function)) + +#define WPROF_MAGIC 0x4E4F4D57 +#define WPROF_VERSION 0x02 + + +typedef unsigned long long counter64_t; +typedef unsigned long counter32_t; + +typedef void * address32_t; + + +typedef struct arc_s { + address32_t addr; + counter32_t count; + counter64_t ticks; + struct arc_s *children; + struct arc_s *next; +} arc_t; + + +enum { + WFLAG_NONE = 0, + WFLAG_CLOSED = 1, + WFLAG_HAS_RUSAGE = 2, +}; + +typedef struct wprof_header_s { + unsigned int magic; + unsigned char version; + unsigned char flags; + unsigned char resv[2]; + pid_t pid; + struct timeval time_start; + struct timeval time_stop; + struct rusage rusage; + int exitcode; + counter32_t cpu_hz; + unsigned int vaddr; + size_t map_count; + unsigned int map_start; + size_t arc_count; + arc_t root[0]; +} wprof_header_t; + + + +typedef struct wprof_map_s { + unsigned int addr_from; + unsigned int addr_to; + unsigned int offset; + char filename[256]; +} wprof_map_t; + + + +void wprof_exit_thread(int status); + + +#endif /* __WPROF_H__ */ --- /dev/null 1994-07-18 08:46:18.000000000 +0900 +++ libs/wprof/proftest.c 2003-05-30 17:19:45.000000000 +0900 @@ -0,0 +1,95 @@ + +#include <stdio.h> +#include <sys/types.h> +#include <signal.h> +#include <sys/time.h> +#include <fcntl.h> + +#include <pthread.h> + +void handler() +{ + printf("ping %d\n", getpid()); +} + +int bar(int a) +{ + return foo(!a); +} + +int foo(int a) +{ + switch(a) + { + case 0: + return 12345; + case 1: + return bar(a); + default: + return 0; + } +} + +void blah() +{ + foo(2); +} + +void set_timer() +{ + struct itimerval it; + struct sigaction sa; + + memset(&sa, 0, sizeof(sa)); + sa.sa_handler = handler; + sa.sa_flags = SA_RESTART; + sigaction(SIGALRM, &sa, NULL); + + memset(&it, 0, sizeof(it)); + it.it_value.tv_usec = 100000; + it.it_interval.tv_usec = 100000; + setitimer(ITIMER_REAL, &it, NULL); + + +} + +int get_random(int q) +{ + return random() % q; +} + + +void *runner(void *unused) +{ + int i; + + set_timer(); + + for(i = 0; i < 1000000; i++) + foo(get_random(2)); +} + + +void test1() +{ + int fd = open("/dev/null", O_RDONLY); + close(fd); +} + +int main() +{ +#if 1 + pthread_t t1, t2; + + pthread_create(&t1, NULL, runner, NULL); + pthread_create(&t2, NULL, runner, NULL); + + pthread_join(t1, 0); + pthread_join(t2, 0); +#else + //runner(0); + test1(); +#endif + printf("proftest %d exiting\n", getpid()); + exit(101); +} --- /dev/null 1994-07-18 08:46:18.000000000 +0900 +++ libs/wprof/string.c 2003-05-30 17:19:45.000000000 +0900 @@ -0,0 +1,10 @@ + +#define __STRING_INLINE +#include <string.h> + +long double __sqrtl(long double __x) +{ + register long double __result; + __asm __volatile__("fsqrt" : "=t" (__result) : "0" (__x)); + return __result; +} --- /dev/null 1994-07-18 08:46:18.000000000 +0900 +++ libs/wprof/wineprof.c 2003-05-30 17:19:45.000000000 +0900 @@ -0,0 +1,871 @@ +/* Wine Profiler + * + * Copyright 2000-2003 Codeweavers, Charles Loep + * + * This library is free software; you can redistribute it and/or + * modify it under the terms of the GNU Lesser General Public + * License as published by the Free Software Foundation; either + * version 2.1 of the License, or (at your option) any later version. + * + * This library is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU + * Lesser General Public License for more details. + * + * You should have received a copy of the GNU Lesser General Public + * License along with this library; if not, write to the Free Software + * Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111-1307 USA + */ + +#include <stdio.h> +#include <stdlib.h> +#include <string.h> +#include <fcntl.h> +#include <unistd.h> +#include <sys/mman.h> +#include <sys/types.h> +#include <sys/stat.h> +#include <time.h> + +#include <getopt.h> + +#include <glib.h> + +#include "profiler.h" +#include "wineprof.h" + + +/*--------------------------------------------------------*/ +// options +/*--------------------------------------------------------*/ + +#define OPT_ON 1 +#define OPT_OFF 0 + +struct options { + int debug; + int flat; + int callers; + int calltree; + int soprefix; + int merge; + int listso; + int source; + char *sort; + int precision; + GList *ignore; + int compress; +}; + +struct options opt = { + debug : OPT_OFF, + flat : OPT_ON, + callers : OPT_OFF, + calltree : OPT_OFF, + soprefix : OPT_OFF, + merge : OPT_OFF, + listso : OPT_OFF, + source : OPT_OFF, + sort : "self", + precision : 3, + ignore : NULL, + compress : OPT_ON, +}; + + +static const struct option long_options[] = +{ + { "flat", no_argument, &opt.flat, OPT_ON }, + { "no-flat", no_argument, &opt.flat, OPT_OFF }, + { "callers", no_argument, &opt.callers, OPT_ON }, + { "no-callers", no_argument, &opt.callers, OPT_OFF }, + { "calltree", no_argument, &opt.calltree, OPT_ON }, + { "no-calltree", no_argument, &opt.calltree, OPT_OFF }, + + { "dso-prefix", no_argument, &opt.soprefix, OPT_ON }, + { "no-dso-prefix", no_argument, &opt.soprefix, OPT_OFF }, + + { "merge", no_argument, &opt.merge, OPT_ON }, + { "no-merge", no_argument, &opt.merge, OPT_OFF }, + { "list-dso", no_argument, &opt.listso, OPT_ON }, + { "no-list-dso", no_argument, &opt.listso, OPT_OFF }, + { "source", no_argument, &opt.source, OPT_ON }, + { "no-source", no_argument, &opt.source, OPT_OFF }, + + { "compress", no_argument, &opt.compress, OPT_ON }, + { "no-compress", no_argument, &opt.compress, OPT_OFF }, + + { "ignore", required_argument, NULL, 'i' }, + { "sort", required_argument, NULL, 's' }, + { "precision", required_argument, NULL, 'p' }, + + { "debug", no_argument, &opt.debug, OPT_ON }, + { "help", no_argument, NULL, 'h' }, +}; + + +/*--------------------------------------------------------*/ +// prototypes +/*--------------------------------------------------------*/ + +void usage(); +void view_profile_flat(profile_t *prof); +void view_profile_calltree(profile_t *prof); + + + +/*--------------------------------------------------------*/ +// the code! +/*--------------------------------------------------------*/ + + +static unsigned long wprof_get_hz() +{ + FILE *fp; + double ticks = 0.0; + + fp = fopen("/proc/cpuinfo", "r"); + while(!feof(fp)) + { + + char line[1024]; + + if(!fgets(line, 1024, fp)) + break; + if(sscanf(line, "cpu MHz : %lf", &ticks) != 1) + continue; + printf("WPROF: ticks per second: %.0lf\n", (ticks * 1000000.0)); + break; + } + fclose(fp); + + if(ticks == 0.0) + { + printf("WPROF: unable to determine CPU HZ\n"); + exit(1); + } + + return (long)(ticks * 1000000.0); +} + + +static size_t file_size_for_fd(int fd) +{ + struct stat st; + fstat(fd, &st); + return st.st_size; +} + +static char *basename(char *file) +{ + char *p = strrchr(file, '/'); + return p ? ++p : file; +} + +static char *fullname(symbol_t *sym) +{ + static char tmp[1024]; + + if(opt.soprefix) + sprintf(tmp, "%s:%s", basename(sym->soname), sym->name); + else + return sym->name; + + return tmp; +} + +static counter64_t msec(counter64_t hz, counter64_t count) +{ + double v; + + v = (double)count / ((double)hz / 1000.0); + return (counter64_t)v; +} + +static double dsec(counter64_t hz, counter64_t count) +{ + double v; + + v = (double)count / (double)hz; + return v; +} + +static double tv_to_double(struct timeval *tv) +{ + return (double)tv->tv_sec + ((double)tv->tv_usec / 1000000.0); +} + + +static char *repeat_char(char ch, int count) +{ + static char tmp[1024]; + memset(tmp, ch, count); + tmp[count] = 0; + return tmp; +} + + + +/* + * allocate a symbol + */ +symbol_t *symbol_new(char *name, address32_t addr) +{ + symbol_t *sym = g_new0(symbol_t, 1); + sym->name = g_strdup(name); + sym->addr = (unsigned int)addr; + + return sym; +} + + +/* + * fetch all symbols from soname + * <lazy> we use nm for now </lazy> + */ +static int read_symtab(GHashTable *hash, unsigned int base, char *soname) +{ + FILE *fp; + char cmd[512], line[256]; + + if(opt.source) + sprintf(cmd, "nm --defined-only --line-numbers '%s' 2> /dev/null", soname); + else + sprintf(cmd, "nm --defined-only '%s' 2> /dev/null", soname); + + fp = popen(cmd, "r"); + if(!fp) + return 0; + + soname = g_strdup(soname); + + while(!feof(fp)) + { + unsigned int addr = 0; + char type = 0; + char symbol[256], source[512] = { 0 }; + symbol_t *sym; + int res = 0; + + if(!fgets(line, 256, fp)) + break; + + if(opt.source) + res = sscanf(line, "%x %c %s %s\n", &addr, &type, symbol, source); + + else if(!opt.source || res != 4) + { + if(sscanf(line, "%x %c %s\n", &addr, &type, symbol) != 3) + continue; + } + + if(addr < base) + addr += base; + + //printf("%c %x %s\n", type, addr, symbol); + + if(!g_hash_table_lookup(hash, (gpointer)addr) || type == 'T') + { + sym = symbol_new(symbol, (address32_t)addr); + sym->soname = soname; + if(strlen(source)) + sym->source = g_strdup(source); + g_hash_table_insert(hash, (gpointer)addr, sym); + } + } + pclose(fp); + + return 1; +} + +/* + * returns true if sym's name is in the ingore list + */ +static int symbol_is_ignored(symbol_t *sym) +{ + GList *e; + + if(!sym) + return 0; + //FIXME this should be a hashtable + for(e = opt.ignore; e; e = e->next) + { + char *str = e->data; + if(!strcmp(str, sym->name)) + return 1; + } + return 0; +} + + +/* + * helper for symbol_add_caller + */ +static int cmp_callinfo_sym(gconstpointer a, gconstpointer b) +{ + callinfo_t *ci = (callinfo_t *)a; + symbol_t *sym = (symbol_t *)b; + + return !(ci->caller == sym); +} + +/* + * add a caller to sym + */ +static void symbol_add_caller(symbol_t *sym, symbol_t *caller, arc_t *arc) +{ + callinfo_t *ci = 0; + + if(opt.compress) + { + GList *e = g_list_find_custom(sym->callers, caller, cmp_callinfo_sym); + if(e) + ci = e->data; + } + + if(!ci) + { + ci = g_new0(callinfo_t, 1); + ci->caller = caller; + sym->callers = g_list_append(sym->callers, ci); + } + + ci->calls += arc->count; + ci->ticks += arc->ticks; +} + +counter64_t calc_all_ticks(arc_t *root, GHashTable *symtab, symbol_t *caller) +{ + counter64_t total_time = 0; + counter64_t children_time = 0; + arc_t *arc; + + if(!root) + return 0; + + for(arc = root->children; arc; arc = arc->next) + { + symbol_t *sym; + + sym = g_hash_table_lookup(symtab, (gpointer)arc->addr); + if(!sym) { + char name[32]; + sprintf(name, "(0x%X)", (unsigned int)arc->addr); + sym = symbol_new(strdup(name), arc->addr); + //printf("SYMBOL NOT FOUND %x\n", arc->addr); + g_hash_table_insert(symtab, (gpointer)arc->addr, sym); + } + + children_time = calc_all_ticks(arc, symtab, sym); + //printf("children_time = %llu\n", children_time); + total_time += children_time; + if(!symbol_is_ignored(sym)) { + total_time += (arc->ticks - children_time); + + sym->count += arc->count; + sym->ticks += arc->ticks; + sym->ticks_kids += children_time; + sym->ticks_self += arc->ticks - children_time; + + if(caller) + { + symbol_add_caller(sym, caller, arc); + //printf("SYM %-20s CALLER %s\n", sym->name, caller->name); + } + } + } + + return total_time; +} + + +static GHashTable *process_maps(wprof_map_t *mp, int num_maps) +{ + GHashTable *hash; + int i; + + hash = g_hash_table_new(g_direct_hash, g_direct_equal); + + for(i = 0; i < num_maps; i++) + { + if(opt.listso) + printf("%08x-%08x %08x %s \n", mp->addr_from, mp->addr_to, mp->offset, mp->filename); + read_symtab(hash, mp->addr_from, mp->filename); + mp++; + } + return hash; +} + + +profile_t *profile_open(char *filename) +{ + profile_t *prof; + wprof_header_t header, *hp; + double idle, systime, usertime; + void *addr; + int fd; + + fd = open(filename, O_RDONLY); + read(fd, &header, sizeof(header)); + if(header.magic != WPROF_MAGIC) + { + printf("WPROF: invalid magic number in %s\n", filename); + close(fd); + return 0; + } + if(header.version != WPROF_VERSION) + { + printf("WPROF: version mismatch in %s\n", filename); + close(fd); + return 0; + } + + if(!(header.flags & WFLAG_CLOSED)) + { + printf("WPROF: profile not properly closed.\n"); + //close(fd); + //return 0; + } + + prof = g_new0(profile_t, 1); + + usertime = tv_to_double(&header.rusage.ru_utime); + systime = tv_to_double(&header.rusage.ru_stime); + + idle = tv_to_double(&header.time_stop) - tv_to_double(&header.time_start); + idle -= tv_to_double(&header.rusage.ru_utime) + tv_to_double(&header.rusage.ru_stime); + + if(opt.debug) + { + printf("WPROF pid: %d\n", header.pid); + printf("WPROF start: %s", ctime(&header.time_start.tv_sec)); + printf("WPROF stop: %s", ctime(&header.time_stop.tv_sec)); + + printf("WPROF utime: %.3lf sec\n", usertime); + printf("WPROF stime: %.3lf sec\n", systime); + printf("WPROF idle: %.3lf sec\n", idle); + + printf("WPROF exit: %d\n", header.exitcode); + printf("WPROF clock: %lu\n", header.cpu_hz); + printf("WPROF addr: %x\n", header.vaddr); + printf("WPROF #arc: %d\n", header.arc_count); + printf("WPROF #map: %d\n", header.map_count); + } + + if(header.flags & WFLAG_HAS_RUSAGE) { + printf("pid utime stime idle total\n"); + printf("----- -------- -------- -------- --------\n"); + printf("%5d %8.3lf %8.3lf %8.3lf %8.3lf\n\n", + header.pid, + usertime, + systime, + idle, + usertime + systime + idle + ); + } else { + printf("WPROF: no rusage available.\n"); + } + + addr = mmap((void *)header.vaddr, file_size_for_fd(fd), PROT_READ, + MAP_SHARED, fd, 0); + if(addr == NULL || addr != (void *)header.vaddr) + { + /* FIXME + * <lazy> we should relocate the file if it can't be mapped at the + * address specified in the header </lazy> + */ + perror("mmap"); + printf("Oops! failed to map profile at %x - bug Charles to fix it if this ever happens.\n", header.vaddr); + exit(1); + } + if(opt.debug) + printf("WPROF mapped at: %p\n", addr); + + hp = (wprof_header_t *)addr; + + prof->fd = fd; + prof->header = hp; + prof->symtab = process_maps((wprof_map_t *)(addr + sizeof(wprof_header_t) + (hp->arc_count * sizeof(arc_t))), hp->map_count); + prof->total_ticks = calc_all_ticks(&hp->root[0], prof->symtab, 0); + + return prof; +} + + +void profile_close(profile_t *prof) +{ + //FIXME: free profile +} + + + +static void do_make_list(gpointer key, gpointer value, gpointer user_data) +{ + GList *list = *(GList **)user_data; + *(GList **)user_data = g_list_prepend(list, value); +} + +GList *symtab_to_symlist(GHashTable *symtab) +{ + GList *list = 0; + g_hash_table_foreach(symtab, do_make_list, &list); + + return list; +} + + + +/*--------------------------------------------------------*/ +// sorting functions +/*--------------------------------------------------------*/ + + +#define COMPARE(a, b) ((a) == (b) ? 0 : (a) < (b) ? -1 : 1) + +#define DEFINE_SORT(TYPE, FIELD, NAME) \ +gint NAME (gconstpointer a, gconstpointer b) \ +{ \ + TYPE *val_a = (TYPE *)a; \ + TYPE *val_b = (TYPE *)b; \ + return COMPARE(val_b->FIELD, val_a->FIELD); \ +} + +DEFINE_SORT(symbol_t, count, do_sort_by_calls); +DEFINE_SORT(symbol_t, ticks, do_sort_by_ticks); +DEFINE_SORT(symbol_t, ticks_self, do_sort_by_ticks_self); +DEFINE_SORT(symbol_t, ticks_kids, do_sort_by_ticks_kids); +DEFINE_SORT(symbol_t, name, do_sort_by_name); + + +static GList *sort_symlist(GList *symlist) +{ + if(!strcmp(opt.sort, "name")) + return g_list_sort(symlist, do_sort_by_name); + + if(!strcmp(opt.sort, "calls")) + return g_list_sort(symlist, do_sort_by_calls); + + if(!strcmp(opt.sort, "ticks")) + return g_list_sort(symlist, do_sort_by_ticks); + + if(!strcmp(opt.sort, "self")) + return g_list_sort(symlist, do_sort_by_ticks_self); + + if(!strcmp(opt.sort, "child")) + return g_list_sort(symlist, do_sort_by_ticks_kids); + + return symlist; +} + +DEFINE_SORT(callinfo_t, caller->name, do_sort_ci_by_name); +DEFINE_SORT(callinfo_t, calls, do_sort_ci_by_calls); +DEFINE_SORT(callinfo_t, ticks, do_sort_ci_by_ticks); + + +static GList *sort_callinfo(GList *callers) +{ + if(!strcmp(opt.sort, "name")) + return g_list_sort(callers, do_sort_ci_by_name); + + if(!strcmp(opt.sort, "calls")) + return g_list_sort(callers, do_sort_ci_by_calls); + + return g_list_sort(callers, do_sort_ci_by_ticks); +} + + +/* + * Display the flat profile + */ +void view_profile_flat(profile_t *prof) +{ + GList *list, *e; + counter64_t total; + counter64_t current = 0; + counter64_t hz = prof->header->cpu_hz; + + list = symtab_to_symlist(prof->symtab); + list = sort_symlist(list); + + total = prof->total_ticks; + + printf("\n\nFlat Profile:\n\n"); + + if(opt.debug) + { + printf("CPU HZ: %llu\n", hz); + printf("Total ticks: %llu (%lf sec)\n", total, dsec(hz, total)); + } + + /* FIXME: add support for variable precision to other fields too */ + + printf("\n"); + printf("%-*.*s cmul %% calls self sec all sec avg self avg all function\n", + opt.precision + 4, opt.precision + 4, "% time"); + printf("%s ------ -------- -------- -------- -------- -------- --------\n", + repeat_char('-', opt.precision + 4)); + + for(e = list; e; e = e->next) + { + symbol_t *sym = e->data; + double percent, cmul; + double sec_self, sec_all, sec_self_avg, sec_all_avg; + + if(sym->count == 0) + continue; + if(symbol_is_ignored(sym)) + continue; + //printf("sym->ticks_self = %lf total = %lf\n", (double)sym->ticks_self, (double)total); + percent = (double)sym->ticks_self / (double)total * 100.0; + + current += sym->ticks_self; + cmul = (double)current / (double)total * 100.0; + + sec_self = dsec(hz, sym->ticks_self); + sec_all = dsec(hz, sym->ticks_self + sym->ticks_kids); + + sec_self_avg = dsec(hz, sym->ticks_self / sym->count); + sec_all_avg = dsec(hz, (sym->ticks_self + sym->ticks_kids) / sym->count); + + + printf("%*.*lf %6.2lf %8lu %8.3lf %8.3lf %8.3lf %8.3lf %s\n", + opt.precision + 4, opt.precision, percent, + cmul, + sym->count, + sec_self, + sec_all, + sec_self_avg, + sec_all_avg, + fullname(sym)); + + if(opt.source && sym->source) + printf("- %s\n", sym->source); + +#if 0 + if(sym->callers) + { + GList *ce; + int line = 0; + for(ce = sym->callers; ce; ce = ce->next) + { + callinfo_t *ci = ce->data; + printf("%*s %8lu %s\n", + opt.precision+4+6+1, "", + ci->calls, + ci->caller->name); + line++; + } + } +#endif + + } +} + +/* + * Display the callers profile + */ +void view_profile_callers(profile_t *prof) +{ + GList *list, *e; + counter64_t total; + counter64_t hz = wprof_get_hz(); //prof->header->cpu_hz; + + list = symtab_to_symlist(prof->symtab); + list = sort_symlist(list); + + total = prof->total_ticks; + + printf("\n\nCallers Profile:\n\n"); + + for(e = list; e; e = e->next) + { + symbol_t *sym = e->data; + + if(sym->count == 0) + continue; + + printf("%s (%lu call%s, %.3lf sec) called by:\n", + fullname(sym), + sym->count, + sym->count == 1 ? "" : "s", + dsec(hz, sym->ticks_kids + sym->ticks_self) + ); + + + printf("-calls----------- -time-------- -caller-------------\n"); + if(sym->callers) + { + GList *ce; + for(ce = sort_callinfo(sym->callers); ce; ce = ce->next) + { + callinfo_t *ci = ce->data; + symbol_t *caller = ci->caller; + +#if 1 + printf(" %8lu %3.0f%% %8.3lf %3.0f%% %s\n", + ci->calls, + 100.0 * ci->calls / sym->count, + dsec(hz, ci->ticks), + 100.0 * ci->ticks / (sym->ticks_kids + sym->ticks_self), + caller->name); +#else + printf(" %s for %lu calls, %.3lf sec\n", + fullname(caller), + ci->calls, + dsec(hz, ci->ticks) + ); +#endif + } + } + else + printf(" <unknown>\n"); + + printf("\n"); + + } +} + + +static void do_view_profile_calltree(arc_t *root, GHashTable *symtab, int idx) +{ + arc_t *arc; + + if(!root) + return; + + for(arc = root->children; arc; arc = arc->next) + { + symbol_t *sym; + int i; + + sym = g_hash_table_lookup(symtab, (gpointer)arc->addr); + + for(i = 0; i < idx; i++) + printf(" "); + + if(sym) + printf("%s (%lu calls, %llu ticks)\n", fullname(sym), arc->count, arc->ticks); + else + printf("%x (%lu calls, %llu ticks)\n", (unsigned int)arc->addr, arc->count, arc->ticks); + + do_view_profile_calltree(arc, symtab, idx + 1); + } +} + +/* + * Display the calltree + */ +void view_profile_calltree(profile_t *prof) +{ + printf("\n\nCalltree:\n\n"); + do_view_profile_calltree(&prof->header->root[0], prof->symtab, 0); +} + + + + +/*--------------------------------------------------------*/ +// MAIN +/*--------------------------------------------------------*/ + + +int main(int argc, char **argv) +{ + int option_index = 0; + + while(1) + { + int c = getopt_long (argc, argv, "h?i:s:", + long_options, &option_index); + if(c == -1) + break; + + switch(c) + { + case 0: + break; + + /*FIXME not sure if this option is useful/works correctly */ + case 'i': + { + gchar **strv = g_strsplit(optarg, ",", 0); + int i = 0; + while(strv[i]) + { + opt.ignore = g_list_append(opt.ignore, g_strdup(strv[i])); + i++; + } + g_strfreev(strv); + } + break; + + case 's': + opt.sort = strdup(optarg); + break; + + case 'p': + opt.precision = atoi(optarg); + break; + + case '?': + case 'h': + usage(); + exit(0); + break; + default: + printf("Something is messed up ...\n"); + break; + } + } + + + if(optind >= argc) + { + usage(); + printf("\nError: no files specified.\n"); + exit(1); + } + + while(optind < argc) + { + profile_t *prof; + char *filename = argv[optind++]; + + prof = profile_open(filename); + if(!prof) + continue; + + if(opt.flat) + view_profile_flat(prof); + + if(opt.callers) + view_profile_callers(prof); + + if(opt.calltree) + view_profile_calltree(prof); + + profile_close(prof); + } + + exit(0); +} + + +void usage() +{ + static const char usage_msg[] = "Usage: wprof [OPTION]... [FILE]...\n\n" + " --flat display flat profile\n" + " --callers display callers profile\n" + " --calltree display entire calltree (can be huge!)\n" + "! --merge merge specified profile files\n" + " --list-dso list shared objects used by the program\n" + " --dso-prefix prefix symbols with the name of the object they reside in\n" + " --ignore SYM ignore symbol SYM (comma separated list)\n" + " --source display source files and line numbers\n" + " --compress compress callers with the same name into a single entry\n" + " --sort KEY sort output by KEY (name, calls, ticks, self, child)\n" + " --help display this help text\n\n" + "Most options can be prefixed with 'no' to disable it, e.g. --no-flat\n"; + + printf("%s", usage_msg); +} --- /dev/null 1994-07-18 08:46:18.000000000 +0900 +++ libs/wprof/wineprof.h 2003-05-30 17:19:45.000000000 +0900 @@ -0,0 +1,56 @@ +/* Wine Profiler + * + * Copyright 2000-2003 Codeweavers, Charles Loep + * + * This library is free software; you can redistribute it and/or + * modify it under the terms of the GNU Lesser General Public + * License as published by the Free Software Foundation; either + * version 2.1 of the License, or (at your option) any later version. + * + * This library is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU + * Lesser General Public License for more details. + * + * You should have received a copy of the GNU Lesser General Public + * License along with this library; if not, write to the Free Software + * Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111-1307 USA + */ + +#ifndef __WINEPROF_H__ +#define __WINEPROF_H__ + +struct callinfo_s; +struct symbol_s; +struct profile_s; + + +typedef struct callinfo_s { + counter32_t calls; + counter64_t ticks; + struct symbol_s *caller; +} callinfo_t; + + +typedef struct symbol_s { + char *name; + char *soname; + char *source; + unsigned int addr; + counter32_t count; + counter64_t ticks; + counter64_t ticks_self; + counter64_t ticks_kids; + GList *callers; +} symbol_t; + +typedef struct profile_s { + int fd; + wprof_header_t *header; + GHashTable *symtab; + GList *symlist; + counter64_t total_ticks; +} profile_t; + + +#endif /*__WINEPROF_H__*/ --- /dev/null 1994-07-18 08:46:18.000000000 +0900 +++ libs/wprof/wrappers.c 2003-08-15 11:27:31.000000000 +0900 @@ -0,0 +1,104 @@ +/* Wine Profiler + * + * Copyright 2000-2003 Codeweavers, Charles Loep + * + * This library is free software; you can redistribute it and/or + * modify it under the terms of the GNU Lesser General Public + * License as published by the Free Software Foundation; either + * version 2.1 of the License, or (at your option) any later version. + * + * This library is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU + * Lesser General Public License for more details. + * + * You should have received a copy of the GNU Lesser General Public + * License along with this library; if not, write to the Free Software + * Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111-1307 USA + */ + +#define __USE_GNU +#include <stdio.h> +#include <stdlib.h> +#include <sys/types.h> +#include <unistd.h> +#include <dlfcn.h> + +#include "profiler.h" + + +#ifndef RTLD_NEXT +#define RTLD_NEXT ((void *)-1L) +#endif + + +#ifdef DEBUG +#define db_printf(args...) printf(args) +#else +#define db_printf(args...) +#endif + + +#define WPROF_DETECT_EXIT + + +#ifdef WPROF_DETECT_EXIT + +static int wrappers_initialized = 0; +static void *(*real_dlopen)(const char *filename, int mode) = 0; +static int (*real_dlclose)(void *handle) = 0; +static void (*real_exit)(int status) __attribute__((__noreturn__)) = 0; +static void (*real__exit)(int status) = 0; + + + +static void init_wrappers() +{ + real_dlopen = dlsym(RTLD_NEXT, "dlopen"); + real_dlclose = dlsym(RTLD_NEXT, "dlclose"); + real_exit = dlsym(RTLD_NEXT, "exit"); + real__exit = dlsym(RTLD_NEXT, "_exit"); +} + + +void *dlopen(const char *filename, int flag) +{ + if(!wrappers_initialized) + init_wrappers(); + + db_printf("[%d] dlopen(%s, %d)\n", getpid(), filename, flag); + return real_dlopen(filename, flag); +} + +int dlclose(void *handle) +{ + if(!wrappers_initialized) + init_wrappers(); + + db_printf("[%d] dlclose(%p)\n", getpid(), handle); + return real_dlclose(handle); +} + +void exit(int status) +{ + if(!wrappers_initialized) + init_wrappers(); + + db_printf("[%d] exit(%d)\n", getpid(), status); + wprof_exit_thread(status); + + real_exit(status); +} + +void _exit(int status) +{ + if(!wrappers_initialized) + init_wrappers(); + + db_printf("[%d] _exit(%d)\n", getpid(), status); + wprof_exit_thread(status); + + real__exit(status); +} + +#endif /*WPROF_DETECT_EXIT*/