15-213 The course that gives CMU its Zip! Time Measurement Time - PowerPoint PPT Presentation

15-213 “The course that gives CMU its Zip!” Time Measurement Time Measurement Oct. 24, 2002 Oct. 24, 2002 Topics Topics n Time scales n Interval counting n Cycle counters n K-best measurement scheme class18.ppt

Computer Time Scales Computer Time Scales Time Scale (1 Ghz Machine) Microscopic Macroscopic Integer Add Disk Access FP Multiply Screen Refresh Keystroke FP Divide Keystroke Interrupt Handler 1 µ s 1 ns 1 ms 1 s 1.E-09 1.E-06 1.E-03 1.E+00 Time (seconds) Two Fundamental Time Scales Implication Two Fundamental Time Scales Implication n Processor: ~10 –9 sec. n Can execute many instructions while waiting n External events: ~10 –2 sec. for external event to occur l Keyboard input n Can alternate among l Disk seek processes without anyone l Screen refresh noticing 15-213, F’02 – 2 –

Measurement Challenge Measurement Challenge How Much Time Does Program X Require? How Much Time Does Program X Require? n CPU time l How many total seconds are used when executing X? l Measure used for most applications l Small dependence on other system activities n Actual (“Wall”) Time l How many seconds elapse between the start and the completion of X? l Depends on system load, I/O times, etc. Confounding Factors Confounding Factors n How does time get measured? n Many processes share computing resources l Transient effects when switching from one process to another l Suddenly, the effects of alternating among processes become noticeable 15-213, F’02 – 3 –

“Time” on a Computer System “Time” on a Computer System real (wall clock) time = user time (time executing instructions in the user process) = 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) + + = real (wall clock) time We will use the word “time” to refer to user time . cumulative user time 15-213, F’02 – 4 –

Activity Periods: Light Load Activity Periods: Light Load Activity Periods, Load = 1 Active 1 Inactive 0 10 20 30 40 50 60 70 80 Time (ms) n Most of the time spent n Other interrupts executing one process l Due to I/O activity n Periodic interrupts every n Inactivity periods 10ms l System time spent l Interval timer processing interrupts l Keep system from l ~250,000 clock cycles executing one process to exclusion of others 15-213, F’02 – 5 –

Activity Periods: Heavy Load Activity Periods: Heavy Load Activity Periods, Load = 2 Active 1 Inactive 0 10 20 30 40 50 60 70 80 Time (ms) n Sharing processor with one other active process n From perspective of this process, system appears to be “inactive” for ~50% of the time l Other process is executing 15-213, F’02 – 6 –

Interval Counting Interval Counting OS Measures Runtimes Using Interval Timer OS Measures Runtimes Using Interval Timer n Maintain 2 counts per process l User time l System time n Each time get timer interrupt, increment counter for executing process l User time if running in user mode l System time if running in kernel mode 15-213, F’02 – 7 –

Interval Counting Example Interval Counting Example (a) Interval Timings (a) Interval Timings (a) Interval Timings A A A B B B A A A B B B A A A A A A 110u + 40s 110u + 40s 110u + 40s B B B 70u + 30s 70u + 30s 70u + 30s Au Au Au As Bu Bs Bu Bu Bu Bu As Au Au Au Au Au Bs Bu Bu Bs Au Au Au As As Au Au Au As Bu Bs Bu Bu Bu Bu As Au Au Au Au Au Bs Bu Bu Bs Au Au Au As As Au Au Au As Bu Bs Bu Bu Bu Bu As Au Au Au Au Au Bs Bu Bu Bs Au Au Au As As (b) Actual Times (b) Actual Times (b) Actual Times A A A A A A A A A A A A 120.0u + 33.3s 120.0u + 33.3s 120.0u + 33.3s B B B 73.3u + 23.3s 73.3u + 23.3s 73.3u + 23.3s B B B B B B 0 0 0 10 20 30 40 50 60 70 80 90 100110120130140150160 10 20 30 40 50 60 70 80 90 100110120130140150160 10 20 30 40 50 60 70 80 90 100110120130140150160 15-213, F’02 – 8 –

Unix time Command Unix time Command time make osevent gcc -O2 -Wall -g -march=i486 -c clock.c gcc -O2 -Wall -g -march=i486 -c options.c gcc -O2 -Wall -g -march=i486 -c load.c gcc -O2 -Wall -g -march=i486 -o osevent osevent.c . . . 0.820u 0.300s 0:01.32 84.8% 0+0k 0+0io 4049pf+0w n 0.82 seconds user time l 82 timer intervals n 0.30 seconds system time l 30 timer intervals n 1.32 seconds wall time n 84.8% of total was used running these processes l (.82+0.3)/1.32 = .848 15-213, F’02 – 9 –

Accuracy of Interval Counting Accuracy of Interval Counting A A Computed time = 70ms Minimum Minimum • Min Actual = 60 + ε • Maximum Maximum A A Max Actual = 80 – ε • 0 0 10 20 30 40 50 60 70 80 10 20 30 40 50 60 70 80 Worst Case Analysis Worst Case Analysis n Timer Interval = δ n Single process segment measurement can be off by ±δ n No bound on error for multiple segments l Could consistently underestimate, or consistently overestimate 15-213, F’02 – 10 –

Accuracy of Int. Cntg. (cont.) Accuracy of Int. Cntg. (cont.) A A Computed time = 70ms Minimum Minimum • Min Actual = 60 + ε • Maximum Maximum A A Max Actual = 80 – ε • 0 0 10 20 30 40 50 60 70 80 10 20 30 40 50 60 70 80 Average Case Analysis Average Case Analysis n Over/underestimates tend to balance out n As long as total run time is sufficiently large l Min run time ~1 second l 100 timer intervals n Consistently miss 4% overhead due to timer interrupts 15-213, F’02 – 11 –

Cycle Counters Cycle Counters n Most modern systems have built in registers that are incremented every clock cycle l Very fine grained l Maintained as part of process state » In Linux, counts elapsed global time n Special assembly code instruction to access n On (recent model) Intel machines: l 64 bit counter. l RDTSC instruction sets %edx to high order 32-bits, %eax to low order 32-bits 15-213, F’02 – 12 –

Cycle Counter Period Cycle Counter Period Wrap Around Times for 550 MHz machine Wrap Around Times for 550 MHz machine n Low order 32 bits wrap around every 2 32 / (550 * 10 6 ) = 7.8 seconds n High order 64 bits wrap around every 2 64 / (550 * 10 6 ) = 33539534679 seconds l 1065 years For 2 GHz machine For 2 GHz machine n Low order 32-bits every 2.1 seconds n High order 64 bits every 293 years 15-213, F’02 – 13 –

Measuring with Cycle Counter Measuring with Cycle Counter Idea Idea n Get current value of cycle counter l store as pair of unsigned’s cyc_hi and cyc_lo n Compute something n Get new value of cycle counter n 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-213, F’02 – 14 –

Accessing the Cycle Cntr. Accessing the Cycle Cntr. n GCC allows inline assembly code with mechanism for matching registers with program variables n Code only works on x86 machine compiling with GCC void access_counter(unsigned *hi, unsigned *lo) { /* Get cycle counter */ asm("rdtsc; movl %%edx,%0; movl %%eax,%1" : "=r" (*hi), "=r" (*lo) : /* No input */ : "%edx", "%eax"); } n Emit assembly with rdtsc and two movl instructions 15-213, F’02 – 15 –

Closer Look at Extended ASM Closer Look at Extended ASM void access_counter asm(Ò Instruction String " (unsigned *hi, unsigned *lo) : Output List { : Input List /* Get cycle counter */ : Clobbers List ); asm("rdtsc; movl %%edx,%0; movl %%eax,%1" } : "=r" (*hi), "=r" (*lo) : /* No input */ : "%edx", "%eax"); } Instruction String Instruction String n Series of assembly commands l Separated by “ ; ” or “ \n ” l Use “ %% ” where normally would use “ % ” 15-213, F’02 – 16 –

Closer Look at Extended ASM Closer Look at Extended ASM void access_counter asm(Ò Instruction String " (unsigned *hi, unsigned *lo) : Output List { : Input List /* Get cycle counter */ : Clobbers List ); asm("rdtsc; movl %%edx,%0; movl %%eax,%1" } : "=r" (*hi), "=r" (*lo) : /* No input */ : "%edx", "%eax"); } Output List Output List n Expressions indicating destinations for values %0 , %1 , …, % j l Enclosed in parentheses l Must be lvalue » Value that can appear on LHS of assignment n Tag "=r" indicates that symbolic value ( %0 , etc.), should be replaced by register 15-213, F’02 – 17 –

Closer Look at Extended ASM Closer Look at Extended ASM void access_counter asm(Ò Instruction String " (unsigned *hi, unsigned *lo) : Output List { : Input List /* Get cycle counter */ : Clobbers List ); asm("rdtsc; movl %%edx,%0; movl %%eax,%1" } : "=r" (*hi), "=r" (*lo) : /* No input */ : "%edx", "%eax"); } Input List Input List n Series of expressions indicating sources for values % j +1 , % j +2 , … l Enclosed in parentheses l Any expression returning value n Tag "r" indicates that symbolic value ( %0 , etc.) will come from register 15-213, F’02 – 18 –