lib/sysutil/profile.c

   1 /*
   2  * profile.c - library functions for call profiling
   3  *
   4  * For processes that were compiled using ACK with the -Rcem-p option,
   5  * procentry and procexit will be called on entry and exit of their
   6  * functions.  Procentry/procexit are implemented here as generic library
   7  * functions.
   8  *
   9  * Changes:
  10  *   14 Aug, 2006   Created (Rogier Meurs)
  11  */
  12
  13 #include <lib.h>
  14
  15 #if CPROFILE
  16
  17 #include <stdio.h>
  18 #include <stdlib.h>
  19 #include <string.h>
  20 #include <minix/profile.h>
  21 #include <minix/syslib.h>
  22 #include <minix/u64.h>
  23 #include "read_tsc.h"
  24
  25 #define U64_LO 0
  26 #define U64_HI 1
  27
  28 PRIVATE char cpath[CPROF_CPATH_MAX_LEN];        /* current call path string */
  29 PRIVATE int cpath_len;                          /* current call path len */
  30 PRIVATE struct cprof_tbl_s *cprof_slot;         /* slot of current function */
  31 PRIVATE struct stack_s {                        /* stack entry */
  32                 int cpath_len;                  /* call path len */
  33                 struct cprof_tbl_s *slot;       /* table slot */
  34                 u64_t start_1;                  /* count @ begin of procentry */
  35                 u64_t start_2;                  /* count @ end of procentry */
  36                 u64_t spent_deeper;             /* spent in called functions */
  37 };
  38 PRIVATE struct stack_s cprof_stk[CPROF_STACK_SIZE];     /* stack */
  39 PRIVATE int cprof_stk_top;                              /* top of stack */
  40 EXTERN struct cprof_tbl_s cprof_tbl[];                  /* hash table */
  41 PRIVATE int cprof_tbl_size;                             /* nr of slots */
  42 PRIVATE struct cprof_tbl_s *idx[CPROF_INDEX_SIZE];      /* index to table */
  43 PRIVATE struct cprof_ctl_s control;             /* for comms with kernel */
  44 PRIVATE int cprof_announce;                     /* announce on n-th execution
  45                                                  * of procentry */
  46 PRIVATE int cprof_locked;                       /* for reentrancy */
  47
  48 _PROTOTYPE(void procentry, (char *name) );
  49 _PROTOTYPE(void procexit, (char *name) );
  50
  51 FORWARD _PROTOTYPE(void cprof_init, (void) );
  52 FORWARD _PROTOTYPE(void reset, (void) );
  53 FORWARD _PROTOTYPE(void clear_tbl, (void) );
  54
  55
  56 PUBLIC void procentry (name)
  57 char *name;
  58 {
  59   static int init = 0;
  60   unsigned hash = 0, i = 0, x = 0;
  61   unsigned long hi, lo;
  62   struct cprof_tbl_s *last;
  63   char c;
  64   u64_t start;
  65
  66   /* Procentry is not reentrant. */
  67   if (cprof_locked) return; else cprof_locked = 1;
  68
  69   /* Read CPU cycle count into local variable. */
  70   read_tsc(&start._[U64_HI], &start._[U64_LO]);
  71
  72   /* Run init code once after system boot. */
  73   if (init == 0) {
  74         cprof_init();
  75         init++;
  76   }
  77
  78   /* Announce once. */
  79   if (init > -1 && init++ == cprof_announce) {
  80         /* Tell kernel about control structure and table locations.
  81         *
  82         * In userspace processes, the library function profile_register
  83         * will be used. This function does a kernel call (sys_profbuf) to
  84         * announce to the kernel the location of the control struct and
  85         * hash table. The control struct is used by the kernel to write
  86         * a flag if resetting of the table is requested. The location of
  87         * the table is needed to copy the information to the user process
  88         * that requests it.
  89         *
  90         * Kernelspace processes don't use the library function but have
  91         * their own implemention that executes logic similar to sys_profbuf.
  92         * The reason for this is that the kernel is non-reentrant, therefore
  93         * a kernelspace process is not able to do a kernel call itself since
  94         * this would cause a deadlock.
  95         */
  96         profile_register((void *) &control, (void *) &cprof_tbl);
  97         init = -1;
  98   }
  99
 100   /* Only continue if sane. */
 101   if (control.err) return;
 102
 103   /* Check if kernel instructed to reset profiling data. */
 104   if (control.reset) reset();
 105
 106   /* Increase stack. */
 107   if (++cprof_stk_top == CPROF_STACK_SIZE) {
 108         printf("CPROFILE error: stack overrun\n");
 109         control.err |= CPROF_STACK_OVERRUN;
 110         return;
 111   }
 112
 113   /* Save initial cycle count on stack. */
 114   cprof_stk[cprof_stk_top].start_1._[U64_HI] = start._[U64_HI];
 115   cprof_stk[cprof_stk_top].start_1._[U64_LO] = start._[U64_LO];
 116
 117   /* Check available call path len. */
 118   if (cpath_len + strlen(name) + 1 > CPROF_CPATH_MAX_LEN) {
 119         printf("CPROFILE error: call path overrun\n");
 120         control.err |= CPROF_CPATH_OVERRUN;
 121         return;
 122   }
 123
 124   /* Save previous call path length on stack. */
 125   cprof_stk[cprof_stk_top].cpath_len = cpath_len;
 126
 127   /* Generate new call path string and length.*/
 128   if (cprof_stk_top > 0)                        /* Path is space separated. */
 129         cpath[cpath_len++] = ' ';
 130   while ((c = *(name++)) != '\0')       /* Append function name. */
 131         cpath[cpath_len++] = c;
 132   cpath[cpath_len] = '\0';              /* Null-termination. */
 133
 134   /* Calculate hash for call path string (algorithm: ELF). */
 135   for (i=0; i<cpath_len; i++) {
 136          hash = (hash << 4) + cpath[i];
 137          if ((x = hash & 0xF0000000L) != 0) {
 138                  hash ^= (x >> 24);
 139                  hash &= ~x;
 140          }
 141   }
 142   hash %= CPROF_INDEX_SIZE;
 143
 144   /* Look up the slot for this call path in the hash table. */
 145   for (cprof_slot = idx[hash]; cprof_slot != 0; cprof_slot = cprof_slot->next)
 146         if (strcmp(cprof_slot->cpath, cpath) == 0) break;
 147
 148   if (cprof_slot)
 149         cprof_slot->calls++;    /* found slot: update call counter */
 150   else {
 151         /* Not found: insert path into hash table. */
 152         if (control.slots_used == cprof_tbl_size) {
 153                 printf("CPROFILE error: table overrun\n");
 154                 control.err |= CPROF_TABLE_OVERRUN;
 155                 return;
 156         }
 157         /* Set values for new slot. */
 158         cprof_slot = &cprof_tbl[control.slots_used++];
 159         strcpy(cprof_slot->cpath, cpath);
 160         cprof_slot->calls = 1;
 161
 162         /* Update index. */
 163         if (idx[hash] == 0) {
 164                 /* No collision: simple update. */
 165                 idx[hash] = cprof_slot;
 166         } else {
 167                 /* Collision: update last in chain. */
 168                 for (last = idx[hash]; last->next != 0; last = last->next);
 169                 last->next = cprof_slot;
 170         }
 171   }
 172   /* Save slot on stack. */
 173   cprof_stk[cprof_stk_top].slot = cprof_slot;
 174
 175   /* Again save CPU cycle count on stack. */
 176   read_tsc(&cprof_stk[cprof_stk_top].start_2._[U64_HI],
 177                 &cprof_stk[cprof_stk_top].start_2._[U64_LO]);
 178   cprof_locked = 0;
 179 }
 180
 181
 182 PUBLIC void procexit (name)
 183 char *name;
 184 {
 185   u64_t stop, spent;
 186
 187   /* Procexit is not reentrant. */
 188   if (cprof_locked) return; else cprof_locked = 1;
 189
 190   /* First thing: read CPU cycle count into local variable. */
 191   read_tsc(&stop._[U64_HI], &stop._[U64_LO]);
 192
 193   /* Only continue if sane. */
 194   if (control.err) return;
 195
 196   /* Update cycle count for this call path. Exclude time spent in procentry/
 197    * procexit by using measurements taken at end of procentry and begin of
 198    * procexit (the "small" difference). This way, only the call overhead for
 199    * the procentry/procexit functions will be attributed to this call path,
 200    * not the procentry/procexit cycles.
 201    */
 202
 203   /* Calculate "small" difference. */
 204   spent = sub64(stop, cprof_stk[cprof_stk_top].start_2);
 205   cprof_stk[cprof_stk_top].slot->cycles =
 206         add64(cprof_stk[cprof_stk_top].slot->cycles,
 207                 sub64(spent, cprof_stk[cprof_stk_top].spent_deeper));
 208
 209   /* Clear spent_deeper for call level we're leaving. */
 210   cprof_stk[cprof_stk_top].spent_deeper._[U64_LO] = 0;
 211   cprof_stk[cprof_stk_top].spent_deeper._[U64_HI] = 0;
 212
 213   /* Adjust call path string and stack. */
 214   cpath_len = cprof_stk[cprof_stk_top].cpath_len;
 215   cpath[cpath_len] = '\0';
 216
 217   /* Update spent_deeper for call level below. Include time spent in
 218    * procentry/procexit by using measurements taken at begin of procentry
 219    * and end of procexit (the "big" difference). This way the time spent in
 220    * procentry/procexit will be included in spent_deeper and therefore, since
 221    * this value is substracted from the lower call level, it will not be
 222    * attributed to any call path. This way, pollution of the statistics
 223    * because of procentry/procexit is kept to a minimum.
 224    */
 225
 226   /* Read CPU cycle count. */
 227   read_tsc(&stop._[U64_HI], &stop._[U64_LO]);
 228
 229   /* Calculate "big" difference. */
 230   spent = sub64(stop, cprof_stk[cprof_stk_top].start_1);
 231   cprof_stk_top--;                                      /* decrease stack */
 232   if (cprof_stk_top >= 0)           /* don't update non-existent level -1 */
 233         cprof_stk[cprof_stk_top].spent_deeper =
 234                 add64(cprof_stk[cprof_stk_top].spent_deeper, spent);
 235   cprof_locked = 0;
 236 }
 237
 238
 239 PRIVATE void cprof_init() {
 240   message m;
 241   int i;
 242
 243   cpath[0] = '\0';
 244   cpath_len = 0;
 245   cprof_stk_top = -1;
 246   control.reset = 0;
 247   control.err = 0;
 248   cprof_tbl_size = profile_get_tbl_size();
 249   cprof_announce = profile_get_announce();
 250   clear_tbl();
 251
 252   for (i=0; i<CPROF_STACK_SIZE; i++) {
 253         cprof_stk[i].cpath_len = 0;
 254         cprof_stk[i].slot = 0;
 255         cprof_stk[i].start_1._[U64_LO] = 0;
 256         cprof_stk[i].start_1._[U64_HI] = 0;
 257         cprof_stk[i].start_2._[U64_LO] = 0;
 258         cprof_stk[i].start_2._[U64_HI] = 0;
 259         cprof_stk[i].spent_deeper._[U64_LO] = 0;
 260         cprof_stk[i].spent_deeper._[U64_HI] = 0;
 261   }
 262 }
 263
 264
 265 PRIVATE void reset()
 266 {
 267   clear_tbl();
 268   control.reset = 0;
 269 }
 270
 271
 272 PRIVATE void clear_tbl()
 273 {
 274   int i;
 275
 276   /* Reset profiling table. */
 277   control.slots_used = 0;
 278   for (i=0; i<CPROF_INDEX_SIZE; i++) idx[i] = 0;        /* clear index */
 279   for (i=0; i<cprof_tbl_size; i++) {                    /* clear table */
 280         memset(cprof_tbl[i].cpath, '\0', CPROF_CPATH_MAX_LEN);
 281         cprof_tbl[i].next = 0;
 282         cprof_tbl[i].calls = 0;
 283         cprof_tbl[i].cycles._[U64_LO] = 0;
 284         cprof_tbl[i].cycles._[U64_HI] = 0;
 285   }
 286 }
 287
 288 #endif /* CPROFILE */
 289