with Type_Definitions, Time_Library_1, Time_Library_2, Read_Log; with Report_Library, Clocks, Calendar, Text_Io; with Simple_Paginated_Output, String_Pkg, Dynarray_Pkg, Heap_Sort; with System; ------------------------ package body Profile_Pkg is ------------------------ use Type_Definitions; --| Global type declarations ----------------- procedure Profile ( --| Performance Analyzer report generator Log_File_Name : in Filename; --| The name of the log file Report_File_Name : in Filename --| The name of Output report file ) is --| Overview --| Profile is the Report Generator for the Ada Performance Analyzer --| Its purpose is to report execution timing and performance --| information about computer programs written in the Ada language that --| have been instrumented by the Ada Source Instrumenter. Execution data --| is dynamically recorded at runtime by the instrumented program in an --| Execution Log File (ELF). Profile reads the information recorded in --| the ELF and prepares a summarizes it in a meaningful format. --| --| The report file generated by Profile contains three reports: --| --| 1) Test Configuration Report --| This report includes information necessary to correlate the --| report with a specific test or execution of the target --| Ada program. Specifically, --| - the name of the program being analyzed --| - the date and time the log file was created --| - the name of the log file --| - the date and time the report was created --| - a test ID specified by the user --| --| 2) Net Execution Time Report --| This report includes the "net" time spent in each program unit. --| The time reported for each unit does not include time spent in --| other program units called by that unit if they have been --| instrumented by the Source Instrumenter. --| --| 3) Cumulative Execution Time Report --| This report includes the "cumulative" time spent in each program --| unit. The time reported for each unit includes all time spent in --| that unit and all other program units called by that unit whether --| or not the other program units have been instrumented by the --| Source Instrumenter. --| --| 4) Call Summary Report --| The Call Summary Report reports the the number of program --| units called by each unit executed. --| --| Each of the reports includes the following information about each --| program unit: --| --| 1) Compilation unit name --| --| 2) Program unit name --| --| 3) Program unit number - a unique ID assigned to each program unit --| by the Source Instrumenter to allow for overloaded procedure --| names. The same program unit number is printed in the listing --| file generated by the Source Instrumenter. --| --| 4) The program unit type: Procedure, Function, Task, or Generic. --| --| 5) The total number of times the unit was executed. --| --| 6) The maximum, minimum, and average execution times for --| a single execution of the unit --| --| 7) The total accumulated execution time for all executions --| of the unit. --| --| 8) The percentage of the program's total execution time --| spent in the unit. --| Requires --| Each Ada program unit about which information is to be recorded --| by ProfileM, the Performance Analyzer Runtime Monitor (RTM), and --| to be reported by ProfileR must have been instrumented by the Ada --| Source Instrumenter prior to compilation, linking, and execution. --| An Ada program unit is a procedure, function, task, or generic. --| N/A: Errors, Raises, Modifies -- Version : 0.20 -- Last Modified : 06/04/85 -- Author : Jeff England -- Initial Release : 02/08/85 package New_Float_Io is new Text_Io.Float_Io (Float); use Report_Library; --| Ada Testing and Analysis Tools use Simple_Paginated_Output; --| Output writer uses Text_IO use String_Pkg; --| String handling pkg for STRING_TYPEs use Read_Log; --| Performs all input from the Execution Log File --| for all Ada Testing and Analysis Tools use Calendar; --| Predefined library package for dates and times Tool_Version : constant String := "Profile 1.0 "; --| The tool version number is inserted in the report title --| and displayed at the user's console when Profile is executed Format_Options : Options --| Formatting options for reports := (80, --| Characters Per Line 60, --| Page size Profile_Tool, --| The tool name Tool_Version); --| The tool version number Report : Paginated_File_Handle; --| "handle" for output report Program_Name : Ada_Name; --| Name of program under test Test_Ident : Test_Identifier; --| Test ID assigned by user Test_Time : Time; --| Time and date of test Report_Line : String_Pkg.String_Type; Overhead_Time : Calendar.Day_Duration := 0.00; Blank_Line : constant String (1 .. 80) := (1 .. 80 => ' '); Dashes : constant String (1 .. 80) := (1 .. 80 => '-'); type Sort_Keys is ( --| Specifies the sort order for reports Total_Execution_Time, --| for Total Execution Times Report Unit_Name --| for Net and Cumulative Execution Times Report --| and Call Summary Report ); type Time_Clocks is record Accum_Time : Day_Duration; --| Total cumulative time (all execs) Max_Time : Day_Duration; --| Maximum execution time (1 exec) Min_Time : Day_Duration; --| Minimum execution time (1 exec) Error : String (1 .. 2); --| Expected error in reported times end record; type Unit_Clocks is record --| records execution time for each unit Unit_Id : Program_Unit_Unique_Identifier; Nest : Natural; --| nesting level (recursion) Max_Nest : Natural; --| maximum nesting level (recursion) Execs : Natural; --| the number of times a executed Last_Start : Time; --| last time this unit started Sons : Natural; --| number of calls made by this unit Grandsons : Natural; --| number of calls made by sons Clock_Fault : Boolean; --| indicates a clock fault occured Dangling_Unit : Boolean; --| indicates whether execution ended Net_Clock : Time_Clocks; --| net time spent in this unit Cum_Clock : Time_Clocks; --| cum time spent in this unit end record; subtype Unit_Nums is Natural; package Program_Clocks is new Dynarray_Pkg (Unit_Clocks); Program_Clock : Program_Clocks.Darray; --| The program clock is a dynamic array containing a --| separate Unit_Clock for each Ada program unit Program_Start_Time : Calendar.Time; --| Time of first "Entering_Unit" Last_Time : Calendar.Time; --| Time of last "Exiting_Unit" Total_Time : Day_Duration; --| Total program execution time Number_Of_Units : Unit_Nums := 0; --| Total number of Ada program units Error : String (1 .. 2); --| Expected error in reported times Percent : String (1 .. 2); --| Percent of total execution time ------------------------ procedure Get_Unit_Clock ( --| Gets the Unit_Clock and the Program_Clock --| Array index of the Unit_ID Unit_Id : in Program_Unit_Unique_Identifier; --| A unique ID assigned by the source instrumenter Program_Clock : in out Program_Clocks.Darray; --| A dynamic array with Net and Cum times for all units Unit_Clock : in out Unit_Clocks; --| The unit clock for Unit_ID Unit_Num : out Unit_Nums --| The array index into Program_Clock ) is --| Effects --| Searches the Program_Clock array for the Unit_Clock assigned to --| Unit_ID. If a match is found then then the Unit_Clock and the --| array index of Unit_Clock, Unit_Num, are returned. If no match --| is found, i.e., this is the first occurrence of Unit_ID, then --| a new Unit_Clock is created and added to the Program_Clock array. --| The new Unit_Clock and the new Array_Index are then returned to --| the calling program. --| Requires --| The Program_Clock array must have been previously created by the --| calling program. --| Modifies --| If the Unit_Clock corresponding to Unit_ID is not arready in --| the Program_Clock array, then it is added to the array and --| Number_of_Units is incremented by 1. --| N/A: Raises, Errors use Program_Clocks; --| for Fetch, Equal, and Add_High Found : Boolean := False; begin --| Search the Program_Clock array for the Unit_Clock --| corresponding to this Unit_ID for Array_Index in 1 .. Length (Program_Clock) loop exit when Found; Unit_Clock := Fetch (Program_Clock, Array_Index); if Equal (Unit_Clock.Unit_Id.Enclosing_Unit_Identifier, Unit_Id.Enclosing_Unit_Identifier) and Unit_Clock.Unit_Id.Program_Unit_Number = Unit_Id.Program_Unit_Number then Found := True; Unit_Num := Array_Index; end if; end loop; if not Found then --| Start a new clock for this unit Unit_Clock.Unit_Id := Unit_Id; Unit_Clock.Nest := 0; Unit_Clock.Max_Nest := 0; Unit_Clock.Execs := 0; Unit_Clock.Sons := 0; Unit_Clock.Grandsons := 0; Unit_Clock.Clock_Fault := False; Unit_Clock.Dangling_Unit := False; Unit_Clock.Net_Clock.Accum_Time := 0.0; Unit_Clock.Net_Clock.Max_Time := 0.0; Unit_Clock.Net_Clock.Min_Time := 86399.0; Unit_Clock.Net_Clock.Error := " "; Unit_Clock.Cum_Clock.Accum_Time := 0.0; Unit_Clock.Cum_Clock.Max_Time := 0.0; Unit_Clock.Cum_Clock.Min_Time := 86399.0; Unit_Clock.Cum_Clock.Error := " "; --| Add the new Unit_Clock to the Program_Clock array Add_High (Program_Clock, Unit_Clock); --| Set the unit number for new unit clock Unit_Num := Length (Program_Clock); end if; end Get_Unit_Clock; ------------------------------ procedure Update_Current_Clock ( --| Updates the unit clock for the --| currently terminating unit Current : in Clocks.Unit_Start_Times; --| Starting time and stop watch for the current unit Stop_Time : in Calendar.Time; --| The ending time for this unit Current_Unit_Clock : in out Unit_Clocks --| The unit clock for Unit_ID ) is --| Effects --| This procedure updates the unit clock for the currently --| terminating program unit. Net and cumulative --| execution times for the current execution of the --| unit is added to the accumulated net and cumulative execution --| times for all executions of the unit. The net and cumulative --| execution times for the current execution of the unit are --| compared to the maximum and minimum times for all executions --| of the unit and the program clock is updated with the overall --| maximum and minimum times. In addition, the terminating unit's --| sons and grandsons are added to total accumulated sons and --| grandsons for all executions of the unit --| Modifies --| The unit clock for the current unit is updated with the current --| times. The Program_Clock array is not modified. --| N/A: Raises, Requires, Errors use Time_Library_2; --| for Maximum, Minimum use Calendar; --| for "+" and "-" of times and durations use Clocks; --| for MORE_UNITS Elapsed_Time : Calendar.Day_Duration; Net_Time : Calendar.Day_Duration; Previous : Clocks.Unit_Start_Times; --| Previous unit starting time begin --| Calculate the elapsed execution time for the current unit Elapsed_Time := Stop_Time - Current.Start_Time; --| Update the cum clock for the current unit. If the current --| unit is the same as the previous unit then the unit is --| recursive and its accumulated cum time should not be --| updated until the top level exits. if More_Units then Previous := Previous_Unit; if Current.Unit_Num /= Previous.Unit_Num then Current_Unit_Clock.Cum_Clock.Accum_Time := Current_Unit_Clock.Cum_Clock.Accum_Time + Elapsed_Time; end if; else Current_Unit_Clock.Cum_Clock.Accum_Time := Current_Unit_Clock.Cum_Clock.Accum_Time + Elapsed_Time; end if; Current_Unit_Clock.Cum_Clock.Max_Time := Maximum (Current_Unit_Clock.Cum_Clock.Max_Time, Elapsed_Time); Current_Unit_Clock.Cum_Clock.Min_Time := Minimum (Current_Unit_Clock.Cum_Clock.Min_Time, Elapsed_Time); --| Update the net clock for the current unit if Current_Unit_Clock.Unit_Id.Unit_Type = Task_Type then Net_Time := Stop_Time - Current.Start_Time; else Net_Time := Stop_Time - Current_Unit_Clock.Last_Start + Current.Stop_Watch; end if; Current_Unit_Clock.Net_Clock.Accum_Time := Current_Unit_Clock.Net_Clock.Accum_Time + Net_Time; Current_Unit_Clock.Net_Clock.Max_Time := Maximum (Current_Unit_Clock.Net_Clock.Max_Time, Net_Time); Current_Unit_Clock.Net_Clock.Min_Time := Minimum (Current_Unit_Clock.Net_Clock.Min_Time, Net_Time); --| Update the offspring for this unit Current_Unit_Clock.Sons := Current_Unit_Clock.Sons + Current.Sons; Current_Unit_Clock.Grandsons := Current_Unit_Clock.Grandsons + Current.Grandsons; end Update_Current_Clock; ----------------------- procedure Read_Log_File ( --| Read and process the log file data Program_Clock : in out Program_Clocks.Darray; --| A dynamic array with Net and Cum times for all units Number_Of_Units : out Unit_Nums; --| Total number of program units Total_Time : out Day_Duration --| Total program execution time ) is --| Effects --| Reads the timing and execution data stored in the log file. --| Only Unit_Start and Unit_Stop log file keys are processed --| by Profile. Breakpoints, and variable trace keys are ignored. --| Unit_ID's are stored in a dynamic array and assigned a unit --| number by the package Log_In. The unit number is also used --| as an index into the Program_Clock for storing the Net and --| cumulative execution times for each unit. --| Algorithm --| When a new unit begins execution: --| - push starting time onto stack --| - stop net clock for calling unit --| - start net clock for this unit --| When a unit ends execution: --| - stop net clock for this unit --| - calculate max and min net times for all executions of this unit --| - add net time for current execution to the accumulated --| net time for all executions of this unit --| - pop starting time from the stack --| - calculate cum execution time ( Stop_Time - Start_Time ) --| - calculate max and min cum times for all executions of this unit --| - add cum time for current execution to the accumulated --| cum time for all executions of this unit --| N/A: Raises, Requires, Modifies, Errors use Clocks; use Program_Clocks; --| for Create, Store Program_Started : Boolean := False; Key : Logfile_Keys; Unit_Num : Unit_Nums; Unit_Id : Program_Unit_Unique_Identifier; Start_Time : Calendar.Time; Stop_Time : Calendar.Time; Elapsed_Time : Calendar.Day_Duration; Time_Of_Day : Calendar.Day_Duration; Twenty_Four_Hours : constant Calendar.Day_Duration := 86400.00; Time_Zero : Calendar.Day_Duration := 0.0; Unit_Clock : Unit_Clocks; Current_Unit_Clock : Unit_Clocks; Previous_Unit_Clock : Unit_Clocks; Current : Unit_Start_Times; Previous : Unit_Start_Times; Clock_Fault : Boolean; First_Unit : Boolean; Test_Date : Time; --| This is initially set to the time of the --| test with 0.00 seconds. If the test --| begins on one day and ends on another --| Test_Date is incremented by 24 hours. begin --| Create the dynamic clock structures for unit starting times Create_Clocks; --| Create a dynamic array of unit clocks to keep track of time --| for each Ada program unit Create (1, 20, --| Start with elements 1..20. 100, --| 100% of Add's are at high end of array. 20, --| Expand the array by 20% when necessary. Program_Clock); --| The name of the array is Program_Clock. --| Establish the date of the test. This date will be incremented --| if a new time is less than the last recorded time, indicating --| that execution of the target test program began before midnight --| and ended after midnight. Test_Date := Test_Time - Seconds (Test_Time); Last_Time := Test_Time; while not End_Of_Log loop Get_Next_Key (Key); case Key is --------------- when Unit_Start => Get_Unit_Time (Unit_Id, Time_Of_Day); Start_Time := Test_Date + Time_Of_Day; if Start_Time < Last_Time then Test_Date := Test_Date + Twenty_Four_Hours; -- It's a new day Start_Time := Test_Date + Time_Of_Day; end if; if not Program_Started then Program_Start_Time := Start_Time; Program_Started := True; end if; Last_Time := Start_Time; Get_Unit_Clock (Unit_Id, Program_Clock, Current_Unit_Clock, Unit_Num); Current := (Unit_Num, Start_Time, Time_Zero, 0, 0); Current_Unit_Clock.Nest := Current_Unit_Clock.Nest + 1; if Current_Unit_Clock.Nest > Current_Unit_Clock.Max_Nest then Current_Unit_Clock.Max_Nest := Current_Unit_Clock.Nest; end if; Current_Unit_Clock.Execs := Current_Unit_Clock.Execs + 1; --| If the current unit is not a task then stop the net clock --| for the previous unit if Unit_Id.Unit_Type /= Task_Type and More_Units then Pause_Unit (Previous); Previous_Unit_Clock := Fetch (Program_Clock, Previous.Unit_Num); Elapsed_Time := Start_Time - Previous_Unit_Clock.Last_Start; Previous.Stop_Watch := Previous.Stop_Watch + Elapsed_Time; Previous.Sons := Previous.Sons + 1; Restart_Unit (Previous); --| It is possible that the current unit has been called by --| a task and that the previous unit has not really --| stopped executing. If this is the case, then the current --| unit will terminate out of sequence and generate a clock --| fault. To insure that the net clock for the previous unit --| is updated properly if a clock fault occurs, Last_Start --| for the previous unit must be updated to the current time. Previous_Unit_Clock.Last_Start := Start_Time; Store (Program_Clock, Previous.Unit_Num, Previous_Unit_Clock); end if; --| Start the net clock for the current unit Current_Unit_Clock.Last_Start := Start_Time; Store (Program_Clock, Current.Unit_Num, Current_Unit_Clock); Start_Unit (Unit_Id, Current); -------------- when Unit_Stop => Get_Unit_Time (Unit_Id, Time_Of_Day); Stop_Time := Test_Date + Time_Of_Day; if Stop_Time < Last_Time then Test_Date := Test_Date + Twenty_Four_Hours; -- It's a new day Stop_Time := Test_Date + Time_Of_Day; end if; Last_Time := Stop_Time; Get_Unit_Clock (Unit_Id, Program_Clock, Current_Unit_Clock, Unit_Num); Current_Unit_Clock.Nest := Current_Unit_Clock.Nest - 1; Stop_Unit (Unit_Num, Unit_Id, Current, Clock_Fault); --| Check to see if a clock fault occurred. If so, then --| clear the fault and set the clock fault flag for all --| non-task program units that were activated after the --| unit in which the fault occurred. if Clock_Fault then Current_Unit_Clock.Clock_Fault := True; while More_Clock_Faults loop Unit_Num := Next_Clock_Fault; Unit_Clock := Fetch (Program_Clock, Unit_Num); Unit_Clock.Clock_Fault := True; Store (Program_Clock, Unit_Num, Unit_Clock); end loop; end if; --| If a clock fault did not occur and the terminating unit is --| not a task then restart the net clock for the previous unit if not Clock_Fault and Unit_Id.Unit_Type /= Task_Type then if More_Units then Pause_Unit (Previous); Previous_Unit_Clock := Fetch (Program_Clock, Previous.Unit_Num); Previous_Unit_Clock.Last_Start := Stop_Time; Store (Program_Clock, Previous.Unit_Num, Previous_Unit_Clock); Previous.Grandsons := Previous.Grandsons + Current.Grandsons + Current.Sons; Restart_Unit (Previous); end if; end if; --| Update Max, Min, and accumulated net and cum times --| for the current program unit Update_Current_Clock (Current, Stop_Time, Current_Unit_Clock); Store (Program_Clock, Current.Unit_Num, Current_Unit_Clock); -------------------- when Timing_Overhead => Overhead_Time := Accumulated_Overhead; ----------- when others => Flush_Logfile_Record (Key); end case; end loop; --| Check to see if there are any unterminated (dangling) program units --| left in the dynamic clock structures. If so, they must be terminated --| and their clocks must be updated. Any tasks that are left in the --| structure are assumed to still be active and are terminated as of --| the last time recorded. For non-task program units, only the last --| unit started is assumed to still be active. Other program units --| must be "restarted" instantaneously as of the last time recorded --| and then stopped again at the same time. This will force the net --| clock to be updated properly with only the time remaining on --| Current.Stop_Watch. First_Unit := True; while More_Tasks or More_Units loop if More_Tasks then Current := Dangling_Task; else Current := Dangling_Unit; end if; Current_Unit_Clock := Fetch (Program_Clock, Current.Unit_Num); if Current_Unit_Clock.Unit_Id.Unit_Type /= Task_Type and not First_Unit then Current_Unit_Clock.Last_Start := Last_Time; end if; Update_Current_Clock (Current, Last_Time, Current_Unit_Clock); Current_Unit_Clock.Dangling_Unit := True; Store (Program_Clock, Current.Unit_Num, Current_Unit_Clock); if Current_Unit_Clock.Unit_Id.Unit_Type /= Task_Type then First_Unit := False; end if; end loop; --| Calculate total program execution time Total_Time := Last_Time - Program_Start_Time; --| The dynamic clock structures are no longer needed. Destroy them. Clocks.Destroy_Clocks; --| Calculate the total number of program units Number_Of_Units := Length (Program_Clock); end Read_Log_File; -------------- procedure Sort ( --| Sort the Program Clock Array Program_Clock : in out Program_Clocks.Darray; Size : in Natural; Sort_Key : in Sort_Keys) is --| Effects --| This procedure sorts the Program Clock dynamic array. The --| array is sorted by cumulative times in descending order. --| If Sort_Key = Total_Execution_Time then the array is sorted in --| descending order by total accumulated cumulative execution time. --| If Sort_Key = Unit_Name then the array is sorted in Ascending --| order by program unit name, compilation unit name, and program --| unit number. --| Modifies --| The elements of Program_Clock are reordered according to the --| specified sort key. --| N/A: Raises, Requires, Errors use Program_Clocks; type Times is array (Integer range <>) of Unit_Clocks; Execution_Times : Times (1 .. Size); -------------- function Order ( --| Return true if Left <= Right in specified order Left : in Unit_Clocks; Right : in Unit_Clocks) return Boolean is --| Effects --| Returns true if the Left element is precedes the right element --| in the desired sort order. This procedure provides the "<=" --| function used by the generic procedure Heap_Sort. --| --| When the sort key is Total_Execution_Time then the order is --| 1) Total accumulated cumulative execution time - descending --| 2) Program unit name (fully qualified) - ascending --| 3) Program unit number - ascending --| When the sort key is Unit_Name then the order is --| 1) Program unit name (fully qualified) - ascending --| 2) Program unit number - ascending --| 3) Total accumulated cumulative execution time - descending --| N/A: Raises, Requires, Modifies, Errors use Calendar; --| for ">=" Left_Name : Ada_Name; --| Temporary variable for program unit name Right_Name : Ada_Name; --| Temporary variable for program unit name begin case Sort_Key is when Total_Execution_Time => if Left.Cum_Clock.Accum_Time = Right.Cum_Clock.Accum_Time then Find_Unit_Name (Left.Unit_Id, Left_Name); Find_Unit_Name (Right.Unit_Id, Right_Name); if Value (Left_Name) = Value (Right_Name) then return Left.Unit_Id.Program_Unit_Number <= Right.Unit_Id.Program_Unit_Number; else return Value (Left_Name) <= Value (Right_Name); end if; else return Left.Cum_Clock.Accum_Time >= Right.Cum_Clock.Accum_Time; end if; when Unit_Name => Find_Unit_Name (Left.Unit_Id, Left_Name); Find_Unit_Name (Right.Unit_Id, Right_Name); if Value (Left_Name) = Value (Right_Name) then return Left.Unit_Id.Program_Unit_Number <= Right.Unit_Id.Program_Unit_Number; else return Value (Left_Name) <= Value (Right_Name); end if; end case; end Order; procedure Sort is new Heap_Sort (Unit_Clocks, Order, Integer, Times); ------------- begin -- Sort --| Build an array of accumulated times and Program_Clock --| dynamic array indices. for I in Execution_Times'Range loop Execution_Times (I) := Fetch (Program_Clock, I); end loop; Sort (Execution_Times); --| Sort the array in descending order --| Reorder the elements of Program_Clock to correspond to the new --| ordering of array indices. for I in Execution_Times'Range loop Store (Program_Clock, I, Execution_Times (I)); end loop; end Sort; ---------------------------------- procedure Calculate_Expected_Error ( --| Calculate Expected error in --| recorded times Program_Clock : in out Program_Clocks.Darray; --| A dynamic array with net and cum times for all units Number_Of_Units : in Unit_Nums --| The total number of program units ) is --| Effects --| --| This procedure calculates an expected error in the recorded --| time for a program unit as a percentage of both "net" and --| "cum"execution times for each program unit in the --| program clock array. Expected errors are stored as two --| character strings in the appropriate unit clock for each --| program unit for later use by the report generation procedures. --| --| If no faults occurred then an expected error in the range 0..99 --| is calculated as a function of the number of times a unit executed --| its execution time as a percentage of total program execution --| time, and the total number of clock periods the program under test --| executed. --| Errors --| If a clock fault occurred during execution of a program unit or --| if the program unit did not terminate normally, then it is not --| possible to calculate an expected error. When this occurs then --| flags are inserted into the expected error to indicate which --| fault occurred. A " C" indicates a clock fault occurred. A " D" --| indicates the unit was a "dangling" unit, i.e., it did not --| terminate normally. A "CD" indicates that both faults occurred. --| Modifies --| Program_Clock.Net_Clock.Error and Program_Clock.Net_Clock.Error --| are set to the appropriate expected error. --| N/A: Raises, Errors, use Program_Clocks; --| for Fetch and Store use Time_Library_2; --| for Minimum and Maximum Unit_Clock : Unit_Clocks; Max_Error : Natural; Error : Integer range 0 .. 130; type Errors is record Percent_Of_Total : Float range 0.0 .. 100.0; Fifty_Periods : Integer range 0 .. 130; One_Hundred_Periods : Integer range 0 .. 73; Five_Hundred_Periods : Integer range 0 .. 50; Five_Thousand_Periods : Integer range 0 .. 20; end record; type Expected_Errors is array (1 .. 31) of Errors; Expected_Error : Expected_Errors := ((1.0, 130, 73, 50, 20), (2.0, 82, 52, 27, 11), (3.0, 54, 46, 17, 8), (4.0, 47, 40, 13, 7), (5.0, 43, 35, 11, 6), (6.0, 41, 31, 10, 5), (7.0, 38, 28, 9, 4), (8.0, 36, 26, 9, 4), (9.0, 34, 25, 8, 3), (10.0, 32, 23, 8, 3), (11.0, 31, 22, 8, 3), (12.0, 30, 20, 7, 3), (13.0, 28, 18, 7, 3), (14.0, 27, 17, 7, 2), (15.0, 26, 16, 6, 2), (16.0, 24, 15, 6, 2), (17.0, 23, 13, 6, 2), (18.0, 22, 12, 6, 2), (19.0, 21, 11, 5, 2), (20.0, 20, 10, 5, 2), (25.0, 17, 8, 5, 2), (30.0, 14, 7, 4, 2), (35.0, 12, 6, 4, 2), (40.0, 11, 6, 4, 2), (45.0, 10, 6, 3, 2), (50.0, 8, 5, 3, 1), (60.0, 8, 5, 3, 1), (70.0, 7, 5, 2, 1), (80.0, 7, 5, 2, 1), (90.0, 6, 5, 1, 1), (100.0, 6, 4, 1, 1)); Error_Range : Integer range Expected_Error'Range; Total_Program_Time : Float; --| Total program execution time Percent_Of_Total : Float; --| Percent of total program execution time Clock_Tick : Float; --| System.Tick converted to float Periods : Natural; --| Number of clock periods program executed ------------------------- function Percent_Of_Error ( --| Return Expected error as a percent --| of program unit execution time Activations : in Natural; --| Number of times a unit was activated Unit_Time : in Calendar.Day_Duration --| Total unit execution time ) return String is --| Effects --| This function performs a table lookup if the expected error --| in the recorded total execution time for a program unit. --| have been calculated as a function of: --| --| 1) total program execution time --| 2) total program unit execution time --| 3) the number of times the program unit executed --| 4) the number of clock periods the test program executed --| N/A: Raises, Modifies, Errors Execution_Time : Float; --| Program unit execution time begin -- Percent_of_Error if Total_Program_Time = 0.0 or Unit_Time = 0.0 or Activations = 0 then return "**"; else Execution_Time := Float (Unit_Time); Percent_Of_Total := Execution_Time / Total_Program_Time * 100.0; --| The maximum possible error is equal to the basic clock period --| times the number of times the unit executed Max_Error := Integer ((Float (Activations) * Clock_Tick * 100.0) / Execution_Time); Error_Range := Expected_Error'Last; for I in 1 .. Expected_Error'Last - 1 loop if Percent_Of_Total < (Expected_Error (I).Percent_Of_Total + Expected_Error (I + 1).Percent_Of_Total) / 2.0 then Error_Range := I; exit; end if; end loop; case Periods is when 5000 => Error := Expected_Error (Error_Range). Five_Thousand_Periods; when 500 => Error := Expected_Error (Error_Range). Five_Hundred_Periods; when 100 => Error := Expected_Error (Error_Range). One_Hundred_Periods; when others => Error := Expected_Error (Error_Range).Fifty_Periods; end case; --| The calculated error cannot be greater than Max_Error. --| If it is then adjust it. if Error > Max_Error then Error := Max_Error; end if; --| Do not return a string greater than 2 characters if Error >= 100 then return "**"; else return String_Of (Error, 2); end if; end if; end Percent_Of_Error; begin -- Calculate_Expected_Error --| To simplify mathematical calculations, total program execution --| time and System.Tick are converted to floating point types. Total_Program_Time := Float (Total_Time); --| Total program execution time Clock_Tick := Float (System.Tick); --| Calculate the number of clock periods in total program execution --| time and then normalize Periods to 50, 100, 500 or 5000 Periods := Integer (Total_Program_Time / Clock_Tick); if Periods in 0 .. 74 then Periods := 50; elsif Periods in 75 .. 299 then Periods := 100; elsif Periods in 300 .. 2749 then Periods := 500; else Periods := 5000; end if; for Unit_Num in 1 .. Number_Of_Units loop --| Fetch the appropriate unit clock from the program clock array Unit_Clock := Fetch (Program_Clock, Unit_Num); --| Never happens: --| --| 1. MAXIMUM times can never be = zero if ACCUMULATED time is > zero --| 2. MAXIMIM times can never be > than ACCUMULATED times --| 3. MINIMUM times can never be > than MAXIMUM times --| 4. NET times can never be > than CUM times --| --| If any of these conditions exists due to round off errors --| then the times must be adjusted if Unit_Clock.Net_Clock.Accum_Time > 0.00 then Unit_Clock.Net_Clock.Max_Time := Maximum (Unit_Clock.Net_Clock.Max_Time, 0.01); Unit_Clock.Cum_Clock.Max_Time := Maximum (Unit_Clock.Cum_Clock.Max_Time, 0.01); end if; Unit_Clock.Net_Clock.Max_Time := Minimum (Unit_Clock.Net_Clock.Max_Time, Unit_Clock.Net_Clock.Accum_Time); Unit_Clock.Cum_Clock.Max_Time := Minimum (Unit_Clock.Cum_Clock.Max_Time, Unit_Clock.Cum_Clock.Accum_Time); Unit_Clock.Net_Clock.Min_Time := Minimum (Unit_Clock.Net_Clock.Min_Time, Unit_Clock.Net_Clock.Max_Time); Unit_Clock.Cum_Clock.Min_Time := Minimum (Unit_Clock.Cum_Clock.Min_Time, Unit_Clock.Cum_Clock.Max_Time); Unit_Clock.Net_Clock.Accum_Time := Minimum (Unit_Clock.Net_Clock.Accum_Time, Unit_Clock.Cum_Clock.Accum_Time); Unit_Clock.Net_Clock.Min_Time := Minimum (Unit_Clock.Net_Clock.Min_Time, Unit_Clock.Cum_Clock.Min_Time); Unit_Clock.Net_Clock.Max_Time := Minimum (Unit_Clock.Net_Clock.Max_Time, Unit_Clock.Cum_Clock.Max_Time); --| Check to see if a clock fault occurred during execution of --| this unit. If so, insert a "C" into the expecred error --| for both the net and cum clocks. if Unit_Clock.Clock_Fault then Unit_Clock.Net_Clock.Error (1) := 'C'; Unit_Clock.Cum_Clock.Error (1) := 'C'; end if; --| Check to see if a this unit was left dangling at program --| termination. If so, insert a "D" into the expected error --| for both the net and cum clocks. if Unit_Clock.Dangling_Unit then Unit_Clock.Net_Clock.Error (2) := 'D'; Unit_Clock.Cum_Clock.Error (2) := 'D'; end if; --| If no faults occurred then calculate an expected error in --| the range 0..99 as a function of the number of times the unit --| executed, the unit's execution time as a percentage of --| total program execution time, and the total number of clock --| periods the program under test executed. if not Unit_Clock.Clock_Fault and not Unit_Clock.Dangling_Unit then Unit_Clock.Net_Clock.Error := Percent_Of_Error (Unit_Clock.Execs + Unit_Clock.Sons, Unit_Clock.Net_Clock.Accum_Time); Unit_Clock.Cum_Clock.Error := Percent_Of_Error (Unit_Clock.Execs, Unit_Clock.Cum_Clock.Accum_Time); end if; --| Pretty it up a bit. If the confidence level contains only --| one character then right justify it. if Unit_Clock.Net_Clock.Error (2) = ' ' then Unit_Clock.Net_Clock.Error := " " & Unit_Clock.Net_Clock.Error (1 .. 1); Unit_Clock.Cum_Clock.Error := Unit_Clock.Net_Clock.Error; end if; --| Put the updated clock back into the array Store (Program_Clock, Unit_Num, Unit_Clock); end loop; end Calculate_Expected_Error; ------------------------ function New_Report_Line ( --| Create a new report line Unit_Id : in Program_Unit_Unique_Identifier --| Program unit for this line ) return String_Type is Report_Line : String_Type; Unit_Name : Ada_Name; Program_Unit_Number : String (1 .. 3); --| Effects --| Starts a new report line. Each of the execution reports --| begins with the same information in the same report columns. --| This function starts a new report line that contains the --| following information: --| --| 1) Col 1-29: Fully qualified Program Unit Name --| 2) Col 31-33: Program Unit Number --| N/A: Raises, Requires, Modifies, Errors Index : Positive; begin --| Start a new report line Report_Line := Create (Blank_Line); --| Get the program unit name from Read_Log Find_Unit_Name (Unit_Id, Unit_Name); --| If the program unit name is longer than the report --| field, 29 characters, then output pieces of it until --| it fits within the field while Length (Unit_Name) > 29 loop --| If the current section of the name is qualified then break --| the name at the last qualifier. Otherwise break it after --| the 29th character for I in reverse 1 .. 29 loop Index := I; exit when Fetch (Unit_Name, I) = '.'; end loop; if Index = 1 then Index := 29; end if; --| Insert the first section of characters Report_Line := Replace (Report_Line, Substr (Unit_Name, 1, Index), 1); --| Output the current line Put_Line (Report, Report_Line); --| Start a new line Report_Line := Create (Blank_Line); --| Indent the remainder of the name 2 spcaes Unit_Name := " " & Substr (Unit_Name, Index + 1, Length (Unit_Name) - Index); end loop; --| Insert the program unit name at character position 1 Report_Line := Replace (Report_Line, Unit_Name, 1); --| Get the program unit number from the unit ID and convert --| it to a string of length 3 Program_Unit_Number := String_Of (Unit_Id.Program_Unit_Number, 3); --| Put leading zeros on the program unit number to pretty it up for Digit in 1 .. 3 loop if Program_Unit_Number (Digit) = ' ' then Program_Unit_Number (Digit) := '0'; end if; end loop; --| Insert the program unit into character position 31 Report_Line := Replace (Report_Line, Program_Unit_Number, 31); return Report_Line; end New_Report_Line; ------------------------- function Percent_Of_Total ( --| Return the percent of total execution time Total_Time : in Day_Duration; --| Total Execution time for the program Partial_Time : in Day_Duration --| Total Execution time for the program unit ) return String is --| Effects --| Returns ( Partial_Time / Total_Time ) * 100. The percentage is --| returned a two character string. --| If Percent in 0.0..94.99 then returns "nn" where nn is the percentage --| If Percent in 95.0 .. 99.99 then returns " *" --| If Percent >= 100.0 then returns "**" --| N/A: Raises, Modifies, Errors Percent : Float; Pct : Integer; begin if Partial_Time = 0.0 then return " 0"; else Percent := Float (Partial_Time) / Float (Total_Time) * 100.0; if Percent >= 95.50 and Percent <= 100.00 then return " *"; elsif Percent < 95.50 then return String_Of (Integer (Percent), 2); else return "**"; end if; end if; end Percent_Of_Total; ------------------------------------- procedure Print_Total_Execution_Times ( --| Print Total Execution Time Report Program_Clock : in Program_Clocks.Darray; --| A dynamic array with Net and Cum times for all units Number_Of_Units : in Unit_Nums; --| Total number of program units Total_Time : in Day_Duration --| Total program execution time ) is use Program_Clocks; --| for Fetch use Time_Library_1; --| for Wall_Clock_of Total_Times_Title : constant String := "TOTAL EXECUTION TIMES"; Total_Times_Columns : constant String := " UNIT NAME " & " PU# T # EXEC NET " & " %T %E CUMULATIVE %T %E"; Total_Times_Dashes : constant String := "---------------------------" & "-- --- - ------ -----------" & " -- -- ----------- -- --"; Unit_Clock : Unit_Clocks; begin String_Pkg.Mark; --| Add an execution time summary to the test configuration report Skip_Line (Report, 2); Put_Line (Report, Dashes); Skip_Line (Report, 3); Put_Line (Report, Center ("=========================================", 80)); Put_Line (Report, Center ("Test Program Start Time: " & Wall_Clock_Of (Seconds (Program_Start_Time)), 80)); Put_Line (Report, Center ("Test Program Stop Time: " & Wall_Clock_Of (Seconds (Last_Time + Overhead_Time)), 80)); Put_Line (Report, Center ("Total Test Execution Time: " & Wall_Clock_Of (Total_Time + Overhead_Time), 80)); Put_Line (Report, Center ("Estimated Profile Overhead: " & Wall_Clock_Of (Overhead_Time), 80)); Put_Line (Report, Center ("Adjusted Test Execution Time: " & Wall_Clock_Of (Total_Time), 80)); Put_Line (Report, Center ("=========================================", 80)); --| Summarize the execution time on the current output device to let --| the user know the program is still running. Text_Io.Put ("Test Program Start Time: "); Text_Io.Put_Line (Wall_Clock_Of (Seconds (Program_Start_Time))); Text_Io.Put ("Test Program Stop Time: "); Text_Io.Put_Line (Wall_Clock_Of (Seconds (Last_Time + Overhead_Time))); Text_Io.Put ("Total Test Execution Time: "); Text_Io.Put_Line (Wall_Clock_Of (Total_Time + Overhead_Time)); if Overhead_Time /= 0.00 then Text_Io.Put_Line ("Estimated Profile Overhead: " & Wall_Clock_Of (Overhead_Time)); Text_Io.Put_Line ("Adjusted Test Execution Time: " & Wall_Clock_Of (Total_Time)); else --| If no estimated overhead was found in the log file then --| the program under test must have terminated abnormally Text_Io.New_Line; Text_Io.Put (Value (Program_Name)); Text_Io.Put_Line (" terminated abnormally"); end if; Put_Page (Report); --| Start the total execution times report on a new page --| Set up a new header for the report Set_Header (Report, 4, Center (Total_Times_Title, Format_Options.Cpl)); Set_Header (Report, 6, Make_Persistent (Total_Times_Columns)); Set_Header (Report, 7, Make_Persistent (Total_Times_Dashes)); --| Print the timing data for each program unit for Unit_Num in 1 .. Number_Of_Units loop Unit_Clock := Fetch (Program_Clock, Unit_Num); Report_Line := New_Report_Line (Unit_Clock.Unit_Id); case Unit_Clock.Unit_Id.Unit_Type is when Procedure_Type => Report_Line := Replace (Report_Line, "P", 35); when Function_Type => Report_Line := Replace (Report_Line, "F", 35); when Task_Type => Report_Line := Replace (Report_Line, "T", 35); when Generic_Type => Report_Line := Replace (Report_Line, "G", 35); when Package_Type => Report_Line := Replace (Report_Line, "K", 35); end case; Report_Line := Replace (Report_Line, String_Of (Unit_Clock.Execs, 7), 36); Report_Line := Replace (Report_Line, Wall_Clock_Of (Unit_Clock.Net_Clock.Accum_Time), 44); Percent := Percent_Of_Total (Total_Time, Unit_Clock.Net_Clock.Accum_Time); Report_Line := Replace (Report_Line, Percent, 56); Report_Line := Replace (Report_Line, Unit_Clock.Net_Clock.Error, 59); Report_Line := Replace (Report_Line, Wall_Clock_Of (Unit_Clock.Cum_Clock.Accum_Time), 63); Percent := Percent_Of_Total (Total_Time, Unit_Clock.Cum_Clock.Accum_Time); Report_Line := Replace (Report_Line, Percent, 75); Report_Line := Replace (Report_Line, Unit_Clock.Cum_Clock.Error, 78); Put_Line (Report, Report_Line); end loop; String_Pkg.Release; end Print_Total_Execution_Times; -------------------------- procedure Print_Unit_Stats ( --| Print statistics for one program unit Unit_Id : in Program_Unit_Unique_Identifier; --| A Unique ID assigned by the source instrumenter Executions : in Natural; --| Number of times unit executed Time_Clock : in Time_Clocks --| Cum, Max, and Min for this unit ) is --| Effects --| This procedure prints the runtime statistics for one program --| unit. The same procedure is used for printing unit statistics --| for both "Net Execution Times" and Cumulative Execution Times." --| The following information is printed for each program unit: --| --| 1) Compilation unit name --| 2) Program unit name --| 3) Program unit number assigned by the Source Instrumenter --| 4) The program unit type: Procedure, Function, Task, Generic, Package --| 5) The total number of times the unit was executed. --| 6) The max, min, and average execution times for each execution --| 7) The total accumulated execution time for the unit --| 8) The percentage of total program execution time --| N/A: Raises, Requires, Modifies, Errors use Time_Library_1; --| for Wall_Clock_of Average_Time : Day_Duration; --| The average execution of a program unit begin String_Pkg.Mark; Report_Line := New_Report_Line (Unit_Id); Report_Line := Replace (Report_Line, String_Of (Executions, 7), 34); Report_Line := Replace (Report_Line, Wall_Clock_Of (Time_Clock.Max_Time), 42); Report_Line := Replace (Report_Line, Wall_Clock_Of (Time_Clock.Min_Time), 54); Average_Time := Day_Duration (Float (Time_Clock.Accum_Time) / Float (Executions)); Report_Line := Replace (Report_Line, Wall_Clock_Of (Average_Time), 66); Report_Line := Replace (Report_Line, Time_Clock.Error, 78); Put_Line (Report, Report_Line); String_Pkg.Release; end Print_Unit_Stats; ------------------------------------- procedure Print_Net_Execution_Times ( --| Print Net Execution Times Program_Clock : in Program_Clocks.Darray; --| A dynamic array with Net and Cum times for all units Number_Of_Units : in Unit_Nums --| The total number of program units ) is use Program_Clocks; --| for Fetch Net_Report_Title : constant String := "NET EXECUTION TIMES"; Max_Min_Columns : constant String := " UNIT NAME P" & "U# # EXEC MAXIMUM MINIMUM" & " AVERAGE %E"; Max_Min_Dashes : constant String := "----------------------------- -" & "-- ------ ----------- ---------" & "-- ----------- --"; Unit_Clock : Unit_Clocks; begin Put_Page (Report); -- Start the report on a new page Set_Header (Report, 4, Center (Net_Report_Title, Format_Options.Cpl)); Set_Header (Report, 6, Make_Persistent (Max_Min_Columns)); Set_Header (Report, 7, Make_Persistent (Max_Min_Dashes)); for Unit_Num in 1 .. Number_Of_Units loop Unit_Clock := Fetch (Program_Clock, Unit_Num); Print_Unit_Stats (Unit_Clock.Unit_Id, Unit_Clock.Execs, Unit_Clock.Net_Clock); end loop; end Print_Net_Execution_Times; ------------------------------------- procedure Print_Cum_Execution_Times ( --| Print Cumulative Execution Times Program_Clock : in Program_Clocks.Darray; --| A dynamic array with Net and Cum times for all units Number_Of_Units : in Unit_Nums --| The total number of program units ) is use Program_Clocks; --| for Fetch Cum_Report_Title : constant String := "CUMULATIVE EXECUTION TIMES"; Unit_Clock : Unit_Clocks; begin Put_Page (Report); -- Start the report on a new page Set_Header (Report, 4, Center (Cum_Report_Title, Format_Options.Cpl)); for Unit_Num in 1 .. Number_Of_Units loop Unit_Clock := Fetch (Program_Clock, Unit_Num); Print_Unit_Stats (Unit_Clock.Unit_Id, Unit_Clock.Execs, Unit_Clock.Cum_Clock); end loop; end Print_Cum_Execution_Times; ----------------------------------- procedure Print_Call_Summary_Report ( --| Print a summary of units called Program_Clock : in Program_Clocks.Darray; --| A dynamic array with Net and Cum times for all units Number_Of_Units : in Unit_Nums --| The total number of program units ) is use Program_Clocks; --| for Fetch Unit_Clock : Unit_Clocks; Call_Report_Columns : constant String := " UNIT NAME " & " PU# T EXECS ABEND M" & "AX RL SONS GRANDSONS"; Call_Report_Dashes : constant String := "---------------------------" & "-- --- - ------- ------- --" & "----- --------- ---------"; begin String_Pkg.Mark; Put_Page (Report); --| Start the total execution times report on a new page --| Set up a new header for the report Set_Header (Report, 4, Center ("CALL SUMMARY REPORT", Format_Options.Cpl)); Set_Header (Report, 6, Call_Report_Columns); Set_Header (Report, 7, Call_Report_Dashes); for Unit_Num in 1 .. Number_Of_Units loop Unit_Clock := Fetch (Program_Clock, Unit_Num); Report_Line := New_Report_Line (Unit_Clock.Unit_Id); case Unit_Clock.Unit_Id.Unit_Type is when Procedure_Type => Report_Line := Replace (Report_Line, "P", 35); when Function_Type => Report_Line := Replace (Report_Line, "F", 35); when Task_Type => Report_Line := Replace (Report_Line, "T", 35); when Generic_Type => Report_Line := Replace (Report_Line, "G", 35); when Package_Type => Report_Line := Replace (Report_Line, "K", 35); end case; Report_Line := Replace (Report_Line, String_Of (Unit_Clock.Execs, 8), 36); Report_Line := Replace (Report_Line, String_Of (Unit_Clock.Nest, 8), 44); Report_Line := Replace (Report_Line, String_Of (Unit_Clock.Max_Nest, 8), 52); --| Tasks never have sons or grandsons. Therefore, if the unit is --| a task then do not print the sons or grandsons. For all other --| units they should be printed. if Unit_Clock.Unit_Id.Unit_Type = Task_Type then Report_Line := Replace (Report_Line, "0", 69); Report_Line := Replace (Report_Line, "0", 79); else Report_Line := Replace (Report_Line, String_Of (Unit_Clock.Sons, 9), 61); Report_Line := Replace (Report_Line, String_Of (Unit_Clock.Grandsons, 9), 71); end if; Put_Line (Report, Report_Line); end loop; String_Pkg.Release; end Print_Call_Summary_Report; ------------------------------- begin -- Profile Main Program --| Identify the tool name and version number Text_Io.New_Line; Text_Io.Put_Line (Tool_Version & "Ada Performance Analyzer"); --| Open the log file and get the test configuration data Open_Log (Log_File_Name, Program_Name, Test_Ident, Test_Time); if Timing_Data then --| Display the Test Configuration data on the current output device --| and query the user as to whether he/she wishes to continue --| processing the log file. Put_Test_Configuration_Data (Program_Name, Test_Time, Test_Ident); if Query ("Do you wish to continue (Y/N)? ") then --| Open the report file and set up the report formatting options Open_Report_File (Report, Report_File_Name, Format_Options); --| Print the Test Configuration Report Print_Test_Configuration_Report (Report, Program_Name, Log_File_Name, Test_Time, Test_Ident); --| Read in the logfile and process the timing data Read_Log_File (Program_Clock, Number_Of_Units, Total_Time); --| Calculate expected errors in reported times Calculate_Expected_Error (Program_Clock, Number_Of_Units); --| Sort the Program_Clock by total cumulative execution time Sort (Program_Clock, Number_Of_Units, Total_Execution_Time); --| Print Total Execution Time Report Print_Total_Execution_Times (Program_Clock, Number_Of_Units, Total_Time); --| Sort the Program_Clock by program unit name Sort (Program_Clock, Number_Of_Units, Unit_Name); --| Print Net Execution Time Report Print_Net_Execution_Times (Program_Clock, Number_Of_Units); --| Print Cumulative Execution Time Report Print_Cum_Execution_Times (Program_Clock, Number_Of_Units); --| Print the Call Summary Report Print_Call_Summary_Report (Program_Clock, Number_Of_Units); --| Close the report file Close_Paginated_File (Report); end if; else Put_Test_Configuration_Data (Program_Name, Test_Time, Test_Ident); Text_Io.Put (Value (Log_File_Name)); Text_Io.Put_Line (" does not contain timing data"); end if; --| Close the log file Close_Log; end Profile; end Profile_Pkg;