Category : Files from Magazines
Archive   : DDJ9210.ZIP
Filename : PROFLE.ASC

 
Output of file : PROFLE.ASC contained in archive : DDJ9210.ZIP
_YOUR OWN SOURCE CODE PROFILER_
by Keith W. Boone

[LISTING ONE]

/* PROFILER.C -- Copyright (c) 1992 by Keith W. Boone, Tallahassee, FL
* This program contains the runtime functions required to profile C source
* code. Permission is granted to use or distribute this source code without
* any restrictions as long as this entire notice is included intact. You may
* use or include this software in any product that you sell for profit.
* This software is distributed as is, and is no liability is granted.
*/

#include
#include

static long start, /* Linear code start address */
end, /* Linear code end address */
reference, /* Main function address */
ticker; /* Global total time in profiler */
static int *buffer, /* Pointer to CS:IP tick buffer */
length, /* Length of the buffer */
scale, /* Scaling factor for the buffer */
status, /* Status = TRUE if profiling */
(interrupt far *old8)(); /* Old clock interrupt */
unsigned speedup_factor = 1; /* Clock speedup factor */

/***** Convert a far pointer to a linear address *****/
long linear(void far *ptr)
{
long addr = FP_SEG(ptr);
if ((long)ptr == -1l)
return 0x100000;
addr <<= 4;
addr += FP_OFF(ptr);
return addr;
}
/***** _profmon is a clock interrupt handler which is used to mark what
function your program is in during the interrupt. *****/
interrupt far _profmon(int es, int ds, int di, int si,
int bp, int sp, int bx, int dx, int cx, int ax,
unsigned ip, unsigned cs
)
{
if (status) /* If profiling */
{ long addr = cs;
addr <<= 4;
addr += ip; /* Compute Phys address */
ticker++; /* Increase total time */
if ((addr >= start) && (addr <= end)) /* If in range of code */
{ addr -= start;
buffer[addr / scale]++; /* Update buffer */
}
}
_chain_intr(old8);
}
/***** profile(buf, len, first, last, speed) initializes the profiler. Buf is
Buf is a pointer to an array of integers that keeps track of CS:IP locations
while profiling. First and last are pointers to the functions where profiling
will occur. Note that the function last is never profiled! Speed is the clock
frequency multiplier passed to speedup() when turning profiling on. *****/
profile(int *buf, int len, int (*first)(), int (*last)(), unsigned speed)
{
unsigned i, j;
long size;
int main();
buffer = buf;
length = len;
start = linear((void far *)first); /* Conver to linear address */
end = linear((void far *)last);
reference = linear((void far *)main); /* main() is relocation ref */
status = 0; /* Profiling off initially */
speedup_factor = speed; /* Used with speedup() */

if (buf == NULL) /* buf==NULL is reset */
{ if (old8 != NULL)
_dos_setvect(0x08, old8);
return 0;
}
size = (end - start); /* Compute size and scale */
scale = ((size - 1) / length) + 1;
return 0;
}
/***** monitor(flag) turns profiling on or off. If turning profiling on then
the program needs to trap the clock interrupt, then set status = TRUE.
Otherwise the program resets the clock interrupt, then sets status = FALSE.
This ensures that status does not change to FALSE while in _profmon(),
not really a big deal, but cleaner. ******/
monitor(int flag)
{
if (buffer == NULL) /* Turn on w/out initialization is error */
return -1;
if (flag) /* If turning profiling on */
{ if (speedup_factor > 1) /* Speed up clock by saved */
speedup(speedup_factor); /* speedup factor */
old8 = _dos_getvect(0x08); /* get old clock handler */

_dos_setvect(0x08, _profmon); /* set new vector */
}
else if (old8 != NULL) /* Else turning off */
{ _dos_setvect(0x08, old8); /* reset old vector */
old8 = NULL;
if (speedup_factor > 1) /* Restore clock speed */
speedup(1); /* Note reverse order! */
}
status = flag; /* Set on/off flag */
return 0;
}
/***** writemon(filename) copies the profiling data to the file specified
for later use by PROF.EXE. *****/
writemon(char *filename)
{
FILE *fp = fopen(filename, "wb");
if (fp == NULL)
return -1;
monitor(0);
fwrite(&reference, 1, sizeof(reference), fp);
fwrite(&ticker, 1, sizeof(ticker), fp);
fwrite(&start, 1, sizeof(start), fp);
fwrite(&end, 1, sizeof(start), fp);
fwrite(&length, 1, sizeof(length), fp);
fwrite(&scale, 1, sizeof(scale), fp);
fwrite(&speedup_factor, 1, sizeof(speedup_factor), fp);
fwrite(buffer, length, sizeof(*buffer), fp);
fclose(fp);
}


[LISTING TWO]

#include

static int (interrupt far *oldclk)(); /* Old clock interrupt */
static unsigned counter, /* Current counter value */
factor;
#define PICCMD 0x20 /* 8259 PIC command port */
#define EOI 0x20 /* EOI command */

#define TCTRL 0x43 /* Timer control port */
#define T0DATA 0x40 /* Timer 0 data port */
#define T0LOAD 0x36 /* Timer 0 load command */

/****** _spdup is an interrupt handler which processes clock interrupts which
have been sped up. *****/
interrupt far _spdup()
{
if (counter--) /* If counter non-zero */
outp(PICCMD, EOI); /* Send EOI and return */
else
{ counter = factor; /* Otherwise reset counter */
_chain_intr(oldclk); /* and exec old handler */
}
}
speedup(unsigned newfact)
{
unsigned divider;
if (newfact <= 1) /* Reset timer handler */
{ factor = 1;
if (oldclk) /* reset only if set */
{ _dos_setvect(0x08, oldclk); /* in the first place */
outp(TCTRL, T0LOAD);
outp(T0DATA, 0);
outp(T0DATA, 0); /* standard divisor */
oldclk = 0;
}
}
else
{ if (!oldclk)
oldclk = _dos_getvect(0x08); /* Save old handler */
counter = factor = newfact;
divider = 65536L / newfact;
_disable(); /* Disable interrupts */
outp(TCTRL, T0LOAD);
outp(T0DATA, divider);
outp(T0DATA, (divider >> 8)); /* load new divisor */
_enable(); /* Enable interrupts */
_dos_setvect(0x08, _spdup); /* use our handler */
}
}


[LISTING THREE]

/* PROF.C -- Copyright (c) 1992 by Keith W. Boone, Tallahassee, FL
* This program contains the reporting facilities used to profile C code.
* Permission is granted to use or distribute this source code without any
* restrictions as long as this entire notice is included intact. You may use
* or include this software in any product that you sell for profit.
* This software is distributed as is, and is no liability is granted.
*/

#include
long start, /* linear address of Start of profiled code */
end, /* End of profiled code */
reference, /* Address of main function to resolve reloc */
ticker; /* Value of ticker at end of profiling */
int *buffer, /* Pointer to profile buffer */
length, /* Length of profile buffer */
scale, /* Scale used (code address to buffer address) */
factor; /* Clock speedup factor */

typedef struct mapentry /* Used to store MAP file information */
{ long address, /* Linear address of function */
count; /* computed # of ticks in function */
char *name; /* Function Name */
} MAP;

MAP map[4096]; /* Limited to 4096 functions */
int nmap = 0; /* Number of Map table entries used */
long emaina; /* Linear address of main function */

/***** Sortmap(m1, m2) is a callback function used by qsort to sort
map table entried by linear address. *****/
sortmap(MAP *m1, MAP *m2)
{ if (m1->address < m2->address)
return -1;
if (m1->address > m2->address)
return 1;
return 0;
}
/***** Readmap(filename) reads in the MAP stored in 'filename' and loads the
data into map[]. *****/
readmap(char *filename)
{
char line[80], *ptr, *strrchr(), *strdup();
long off, seg;
FILE *fp = fopen(filename, "rt");

if (fp == NULL) /* Return error code if cannot open MAP file */
return -1;
map[nmap++].name = "DOS"; /* Address below first are in DOS */

/* Read each line of the map file until you find "Publics by Value".
* This is VERY linker dependent! */
while (fgets(line, 80, fp))
{ if (ptr = strrchr(line, 'b'))
{ if (strcmp(ptr, "by Value\n") == 0)
break;
else ptr = NULL;
}
}
if (ptr == NULL) /* If we didn't find "Publics by Value" */
{ fclose(fp); /* the return with an failure code. */
return -1;
}
while (fgets(line, 80, fp))
{ /* remove trailing linefeed from line */
if (ptr = strrchr(line, '\n'))
*ptr = 0;
if (!*line)
continue; /* Ignore empty lines */
else if (strncmp(line + 12, "Abs", 3) == 0)
continue; /* And Absolue values */
sscanf(line, " %lX:%lX", &seg, &off); /* Get the seg:off */
map[nmap].address = (seg << 4) + off; /* convert to linear */
ptr = strrchr(line, ' '); /* find function name */
map[nmap].name = strdup(++ptr); /* make a copy of it */

if (strcmp(ptr, "_main") == 0) /* Found main() */
emaina = map[nmap].address; /* save it's address */
nmap++;
}
qsort(map + 1, nmap - 1, sizeof(MAP), sortmap); /* Sort by address */
map[nmap++].name = "BIOS"; /* Addresses beyond last are in BOIS */
return 0;
}
/***** Readmon(filename) reads in the profile data stored in 'filename' and
and outputs vitals on the profiled data. *****/
readmon(char *filename)
{
FILE *fp = fopen(filename, "rb");
void *calloc();
int m, s, k;
float T;

if (fp == NULL)
return -1;
fread(&reference, 1, sizeof(reference), fp);
fread(&ticker, 1, sizeof(ticker), fp);
fread(&start, 1, sizeof(start), fp);
fread(&end, 1, sizeof(start), fp);
fread(&length, 1, sizeof(length), fp);
fread(&scale, 1, sizeof(scale), fp);
fread(&factor, 1, sizeof(factor), fp);
buffer = (int *)calloc(sizeof(int), length);
fread(buffer, length, sizeof(int), fp);
fclose(fp);

T = ticker / (18.2 * factor);
m = T / 60;
T -= m * 60;
s = T;
T -= s;
k = T * 1000;
printf(" Start: %6ld\n", start);
printf(" End: %6ld\n", end);
printf("Length: %6d\n", length);
printf(" Scale: %6d\n", scale);
printf(" Speed: %6d\n", factor);
printf(" Time: %02d:%02d.%03d\n", m, s, k);
return 0;
}
/***** mapcmp(m1, m2) is a callback function used by qsort to sort map table
entried by amount of time used by the function. *****/
mapcmp(MAP *m1, MAP *m2)
{ if (m1->count > m2->count)
return -1;
else if (m1->count == m2->count)
return 0;
else return 1;
}
main(int argc, char **argv)
{
int i, /* profile buffer index */
j; /* MAP entry index */
long addr; /* Current linear address */
int m, /* Minutes */
s, /* Seconds */
t; /* thousandths */
char buf[32], /* File name buffer */
*strchr();
float seconds, /* time in a function in seconds */
accounted, /* accounted for in all profiled functions */
percent; /* Percent of total accounted */
if (argc < 2)
{ fprintf(stderr, "Usage: %s program[.map] [program[.mon]]\n", *argv);
exit(1);
}
/* Append .map to files that have no extension specified for arg 1 */
if (strchr(argv[1], '.'))
strcpy(buf, argv[1]);
else sprintf(buf, "%s.map", argv[1]);
if (readmap(buf))
{ fprintf(stderr, "Error reading map '%s'.\n", buf);
exit(1);
}
/* If second arg specified, then use it, otherwise use first arg */
if (argc > 2)
i = 2;
else
{ i = 1;
if (strchr(argv[1], '.')) /* remove ext from first arg */
*strchr(argv[1], '.') = 0;
}
/* Append .mon to files that have no extension specified for arg 2 */
if (strchr(argv[i], '.'))
strcpy(buf, argv[i]);
else sprintf(buf, "%s.mon", argv[i]);
if (readmon(buf))
{ fprintf(stderr, "Error reading '%s'.\n", buf);
exit(1);
}
start -= reference; /* Offset start by the &main */
end -= reference;
for (i = 1; i < (nmap - 1); i++) /* adjust map by &main */
map[i].address -= emaina;
map[0].address = 0x8000000; /* DOS start = max neg */
map[nmap].address = 0x7FFFFFF; /* BIOS end = max pos */

/***** For each entry in the buffer, find the first map address (j)
whose function encompasses addr, and update the time spent in
that function. *****/
accounted = 0.0;
addr = start;
j = 0;
for (i = 0; (i < length) && (j < nmap); i++)
{ if (buffer[i])
{ while ((j < nmap) && (addr > map[j+1].address))
j++;
map[j].count += buffer[i];
accounted += buffer[i];
}
addr += scale;
}
qsort(map, nmap, sizeof(MAP), mapcmp); /* Sort by time used */
/* For each function, output time used, and accumulate the total */
printf("Time\t\tRoutine\t\t %% of Total\t %% of Accounted\n");
for (i = 0; i < nmap; i++)
{ if (map[i].count)
{ seconds = map[i].count;
seconds /= (18.2 * factor);
m = seconds / 60;
seconds -= m * 60;
s = seconds;
seconds -= s;
t = seconds * 1000;
printf("%02d:%02d.%03d\t%-20s\t%5.2f%%\t%5.2f%%\n",
m, s, t, map[i].name,
map[i].count * 100.0 / ticker,
map[i].count * 100.0 / accounted);
}
}
/* Output accounted/total times */
percent = (100.0 * accounted) / ticker;
accounted /= 18.2 * factor; /* Convert accounted to seconds */
m = accounted / 60;
accounted -= m * 60;
s = accounted;
accounted -= s;
t = accounted * 1000;
printf("%02d:%02d.%03d\t%-20s\t%5.2f%%\n", m, s, t, "Total", percent);
}


[LISTING FOUR]

#include
#define PLEN 4096
unsigned pbuf[PLEN];

#define ALEN 8000
#define MAX (ALEN*8L)
char array[ALEN];

markbit(char *array, long bit)
{
array[bit/8] |= 1 << (bit % 8l);
}
testbit(char *array, long bit)
{
return array[bit/8] & (1 << (bit % 8l));
}
markall(char *array, long bit)
{
long temp;
for (temp = bit + bit; temp < MAX; temp += bit)
markbit(array, temp);
}
long findnext(char *array, long bit)
{
long temp;
for (temp = bit + 1; temp < MAX; temp++)
if (!testbit(array, temp))
return temp;
return 0;
}
extern last();
main()
{
long value,
start,
clock();
int speed;
char buff[16];
printf("Speedup\tTime\n");
for (speed = 1; speed <= 2048; speed += speed)
{ /* reset program workspace on each iteration */
memset(pbuf, 0, sizeof(pbuf));
memset(array, 0, sizeof(array));
/* Set profile buffer, program addresses and speedup */
/* note that main() is not profiled */
profile(pbuf, PLEN, markbit, main, speed);
start = clock();
printf("%5d\t", speed);
/* Enable profiling */
monitor(1);
/* Execute sieve of Eratosthenese */
for (value = 2; value; value = findnext(array, value))
markall(array, value);
/* Disable profiling */
monitor(0);
/* Output profile data for this pass */
printf("%ld\n", clock() - start);
sprintf(buff, "tst%05d.mon", speed);
writemon(buff);
}
}



Figure 1: Sample profiler output for the TESTPROF.C program

Start: 24624
End: 24952
Length: 4096
Scale: 1
Speed: 1
Time: 00:10.384
Time Routine % of Total % of Accounted

00:02.197 _markbit 21.16% 40.82%
00:02.087 _markall 20.11% 38.78%
00:00.659 _findnext 6.35% 12.24%
00:00.439 _testbit 4.23% 8.16%
00:05.384 Total 51.85%
Start: 24624
End: 24952
Length: 4096
Scale: 1
Speed: 2
Time: 00:15.741
Time Routine % of Total % of Accounted
00:02.060 _markbit 13.09% 41.90%
00:01.483 _markall 9.42% 30.17%
00:00.741 _testbit 4.71% 15.08%
00:00.467 _findnext 2.97% 9.50%
00:00.164 DOS 1.05% 3.35%
00:04.917 Total 31.24%
Start: 24624
End: 24952
Length: 4096
Scale: 1
Speed: 4
Time: 00:18.434
Time Routine % of Total % of Accounted
00:01.895 _markbit 10.28% 45.10%
00:01.208 _markall 6.56% 28.76%
00:00.659 _testbit 3.58% 15.69%
00:00.398 _findnext 2.16% 9.48%
00:00.041 DOS 0.22% 0.98%
00:04.203 Total 22.80%
Start: 24624
End: 24952
Length: 4096
Scale: 1
Speed: 8
Time: 00:19.848
Time Routine % of Total % of Accounted
00:01.737 _markall 8.75% 36.19%
00:01.675 _markbit 8.44% 34.91%
00:00.748 _testbit 3.77% 15.59%
00:00.521 _findnext 2.63% 10.87%
00:00.116 DOS 0.59% 2.43%
00:04.800 Total 24.19%
Start: 24624
End: 24952
Length: 4096
Scale: 1
Speed: 16
Time: 00:20.669
Time Routine % of Total % of Accounted
00:02.026 _markbit 9.80% 44.66%
00:01.146 _markall 5.55% 25.28%
00:00.831 _testbit 4.02% 18.32%
00:00.484 _findnext 2.34% 10.67%
00:00.048 DOS 0.23% 1.06%
00:04.536 Total 21.95%
Start: 24624
End: 24952
Length: 4096
Scale: 1
Speed: 32
Time: 00:21.299
Time Routine % of Total % of Accounted
00:02.558 _markbit 12.01% 49.03%
00:01.237 _markall 5.81% 23.72%
00:00.781 _testbit 3.67% 14.97%
00:00.506 _findnext 2.38% 9.71%
00:00.133 DOS 0.63% 2.57%
00:05.218 Total 24.50%
Start: 24624
End: 24952
Length: 4096
Scale: 1
Speed: 64
Time: 00:22.092
Time Routine % of Total % of Accounted
00:02.423 _markbit 10.97% 45.22%
00:01.655 _markall 7.49% 30.88%
00:00.728 _testbit 3.30% 13.58%
00:00.510 _findnext 2.31% 9.53%
00:00.042 DOS 0.19% 0.78%
00:05.359 Total 24.26%
Start: 24624
End: 24952
Length: 4096
Scale: 1
Speed: 128
Time: 00:23.507
Time Routine % of Total % of Accounted
00:01.892 _markall 8.05% 37.09%
00:01.677 _markbit 7.14% 32.89%
00:01.008 _testbit 4.29% 19.77%
00:00.518 _findnext 2.21% 10.16%
00:00.004 DOS 0.02% 0.08%
00:05.101 Total 21.70%
Start: 24624
End: 24952
Length: 4096
Scale: 1
Speed: 256
Time: 00:27.389
Time Routine % of Total % of Accounted
00:04.228 _markall 15.44% 46.14%
00:02.544 _markbit 9.29% 27.77%
00:01.134 _findnext 4.14% 12.38%
00:00.973 _testbit 3.55% 10.62%
00:00.283 DOS 1.04% 3.09%
00:09.164 Total 33.46%
Start: 24624
End: 24952
Length: 4096
Scale: 1
Speed: 512
Time: 00:39.369
Time Routine % of Total % of Accounted
00:01.964 _markbit 4.99% 57.89%
00:01.161 _testbit 2.95% 34.21%
00:00.182 _findnext 0.46% 5.38%
00:00.082 _markall 0.21% 2.42%
00:00.002 DOS 0.01% 0.09%
00:03.393 Total 8.62%



  3 Responses to “Category : Files from Magazines
Archive   : DDJ9210.ZIP
Filename : PROFLE.ASC

  1. Very nice! Thank you for this wonderful archive. I wonder why I found it only now. Long live the BBS file archives!

  2. This is so awesome! 😀 I’d be cool if you could download an entire archive of this at once, though.

  3. But one thing that puzzles me is the “mtswslnkmcjklsdlsbdmMICROSOFT” string. There is an article about it here. It is definitely worth a read: http://www.os2museum.com/wp/mtswslnk/