Rev 1506 | Go to most recent revision | Blame | Compare with Previous | Last modification | View Log | RSS feed
This is an example file from "extract" utility,some comments are added to make it clearer.Jumpball demo (ecp) statisticsClk/msec = 651493 (CPU Pentium 3 - 650 MHz)EVT:Log starts at [ 56030135789]EVT:Log ends at [ 66409519772]Total dTSC [ 10379383983] us [ 15931689]Events [ 62210]Execs [ 53868]EndCycles [ 8317]Exec TSC sum = 10379383983 (100.00)Preemption Removing....Compute Task Statistics....Background Task CTX [ 0] PID [NODEF]Total Execution dTSC [ 329692] us [ 506]Mean CPU Bandwidth [ 0.003176%]after first exec [ 0.003176%]Execs Number [ 1]Min Exec dTSC [ 329692] us [ 506]Mean Exec dTSC [ 329692] us [ 506]Max Exec dTSC [ 329692] us [ 506]- Unknown context: this is the context running when the traceris enabled. Before the first context switch, the tracer doesn'tknow who is executing... 506 unkwnown microsecondsInterruptsTotal Execution dTSC [ 41464053] us [ 63644]Mean CPU Bandwidth [ 0.399485%]after first int [ 0.399497%]Interrupts Number [ 15114]Min Interrupt dTSC [ 606] us [ 0]Mean Interrupt dTSC [ 2743] us [ 4]Max Interrupt dTSC [ 17730] us [ 27]Min Arr. Delta dTSC [ 1386] us [ 2]Mean Arr. Delta dTSC [ 686759] us [ 1054]Max Arr. Delta dTSC [ 7667924] us [ 11769]- System Interrupts: All the hardware interruptsPeriodical Task CTX [ 256] PID [ 9]Total Execution dTSC [ 86633408] us [ 132976]Mean CPU Bandwidth [ 0.834668%]after first exec [ 1.155236%]Execs Number [ 4799]Min Exec dTSC [ 604] us [ 0]Mean Exec dTSC [ 18052] us [ 27]Max Exec dTSC [ 29466] us [ 45]Total Job Exec dTSC [ 86633408] us [ 132976]Jobs Number [ 1152]Min Job dTSC [ 74829] us [ 114]Mean Job dTSC [ 75202] us [ 115]Max Job dTSC [ 78716] us [ 120]Min Arr. Delta dTSC [ 6513566] us [ 9997]Mean Arr. Delta dTSC [ 6514935] us [ 10000]Max Arr. Delta dTSC [ 6515900] us [ 10001]- Task 9 "palla0": Soft Task. The CTX 256 was at the beginning assignedto the "main" task. After the task death, the context was free until thenew "palla0" task was created. "main" task context number is converted to1256 to make independent statistics.Background Task CTX [ 264] PID [ 1]Total Execution dTSC [ 9204161436] us [ 14127797]Mean CPU Bandwidth [ 88.677338%]after first exec [ 88.733345%]Execs Number [ 7194]Min Exec dTSC [ 1071] us [ 1]Mean Exec dTSC [ 1279421] us [ 1963]Max Exec dTSC [ 6438158] us [ 9882]- Task 1 "dummy": The dummy task, it represents the systemidle time, near 88% as mean valueBackground Task CTX [ 272] PID [ 2]Total Execution dTSC [ 2319] us [ 3]Mean CPU Bandwidth [ 0.000022%]after first exec [ 100.000000%]Execs Number [ 1]Min Exec dTSC [ 2319] us [ 3]Mean Exec dTSC [ 2319] us [ 3]Max Exec dTSC [ 2319] us [ 3]- Task 2 "shutdown task": Shutting down the system. It closesthe tracer too (this is the reason of only 3 us exec time).Periodical Task CTX [ 280] PID [ 3]Total Execution dTSC [ 1590194] us [ 2440]Mean CPU Bandwidth [ 0.015321%]after first exec [ 0.015349%]Execs Number [ 334]Min Exec dTSC [ 2864] us [ 4]Mean Exec dTSC [ 4761] us [ 7]Max Exec dTSC [ 12342] us [ 18]Total Job Exec dTSC [ 1590194] us [ 2440]Jobs Number [ 334]Min Job dTSC [ 2864] us [ 4]Mean Job dTSC [ 4761] us [ 7]Max Job dTSC [ 12342] us [ 18]Min Arr. Delta dTSC [ 152610] us [ 234]Mean Arr. Delta dTSC [ 31110745] us [ 47752]Max Arr. Delta dTSC [ 32575381] us [ 50001]- Task 3 "interrupt server": The interrupt contextPeriodical Task CTX [ 288] PID [ 4]Total Execution dTSC [ 217057] us [ 333]Mean CPU Bandwidth [ 0.002091%]after first exec [ 0.002894%]Execs Number [ 38]Min Exec dTSC [ 2107] us [ 3]Mean Exec dTSC [ 5712] us [ 8]Max Exec dTSC [ 22741] us [ 34]Total Job Exec dTSC [ 217057] us [ 333]Jobs Number [ 15]Min Job dTSC [ 4683] us [ 7]Mean Job dTSC [ 14470] us [ 22]Max Job dTSC [ 31155] us [ 47]Min Arr. Delta dTSC [ 67049248] us [ 102916]Mean Arr. Delta dTSC [ 535655892] us [ 822197]Max Arr. Delta dTSC [ 2822877293] us [ 4332935]- Task 4 "key task": The task for keyboard handlerPeriodical Task CTX [ 296] PID [ 5]Total Execution dTSC [ 441386657] us [ 677500]Mean CPU Bandwidth [ 4.252532%]after first exec [ 4.253727%]Execs Number [ 412]Min Exec dTSC [ 21950] us [ 33]Mean Exec dTSC [ 1071326] us [ 1644]Max Exec dTSC [ 2809349] us [ 4312]Total Job Exec dTSC [ 441386657] us [ 677500]Jobs Number [ 160]Min Job dTSC [ 2718736] us [ 4173]Mean Job dTSC [ 2758666] us [ 4234]Max Job dTSC [ 2809349] us [ 4312]Min Arr. Delta dTSC [ 65129432] us [ 99969]Mean Arr. Delta dTSC [ 65149346] us [ 100000]Max Arr. Delta dTSC [ 65169241] us [ 100030]- Task 5 "jetctrl" : Soft taskPeriodical Task CTX [ 304] PID [ 6]Total Execution dTSC [ 2724296] us [ 4181]Mean CPU Bandwidth [ 0.026247%]after first exec [ 0.026262%]Execs Number [ 320]Min Exec dTSC [ 2887] us [ 4]Mean Exec dTSC [ 8513] us [ 13]Max Exec dTSC [ 14244] us [ 21]Total Job Exec dTSC [ 2724296] us [ 4181]Jobs Number [ 160]Min Job dTSC [ 16496] us [ 25]Mean Job dTSC [ 17026] us [ 26]Max Job dTSC [ 20264] us [ 31]Min Arr. Delta dTSC [ 62335736] us [ 95681]Mean Arr. Delta dTSC [ 65131657] us [ 99972]Max Arr. Delta dTSC [ 67938661] us [ 104281]- Task 6 "jetdummy" : Soft TaskPeriodical Task CTX [ 312] PID [ 7]Total Execution dTSC [ 124817741] us [ 191587]Mean CPU Bandwidth [ 1.202554%]after first exec [ 1.203219%]Execs Number [ 363]Min Exec dTSC [ 12744] us [ 19]Mean Exec dTSC [ 343850] us [ 527]Max Exec dTSC [ 767572] us [ 1178]Total Job Exec dTSC [ 124817741] us [ 191587]Jobs Number [ 160]Min Job dTSC [ 778669] us [ 1195]Mean Job dTSC [ 780110] us [ 1197]Max Job dTSC [ 783045] us [ 1201]Min Arr. Delta dTSC [ 62314571] us [ 95648]Mean Arr. Delta dTSC [ 65131531] us [ 99972]Max Arr. Delta dTSC [ 67955583] us [ 104307]- Task 7 "jetslice": Soft TaskPeriodical Task CTX [ 320] PID [ 8]Total Execution dTSC [ 118468086] us [ 181840]Mean CPU Bandwidth [ 1.141379%]after first exec [ 1.141687%]Execs Number [ 4779]Min Exec dTSC [ 22161] us [ 34]Mean Exec dTSC [ 24789] us [ 38]Max Exec dTSC [ 35479] us [ 54]Total Job Exec dTSC [ 118468086] us [ 181840]Jobs Number [ 1593]Min Job dTSC [ 72879] us [ 111]Mean Job dTSC [ 74367] us [ 114]Max Job dTSC [ 86971] us [ 133]Min Arr. Delta dTSC [ 6509004] us [ 9990]Mean Arr. Delta dTSC [ 6514929] us [ 9999]Max Arr. Delta dTSC [ 6516186] us [ 10001]- Task 8 "pallaEDF": Hard TaskBackground Task CTX [ 1256] PID [ 0]Total Execution dTSC [ 2515575] us [ 3861]Mean CPU Bandwidth [ 0.024236%]after first exec [ 0.024237%]Execs Number [ 4]Min Exec dTSC [ 24256] us [ 37]Mean Exec dTSC [ 628893] us [ 965]Max Exec dTSC [ 1296253] us [ 1989]- Task 0 "main": Main task was killed, so the original contextnumber 256 became 1256Periodical Task CTX [ 328] PID [ 10]Total Execution dTSC [ 80067300] us [ 122898]Mean CPU Bandwidth [ 0.771407%]after first exec [ 1.145789%]Execs Number [ 4479]Min Exec dTSC [ 588] us [ 0]Mean Exec dTSC [ 17876] us [ 27]Max Exec dTSC [ 28734] us [ 44]Total Job Exec dTSC [ 80067300] us [ 122898]Jobs Number [ 1073]Min Job dTSC [ 74133] us [ 113]Mean Job dTSC [ 74620] us [ 114]Max Job dTSC [ 78837] us [ 121]Min Arr. Delta dTSC [ 3437857] us [ 5276]Mean Arr. Delta dTSC [ 6514935] us [ 10000]Max Arr. Delta dTSC [ 9593285] us [ 14725]- Task 10 "palla1": Soft TaskPeriodical Task CTX [ 336] PID [ 11]Total Execution dTSC [ 73395130] us [ 112656]Mean CPU Bandwidth [ 0.707124%]after first exec [ 1.145517%]Execs Number [ 4120]Min Exec dTSC [ 590] us [ 0]Mean Exec dTSC [ 17814] us [ 27]Max Exec dTSC [ 28349] us [ 43]Total Job Exec dTSC [ 73395130] us [ 112656]Jobs Number [ 984]Min Job dTSC [ 73933] us [ 113]Mean Job dTSC [ 74588] us [ 114]Max Job dTSC [ 79602] us [ 122]Min Arr. Delta dTSC [ 4602409] us [ 7064]Mean Arr. Delta dTSC [ 6514935] us [ 10000]Max Arr. Delta dTSC [ 8427197] us [ 12935]- Task 11 "palla2": Soft TaskPeriodical Task CTX [ 344] PID [ 12]Total Execution dTSC [ 67886363] us [ 104201]Mean CPU Bandwidth [ 0.654050%]after first exec [ 1.158283%]Execs Number [ 4482]Min Exec dTSC [ 584] us [ 0]Mean Exec dTSC [ 15146] us [ 23]Max Exec dTSC [ 29002] us [ 44]Total Job Exec dTSC [ 67886363] us [ 104201]Jobs Number [ 900]Min Job dTSC [ 74442] us [ 114]Mean Job dTSC [ 75429] us [ 115]Max Job dTSC [ 79661] us [ 122]Min Arr. Delta dTSC [ 3431395] us [ 5266]Mean Arr. Delta dTSC [ 6514935] us [ 10000]Max Arr. Delta dTSC [ 9598324] us [ 14732]- Task 12 "palla3": Soft TaskPeriodical Task CTX [ 352] PID [ 13]Total Execution dTSC [ 61391584] us [ 94232]Mean CPU Bandwidth [ 0.591476%]after first exec [ 1.153238%]Execs Number [ 3402]Min Exec dTSC [ 588] us [ 0]Mean Exec dTSC [ 18045] us [ 27]Max Exec dTSC [ 29668] us [ 45]Total Job Exec dTSC [ 61391584] us [ 94232]Jobs Number [ 818]Min Job dTSC [ 74694] us [ 114]Mean Job dTSC [ 75050] us [ 115]Max Job dTSC [ 78298] us [ 120]Min Arr. Delta dTSC [ 6513915] us [ 9998]Mean Arr. Delta dTSC [ 6514936] us [ 10000]Max Arr. Delta dTSC [ 6515731] us [ 10001]- Task 13 "palla4": Soft TaskPeriodical Task CTX [ 360] PID [ 14]Total Execution dTSC [ 39064984] us [ 59962]Mean CPU Bandwidth [ 0.376371%]after first exec [ 1.148329%]Execs Number [ 2176]Min Exec dTSC [ 588] us [ 0]Mean Exec dTSC [ 17952] us [ 27]Max Exec dTSC [ 27187] us [ 41]Total Job Exec dTSC [ 39064984] us [ 59962]Jobs Number [ 523]Min Job dTSC [ 74198] us [ 113]Mean Job dTSC [ 74694] us [ 114]Max Job dTSC [ 81677] us [ 125]Min Arr. Delta dTSC [ 6506703] us [ 9987]Mean Arr. Delta dTSC [ 6514934] us [ 10000]Max Arr. Delta dTSC [ 6523588] us [ 10013]- Task 14 "palla5": Soft TaskPeriodical Task CTX [ 368] PID [ 15]Total Execution dTSC [ 33250615] us [ 51037]Mean CPU Bandwidth [ 0.320352%]after first exec [ 1.147064%]Execs Number [ 1849]Min Exec dTSC [ 605] us [ 0]Mean Exec dTSC [ 17983] us [ 27]Max Exec dTSC [ 29733] us [ 45]Total Job Exec dTSC [ 33250615] us [ 51037]Jobs Number [ 445]Min Job dTSC [ 74441] us [ 114]Mean Job dTSC [ 74720] us [ 114]Max Job dTSC [ 78640] us [ 120]Min Arr. Delta dTSC [ 6513773] us [ 9998]Mean Arr. Delta dTSC [ 6514933] us [ 10000]Max Arr. Delta dTSC [ 6515594] us [ 10001]- Task 15 "palla6": Soft TaskBackground Task CTX [ 248] PID [NODEF]Total Execution dTSC [ 17493] us [ 26]Mean CPU Bandwidth [ 0.000169%]after first exec [ 63.226949%]Execs Number [ 1]Min Exec dTSC [ 17493] us [ 26]Mean Exec dTSC [ 17493] us [ 26]Max Exec dTSC [ 17493] us [ 26]- Global context: the kernel context