NAME
====

ProcStats - dump rusage process statistics with optional label.

SYNOPSIS
========

    # display process stats provided by 
    # getrusage(2) & now() to stderr ($*ERR).
    #
    # Initial stats show all values as-is with an 
    # added "initial" and $*INIT-INSTANT. 
    # 
    # Successive calls print progressive stats
    # for non-zero incremental differences with
    # leading '+' to indicate differences.
    #
    # Final includes all values with totals from
    # initial values and include a "Final" key
    # with value of elapsed time from the program
    # startup to the final sample.
    #
    # outputs are YAML array-of-hashes, with one
    # document per print.
    #
    # see example/bare-for-loop

    #!/usr/bin/env perl6
    use v6.d;
    use ProcStats;  # or ( :Print ) for print-stats.

    print-stats :label( $*PROGRAM );

    print-stats
    for 1 .. 3;

    print-stats( final => True );

    # output #0 has all parameters without any differences
    # (there is no prior sample to diff).
    # successive stats w/o prior will show only outputs with
    # differenes in stats other than user and wallclock time
    # using a leading '+' for the offset values.
    #
    # if 'final' is used then all stats are output, even if
    # they are zero, and Final => True is added to the output.
    # (:final defaults to :first, :force).
    #
    # label is output if provided (e.g., :label($*PROGRAM) );

    ---
    label    : ./bare-for-loop
    output   : 0
    sample   : 0
    initial  : 1563047524.012407    # $*INIT-INSTANT
    wtime    : 1563047524.627299    # now()
    utime    : 0.269591
    stime    : 0.038513
    maxrss   : 105852
    minflt   : 20822
    majflt   : 0
    inblock  : 0
    oublock  : 8
    ---
    output   : 1
    sample   : 1
    maxrss   : +760         # only stats with differnces
    minflt   : +173         # are listed.
    utime    : +0.018007    # utime and wtime will always grow,
    wtime    : +0.008687    # returned with :force or other diff's.
    ---
    <snip...>
    ---
    output   : 4            # 4 == 4 => all samples were output
    sample   : 4
    inblock  : +0           # +0 => no change during execution
    majflt   : +0
    maxrss   : +1024        # >0 => growth compared to sample0
    minflt   : +247         
    oublock  : +0
    stime    : +0.000745    # system time during samples.
    utime    : +0.038095    # user time during samples.
    wtime    : +0.019526    # elapsed wallclock from sample0
    final    : +0.804102    # elapsed wallclock from program init.

    # Output is only provided if there are differences in
    # the compared fields. If any of those are different
    # then the wallclock, user, and system times are added
    # the entire difference returned.
    #
    # :force & :first can be used with intermediate
    # outputs to generate output for all fields or compute
    # differenes with first sample.
    #
    # :final(True) defaults :force and :first to true.

    print-stats :force;         # ouput zeros.
    print-stats :first;         # compare to sample0.

    print-stats :first :force;  # all stats compared to sample0.

    # see example/rand-user-table

    print-stats label => "$*PROGRAM";

    for 1 .. 100
    {
        (
            &user-add  => 0.10,
            &user-drop => 0.10,
            &user-op   => 0.80,
        ).Mix.roll( 1_000 )».()
        ;

        print-stats label => 'Keys: ' ~ %user-data.elems;
    }

    print-stats :final, label => 'Keys: ' ~ %user-data.elems;

    # output

    ---
    label    : exmaple/rand-user-table
    output   : 0                        # first sample:
    sample   : 0                        # output = sample = 0.
    wtime    : 1563048388.1687117
    utime    : 0.579475
    stime    : 0
    maxrss   : 116448
    minflt   : 23573
    majflt   : 0
    inblock  : 0
    oublock  : 8
    ---
    label    : Keys: 19
    output   : 1
    sample   : 1
    maxrss   : +3884
    minflt   : +901
    utime    : +0.100587
    wtime    : +0.052823
    ---
    <snip...>
    ---
    label    : Keys: 60
    output   : 14           # 1 .. 14 output have 1 .. 14
    sample   : 14           # samples: something changed each time.
    maxrss   : +264
    minflt   : +24
    utime    : +0.029787    # utime & wtime are alwyas output if
    wtime    : +0.020622    # there are other differences.
    ---
    label    : Keys: 117
    output   : 15           # 15th output has 18th sample:
    sample   : 18           # samples 15 .. 17 were unchanged.
    minflt   : +27          # minflt increased 27 in sample 18.
    utime    : +0.027277
    wtime    : +0.022936
    ---
    <snip...>

    ---
    label    : Keys: 129
    output   : 61           # 39 samples had no differences
    sample   : 100
    minflt   : +10          # minflt increased by 10.
    utime    : +0.024304
    wtime    : +0.024276
    ---
    label    : Keys: 129
    output   : 62           # 62 changes.
    sample   : 101          # in 101 samples.
    inblock  : +0           # +0 values never changed.
    majflt   : +0
    maxrss   : +9424
    minflt   : +2323
    oublock  : +0
    stime    : +0
    utime    : +2.361321
    wtime    : +2.202044    # elapsed wallclock from first call.
    final    : +0.804102    # sec from initial -> final wtime.

DESCRIPTION
===========

This module exports print-stats (via DEFAULT or :Print) or extract-stats & diff-stats (via :Extract). Together these give a simple interface for accessing process statistics via getrusage(2) on systems which support it.

Subroutines
-----------

### Exported by default or with :Print.

  * print-stats

Formats the result of calling diff-stats on extract-stats, passing through :force & :final.

### Exported with :Extract.

  * extract-stats

Calls getrusage(2), removes the parameters not supported by Linux (see Procstats::IGNORE). getrusage returns user and system times as separate int's for seconds and microseconds. These are removed from the initial input, combined into a rational, and rounded to microseconds as "stime" & "utime". Additionally now() is rounded to microseconds and returned as "wtime".

  * diff-stats

If :force is used then all non-ignored values are compared; if :first is used then differnces are compared with the initial sample not the prior one.

Note that :force & :first have no effect on the initial sample. 

Normally compared incrmental keys are:

    stime
    maxrss
    minflt majflt  
    inblock oublock

If at least one of these does not provide non-zero differences then nothing is printed. Using ":force" will cause diff-stats to always generate a list of differences and will always yield

Notes
-----

  * Sample & Output

Comparing sample & output counts allows verifying average rate at which parameters change: output only increments when something changes, %sample<sample> increments with every call to extract-stats.

  * Wallclock Time (wtime)

This is derived from Perl's now() result (rounded to microseconds). Combined with the program name ($*PROGRAM), this makes a reasonable candiate key for tracking execution history over mulitple tests.

Sample code.
------------

  * rand-user-table

This performs a set of random operations on a hash by adding keys, dropping keys, and incrementing the stored values.

It prints the stats every 1000 iterations of the trial:

    for 1 .. 1000
    {
        constant weighted_operations =
        (
            &user-add  => 0.10,
            &user-drop => 0.10,
            &user-op   => 0.80,
        ).Mix;

        weighted_operations.roll( 1_000 )».();

        print-stats label => 'Keys: ' ~ %user-data.elems;
    }

The output illustrates adding progress information to the labels, and will [usually] show examples of the output count being lower than the sample count due to the compared statistics not changing.

Also note here that the final sample shows wallclock time less than user time: MOAR is threaded! Use wtime for elapsed:

stime will grow due to output from print-stats and overhead from calling getrusage(2). Where stime is very small it is probably due to overhead from ProcStats.

    ---
    label    : Keys: 13

* Final : True output : 53 sample : 101 inblock : +0 majflt : +0 maxrss : +5768 minflt : +1467 oublock : +0 stime : +0.018914 utime : +2.24491 # 2.24 > 2.12 due to threading! wtime : +2.123665

NOTES
=====

  * Linux-specific

This could easily be split into extract-stats with O/S-specific extractors and a top module with diff-stats and print-stats. If anyone has access to BSD, Windows, VMS, or OSX systems with Perl6 feel free to send me the information on how to extract the stats and I'll break this up into platform-specific extractors and the rest.

SEE ALSO
========

  * getrusage(2) getrusage(3p)

getrusage is POSIX (3p).

Thing is that Linux does not maintain values for all of the contents (see getrusage(2) for descriptions).

    struct rusage
    {
       struct timeval ru_utime; /* user CPU time used */
       struct timeval ru_stime; /* system CPU time used */
       long   ru_maxrss;        /* maximum resident set size */
     * long   ru_ixrss;         /* integral shared memory size */
     * long   ru_idrss;         /* integral unshared data size */
     * long   ru_isrss;         /* integral unshared stack size */
       long   ru_minflt;        /* page reclaims (soft page faults) */
       long   ru_majflt;        /* page faults (hard page faults) */
     * long   ru_nswap;         /* swaps */
       long   ru_inblock;       /* block input operations */
       long   ru_oublock;       /* block output operations */
     * long   ru_msgsnd;        /* IPC messages sent */
     * long   ru_msgrcv;        /* IPC messages received */
     * long   ru_nsignals;      /* signals received */
       long   ru_nvcsw;         /* voluntary context switches */
       long   ru_nivcsw;        /* involuntary context switches */
    };

  * timeval (3bsd)

Struct timeval is a pair of ints for seconds + microseconds which are dealt with by dividing the microseconcs and adding to get utime and stime in the reported stats.