view release on metacpan or  search on metacpan

lib/Log/Any/Progress.pm  view on Meta::CPAN

package Log::Any::Progress;

use 5.006;
use strict;
use warnings;

=head1 NAME

Log::Any::Progress - log incremental progress using Log::Any

=head1 VERSION

Version 1.00

=cut

our $VERSION = '1.00';

=head1 SYNOPSIS

  use Log::Any::Progress;

  use Log::Any::Adapter 'Stderr';

  my $progress = Log::Any::Progress->new(
      count  => $num_things_to_do,
      prefix => 'Processing widgets',
  );

  foreach my $thing_to_do (@things_to_do) {
      do_the_thing($thing_to_do);
      $progress->update;
  }

=head1 DESCRIPTION

This module makes it easy to use L<Log::Any> to log incremental
progress, similar in concept to L<Term::ProgressBar>.  It can be
useful for monitoring the progress of a long-running process and to
get an idea of how long that process might take to finish.

It is generally applied to a processing loop.  In the typical case
where the expected number of iterations is known in advance, it
produces output containing the iteration count, percent completion,
elapsed time, average time per iteration, and estimated time remaining.
For example:

  Progress: Iteration:0/5 0% STARTING
  Progress: Iteration:1/5 20% Elapsed:2.000s Avg:2.000s Remaining:8.001s
  Progress: Iteration:2/5 40% Elapsed:4.001s Avg:2.000s Remaining:6.001s
  Progress: Iteration:3/5 60% Elapsed:6.001s Avg:2.000s Remaining:4.001s
  Progress: Iteration:4/5 80% Elapsed:8.001s Avg:2.000s Remaining:2.000s
  Progress: Iteration:5/5 100% FINISHED Elapsed:10.002s Avg:2.000s

The remaining time estimate as of any particular iteration is a
simple linear calculation based on the average time per iteration up
to that point, and the number of remaining iterations.

If the expected number of iterations is not known in advance, it still
reports on incremental progress, but cannot compute either percent
completion or estimated remaining time.  For example:

  Progress: Iteration:0 STARTING
  Progress: Iteration:1 Elapsed:2.000s Avg:2.000s
  Progress: Iteration:2 Elapsed:4.001s Avg:2.000s
  Progress: Iteration:3 Elapsed:6.001s Avg:2.000s
  Progress: Iteration:4 Elapsed:8.001s Avg:2.000s
  Progress: Iteration:5 Elapsed:10.001s Avg:2.000s

=cut

use Log::Any ();
use Time::HiRes qw( gettimeofday tv_interval );

use constant {
    DEFAULT_LOG_LEVEL                => 'infof',
    DEFAULT_LOG_LEVEL_START_FINISH   => 'noticef',
    DEFAULT_MIN_SEC_BETWEEN_MESSAGES => 10,
    DEFAULT_PREFIX                   => 'Progress',
};

=head1 METHODS

=head2 new

  my $progress = Log::Any::Progress->new(

      count => $num_things_to_do,    # mandatory

      delayed_start            => 1,
      logger                   => $logger,
      log_level                => 'info',
      log_level_start_finish   => 'notice',
      min_sec_between_messages => 10,
      prefix                   => 'Processing widgets',
  );

Create a new object for logging incremental progress.  Options include:

=over 4

=item count

A mandatory non-zero count of the expected number of iterations for
progress tracking.

Specifying C<-1> indicates that the expected number of iterations is
unknown, in which case abbreviated statistics will be logged for each
iteration (percent completion and estimated finish time cannot be
computed without knowing the expected number of iterations in advance).

=item delayed_start

An optional boolean value controlling whether or not L</start> should
be automatically called at time of object construction.  It defaults
to false, in which case L</start> is automatically called, assuming
that progress tracking will commence immediately after.

Specifying a true value for C<delayed_start> will prevent L</start>
from being automatically called, in which case it should be explicitly
called just before progress iteration begins.

=item logger

An optional L<Log::Any> logger object to use for logging.

If not specified, a logger object will be obtained via
C<< Log::Any->get_logger() >>, which will in turn use whatever
L<Log::Any::Adapter> might be configured.

If not specifying a logger object, you will want to make sure that
some adapter other than the default L<Log::Any::Adapter::Null>
adapter is configured (for example, L<Log::Any::Adapter::Stderr>),
otherwise no log messages will be emitted.

=item log_level

An optional L<Log::Any> log level for the incremental progress lines.
It defaults to C<info>.

Valid log levels include:

  trace
  debug
  info (inform)
  notice
  warning (warn)
  error (err)
  critical (crit, fatal)
  alert
  emergency

=item log_level_start_finish

An optional L<Log::Any> log level for the start and finish progress
lines.  It defaults to C<notice>.

Valid log levels include:

  trace
  debug
  info (inform)
  notice
  warning (warn)
  error (err)
  critical (crit, fatal)
  alert
  emergency

=item min_sec_between_messages

An optional value for the minimum number of seconds to wait before
emitting the next incremental progress log message (as a result of
calling L</update>).  Values specifying fractional seconds are allowed
(e.g. C<0.5>).  It defaults to C<10> seconds.

Setting C<min_sec_between_messages> appropriately can be used to
control log verbosity in cases where many hundreds or thousands of
iterations are being processed and it's not necessary to report after
each iteration.  Setting it to C<0> will result in every incremental
progress message will be emitted.

=item prefix

An optional string which will be used to prefix each logged message.
It defaults to C<Progress>.

=back

=cut

sub new
{
    my $class_or_instance = shift;

    my %args = @_ == 1 && ref $_[0] eq 'HASH' ? %{$_[0]} : @_;

    my $logger = $args{logger} || Log::Any->get_logger;

    die $logger->fatal('No "count" specified') unless $args{count};

    my $class = ref $class_or_instance || $class_or_instance;
    my $self  = bless {
        delayed_start            => 0,
        logger                   => $logger,
        log_level                => DEFAULT_LOG_LEVEL,
        log_level_start_finish   => DEFAULT_LOG_LEVEL_START_FINISH,
        min_sec_between_messages => DEFAULT_MIN_SEC_BETWEEN_MESSAGES,
        prefix                   => DEFAULT_PREFIX,
        %args,
        _initialized       => 0,
        _finished          => 0,
        _current_iteration => 0,
    }, $class;

    for ( qw( log_level log_level_start_finish ) ) {
        $self->{$_} .= "f" unless $self->{$_} =~ /f\z/;
    }

    $self->{_format}         = $self->{prefix} . ': Iteration:%d/%d %.0f%% Elapsed:%s Avg:%s Remaining:%s';
    $self->{_format_nocount} = $self->{prefix} . ': Iteration:%d Elapsed:%s Avg:%s';

    $self->start unless $self->{delayed_start};

    return $self;
}

=head2 start

  my $progress = Log::Any::Progress->new(
      count => $num_things_to_do,
      delayed_start => 1,  # don't start the timer yet
  );

  # Do some other work here that might take some time...

  $progress->start;

  foreach my $thing_to_do (@things_to_do) {