FM> I'm not sure that a profiler would show you the problem. If it's just
FM> timing your *code* execution, it may not indicate where *DOS* is taking
FM> a long time, such as in file I/O.
I can't remember which one I used to do the profiling, but since
I last did profiling, I discovered that Watcom's profiler is
inadequate, but that IBM's CSET is very good albeit difficult to
set up, but it generates hooks at every function call, so I get
great results, which I have provided below. As you can see, the
bottleneck is in reading a message, which is because of the silly
way it is doing it with continual-reseeking (simplifies the code
though), so the bottleneck is not in writing the output file.
Since the next bit of optimization requires rewriting code, I'm
not keen on the idea. Of course, if anyone wants to jump in and
volunteer, don't let me stand in your way...
E:\DEVEL\PQWK\PKT2QWKP.EXE run 11/02/95 at 07:40:10 PM
Executables generating events: 1 of 3
Functions generating events: 23
Threads generating events: 1
Maximum nesting depth of each thread:
thread: 1 depth 6
Total events: 36044
User events: 0
Number of trace buffer flushes: 0
Total trace time excluding overhead: 14139106 tics or 11.850 seconds
Trace overhead: 702858 tics or 0.589 seconds
All times in the details window are given in milliseconds.
Number Function Name
------ -------------
1 get_msg
2 main
3 xwriteqwkmsg
4 write_line
5 qwkwritehdr
6 bmgStrstr
7 bmgSearch
8 qwkwriteidx
9 fdt_split
10 bmgCompile
11 get_numerical_token
12 asctoi
13 assign
14 lstrip
15 rstrip
16 dt_split
17 IEEEToMSBIN
18 qwkwriteblk
19 parse_addr
20 to_delim
21 qwkfreeareas
22 stripcr
23 skip_white
Func % % Total Run Active Min Max Avg
Num Run Act Calls Time Time Time Time Time
------ --- --- -------- --------- --------- --------- --------- ---------
1 59 64 241 6,986 7,619 0.713 41.7 29.0
2 15 100 1 1,796 11,832 1,796 1,796 1,796
3 10 20 240 1,187 2,410 2.22 26.1 4.94
4 6 6 9,312 719 719 0.003 5.15 0.077
5 3 3 480 312 312 0.556 4.04 0.650
6 3 5 1,296 301 625 0.029 5.37 0.232
7 2 2 1,296 289 289 0.014 5.46 0.223
8 1 1 240 79.3 81.1 0.029 4.32 0.330
9 1 1 240 66.4 108 0.219 3.33 0.277
10 0 0 1,104 34.7 34.7 0.022 1.46 0.031
11 0 0 1,200 23.7 41.4 0.005 5.19 0.020
12 0 0 1,200 17.6 17.6 0.011 0.232 0.015
13 0 0 192 6.57 6.57 0.031 0.041 0.034
14 0 0 242 4.79 4.79 0.003 0.060 0.020
15 0 0 242 3.22 3.22 0.004 0.913 0.013
16 0 1 240 2.41 110 0.006 0.057 0.010
17 0 0 240 1.79 1.79 0.004 0.013 0.008
18 0 0 1 0.629 0.629 0.629 0.629 0.629
19 0 0 1 0.192 0.324 0.192 0.192 0.192
20 0 0 5 0.119 0.119 0.012 0.045 0.023
21 0 0 2 0.076 0.076 0.002 0.075 0.039
22 0 0 6 0.048 0.048 0.004 0.022 0.008
23 0 0 1 0.006 0.006 0.006 0.006 0.006
@EOT:
---
* Origin: X (3:711/934.9)
|