diff --git a/PVE/CLI/pvesr.pm b/PVE/CLI/pvesr.pm index be5ae5ee..8a5075ad 100644 --- a/PVE/CLI/pvesr.pm +++ b/PVE/CLI/pvesr.pm @@ -33,19 +33,34 @@ __PACKAGE__->register_method ({ additionalProperties => 0, properties => { id => get_standard_option('pve-replication-id', { optional => 1 }), + verbose => { + description => "Print more verbose logs to stdout.", + type => 'boolean', + default => 0, + optional => 1, + }, }, }, returns => { type => 'null' }, code => sub { my ($param) = @_; + my $logfunc; + + if ($param->{verbose}) { + $logfunc = sub { + my ($start_time, $msg) = @_; + print "$msg\n"; + }; + } + if (my $id = extract_param($param, 'id')) { - PVE::Replication::run_single_job($id); + PVE::Replication::run_single_job($id, undef, $logfunc); } else { - PVE::Replication::run_jobs(); + PVE::Replication::run_jobs(undef, $logfunc); } return undef; diff --git a/PVE/Replication.pm b/PVE/Replication.pm index ab4f9eca..1646dff9 100644 --- a/PVE/Replication.pm +++ b/PVE/Replication.pm @@ -156,14 +156,15 @@ my $get_next_job = sub { return $jobcfg; }; + sub replicate { - my ($jobcfg, $start_time) = @_; + my ($jobcfg, $start_time, $logfunc) = @_; die "implement me"; } my $run_replication = sub { - my ($stateobj, $jobcfg, $start_time) = @_; + my ($stateobj, $jobcfg, $start_time, $logfunc) = @_; my $state = delete $jobcfg->{state}; @@ -183,7 +184,9 @@ my $run_replication = sub { $state->{last_try} = $start_time; $update_job_state->($stateobj, $jobcfg, $state); - eval { replicate($jobcfg, $start_time); }; + $logfunc->($start_time, "$jobcfg->{id}: start replication job") if $logfunc; + + eval { replicate($jobcfg, $start_time, $logfunc); }; my $err = $@; $state->{duration} = tv_interval($t0); @@ -194,8 +197,14 @@ my $run_replication = sub { $state->{fail_count}++; $state->{error} = "$err"; $update_job_state->($stateobj, $jobcfg, $state); - warn $err; - } else { + if ($logfunc) { + chomp $err; + $logfunc->($start_time, "$jobcfg->{id}: end replication job with error: $err"); + } else { + warn $err; + } + } else { + $logfunc->($start_time, "$jobcfg->{id}: end replication job") if $logfunc; $state->{last_sync} = $start_time; $state->{fail_count} = 0; delete $state->{error}; @@ -204,7 +213,7 @@ my $run_replication = sub { }; sub run_single_job { - my ($jobid, $now) = @_; # passing $now useful for regression testing + my ($jobid, $now, $logfunc) = @_; # passing $now useful for regression testing my $local_node = PVE::INotify::nodename(); @@ -239,7 +248,7 @@ sub run_single_job { $jobcfg->{state}->{last_iteration} = $now; $update_job_state->($stateobj, $jobcfg, $jobcfg->{state}); - $run_replication->($stateobj, $jobcfg, $now); + $run_replication->($stateobj, $jobcfg, $now, $logfunc); }; my $res = PVE::Tools::lock_file($state_path, 60, $code); @@ -247,7 +256,7 @@ sub run_single_job { } sub run_jobs { - my ($now) = @_; # passing $now useful for regression testing + my ($now, $logfunc) = @_; # useful for regression testing my $iteration = $now // time(); @@ -256,7 +265,7 @@ sub run_jobs { my $start_time = $now // time(); while (my $jobcfg = $get_next_job->($stateobj, $iteration, $start_time)) { - $run_replication->($stateobj, $jobcfg, $start_time); + $run_replication->($stateobj, $jobcfg, $start_time, $logfunc); $start_time = $now // time(); } }; diff --git a/bin/test/ReplicationTestEnv.pm b/bin/test/ReplicationTestEnv.pm index b154b8e4..c11369aa 100755 --- a/bin/test/ReplicationTestEnv.pm +++ b/bin/test/ReplicationTestEnv.pm @@ -215,7 +215,7 @@ sub track_jobs { } } - PVE::Replication::run_jobs($ctime); + PVE::Replication::run_jobs($ctime, \&logmsg); my $new = PVE::Replication::job_status(); diff --git a/bin/test/replication_test4.log b/bin/test/replication_test4.log index 3e269748..d8eb2eef 100644 --- a/bin/test/replication_test4.log +++ b/bin/test/replication_test4.log @@ -1,7 +1,13 @@ 1000 job_900_to_node2: new job next_sync => 900 +1000 job_900_to_node2: start replication job +1000 job_900_to_node2: end replication job with error: faked replication error 1000 job_900_to_node2: changed config next_sync => 1300 1000 job_900_to_node2: changed state last_try => 1000, fail_count => 1, error => faked replication error +1300 job_900_to_node2: start replication job +1300 job_900_to_node2: end replication job with error: faked replication error 1300 job_900_to_node2: changed config next_sync => 1900 1300 job_900_to_node2: changed state last_try => 1300, fail_count => 2 +1900 job_900_to_node2: start replication job +1900 job_900_to_node2: end replication job with error: faked replication error 1900 job_900_to_node2: changed config next_sync => 0 1900 job_900_to_node2: changed state last_try => 1900, fail_count => 3