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.
Results Group Keywords
Description of Results group keywords as produced
by the prtloganalyzer application
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.
ProgramTotals Group Keywords
Description of ProgramTotals group keywords as produced by
the prtloganalyzer application.
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.