home *** CD-ROM | disk | FTP | other *** search
/ Shareware Supreme Volume 6 #1 / swsii.zip / swsii / 215 / DDJ9210.ZIP / PROFLE.ASC < prev    next >
Text File  |  1992-08-26  |  21KB  |  602 lines
  1. _YOUR OWN SOURCE CODE PROFILER_
  2. by Keith W. Boone
  3.  
  4. [LISTING ONE]
  5.  
  6. /* PROFILER.C -- Copyright (c) 1992 by Keith W. Boone, Tallahassee, FL
  7.  * This program contains the runtime functions required to profile C source 
  8.  * code. Permission is granted to use or distribute this source code without
  9.  * any restrictions as long as this entire notice is included intact. You may 
  10.  * use or include this software in any product that you sell for profit.
  11.  * This software is distributed as is, and is no liability is granted.
  12.  */
  13.  
  14. #include    <stdio.h>
  15. #include    <dos.h>
  16.  
  17. static long     start,      /*  Linear code start address      */
  18.                 end,        /*  Linear code end address        */
  19.                 reference,  /*  Main function address          */
  20.                 ticker;     /*  Global total time in profiler  */
  21. static int      *buffer,    /*  Pointer to CS:IP tick buffer   */
  22.                 length,     /*  Length of the buffer           */
  23.                 scale,      /*  Scaling factor for the buffer  */
  24.                 status,     /*  Status = TRUE if profiling     */
  25.                 (interrupt far *old8)(); /* Old clock interrupt */
  26. unsigned        speedup_factor = 1; /*  Clock speedup factor    */
  27.  
  28. /***** Convert a far pointer to a linear address *****/
  29. long linear(void far *ptr)
  30. {
  31.     long    addr = FP_SEG(ptr);
  32.     if ((long)ptr == -1l)
  33.         return 0x100000;
  34.     addr <<= 4;
  35.     addr += FP_OFF(ptr);
  36.     return addr;
  37. }
  38. /*****  _profmon is a clock interrupt handler which is used to  mark what 
  39. function your program is in during the interrupt. *****/
  40. interrupt far _profmon(int es, int ds, int di, int si,
  41.     int bp, int sp, int bx, int dx, int cx, int ax, 
  42.     unsigned ip, unsigned cs
  43. )
  44. {
  45.     if (status)         /* If profiling */
  46.     {   long    addr = cs;
  47.         addr <<= 4;
  48.         addr += ip;     /* Compute Phys address */
  49.         ticker++;       /* Increase total time */
  50.         if ((addr >= start) && (addr <= end)) /* If in range of code */
  51.         {   addr -= start;
  52.             buffer[addr / scale]++; /* Update buffer */
  53.         }
  54.     }
  55.     _chain_intr(old8);
  56. }
  57. /***** profile(buf, len, first, last, speed) initializes the profiler. Buf is 
  58.  Buf is a pointer to an array of integers that keeps track of CS:IP locations 
  59.  while profiling.  First and last are pointers to the functions where profiling
  60.  will occur. Note that the function last is never profiled! Speed is the clock
  61.  frequency multiplier passed to speedup() when turning profiling on. *****/
  62. profile(int *buf, int len, int (*first)(), int (*last)(), unsigned speed)
  63. {
  64.     unsigned    i, j;
  65.     long        size;
  66.     int     main();
  67.     buffer = buf;
  68.     length = len;
  69.     start = linear((void far *)first);    /* Conver to linear address */
  70.     end = linear((void far *)last);
  71.     reference = linear((void far *)main); /* main() is relocation ref */
  72.     status = 0;                           /* Profiling off initially */
  73.     speedup_factor = speed;               /* Used with speedup() */
  74.  
  75.     if (buf == NULL)                      /* buf==NULL is reset */
  76.     {   if (old8 != NULL)
  77.             _dos_setvect(0x08, old8);
  78.         return 0;
  79.     }
  80.     size = (end - start);                /* Compute size and scale */
  81.     scale = ((size - 1) / length) + 1;
  82.     return 0;
  83. }
  84. /***** monitor(flag) turns profiling on or off.  If turning profiling on then 
  85.  the program needs to trap the clock interrupt, then set status = TRUE. 
  86.  Otherwise the program resets the clock interrupt, then sets status = FALSE.  
  87.  This ensures that status does not change to FALSE while in _profmon(), 
  88.  not really a big deal, but cleaner. ******/
  89. monitor(int flag)
  90. {
  91.     if (buffer == NULL)          /* Turn on w/out initialization is error */
  92.         return -1;
  93.     if (flag)                    /* If turning profiling on */
  94.     {   if (speedup_factor > 1)  /* Speed up clock by saved */
  95.             speedup(speedup_factor);  /* speedup factor */
  96.         old8 = _dos_getvect(0x08);    /* get old clock handler */
  97.         _dos_setvect(0x08, _profmon); /* set new vector */
  98.     }
  99.     else    if (old8 != NULL)         /* Else turning off */
  100.     {   _dos_setvect(0x08, old8);     /* reset old vector */
  101.         old8 = NULL;
  102.         if (speedup_factor > 1)       /* Restore clock speed */
  103.             speedup(1);               /* Note reverse order! */
  104.     }
  105.     status = flag;                    /* Set on/off flag */
  106.     return 0;
  107. }
  108. /***** writemon(filename) copies the profiling data to the file specified
  109.  for later use by PROF.EXE. *****/
  110. writemon(char *filename)
  111. {
  112.     FILE    *fp = fopen(filename, "wb");
  113.     if (fp == NULL)
  114.         return -1;
  115.     monitor(0);
  116.     fwrite(&reference, 1, sizeof(reference), fp);
  117.     fwrite(&ticker, 1, sizeof(ticker), fp);
  118.     fwrite(&start, 1, sizeof(start), fp);
  119.     fwrite(&end, 1, sizeof(start), fp);
  120.     fwrite(&length, 1, sizeof(length), fp);
  121.     fwrite(&scale, 1, sizeof(scale), fp);
  122.     fwrite(&speedup_factor, 1, sizeof(speedup_factor), fp);
  123.     fwrite(buffer, length, sizeof(*buffer), fp);
  124.     fclose(fp);
  125. }
  126.  
  127.  
  128. [LISTING TWO]
  129.  
  130. #include    <dos.h>
  131.  
  132. static int  (interrupt far *oldclk)();  /* Old clock interrupt  */
  133. static unsigned counter,                /* Current counter value */
  134.                 factor;
  135. #define PICCMD  0x20                    /* 8259 PIC command port */
  136. #define EOI     0x20                    /* EOI command */
  137.  
  138. #define TCTRL   0x43                    /* Timer control port */
  139. #define T0DATA  0x40                    /* Timer 0 data port */
  140. #define T0LOAD  0x36                    /* Timer 0 load command */
  141.  
  142. /****** _spdup is an interrupt handler which processes clock interrupts which 
  143.  have been sped up. *****/
  144. interrupt far _spdup()
  145. {
  146.     if (counter--)                      /* If counter non-zero */
  147.         outp(PICCMD, EOI);              /* Send EOI and return */
  148.     else
  149.     {   counter = factor;               /* Otherwise reset counter */
  150.         _chain_intr(oldclk);            /* and exec old handler */
  151.     }
  152. }
  153. speedup(unsigned newfact)
  154. {
  155.     unsigned divider;
  156.     if (newfact <= 1)                   /* Reset timer handler */
  157.     {   factor = 1; 
  158.         if (oldclk)                     /* reset only if set */
  159.         {   _dos_setvect(0x08, oldclk); /* in the first place */
  160.             outp(TCTRL, T0LOAD);
  161.             outp(T0DATA, 0);
  162.             outp(T0DATA, 0);            /* standard divisor */
  163.             oldclk = 0;
  164.         }
  165.     }
  166.     else
  167.     {   if (!oldclk)
  168.             oldclk = _dos_getvect(0x08); /* Save old handler */
  169.         counter = factor = newfact;
  170.         divider = 65536L / newfact;
  171.         _disable();                     /* Disable interrupts */
  172.         outp(TCTRL, T0LOAD);
  173.         outp(T0DATA, divider);
  174.         outp(T0DATA, (divider >> 8));   /* load new divisor */
  175.         _enable();                      /* Enable interrupts */
  176.         _dos_setvect(0x08, _spdup);     /* use our handler */
  177.     }
  178. }
  179.  
  180.  
  181. [LISTING THREE]
  182.  
  183. /*  PROF.C -- Copyright (c) 1992 by Keith W. Boone, Tallahassee, FL
  184.  * This program contains the reporting facilities used to profile C code.  
  185.  * Permission is granted to use or distribute this source code without any 
  186.  * restrictions as long as this entire notice is included intact. You may use 
  187.  * or include this software in any product that you sell for profit.
  188.  * This software is distributed as is, and is no liability is granted.
  189.  */
  190.  
  191. #include    <stdio.h>
  192. long start,     /* linear address of Start of profiled code    */
  193.     end,        /* End of profiled code                        */
  194.     reference,  /* Address of main function to resolve reloc   */
  195.     ticker;     /* Value of ticker at end of profiling         */
  196. int *buffer,    /* Pointer to profile buffer                   */
  197.     length,     /* Length of profile buffer                    */
  198.     scale,      /* Scale used (code address to buffer address) */
  199.     factor;     /* Clock speedup factor                        */
  200.  
  201. typedef struct mapentry  /* Used to store MAP file information */
  202. {   long    address, /* Linear address of function             */
  203.         count;       /* computed # of ticks in function        */
  204.     char    *name;   /* Function Name                          */
  205. }   MAP;
  206.  
  207. MAP map[4096];          /*  Limited to 4096 functions           */
  208. int nmap = 0;           /*  Number of Map table entries used    */
  209. long    emaina;         /*  Linear address of main function     */
  210.  
  211. /***** Sortmap(m1, m2) is a callback function used by qsort to sort
  212.  map table entried by linear address. *****/
  213. sortmap(MAP *m1, MAP *m2)
  214. {   if (m1->address < m2->address)
  215.         return -1;
  216.     if (m1->address > m2->address)
  217.         return 1;
  218.     return 0;
  219. }
  220. /***** Readmap(filename) reads in the MAP stored in 'filename' and loads the 
  221. data into map[].  *****/
  222. readmap(char *filename)
  223. {
  224.     char    line[80], *ptr, *strrchr(), *strdup();
  225.     long    off, seg;
  226.     FILE    *fp = fopen(filename, "rt");
  227.  
  228.     if (fp == NULL) /* Return error code if cannot open MAP file */
  229.         return -1;
  230.     map[nmap++].name = "DOS"; /* Address below first are in DOS */
  231.  
  232.     /* Read each line of the map file until you find "Publics by Value".
  233.      * This is VERY linker dependent! */
  234.     while (fgets(line, 80, fp))
  235.     {   if (ptr = strrchr(line, 'b'))
  236.         {   if (strcmp(ptr, "by Value\n") == 0)
  237.                 break;
  238.             else ptr = NULL;
  239.         }
  240.     }
  241.     if (ptr == NULL)    /* If we didn't find "Publics by Value" */
  242.     {   fclose(fp);     /* the return with an failure code. */
  243.         return -1;
  244.     }
  245.     while (fgets(line, 80, fp))
  246.     {   /* remove trailing linefeed from line */
  247.         if (ptr = strrchr(line, '\n'))
  248.             *ptr = 0;
  249.         if (!*line)
  250.             continue;                         /* Ignore empty lines  */
  251.         else if (strncmp(line + 12, "Abs", 3) == 0)
  252.             continue;                         /* And Absolue values */
  253.         sscanf(line, " %lX:%lX", &seg, &off); /* Get the seg:off */
  254.         map[nmap].address = (seg << 4) + off; /* convert to linear */
  255.         ptr = strrchr(line, ' ');             /* find function name */
  256.         map[nmap].name = strdup(++ptr);       /* make a copy of it */
  257.  
  258.         if (strcmp(ptr, "_main") == 0)        /* Found main() */
  259.             emaina = map[nmap].address;       /* save it's address */
  260.         nmap++;
  261.     }
  262.     qsort(map + 1, nmap - 1,  sizeof(MAP), sortmap); /* Sort by address */
  263.     map[nmap++].name = "BIOS";     /* Addresses beyond last are in BOIS */
  264.     return 0;   
  265. }
  266. /***** Readmon(filename) reads in the profile data stored in 'filename' and
  267.  and outputs vitals on the profiled data. *****/
  268. readmon(char *filename)
  269. {
  270.     FILE    *fp = fopen(filename, "rb");
  271.     void    *calloc();
  272.     int m, s, k;
  273.     float   T;
  274.  
  275.     if (fp == NULL)
  276.         return -1;
  277.     fread(&reference, 1, sizeof(reference), fp);
  278.     fread(&ticker, 1, sizeof(ticker), fp);
  279.     fread(&start, 1, sizeof(start), fp);
  280.     fread(&end, 1, sizeof(start), fp);
  281.     fread(&length, 1, sizeof(length), fp);
  282.     fread(&scale, 1, sizeof(scale), fp);
  283.     fread(&factor, 1, sizeof(factor), fp);
  284.     buffer = (int *)calloc(sizeof(int), length);
  285.     fread(buffer, length, sizeof(int), fp);
  286.     fclose(fp);
  287.  
  288.     T = ticker / (18.2 * factor);
  289.     m = T / 60;
  290.     T -= m * 60;
  291.     s = T;
  292.     T -= s;
  293.     k = T * 1000;
  294.     printf(" Start: %6ld\n", start);
  295.     printf("   End: %6ld\n", end);
  296.     printf("Length: %6d\n", length);
  297.     printf(" Scale: %6d\n", scale);
  298.     printf(" Speed: %6d\n", factor);
  299.     printf("  Time: %02d:%02d.%03d\n", m, s, k);
  300.     return 0;
  301. }
  302. /***** mapcmp(m1, m2) is a callback function used by qsort to sort map table 
  303.  entried by amount of time used by the function. *****/
  304. mapcmp(MAP *m1, MAP *m2)
  305. {   if (m1->count > m2->count)
  306.         return -1;
  307.     else if (m1->count == m2->count)
  308.         return 0;
  309.     else return 1;
  310. }
  311. main(int argc, char **argv)
  312. {
  313.     int i,                  /* profile buffer index */
  314.         j;                  /* MAP entry index */
  315.     long    addr;           /* Current linear address */
  316.     int m,                  /* Minutes */
  317.         s,                  /* Seconds */
  318.         t;                  /* thousandths */
  319.     char    buf[32],        /* File name buffer */
  320.         *strchr();
  321.     float   seconds,        /* time in a function in seconds */
  322.         accounted,          /* accounted for in all profiled functions */
  323.         percent;            /* Percent of total accounted */
  324.     if (argc < 2)
  325.     {  fprintf(stderr, "Usage: %s program[.map] [program[.mon]]\n", *argv);
  326.         exit(1);
  327.     }
  328.     /* Append .map to files that have no extension specified for arg 1 */
  329.     if (strchr(argv[1], '.'))
  330.         strcpy(buf, argv[1]);
  331.     else sprintf(buf, "%s.map", argv[1]);
  332.     if (readmap(buf))
  333.     {   fprintf(stderr, "Error reading map '%s'.\n", buf);
  334.         exit(1);
  335.     }
  336.     /* If second arg specified, then use it, otherwise use first arg */
  337.     if (argc > 2)
  338.         i = 2;
  339.     else 
  340.     {   i = 1;
  341.         if (strchr(argv[1], '.')) /* remove ext from first arg  */
  342.             *strchr(argv[1], '.') = 0;
  343.     }
  344.     /* Append .mon to files that have no extension specified for arg 2 */
  345.     if (strchr(argv[i], '.'))
  346.         strcpy(buf, argv[i]);
  347.     else    sprintf(buf, "%s.mon", argv[i]);
  348.     if (readmon(buf))
  349.     {   fprintf(stderr, "Error reading '%s'.\n", buf);
  350.         exit(1);
  351.     }
  352.     start -= reference; /* Offset start by the &main */
  353.     end -= reference;
  354.     for (i = 1; i < (nmap - 1); i++) /* adjust map by &main */
  355.         map[i].address -= emaina;
  356.     map[0].address = 0x8000000;  /* DOS start = max neg */
  357.     map[nmap].address = 0x7FFFFFF;   /* BIOS end = max pos */
  358.     
  359.     /***** For each entry in the buffer, find the first map address (j)
  360.      whose function encompasses addr, and update the time spent in
  361.      that function. *****/
  362.     accounted = 0.0;
  363.     addr = start;
  364.     j = 0;
  365.     for (i = 0; (i < length) && (j < nmap); i++)
  366.     {   if (buffer[i])
  367.         {   while ((j < nmap) && (addr > map[j+1].address))
  368.                 j++;
  369.             map[j].count += buffer[i];
  370.             accounted += buffer[i];
  371.         }
  372.         addr += scale;
  373.     }
  374.     qsort(map, nmap, sizeof(MAP), mapcmp);  /* Sort by time used */
  375.     /* For each function, output time used, and accumulate the total */
  376.     printf("Time\t\tRoutine\t\t    %% of Total\t    %% of Accounted\n");
  377.     for (i = 0; i < nmap; i++)
  378.     {   if (map[i].count)
  379.         {   seconds = map[i].count;
  380.             seconds /= (18.2 * factor);
  381.             m = seconds / 60;
  382.             seconds -= m * 60;
  383.             s = seconds;
  384.             seconds -= s;
  385.             t = seconds * 1000;
  386.             printf("%02d:%02d.%03d\t%-20s\t%5.2f%%\t%5.2f%%\n", 
  387.                 m, s, t, map[i].name, 
  388.                 map[i].count * 100.0 / ticker,
  389.                 map[i].count * 100.0 / accounted);
  390.         }
  391.     }
  392.     /* Output accounted/total times */
  393.     percent = (100.0 * accounted) / ticker;
  394.     accounted /= 18.2 * factor;        /* Convert accounted to seconds */
  395.     m = accounted / 60;
  396.     accounted -= m * 60;
  397.     s = accounted;
  398.     accounted -= s;
  399.     t = accounted * 1000;
  400.     printf("%02d:%02d.%03d\t%-20s\t%5.2f%%\n", m, s, t, "Total", percent);
  401. }
  402.  
  403.  
  404. [LISTING FOUR]
  405.  
  406. #include    <stdio.h>
  407. #define PLEN    4096
  408. unsigned    pbuf[PLEN];
  409.  
  410. #define ALEN    8000
  411. #define MAX (ALEN*8L)
  412. char    array[ALEN];
  413.  
  414. markbit(char *array, long bit)
  415. {
  416.     array[bit/8] |= 1 << (bit % 8l);
  417. }
  418. testbit(char *array, long bit)
  419. {
  420.     return array[bit/8] & (1 << (bit % 8l));
  421. }
  422. markall(char *array, long bit)
  423. {
  424.     long    temp;
  425.     for (temp = bit + bit; temp < MAX; temp += bit)
  426.         markbit(array, temp);
  427. }
  428. long findnext(char *array, long bit)
  429. {
  430.     long    temp;
  431.     for (temp = bit + 1; temp < MAX; temp++)
  432.         if (!testbit(array, temp))
  433.             return temp;
  434.     return 0;
  435. }
  436. extern last();
  437. main()
  438. {
  439.     long    value, 
  440.         start,
  441.         clock();
  442.     int speed;
  443.     char    buff[16];
  444.     printf("Speedup\tTime\n");
  445.     for (speed = 1; speed <= 2048; speed += speed)
  446.     {   /* reset program workspace on each iteration */
  447.         memset(pbuf, 0, sizeof(pbuf));
  448.         memset(array, 0, sizeof(array));
  449.         /* Set profile buffer, program addresses and speedup */
  450.         /* note that main() is not profiled */
  451.         profile(pbuf, PLEN, markbit, main, speed);
  452.         start = clock();
  453.         printf("%5d\t", speed);
  454.         /* Enable profiling */
  455.         monitor(1);
  456.         /* Execute sieve of Eratosthenese */
  457.         for (value = 2; value; value = findnext(array, value))
  458.             markall(array, value);
  459.         /* Disable profiling */
  460.         monitor(0);
  461.         /* Output profile data for this pass */
  462.         printf("%ld\n", clock() - start);
  463.         sprintf(buff, "tst%05d.mon", speed);
  464.         writemon(buff);
  465.     }
  466. }
  467.  
  468.  
  469.  
  470. Figure 1: Sample profiler output for the TESTPROF.C program
  471.  
  472.  Start:  24624
  473.  End:  24952
  474. Length:   4096
  475.  Scale:      1
  476.  Speed:      1
  477.  Time: 00:10.384
  478. Time        Routine    % of Total  % of Accounted
  479. 00:02.197   _markbit   21.16%       40.82%
  480. 00:02.087   _markall   20.11%       38.78%
  481. 00:00.659   _findnext   6.35%       12.24%
  482. 00:00.439   _testbit    4.23%        8.16%
  483. 00:05.384   Total   51.85%
  484.  Start:  24624
  485.  End:  24952
  486. Length:   4096
  487.  Scale:      1
  488.  Speed:      2
  489.  Time: 00:15.741
  490. Time        Routine    % of Total  % of Accounted
  491. 00:02.060   _markbit   13.09%      41.90%
  492. 00:01.483   _markall    9.42%      30.17%
  493. 00:00.741   _testbit    4.71%      15.08%
  494. 00:00.467   _findnext   2.97%       9.50%
  495. 00:00.164   DOS         1.05%       3.35%
  496. 00:04.917   Total  31.24%
  497.  Start:  24624
  498.    End:  24952
  499. Length:   4096
  500.  Scale:      1
  501.  Speed:      4
  502.  Time: 00:18.434
  503. Time        Routine    % of Total  % of Accounted
  504. 00:01.895   _markbit   10.28%      45.10%
  505. 00:01.208   _markall    6.56%      28.76%
  506. 00:00.659   _testbit    3.58%      15.69%
  507. 00:00.398   _findnext   2.16%       9.48%
  508. 00:00.041   DOS         0.22%       0.98%
  509. 00:04.203   Total   22.80%
  510.  Start:  24624
  511.    End:  24952
  512. Length:   4096
  513.  Scale:      1
  514.  Speed:      8
  515.  Time: 00:19.848
  516. Time        Routine    % of Total  % of Accounted
  517. 00:01.737   _markall   8.75%       36.19%
  518. 00:01.675   _markbit   8.44%       34.91%
  519. 00:00.748   _testbit   3.77%       15.59%
  520. 00:00.521   _findnext  2.63%       10.87%
  521. 00:00.116   DOS        0.59%        2.43%
  522. 00:04.800   Total   24.19%
  523.  Start:  24624
  524.    End:  24952
  525. Length:   4096
  526.  Scale:      1
  527.  Speed:     16
  528.  Time: 00:20.669
  529. Time        Routine    % of Total   % of Accounted
  530. 00:02.026   _markbit   9.80%        44.66%
  531. 00:01.146   _markall   5.55%        25.28%
  532. 00:00.831   _testbit   4.02%        18.32%
  533. 00:00.484   _findnext  2.34%        10.67%
  534. 00:00.048   DOS        0.23%         1.06%
  535. 00:04.536   Total   21.95%
  536.  Start:  24624
  537.    End:  24952
  538. Length:   4096
  539.  Scale:      1
  540.  Speed:     32
  541.  Time: 00:21.299
  542. Time        Routine    % of Total  % of Accounted
  543. 00:02.558   _markbit   12.01%      49.03%
  544. 00:01.237   _markall    5.81%      23.72%
  545. 00:00.781   _testbit    3.67%      14.97%
  546. 00:00.506   _findnext   2.38%       9.71%
  547. 00:00.133   DOS         0.63%       2.57%
  548. 00:05.218   Total    24.50%
  549.  Start:  24624
  550.    End:  24952
  551. Length:   4096
  552.  Scale:      1
  553.  Speed:     64
  554.  Time: 00:22.092
  555. Time        Routine    % of Total  % of Accounted
  556. 00:02.423   _markbit   10.97%      45.22%
  557. 00:01.655   _markall    7.49%      30.88%
  558. 00:00.728   _testbit    3.30%      13.58%
  559. 00:00.510   _findnext   2.31%       9.53%
  560. 00:00.042   DOS         0.19%       0.78%
  561. 00:05.359   Total   24.26%
  562.  Start:  24624
  563.    End:  24952
  564. Length:   4096
  565.  Scale:      1
  566.  Speed:    128
  567.  Time: 00:23.507
  568. Time        Routine    % of Total  % of Accounted
  569. 00:01.892   _markall   8.05%       37.09%
  570. 00:01.677   _markbit   7.14%       32.89%
  571. 00:01.008   _testbit   4.29%       19.77%
  572. 00:00.518   _findnext  2.21%       10.16%
  573. 00:00.004   DOS        0.02%        0.08%
  574. 00:05.101   Total   21.70%
  575.  Start:  24624
  576.    End:  24952
  577. Length:   4096
  578.  Scale:      1
  579.  Speed:    256
  580.  Time: 00:27.389
  581. Time        Routine    % of Total  % of Accounted
  582. 00:04.228   _markall   15.44%      46.14%
  583. 00:02.544   _markbit    9.29%      27.77%
  584. 00:01.134   _findnext   4.14%      12.38%
  585. 00:00.973   _testbit    3.55%      10.62%
  586. 00:00.283   DOS         1.04%       3.09%
  587. 00:09.164   Total    33.46%
  588.  Start:  24624
  589.    End:  24952
  590. Length:   4096
  591.  Scale:      1
  592.  Speed:    512
  593.  Time: 00:39.369
  594. Time        Routine    % of Total  % of Accounted
  595. 00:01.964   _markbit   4.99%       57.89%
  596. 00:01.161   _testbit   2.95%       34.21%
  597. 00:00.182   _findnext  0.46%       5.38%
  598. 00:00.082   _markall   0.21%       2.42%
  599. 00:00.002   DOS        0.01%       0.09%
  600. 00:03.393   Total   8.62%
  601.  
  602.