ISIS Application Documentation
prtloganalyzer | Standard View | TOC | Home |
Analyze program execution efficiency in ISIS print.prt logs
Description
Categories
Groups
History
prtloganalyzer analyzes the content of an ISIS print.prt log file for application efficiency, frequency and validity. It reads the full contents of the ISIS log file (generally named print.prt but can be changed with command line and/or IsisPreferences files) and categorizes them by application name. Runtime statistics (run time, CPU utilization and I/O time) are computed for each applicaiton. A running total for all applications as well as each unique program are maintained. The results are provided in Pvl and comma separated value (CSV) file format for easy evaluation.
The ISIS print log file contain Pvl objects that, at a minimum, describe for each program its parameters and accounting numbers for each run. Nearly all ISIS applications write to this log at the end of their execution. Here is an small example of the contents an ISIS print.prt log file:
Object = lrowac2isis IsisVersion = "3.2.1beta | 2010-03-18" ProgramVersion = 2010-01-19 ProgramPath = /usgs/pkgs/isis3nightly2010-05-04/isis/bin ExecutionDateTime = 2010-05-04T14:45:04 HostName = blackflag UserName = kbecker Description = "Import LRO WAC EDR images into Isis cube format" Group = UserParameters FROM = M109629168CE.IMG TO = M109629168CE COLOROFFSET = false COLOROFFSETSIZE = 2 UNLUT = true End_Group Group = Accounting ConnectTime = 00:00:04.0 CpuTime = 00:00:02.6 End_Group End_Object Object = spiceinit IsisVersion = "3.2.1beta | 2010-03-18" ProgramVersion = 2009-07-21 ProgramPath = /usgs/pkgs/isis3nightly2010-05-04/isis/bin ExecutionDateTime = 2010-05-04T14:45:40 HostName = blackflag UserName = kbecker Description = "Determine SPICE kernels for a camera cube" Group = UserParameters FROM = M109629168CE.vis.even.cub ATTACH = TRUE CKSMITHED = FALSE CKRECON = TRUE CKPREDICTED = FALSE CKNADIR = FALSE SPKSMITHED = FALSE SPKRECON = TRUE SPKPREDICTED = FALSE SHAPE = SYSTEM STARTPAD = 0.0 ENDPAD = 0.0 End_Group Group = Kernels NaifIkCode = -85621 LeapSecond = $base/kernels/lsk/naif0009.tls TargetAttitudeShape = ($base/kernels/pck/pck00009.tpc, $lro/kernels/pck/moon_080317.tf, $lro/kernels/pck/moon_assoc_me.tf) TargetPosition = ($lro/kernels/tspk/moon_pa_de421_1900-2050.bp- c, $lro/kernels/tspk/de421.bsp) InstrumentPointing = ($lro/kernels/ck/moc42_2009281_2009282_v01.bc, $lro/kernels/fk/lro_frames_2010034_v01.tf) Instrument = $lro/kernels/ik/lro_instruments_v11.ti SpacecraftClock = $lro/kernels/sclk/lro_clkcor_2010117_v00.tsc InstrumentPosition = $lro/kernels/spk/fdf29_2009281_2009282_n01.bsp InstrumentAddendum = $lro/kernels/iak/lro_instrumentAddendum_v03.ti ShapeModel = $base/dems/ulcn2005_lpo_0003.cub InstrumentPositionQuality = Reconstructed InstrumentPointingQuality = Reconstructed CameraVersion = 1 End_Group Group = Accounting ConnectTime = 00:00:02.0 CpuTime = 00:00:02.2 End_Group End_Object Object = lrowaccal IsisVersion = "3.2.1beta | 2010-03-18" ProgramVersion = 2009-07-01 ProgramPath = /usgs/pkgs/isis3nightly2010-05-04/isis/bin ExecutionDateTime = 2010-05-04T14:46:30 HostName = blackflag UserName = kbecker Description = "This program calibrates WAC images" Group = UserParameters FROM = M109629168CE.vis.even.cub TO = M109629168CE.vis.even.cal.cub Dark = True DarkFile = Default Flatfield = True FlatfieldFile = Default Radiometric = True RadiometricType = IOF RadiometricFile = Default SpecialPixels = True SpecialPixelsFile = Default End_Group Group = Accounting ConnectTime = 00:00:02.0 CpuTime = 00:00:01.3 End_Group End_Object Object = cam2map IsisVersion = "3.2.1beta | 2010-03-18" ProgramVersion = 2009-08-10 ProgramPath = /usgs/pkgs/isis3nightly2010-05-04/isis/bin ExecutionDateTime = 2010-05-04T14:48:16 HostName = blackflag UserName = kbecker Description = "Convert camera image to a map projection" Group = UserParameters FROM = M109629168CE.vis.even.cal.cub MAP = ../Truth/M109629168CE.vis.pair.cub TO = M109629168CE.vis.even.proj.cub MATCHMAP = true PIXRES = CAMERA DEFAULTRANGE = MINIMIZE LONSEAM = AUTO INTERP = CUBICCONVOLUTION End_Group Group = Mapping TargetName = Moon ProjectionName = Sinusoidal EquatorialRadius = 1737400.0 <meters> PolarRadius = 1737400.0 <meters> LatitudeType = Planetocentric LongitudeDirection = PositiveEast LongitudeDomain = 360 MinimumLatitude = 68.9554409639 MaximumLatitude = 74.97852210253 MinimumLongitude = 295.368508761 MaximumLongitude = 303.5219691619 CenterLongitude = 3.000000000000e+02 End_Group Group = Accounting ConnectTime = 00:39:12.0 CpuTime = 00:39:10.5 End_Group End_Object Object = cam2map IsisVersion = "3.2.1beta | 2010-03-18" ProgramVersion = 2009-08-10 ProgramPath = /usgs/pkgs/isis3nightly2010-05-04/isis/bin ExecutionDateTime = 2010-05-04T15:27:42 HostName = blackflag UserName = kbecker Description = "Convert camera image to a map projection" Group = UserParameters FROM = M109629168CE.vis.odd.cal.cub MAP = ../Truth/M109629168CE.vis.pair.cub TO = M109629168CE.vis.odd.proj.cub MATCHMAP = true PIXRES = CAMERA DEFAULTRANGE = MINIMIZE LONSEAM = AUTO INTERP = CUBICCONVOLUTION End_Group Group = Mapping TargetName = Moon ProjectionName = Sinusoidal EquatorialRadius = 1737400.0 <meters> PolarRadius = 1737400.0 <meters> LatitudeType = Planetocentric LongitudeDirection = PositiveEast LongitudeDomain = 360 MinimumLatitude = 68.9554409639 MaximumLatitude = 74.97852210253 MinimumLongitude = 295.368508761 MaximumLongitude = 303.5219691619 CenterLongitude = 3.000000000000e+02 End_Group Group = Accounting ConnectTime = 00:39:28.0 CpuTime = 00:39:26.7 End_Group End_Object Object = automos IsisVersion = "3.2.1beta | 2010-03-18" ProgramVersion = 2009-10-19 ProgramPath = /usgs/pkgs/isis3nightly2010-05-04/isis/bin ExecutionDateTime = 2010-05-04T16:31:56 HostName = blackflag UserName = kbecker Description = "Create a mosaic using a list of map projected cubes" Group = UserParameters FROMLIST = proj.lis MOSAIC = M109629168CE.vis.usgs.cub PRIORITY = ONTOP GRANGE = AUTO TRACK = FALSE MATCHBANDBIN = TRUE HIGHSATURATION = FALSE LOWSATURATION = FALSE NULL = FALSE End_Group Group = ImageLocation File = M109629168CE.vis.even.proj.cub StartSample = 1 StartLine = 1 End_Group Group = ImageLocation File = M109629168CE.vis.odd.proj.cub StartSample = 1 StartLine = 1 End_Group Group = Accounting ConnectTime = 00:00:03.0 CpuTime = 00:00:01.5 End_Group End_Object
In the above example, there are 6 total programs of which 5 are unique (cam2map is run twice). The output of this application with command line prtloganalyzer from=print.prt is:
Group = Results Programs = 6 Unique = 5 Included = 0 Excluded = 0 Valid = 6 Errors = 0 ZeroTime = 0 NoData = 0 BadData = 0 Total = 6 End_Group Group = ProgramTotals Hits = 6 ConnectTimeMinimum = 2.00 ConnectTimeMaximum = 2368.00 ConnectTimeAverage = 788.50 ConnectTimeStdDev = 1217.2894 CpuTimeMinimum = 1.30 CpuTimeMaximum = 2366.70 CpuTimeAverage = 787.47 CpuTimeStdDev = 1217.0055 IOTimeMinimum = -0.20 IOTimeMaximum = 1.50 IOTimeAverage = 1.03 IOTimeStdDev = 0.6743 End_Group
The following table summarizes the definitions of the keywords and values found in the Results group. This group provides a count summary of applications categorized to indicate the applications processing status as found in the log file.
Keyword | Description |
---|---|
Programs | Provides the total number of all applications found in the print log file. |
Unique | Count of the number of unique programs found in the print log. Programs with the same name are tabulated together to form an indication of a single programs efficiency. |
Included | The application provides two ways to include only named applications (see the INCLUDE and INCLUDEFROM parameters). This keyword provides a count of all the included programs analyzed. |
Excluded | The application provides two ways to exclude specific applications (see the EXCLUDE and EXCLUDEFROM parameters). This keyword provides a count of all excluded programs from the print log file. |
Valid | This keyword provides a count of the number of valid programs that were found in the print log file. These are application Pvl objects that do not contain an Errors group. |
ZeroTime | This keyword provides a count of the number of applications that have 0 times for ConnectTime and CpuTime in the Accounting group of an application. These occurances are not included in the efficiency analysis as the statistical results are skewed by them. |
NoData | There are times when an application may not contain an Accounting group. These are rare occasions and may not ever occur in the wild, but a count is provided here. |
BadData | Occasionally something can go wrong with the print log file and it can become corrupted or the application did not format the contents properly. This parameter counts the number of occurances where some of the data is invalid or missing entitirely. |
Total | This number provides the total number of valid programs found in the given print log file. This number includes only those used in the ProgramTotals group in the results. |
The ProgramTotals group provides the runtime numbers for all the programs. This will give an indication of performance for all applications included in the analysis. The SUMMARY parameter indicates the name of a file that will included the Results and ProgramTotals groups and a ProgramTotals group for each unique set of applications, such as cam2map. The following table describes the meaning of the keywords contained in the ProgramTotals group above.
All units of times are in seconds unless otherwise indicated. All these values are computed from the Accounting group in each application object entry in the log file. These numbers are computed from keywords in this group. The ConnectTime keyword is used to compute runtime values. The CpuTime keyword is used to compute CPU values. The I/O values are computed using the difference between the connect times and the cpu times. Not real scientific but is the best we can do given the data to work with. I/O times may also include wait states during the run of the application other than disk I/O. Our assumption is that I/O dominates this difference.
Keyword | Description |
---|---|
Hits | Provides the total number of all applications found in the print log file. Should be the same as the Total keyword in the Results group. |
ConnectTimeMinimum | Indicates the minimum time an application took to complete. |
ConnectTimeMaximum | Indicates the maximum time an application took to complete. |
ConnectTimeAverage | Indicates the average time an application took to complete. |
ConnectTimeStdDev | Indicates the standard deviation of the time an application took to complete. |
CpuTimeMinimum | Indicates the minimum cpu time an application used. |
CpuTimeMaximum | Indicates the maximum cpu time an application used. |
CpuTimeAverage | Indicates the average cpu time an application used. |
CpuTimeStdDev | Indicates the standard deviation of the cpu time an application used. |
IOTimeMinimum | Indicates the minimum I/O time an application used. |
IOTimeMaximum | Indicates the maximum I/O time an application used. |
IOTimeAverage | Indicates the average I/O time an application used. |
IOTimeStdDev | Indicates the standard deviation of the I/O time an application used. |
Finally, the name of the file specified in the LOG parameter will contain a flat file of comma separated values (CSV) for each program. This files is intended to be used to plot the computed values for each of the applications. The following is the contents of the LOG file.
Program,From,To,ExecutionDateTime,ConnectTime,CpuTime,IOTime lrowac2isis,M109629168CE.IMG,M109629168CE,2010-05-04T14:45:04,4.00,2.60,1.40 spiceinit,M109629168CE.vis.even.cub,NULL,2010-05-04T14:45:40,2.00,2.20,-0.20 lrowaccal,M109629168CE.vis.even.cub,M109629168CE.vis.even.cal.cub,2010-05-04T14:46:30,2.00,1.30,0.70 cam2map,M109629168CE.vis.even.cal.cub,M109629168CE.vis.even.proj.cub,2010-05-04T14:48:16,2352.00,2350.50,1.50 cam2map,M109629168CE.vis.odd.cal.cub,M109629168CE.vis.odd.proj.cub,2010-05-04T15:27:42,2368.00,2366.70,1.30 automos,NULL,NULL,2010-05-04T16:31:56,3.00,1.50,1.50
As you can see the file contains certain fields from each application selected from the print log file. The name of the program is provided as well as the FROM and TO parameters to the program if they exist. It either one does not exist, a NULL values is written (some programs don't have a FROM or a TO parameter). The time the program was executed/started is also provided. This parameter provides the ability to plot a time based parameter. The connect, CPU and I/O times then follow.
Name | Description |
---|---|
FROM | Name of an ISIS print.prt log file |
INCLUDEFROM | File containing list of application names to include in analysis |
EXCLUDEFROM | File containing list of application names to exclude in analysis |
SUMMARY | Output file containing summarization of each unique program in print file analysis |
LOG | Writes the specifics for all valid programs to this file |
Name | Description |
---|---|
INCLUDE | Application names to include in analysis |
EXCLUDE | Application names to exclude in analysis |
This parameter provides the name of the ISIS print log file. The name is typically "print.prt" but can vary. Note that many different print.prt files can be concatenated together in one file so that analysis can be performed on many files. One such way to concatenate print files is to use the UNIX cat command to combine two or more files to a single file. The general form is cat file1 file2 file3 > catfile.
Type | filename |
---|---|
File Mode | input |
Default Path | . |
Internal Default | print.prt |
Filter | *.prt |
This parameter is optional and can be used to list the names of programs that will be included in from the print file. This is handy to limit the full-up analysis to a specific set of applications. The file should contain the name of a single application on each line.
If applications of the same name exist in the exclude list as well, exclusions always takes precedence over the inclusions.
Type | filename |
---|---|
File Mode | input |
Internal Default | None |
Filter | *.lis |
This parameter is optional and can be used to list the names of programs that will be excluded in from the print file. This is handy to exlude programs that are mostly benign in nature (.e.g., getkey) that may skew the analysis. The file should contain the name of a single application on each line.
If applications of the same name exist in the include list as well, exclusions always takes precedence over the inclusions.
Type | filename |
---|---|
File Mode | input |
Internal Default | None |
Filter | *.lis |
If specifed the file name given for this parameter will contain the reported Results and ProgramTotals groups as well as a ProgramTotals group but with the name for each unique application set.
Type | filename |
---|---|
File Mode | output |
Internal Default | None |
Filter | *.dat |
If specified, the file name given for this parameter will contain a comma separated value format listing for each application included in the analysis. See the main documentation for details on the contents of this file.
Type | filename |
---|---|
File Mode | output |
Internal Default | None |
This parameter is a convenient way to provided a list of applications to include in the analysis. Expected is a comma separated list of ISIS application names. All other applications that occur in the print log are excluded from the analysis.
Type | string |
---|---|
Internal Default | None |
This parameter is a convenient way to provided a list of applications to exclude in the analysis. Expected is a comma separated list of ISIS application names. All other applications that occur in the print log are included in the analysis.
Type | string |
---|---|
Internal Default | None |
Kris Becker | 2010-09-07 | Original version |