wiki:ParNCLDeveloperInfo/UsingNCLProfiler/ProfilingNCLScript
Last modified 6 years ago Last modified on 04/30/12 09:52:42

Creating a profile log

If you enabled building the profiler (Enabling Profiler at compile time) while compiling NCL a profile log output file (named "<NCL USER SCRIPT NAME>.prof.log") is created when you run your NCL script. Note that the profile log output is not created if the user explicitly disables profiling at runtime (see Controlling the profiler at runtime).

Analyzing the profile log

The perl script ncl_pr_analyzer.pl (ni/src/scripts/ncl_pr_analyzer.pl) can be used to analyze the profile log.

To find options available with the analyzer script use the following command,

./ncl_pr_analyze.pl /?

You can analyze a profile log file (say foo.ncl.prof.log) using the following command,

./ncl_pr_analyze.pl --log=foo.ncl.prof.log

You can analyze multiple profile log files (say ./*.prof.log) using the following command,

./ncl_pr_analyze.pl --log=`ls ./*.prof.log`

The analyzer script outputs an XML file (named "<NCL USER SCRIPT NAME><NCL LOADED SCRIPT NAME>.xml") corresponding to each NCL source loaded in the NCL script. It also creates an XML file (named "<NCL USER SCRIPT NAME>.xml") corresponding to the script that was run by the user. The forward slashes in the script names are converted to underscores when creating the name of the corresponding XML file.

Viewing the profile log analyzer output

The output XML files from the analyzer script can be viewed using an XML viewer like a browser. To view the XML file, the stylesheet ncl_pr_analyze.xsl (ni/src/scripts/ncl_pr_analyze.xsl) needs to be copied to the directory containing the XML files.

The following is a sample output viewed using Mozilla browser by double clicking on the output XML file.

Browser view of a profile log

Understanding the profile log output

The profile log output shows the line number, time taken for executing the line (wall clock time), percentage of total time taken to execute the line and the NCL source for the line in different columns. The columns are color coded using a VIBGYOR color table such that lines that take within 10% of the median execution time of the lines is color coded as green. The lines that fall within 10% of the green lines are color coded as blue (if they take less time than the "green lines") and yellow (if they take more time than the "green lines") and so on.

For example, to see the heavy weight outliers w.r.t to execution time look for lines color coded as red in the XML output.

Attachments