From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (qmail 25460 invoked from network); 13 Dec 1999 12:38:35 -0000 Received: from sunsite.auc.dk (130.225.51.30) by ns1.primenet.com.au with SMTP; 13 Dec 1999 12:38:35 -0000 Received: (qmail 3687 invoked by alias); 13 Dec 1999 12:38:25 -0000 Mailing-List: contact zsh-workers-help@sunsite.auc.dk; run by ezmlm Precedence: bulk X-No-Archive: yes X-Seq: 9019 Received: (qmail 3680 invoked from network); 13 Dec 1999 12:38:25 -0000 Date: Mon, 13 Dec 1999 13:38:23 +0100 (MET) Message-Id: <199912131238.NAA27796@beta.informatik.hu-berlin.de> From: Sven Wischnowsky To: zsh-workers@sunsite.auc.dk In-reply-to: Adam Spiers's message of Mon, 13 Dec 1999 12:21:27 +0000 Subject: Re: PATCH: some small speedups Adam Spiers wrote: > Sven Wischnowsky (wischnow@informatik.hu-berlin.de) wrote: > > Btw, at the weekend I remembered that I had once written myself a > > small shell function profiling module -- anyone interested? > > Yes please... In the form of a patch... Note that I wrote that between 11pm and 1am some time ago, so don't expect any wonders... It works like this: you zmodload zprof, execute the functions you want to profile and then call the builtin zprof (without args). It will then print profiling information to stdout. But the module will continue profiling functions (until you unload the module). The zprof builtin understands only one option: -c clears the profiling information it has collected so far. When profiling the completion code (or any autoloaded function) it probably makes sense to fisrt call the functions at least once and start profiling after that -- otherwise the time to load the functions might give results for things you don't really care about. The output is slightly modelled after the gprof output: a summary at the top showing number of calls and timing information (total, per call and percent) for the functions (both including times for called functions and the time for only the function itself). After that comes the information for the call arcs (from function A to function B). That's all. No docs, no configure (but the module uses gettimeofday()!). If anyone has questions -- ask me. If anyone wants to have this improved (or turned into a real module with configure testing and docs) -- don't ask me. But feel free to do that yourself, don't forget to stick your name in the comment in zprof.c, then ;-) Bye Sven diff -ru ../z.old/Src/Modules/zprof.c Src/Modules/zprof.c --- ../z.old/Src/Modules/zprof.c Mon Dec 13 13:26:15 1999 +++ Src/Modules/zprof.c Mon Dec 13 13:08:45 1999 @@ -0,0 +1,328 @@ +/* + * zprof.c - a shell function profiling module for zsh + * + * This file is part of zsh, the Z shell. + * + * Copyright (c) 1996-1997 Sven Wischnowsky + * All rights reserved. + * + * Permission is hereby granted, without written agreement and without + * license or royalty fees, to use, copy, modify, and distribute this + * software and to distribute modified versions of this software for any + * purpose, provided that the above copyright notice and the following + * two paragraphs appear in all copies of this software. + * + * In no event shall Sven Wischnowsky or the Zsh Development Group be liable + * to any party for direct, indirect, special, incidental, or consequential + * damages arising out of the use of this software and its documentation, + * even if Sven Wischnowsky and the Zsh Development Group have been advised of + * the possibility of such damage. + * + * Sven Wischnowsky and the Zsh Development Group specifically disclaim any + * warranties, including, but not limited to, the implied warranties of + * merchantability and fitness for a particular purpose. The software + * provided hereunder is on an "as is" basis, and Sven Wischnowsky and the + * Zsh Development Group have no obligation to provide maintenance, + * support, updates, enhancements, or modifications. + * + */ + +#include "zprof.mdh" +#include "zprof.pro" + +#include +#include + +typedef struct pfunc *Pfunc; + +struct pfunc { + Pfunc next; + char *name; + long calls; + double time; + double self; + long num; +}; + +typedef struct sfunc *Sfunc; + +struct sfunc { + Pfunc p; + Sfunc prev; + double beg; +}; + +typedef struct parc *Parc; + +struct parc { + Parc next; + Pfunc from; + Pfunc to; + long calls; + double time; + double self; +}; + +static Pfunc calls; +static int ncalls; +static Parc arcs; +static int narcs; +static Sfunc stack; + +static void +freepfuncs(Pfunc f) +{ + Pfunc n; + + for (; f; f = n) { + n = f->next; + zsfree(f->name); + zfree(f, sizeof(*f)); + } +} + +static void +freeparcs(Parc a) +{ + Parc n; + + for (; a; a = n) { + n = a->next; + zfree(a, sizeof(*a)); + } +} + +static Pfunc +findpfunc(char *name) +{ + Pfunc f; + + for (f = calls; f; f = f->next) + if (!strcmp(name, f->name)) + return f; + + return NULL; +} + +static Parc +findparc(Pfunc f, Pfunc t) +{ + Parc a; + + for (a = arcs; a; a = a->next) + if (a->from == f && a->to == t) + return a; + + return NULL; +} + +static int +cmpsfuncs(Pfunc *a, Pfunc *b) +{ + return ((*a)->self > (*b)->self ? -1 : ((*a)->self != (*b)->self)); +} + +static int +cmptfuncs(Pfunc *a, Pfunc *b) +{ + return ((*a)->time > (*b)->time ? -1 : ((*a)->time != (*b)->time)); +} + +static int +cmpparcs(Parc *a, Parc *b) +{ + return ((*a)->time > (*b)->time ? -1 : ((*a)->time != (*b)->time)); +} + +static int +bin_zprof(char *nam, char **args, char *ops, int func) +{ + if (ops['c']) { + freepfuncs(calls); + calls = NULL; + ncalls = 0; + freeparcs(arcs); + arcs = NULL; + narcs = 0; + } else { + VARARR(Pfunc, fs, (ncalls + 1)); + Pfunc f, *fp; + VARARR(Parc, as, (narcs + 1)); + Parc a, *ap; + long i; + double total; + + for (total = 0.0, f = calls, fp = fs; f; f = f->next, fp++) { + *fp = f; + total += f->self; + } + *fp = NULL; + for (a = arcs, ap = as; a; a = a->next, ap++) + *ap = a; + *ap = NULL; + + qsort(fs, ncalls, sizeof(f), + (int (*) _((const void *, const void *))) cmpsfuncs); + qsort(as, narcs, sizeof(a), + (int (*) _((const void *, const void *))) cmpparcs); + + printf("num calls time self name\n-----------------------------------------------------------------------------------\n"); + for (fp = fs, i = 1; *fp; fp++, i++) { + printf("%2ld) %4ld %8.2f %8.2f %5.2f%% %8.2f %8.2f %5.2f%% %s\n", + ((*fp)->num = i), + (*fp)->calls, + (*fp)->time, (*fp)->time / ((double) (*fp)->calls), + ((*fp)->time / total) * 100.0, + (*fp)->self, (*fp)->self / ((double) (*fp)->calls), + ((*fp)->self / total) * 100.0, + (*fp)->name); + } + qsort(fs, ncalls, sizeof(f), + (int (*) _((const void *, const void *))) cmptfuncs); + + for (fp = fs; *fp; fp++) { + printf("\n-----------------------------------------------------------------------------------\n\n"); + for (ap = as; *ap; ap++) + if ((*ap)->to == *fp) { + printf(" %4ld/%-4ld %8.2f %8.2f %5.2f%% %8.2f %8.2f %s [%ld]\n", + (*ap)->calls, (*fp)->calls, + (*ap)->time, (*ap)->time / ((double) (*ap)->calls), + ((*ap)->time / total) * 100.0, + (*ap)->self, (*ap)->self / ((double) (*ap)->calls), + (*ap)->from->name, (*ap)->from->num); + } + printf("%2ld) %4ld %8.2f %8.2f %5.2f%% %8.2f %8.2f %5.2f%% %s\n", + (*fp)->num, (*fp)->calls, + (*fp)->time, (*fp)->time / ((double) (*fp)->calls), + ((*fp)->time / total) * 100.0, + (*fp)->self, (*fp)->self / ((double) (*fp)->calls), + ((*fp)->self / total) * 100.0, + (*fp)->name); + for (ap = as + narcs - 1; ap >= as; ap--) + if ((*ap)->from == *fp) { + printf(" %4ld/%-4ld %8.2f %8.2f %5.2f%% %8.2f %8.2f %s [%ld]\n", + (*ap)->calls, (*ap)->to->calls, + (*ap)->time, (*ap)->time / ((double) (*ap)->calls), + ((*ap)->time / total) * 100.0, + (*ap)->self, (*ap)->self / ((double) (*ap)->calls), + (*ap)->to->name, (*ap)->to->num); + } + } + } + return 0; +} + +/**/ +static int +zprof_wrapper(List list, FuncWrap w, char *name) +{ + struct sfunc sf, *sp; + Pfunc f; + Parc a = NULL; + struct timeval tv; + struct timezone dummy; + double prev, now; + + if (!(f = findpfunc(name))) { + PERMALLOC { + f = (Pfunc) zalloc(sizeof(*f)); + f->name = ztrdup(name); + f->calls = 0; + f->time = f->self = 0.0; + f->next = calls; + calls = f; + ncalls++; + } LASTALLOC; + } + if (stack) { + if (!(a = findparc(stack->p, f))) { + PERMALLOC { + a = (Parc) zalloc(sizeof(*a)); + a->from = stack->p; + a->to = f; + a->calls = 0; + a->time = a->self = 0.0; + a->next = arcs; + arcs = a; + narcs++; + } LASTALLOC; + } + } + sf.prev = stack; + sf.p = f; + stack = &sf; + + f->calls++; + tv.tv_sec = tv.tv_usec = 0; + gettimeofday(&tv, &dummy); + sf.beg = prev = ((((double) tv.tv_sec) * 1000.0) + + (((double) tv.tv_usec) / 1000.0)); + runshfunc(list, w, name); + tv.tv_sec = tv.tv_usec = 0; + gettimeofday(&tv, &dummy); + + now = ((((double) tv.tv_sec) * 1000.0) + + (((double) tv.tv_usec) / 1000.0)); + f->self += now - sf.beg; + for (sp = sf.prev; sp && sp->p != f; sp = sp->prev); + if (!sp) + f->time += now - prev; + if (a) { + a->calls++; + a->self += now - sf.beg; + } + stack = sf.prev; + + if (stack) { + stack->beg += now - prev; + if (a) + a->time += now - prev; + } + return 0; +} + +static struct builtin bintab[] = { + BUILTIN("zprof", 0, bin_zprof, 0, 0, 0, "c", NULL), +}; + +static struct funcwrap wrapper[] = { + WRAPDEF(zprof_wrapper), +}; + +/**/ +int +setup_zprof(Module m) +{ + return 0; +} + +/**/ +int +boot_zprof(Module m) +{ + calls = NULL; + ncalls = 0; + arcs = NULL; + narcs = 0; + stack = NULL; + return !(addbuiltins(m->nam, bintab, sizeof(bintab)/sizeof(*bintab)) | + !addwrapper(m, wrapper)); +} + +/**/ +int +cleanup_zprof(Module m) +{ + freepfuncs(calls); + freeparcs(arcs); + deletebuiltins(m->nam, bintab, sizeof(bintab)/sizeof(*bintab)); + deletewrapper(m, wrapper); + return 0; +} + +/**/ +int +finish_zprof(Module m) +{ + return 0; +} diff -ru ../z.old/Src/Modules/zprof.mdd Src/Modules/zprof.mdd --- ../z.old/Src/Modules/zprof.mdd Mon Dec 13 13:26:15 1999 +++ Src/Modules/zprof.mdd Mon Dec 13 12:44:09 1999 @@ -0,0 +1,3 @@ +autobins="zprof" + +objects="zprof.o" -- Sven Wischnowsky wischnow@informatik.hu-berlin.de