diff --git a/src/lib/Hydra/Plugin/RunCommand.pm b/src/lib/Hydra/Plugin/RunCommand.pm index 38547fa2..6a997d17 100644 --- a/src/lib/Hydra/Plugin/RunCommand.pm +++ b/src/lib/Hydra/Plugin/RunCommand.pm @@ -150,8 +150,20 @@ sub buildFinished { foreach my $commandToRun (@{$commandsToRun}) { my $command = $commandToRun->{command}; + + # todo: make all the to-run jobs "unstarted" in a batch, then start processing + my $runlog = $self->{db}->resultset("RunCommandLogs")->create({ + job_matcher => $commandToRun->{matcher}, + build_id => $build->get_column('id'), + command => $command + }); + + $runlog->started(); + system("$command") == 0 or warn "notification command '$command' failed with exit status $?\n"; + + $runlog->completed_with_child_error($?); } } diff --git a/src/lib/Hydra/Schema/Result/RunCommandLogs.pm b/src/lib/Hydra/Schema/Result/RunCommandLogs.pm index 94bb0ec4..bce53a9c 100644 --- a/src/lib/Hydra/Schema/Result/RunCommandLogs.pm +++ b/src/lib/Hydra/Schema/Result/RunCommandLogs.pm @@ -148,10 +148,82 @@ __PACKAGE__->belongs_to( ); -# Created by DBIx::Class::Schema::Loader v0.07049 @ 2021-11-18 12:35:52 -# DO NOT MODIFY THIS OR ANYTHING ABOVE! md5sum:N0G71diB8DNDgkYgaSQrFA +# Created by DBIx::Class::Schema::Loader v0.07049 @ 2021-11-19 15:15:36 +# DO NOT MODIFY THIS OR ANYTHING ABOVE! md5sum:9AIzlQl1RjRXrs9gQCZKVw + +use POSIX qw(WEXITSTATUS WIFEXITED WIFSIGNALED WTERMSIG); + +=head2 started + +Update the row with the current timestamp as the start time. + +=cut +sub started { + my ($self) = @_; + + return $self->update({ + start_time => time() + }); +} + +=head2 completed_with_child_error + +Update the row with the current timestamp, exit code, core dump, errno, +and signal status. + +Arguments: + +=over 2 + +=item C<$child_error> + +The value of $? or $CHILD_ERROR (with use English) after calling system(). + +=item C<$errno> + +The value of $! or $ERRNO (with use English) after calling system(). + +=back + +=cut +sub completed_with_child_error { + my ($self, $child_error, $reported_errno) = @_; + + my $errno = undef; + my $exit_code = undef; + my $signal = undef; + my $core_dumped = undef; + + if ($child_error == -1) { + # -1 indicates `exec` failed, and this is the only + # case where the reported errno is valid. + $errno = $reported_errno; + } + + if (WIFEXITED($child_error)) { + # The exit status bits are only meaningful if the process exited + $exit_code = WEXITSTATUS($child_error); + } + + if (WIFSIGNALED($child_error)) { + # The core dump and signal bits are only meaningful if the + # process was terminated via a signal + $signal = WTERMSIG($child_error); + + # This `& 128` comes from where Perl constructs the CHILD_ERROR + # value: + # https://github.com/Perl/perl5/blob/a9d7a07c2ebbfd8ee992f1d27ef4cfbed53085b6/perl.h#L3609-L3621 + $core_dumped = ($child_error & 128) == 128; + } + + return $self->update({ + end_time => time(), + error_number => $errno, + exit_code => $exit_code, + signal => $signal, + core_dumped => $core_dumped, + }); +} - -# You can replace this text with custom code or comments, and it will be preserved on regeneration 1; diff --git a/t/Schema/Result/RunCommandLogs.t b/t/Schema/Result/RunCommandLogs.t new file mode 100644 index 00000000..ee65ef41 --- /dev/null +++ b/t/Schema/Result/RunCommandLogs.t @@ -0,0 +1,111 @@ +use strict; +use warnings; +use Setup; + +my %ctx = test_init(); + +require Hydra::Schema; +require Hydra::Model::DB; + +use Test2::V0; + +my $db = Hydra::Model::DB->new; +hydra_setup($db); + +my $project = $db->resultset('Projects')->create({name => "tests", displayname => "", owner => "root"}); +my $jobset = createBaseJobset("basic", "basic.nix", $ctx{jobsdir}); +ok(evalSucceeds($jobset), "Evaluating jobs/basic.nix should exit with return code 0"); +is(nrQueuedBuildsForJobset($jobset), 3, "Evaluating jobs/basic.nix should result in 3 builds"); + +my ($build, @_) = queuedBuildsForJobset($jobset); + +sub new_run_log { + return $db->resultset('RunCommandLogs')->create({ + job_matcher => "*:*:*", + build_id => $build->get_column('id'), + command => "bogus", + }); +} + + +subtest "Not yet started" => sub { + my $runlog = new_run_log(); + + is($runlog->start_time, undef, "The start time is undefined."); + is($runlog->end_time, undef, "The start time is undefined."); + is($runlog->exit_code, undef, "The exit code is undefined."); + is($runlog->signal, undef, "The signal is undefined."); + is($runlog->core_dumped, undef, "The core dump status is undefined."); +}; + +subtest "Completing a process before it is started is invalid" => sub { + my $runlog = new_run_log(); + + like( + dies { + $runlog->completed_with_child_error(0, 0); + }, + qr/runcommandlogs_end_time_has_start_time/, + "It is invalid to complete the process before it started" + ); +}; + +subtest "Starting a process" => sub { + my $runlog = new_run_log(); + $runlog->started(); + is($runlog->start_time, within(time() - 1, 2), "The start time is recent."); + is($runlog->end_time, undef, "The end time is undefined."); + is($runlog->exit_code, undef, "The exit code is undefined."); + is($runlog->signal, undef, "The signal is undefined."); + is($runlog->core_dumped, undef, "The core dump status is undefined."); +}; + +subtest "The process completed (success)" => sub { + my $runlog = new_run_log(); + $runlog->started(); + $runlog->completed_with_child_error(0, 123); + is($runlog->start_time, within(time() - 1, 2), "The start time is recent."); + is($runlog->end_time, within(time() - 1, 2), "The end time is recent."); + is($runlog->error_number, undef, "The error number is undefined"); + is($runlog->exit_code, 0, "The exit code is 0."); + is($runlog->signal, undef, "The signal is undefined."); + is($runlog->core_dumped, undef, "The core dump is undefined."); +}; + +subtest "The process completed (errored)" => sub { + my $runlog = new_run_log(); + $runlog->started(); + $runlog->completed_with_child_error(21760, 123); + is($runlog->start_time, within(time() - 1, 2), "The start time is recent."); + is($runlog->end_time, within(time() - 1, 2), "The end time is recent."); + is($runlog->error_number, undef, "The error number is undefined"); + is($runlog->exit_code, 85, "The exit code is 85."); + is($runlog->signal, undef, "The signal is undefined."); + is($runlog->core_dumped, undef, "The core dump is undefined."); +}; + +subtest "The process completed (signaled)" => sub { + my $runlog = new_run_log(); + $runlog->started(); + $runlog->completed_with_child_error(393, 234); + is($runlog->start_time, within(time() - 1, 2), "The start time is recent."); + is($runlog->end_time, within(time() - 1, 2), "The end time is recent."); + is($runlog->error_number, undef, "The error number is undefined"); + is($runlog->exit_code, undef, "The exit code is undefined."); + is($runlog->signal, 9, "The signal is 9."); + is($runlog->core_dumped, 1, "The core dumped."); +}; + +subtest "The process failed to start" => sub { + my $runlog = new_run_log(); + $runlog->started(); + $runlog->completed_with_child_error(-1, 2); + is($runlog->start_time, within(time() - 1, 2), "The start time is recent."); + is($runlog->end_time, within(time() - 1, 2), "The end time is recent."); + is($runlog->error_number, 2, "The error number is saved"); + is($runlog->exit_code, undef, "The exit code is undefined."); + is($runlog->signal, undef, "The signal is undefined."); + is($runlog->core_dumped, undef, "The core dumped is not defined."); +}; + +done_testing; diff --git a/t/plugins/RunCommand/basic.t b/t/plugins/RunCommand/basic.t index 0dfcd79d..cb025095 100644 --- a/t/plugins/RunCommand/basic.t +++ b/t/plugins/RunCommand/basic.t @@ -50,4 +50,13 @@ subtest "Validate the file parsed and at least one field matches" => sub { is($dat->{build}, $newbuild->id, "The build event matches our expected ID."); }; +subtest "Validate a run log was created" => sub { + my $runlog = $build->runcommandlogs->find({}); + is($runlog->job_matcher, "*:*:*", "An unspecified job matcher is defaulted to *:*:*"); + is($runlog->command, 'cp "$HYDRA_JSON" "$HYDRA_DATA/joboutput.json"', "The executed command is saved."); + is($runlog->start_time, within(time() - 1, 2), "The start time is recent."); + is($runlog->end_time, within(time() - 1, 2), "The end time is also recent."); + is($runlog->exit_code, 0, "This command should have succeeded."); +}; + done_testing;