Method and system for compensating for output overhead in trace date using trace record information

• US 6,598,012 B1
• Filed: 10/07/1999
• Issued: 07/22/2003
• Est. Priority Date: 10/07/1999
• Status: Expired due to Fees

• Current Assignee: International Business Machines Corporation
• Original Assignee: International Business Machines Corporation
• Inventors: Berry, Robert Francis, Levine, Frank Eliot, Hussain, Riaz Y., Urquhart, Robert J., Gordon, Jesse Mannes
• Primary Examiner(s): Hoff, Marc S.
• Assistant Examiner(s): Charioui, Mohamed
• Application Number:
  US09/414,344
• Time in Patent Office: 1,384 Days
• Field of Search: 702/119, 702/122, 702/123, 702/182, 702/183, 702/184, 702/185, 702/186, 702/176, 702/177, 702/178, 702/187, 702/188, 714/38, 714/45, 717/128, 717/130
• US Class Current: 702/187
• CPC Class Codes: G06F 11/3096 wherein the means or processing minimize the use of computing system or of computing system component resources, e.g. non-intrusive monitoring which minimizes the probe effect: sniffing, intercepting, indirectly deriving the monitored data from other directly available data
• CPC Class Codes: G06F 11/323 Visualisation of programs or trace data
• CPC Class Codes: G06F 11/3419 by assessing time
• CPC Class Codes: G06F 11/3466 Performance evaluation by tracing or monitoring
• CPC Class Codes: G06F 11/3476 Data logging G06F11/14, G06F11/2205 take precedence
• CPC Class Codes: G06F 2201/805 Real-time
• CPC Class Codes: G06F 2201/86 Event-based monitoring

Abstract

A method and system for compensating for output overhead in trace data is provided by analyzing and compensating for the overhead associated with outputting trace information to a trace buffer or a trace file in the form of trace records. A trace record represents an occurrence of some profiling event of interest. Each trace record contains a starting timestamp representing the time at which the generation of the trace record was commenced and an ending timestamp representing the time at which the generation of the trace record was completed. In order to compute the period of execution time attributable to the application program or system being profiled, a starting timestamp of a trace record is compared with the ending timestamp of a preceding trace record, and the difference between the timestamps is directly related to the execution time of the application program or system being profiled. The time period between the timestamps in a trace record is implicitly disregarded as attributable to overhead in the generation of trace records.

Claims

1. A method for processing trace data output in a data processing system, the method comprising the computer-implemented steps of:

reading a first timestamp and a second timestamp from a first trace record;

reading a third timestamp and a fourth timestamp from a second trace record; and

computing the difference between a time value associated with the first trace record and a time value associated with the second trace record to obtain a delta time.

2. The method of claim 1 wherein the first trace record represents an occurrence of a first event, and wherein the second trace record represents an occurrence of a second event that succeeds the first event.

3. The method of claim 2 wherein the first timestamp represents a time at which recording of the first event commenced and the second timestamp represents a time at which recording of the first event ended, and wherein the third timestamp represents a time at which recording of the second event commenced and the fourth timestamp represents a time at which recording of the second event ended.

4. The method of claim 1 further comprising:

attributing the delta time to a performance statistic for a routine whose execution caused a trace record to be generated.

5. The method of claim 1 wherein the first trace record and the second trace record are output during execution of a profiling process in the data processing system.

6. The method of claim 1 wherein the delta time is the difference between the third timestamp and the second timestamp.

7. The method of claim 1 further comprising:

adjusting the delta time in proportion to an amount of time required to obtain a timestamp.

8. The method of claim 1 further comprising:

adjusting a time value associated with the second timestamp in proportion to an amount of time required to obtain a timestamp.

9. The method of claim 1 wherein the trace records are generated by a trace card.

10. A data processing system for processing trace data output in the data processing system, the data processing system comprising:

first reading means for reading a first timestamp and a second timestamp from a first trace record;

second reading means for reading a third timestamp and a fourth timestamp from a second trace record; and

computing means for computing the difference between a time value associated with the first trace record and a time value associated with the second trace record to obtain a delta time.

11. The data processing system of claim 10 wherein the first trace record represents an occurrence of a first event, and wherein the second trace record represents an occurrence of a second event that succeeds the first event.

12. The data processing system of claim 11 wherein the first timestamp represents a time at which recording of the first event commenced and the second timestamp represents a time at which recording of the first event ended, and wherein the third timestamp represents a time at which recording of the second event commenced and the fourth timestamp represents a time at which recording of the second event ended.

13. The data processing system of claim 10 further comprising:

attributing means for attributing the delta time to a performance statistic for a routine whose execution caused a trace record to be generated.

14. The data processing system of claim 10 wherein the first trace record and the second trace record are output during execution of a profiling process in the data processing system.

15. The data processing system of claim 10 wherein the delta time is the difference between the third timestamp and the second timestamp.

16. The data processing system of claim 10 further comprising:

first adjusting means for adjusting the delta time in proportion to an amount of time required to obtain a timestamp.

17. The data processing system of claim 10 further comprising:

second adjusting means for adjusting a time value associated with the second timestamp in proportion to an amount of time required to obtain a timestamp.

18. The data processing system of claim 10 wherein the trace records are generated by a trace card.

19. A computer program product in a computer-readable medium for use in a data processing system for processing trace data output, the computer program product comprising:

first instructions for reading a first timestamp and a second timestamp from a first trace record;

second instructions for reading a third timestamp and a fourth timestamp from a second trace record; and

third instructions for computing the difference between a time value associated with the first trace record and a time value associated with the second trace record to obtain a delta time.

20. The computer program product of claim 19 wherein the first trace record represents an occurrence of a first event, and wherein the second trace record represents an occurrence of a second event that succeeds the first event.

21. The computer program product of claim 20 wherein the first timestamp represents a time at which recording of the first event commenced and the second timestamp represents a time at which recording of the first event ended, and wherein the third timestamp represents a time at which recording of the second event commenced and the fourth timestamp represents a time at which recording of the second event ended.

22. The computer program product of claim 19 further comprising:

instructions for attributing the delta time to a performance statistic for a routine whose execution caused a trace record to be generated.

23. The computer program product of claim 19 wherein the first trace record and the second trace record are output during execution of a profiling process in the data processing system.

24. The computer program product of claim 19 wherein the delta time is the difference between the third timestamp and the second timestamp.

25. The computer program product of claim 19 further comprising:

instructions for adjusting the delta time in proportion to an amount of time required to obtain a timestamp.

26. The computer program product of claim 19 further comprising:

instructions for adjusting a time value associated with the second timestamp in proportion to an amount of time required to obtain a timestamp.

27. The computer program product of claim 19 wherein the trace records are generated by a trace card.