Time MeasurementApr. 8, 2003TopicsTopics Time scales Interval counting Cycle counters K-best measurement schemeclass22.ppt15-213“The course that gives CMU its Zip!”–2–15-213, F’03Computer Time ScalesTwo Fundamental Time ScalesTwo Fundamental Time Scales Processor: ~10–9sec. External events: ~10–2sec.z Keyboard inputz Disk seekz Screen refreshImplicationImplication Can execute many instructions while waitingfor external event to occur Can alternate among processes without anyone noticingTime Scale (1 Ghz Machine)1.E-09 1.E-06 1.E-03 1.E+00Time (seconds)1 ns1µs1 ms 1 sInteger AddFP MultiplyFP DivideKeystrokeInterruptHandlerDisk AccessScreen RefreshKeystrokeMicroscopicMacroscopic–3–15-213, F’03Measurement ChallengeHow Much Time Does Program X Require?How Much Time Does Program X Require? CPU timez How many total seconds are used when executing X?z Measure used for most applicationsz Small dependence on other system activities Actual (“Wall”) Timez How many seconds elapse between the start and the completion of X?z Depends on system load, I/O times, etc.Confounding FactorsConfounding Factors How does time get measured? Many processes share computing resourcesz Transient effects when switching from one process to anotherz Suddenly, the effects of alternating among processes become noticeable–4–15-213, F’03“Time” on a Computer Systemreal (wall clock) time= user time (time executing instructions in the user process)+ = real (wall clock) timeWe will use the word “time” to refer to user time.= system time (time executing instructions in kernel on behalf of user process)+= some other user’s time (time executing instructions in different user’s process)cumulative user time–5–15-213, F’03Activity Periods: Light Load Most of the time spent executing one process Periodic interrupts every 10msz Interval timerz Keep system from executing one process to exclusion of others Other interruptsz Due to I/O activity Inactivity periodsz System time spent processing interruptsz ~250,000 clock cycles Activity Periods, Load = 10 10203040506070801Time (ms)ActiveInactive–6–15-213, F’03Activity Periods: Heavy Load Sharing processor with one other active process From perspective of this process, system appears to be “inactive” for ~50% of the timez Other process is executingActivity Periods, Load = 20 10203040506070801Time (ms)ActiveInactive–7–15-213, F’03Interval CountingOS Measures Runtimes Using Interval TimerOS Measures Runtimes Using Interval Timer Maintain 2 counts per processz User timez System time Each time get timer interrupt, increment counter for executing processz User time if running in user modez System time if running in kernel mode–8–15-213, F’03Interval Counting ExampleAu Au Au As Bu Bs Bu Bu Bu Bu As Au Au Au Au Au Bs Bu Bu Bs Au Au Au As AsA 110u + 40sB 70u + 30s(a) Interval TimingsB BAA A(b) Actual TimesBAABA 120.0u + 33.3sB 73.3u + 23.3s0 10 20 30 40 50 60 70 80 90 100 110 120 130 140 150 160AAu Au Au As Bu Bs Bu Bu Bu Bu As Au Au Au Au Au Bs Bu Bu Bs Au Au Au As AsA 110u + 40sB 70u + 30s(a) Interval TimingsB BAA AAu Au Au As Bu Bs Bu Bu Bu Bu As Au Au Au Au Au Bs Bu Bu Bs Au Au Au As AsA 110u + 40sB 70u + 30s(a) Interval TimingsB BAA A(b) Actual TimesBAABA 120.0u + 33.3sB 73.3u + 23.3s0 10 20 30 40 50 60 70 80 90 100 110 120 130 140 150 160A(b) Actual TimesBAABA 120.0u + 33.3sB 73.3u + 23.3s0 10 20 30 40 50 60 70 80 90 100 110 120 130 140 150 160A–9–15-213, F’03Unix time Command 0.82 seconds user timez 82 timer intervals 0.30 seconds system timez 30 timer intervals 1.32 seconds wall time 84.8% of total was used running these processes z (.82+0.3)/1.32 = .848time make oseventgcc -O2 -Wall -g -march=i486 -c clock.cgcc -O2 -Wall -g -march=i486 -c options.cgcc -O2 -Wall -g -march=i486 -c load.cgcc -O2 -Wall -g -march=i486 -o osevent osevent.c . . .0.820u 0.300s 0:01.32 84.8% 0+0k 0+0io 4049pf+0w–10–15-213, F’03Accuracy of Interval CountingWorst Case AnalysisWorst Case Analysis Timer Interval = δ Single process segment measurement can be off by ±δ No bound on error for multiple segmentsz Could consistently underestimate, or consistently overestimate0 1020304050607080AAMinimumMaximum0 1020304050607080AAMinimumMaximum• Computed time = 70ms• Min Actual = 60 + ε• Max Actual = 80 – ε–11–15-213, F’03Accuracy of Int. Cntg. (cont.)Average Case AnalysisAverage Case Analysis Over/underestimates tend to balance out As long as total run time is sufficiently largez Min run time ~1 secondz 100 timer intervals Consistently miss 4% overhead due to timer interrupts0 1020304050607080AAMinimumMaximum0 1020304050607080AAMinimumMaximum• Computed time = 70ms• Min Actual = 60 + ε• Max Actual = 80 – ε–12–15-213, F’03Cycle Counters Most modern systems have built in registers that are incremented every clock cyclez Very fine grainedz Maintained as part of process state» In Linux, counts elapsed global time Special assembly code instruction to access On (recent model) Intel machines:z 64 bit counter.z RDTSC instruction sets %edx to high order 32-bits, %eaxto low order 32-bits–13–15-213, F’03Cycle Counter PeriodWrap Around Times for 550 MHz machineWrap Around Times for 550 MHz machine Low order 32 bits wrap around every 232/ (550 * 106) = 7.8 seconds High order 64 bits wrap around every 264/ (550 * 106) = 33539534679 secondsz 1065 yearsFor 2 GHz machineFor 2 GHz machine Low order 32-bits every 2.1 seconds High order 64 bits every 293 years–14–15-213, F’03Measuring with Cycle CounterIdeaIdea Get current value of cycle counterz store as pair of unsigned’s cyc_hi and cyc_lo Compute something Get new value of cycle counter Perform double precision subtraction to get elapsed cycles/* Keep track of most recent reading of cycle counter */static unsigned cyc_hi = 0;static unsigned cyc_lo = 0;void start_counter(){/* Get current value of cycle counter */access_counter(&cyc_hi, &cyc_lo);}–15–15-213, F’03Accessing the Cycle Cntr. GCC allows inline assembly code with mechanism for matching registers with program variables Code only works on x86 machine compiling with GCC Emit assembly with rdtsc and two movl instructionsvoid access_counter(unsigned *hi, unsigned *lo){/* Get cycle counter */asm("rdtsc; movl %%edx,%0; movl %%eax,%1": "=r" (*hi), "=r"
View Full Document