Visual C++ 4.0 Trivia -- some old working set results
This isn't exactly a quiz because you couldn't possibly know the answer unless you were there or are pyschic but it's a fun result anyway so I thought I'd share.
If you've ever read my mini-bio anywhere you'll know that this is actually my second stint in the Developer Division at MS. My first stint was about 7 years long and ended back in 1995. One of the last things I did then was tune what would become Visual C++ 4.0 -- we called it the "Olympus" release.
A big problem we faced in Olympus was that compile times within the IDE were significantly slower than they were if you did the same compile from the command line. It was pretty easy to see that the reason for this was that the IDE was using memory (and doing processing) during the build and so there was less available for the compiler/linker hence a little more swapping and slower builds. My job was to get the IDE's footprint to be as small as possible.
OK, so here's the quiz.
The test case is building a simple "MFC App Wizard" default application from scratch on a machine with 16M of memory. How many pages did the IDE use while the build is active after I was done? For bonus points how many of those were code pages? Most people answer in megabytes and divide by 4k to get pages.
...
answer below
...
...
...
...
...
...
The way I did analysis was I sampled the working set once a second for the entire build so I would get numbers for each module. In the interest of typing less (I only have a hard copy of my last report) I will just give the totals rather than the breakdown by module.
| Time |
Total |
DynamicData |
StaticData |
Code |
Notes |
| 23.88 |
31 |
10 |
- |
- |
ready to build, ide idle |
| 24.89 |
31 |
10 |
- |
- |
|
| 25.90 |
347 |
96 |
122 |
106 |
build initiated |
| 26.91 |
467 |
120 |
157 |
167 |
thinking about what to build |
| 27.92 |
200 |
55 |
51 |
71 |
|
| 28.93 |
189 |
54 |
50 |
62 |
|
| 29.95 |
31 |
10 |
- |
- |
IDE has launched compiler |
| 30.96 |
31 |
10 |
- |
- |
|
| 31.97 |
43 |
13 |
2 |
7 |
output, first file done |
| 32.98 |
31 |
10 |
- |
- |
|
| 33.99 |
31 |
10 |
- |
- |
|
| 35.00 |
31 |
10 |
- |
- |
|
| 36.01 |
31 |
10 |
- |
- |
|
| 37.03 |
43 |
13 |
2 |
7 |
output, second file done |
| 38.04 |
31 |
10 |
- |
- |
|
| 39.05 |
31 |
10 |
- |
- |
|
| 40.06 |
31 |
10 |
- |
- |
|
| 41.07 |
31 |
10 |
- |
- |
|
| 42.08 |
43 |
13 |
2 |
7 |
output, third file done |
| 43.09 |
31 |
10 |
- |
- |
|
| 44.11 |
31 |
10 |
- |
- |
|
| 45.12 |
31 |
10 |
- |
- |
|
| 46.13 |
31 |
10 |
- |
- |
|
| 47.14 |
43 |
13 |
2 |
7 |
output, fourth file done |
| 48.15 |
218 |
10 |
- |
- |
IDE thinking about link steps |
| 49.16 |
218 |
10 |
- |
- |
|
| 50.17 |
216 |
10 |
- |
- |
|
| 51.19 |
193 |
10 |
- |
- |
|
| 52.20 |
276 |
10 |
- |
- |
|
| 53.21 |
31 |
10 |
- |
- |
link starts |
| 54.22 |
31 |
10 |
- |
- |
|
| 55.23 |
31 |
10 |
- |
- |
|
| 56.24 |
31 |
10 |
- |
- |
|
| 57.25 |
43 |
13 |
2 |
7 |
processing linker output |
| 58.27 |
31 |
10 |
- |
- |
|
| 59.28 |
31 |
10 |
- |
- |
|
| 60.29 |
31 |
10 |
- |
- |
|
| 61.30 |
31 |
10 |
- |
- |
|
| 62.31 |
43 |
13 |
2 |
7 |
processing linker output |
| 63.32 |
31 |
10 |
- |
- |
|
| 64.34 |
31 |
10 |
- |
- |
|
| 65.35 |
31 |
10 |
- |
- |
|
| 66.36 |
192 |
54 |
50 |
65 |
link finishes bscmake invoked |
| 67.37 |
43 |
13 |
2 |
7 |
processing bscmake output |
| 68.38 |
31 |
10 |
- |
- |
|
| 69.39 |
31 |
10 |
- |
- |
|
| 70.40 |
31 |
10 |
- |
- |
|
| 71.42 |
43 |
13 |
2 |
7 |
processing bscmake output |
| 72.43 |
31 |
10 |
- |
- |
|
| 73.44 |
566 |
150 |
169 |
224 |
build finished |
| 74.45 |
711 |
234 |
222 |
232 |
IDE returning to normal state |
| 75.46 |
776 |
214 |
216 |
322 |
|
| 76.47 |
629 |
141 |
218 |
277 |
|
First thing to note is that the times shown here aren't "real." In order to do this experiment I flushed the working set every second (well it ended up being every 1.01 seconds but anyway) and that slows things down a lot. So the true times would be much less (this build took about 15s on that era of hardware as I recall). Also note that the total is greater than the sume of the other 3 columns because it includes system overhead costs as well (like page table pages) that are not broken out.
OK with that in mind you can still see the phases clearly and... while the compiler(s) are running the ide is using either 31 or 43 pages respectively. That's 124k or 172k. During normal compiler processing ZERO code ran in the IDE for seconds at a time (no code pages were faulted in). Output processing took 7 pages -- 28k. Note that 21 of the pages were (nearly) unavoidable system overhead to handle mapping our VM and whatnot.
To get these kind of results we did some pretty careful analysis. One I distinctly remember was that I was seeing a sort of one second "pulse" in the working set that I couldn't explain. I was staring at my screen trying to think what it could be and then I saw it was literally in my face -- the caret was beating at about 1 Hz. So I turned off the caret in the output window during the build and poof the pulsing went away.
Anyway fun stuff.
How did you do? Most people who answer are off by a factor of about 20.
