Operator execution time

development
#1

Hello everybody,

I am currently working with some workflows built using GPF graphs. I would like to record the duration of execution for each operator in a graph.

Is it possible?

Thank you in advance

#2

You donā€™t mention your OS. Also, you will find that additional detail is needed to understand performance bottlenecks. What I do when designing a GPT graph is start with each operator in a separate .xml graph and use OS tools, mostly the GNU version of the time command (linux, macOS from macports or homebrew, or Windows from Cygwin or Msys2):

$ /usr/bin/time --help
Usage: /usr/bin/time [OPTIONS] COMMAND [ARG]...
Run COMMAND, then print system resource usage.

  -a, --append              with -o FILE, append instead of overwriting
  -f, --format=FORMAT       use the specified FORMAT instead of the default
  -o, --output=FILE         write to FILE instead of STDERR
  -p, --portability         print POSIX standard 1003.2 conformant string:
                              real %%e
                              user %%U
                              sys %%S
  -q, --quiet               do not print information about abnormal program
                            termination (non-zero exit codes or signals)
  -v, --verbose             print all resource usage information instead of
                            the default format
  -h,  --help               display this help and exit
  -V,  --version            output version information and exit

Commonly usaged format sequences for -f/--format:
(see documentation for full list)
  %%   a literal '%'
  %C   command line and arguments
  %c   involuntary context switches
  %E   elapsed real time (wall clock) in [hour:]min:sec
  %e   elapsed real time (wall clock) in seconds
  %F   major page faults
  %M   maximum resident set size in KB
  %P   percent of CPU this job got
  %R   minor page faults
  %S   system (kernel) time in seconds
  %U   user time in seconds
  %w   voluntary context switches
  %x   exit status of command

Default output format:
%Uuser %Ssystem %Eelapsed %PCPU (%Xavgtext+%Davgdata %Mmaxresident)k
%Iinputs+%Ooutputs (%Fmajor+%Rminor)pagefaults %Wswaps

NOTE: your shell may have its own version of time, which usually supersedes
the version described here.  Please refer to your shell's documentation
for details about the options it supports.

GNU Time website: <https://www.gnu.org/software/time/>
Full documentation at: <https://www.gnu.org/software/time/manual>
E-mail bug reports to: bug-time@gnu.org

When you combine graphs you usually see a boost in performance as the individual graphs are doing extra I/O. The separate steps are, however, helpful in checking the results or tracking down the reason for an error when the full graph breaks due to ā€œunexpectedā€ things in the data, corrupt input file, hardware issue, etc.

2 Likes
#3

Thank you for your reply.

I already tried that solution before but I need something more accurateā€¦ Maybe something that could hook into logs and print some information on stdout while executing.

I have to record only the execution time of an operator, without I/O.

Thanks

#4

There are three special observer classes.

org.esa.snap.core.gpf.monitor.OperatorRuntimeReport
org.esa.snap.core.gpf.monitor.TileComputationEventLogger
org.esa.snap.core.gpf.monitor.TileUsageReportGenerator

You can specify them with the gpt call by using the following parameter:
-Dsnap.gpf.tileComputationObserver=<ONE_OF_THE_ABOVE_CLASS_NAMES>
This property can also be specified in the snap-properties files. In this case without the leading ā€˜-Dā€™

They were made for internal debugging purpose. So, Iā€™m not sure if they match your requirements and the output is maybe a bit verbose.

#5

Thank you for your help marpet, I will give them a try.

#6

logs what I was looking for.

I tried it on a couple of workflows, but it seems that reports only one operator ( last one ). Do you know if thereā€™s a way to have information about each operator?

Thank you in advance