[tbb-commits] [rbm/master] Bug 40019: Print build finish date and build time in logs

[gk at torproject.org]

commit 1ebbf5ee34239a58d91e59acd0c2c85e1900aceb
Author: Nicolas Vigier <boklm at torproject.org>
Date:   Thu Apr 8 17:57:47 2021 +0200

    Bug 40019: Print build finish date and build time in logs
---
 lib/RBM.pm                    | 35 +++++++++++++++++++++++++++++++----
 test/.gitignore               |  1 +
 test/projects/test-log/config |  9 +++++++++
 3 files changed, 41 insertions(+), 4 deletions(-)

diff --git a/lib/RBM.pm b/lib/RBM.pm
index 1294b4e..a81a290 100644
--- a/lib/RBM.pm
+++ b/lib/RBM.pm
@@ -2,6 +2,7 @@ package RBM;
 
 use warnings;
 use strict;
+use DateTime;
 use Path::Tiny;
 use Encode qw(encode);
 use Cwd qw(getcwd);
@@ -999,6 +1000,24 @@ sub system_log {
     exec(@args);
 }
 
+sub log_start_time {
+    my ($log_file, $script_name) = @_;
+    my $start_time = DateTime->now;
+    my $start_time_txt = $start_time->ymd . ' ' . $start_time->hms;
+    path($log_file)->append_utf8("Starting build (script: $script_name): $start_time_txt\n");
+    return $start_time;
+}
+
+sub log_end_time {
+    my ($log_file, $script_name, $start_time) = @_;
+    my $end_time = DateTime->now;
+    my $end_time_txt = $end_time->ymd . ' ' . $end_time->hms;
+    path($log_file)->append_utf8("Finishing build (script: $script_name): $end_time_txt\n");
+    my $build_time = $end_time - $start_time;
+    my ($bth, $btm, $bts) = $build_time->in_units('hours', 'minutes', 'seconds');
+    path($log_file)->append_utf8("Build time: $bth hours $btm minutes and $bts seconds\n");
+}
+
 sub build_run {
     my ($project, $script_name, $options) = @_;
     my $old_step = $config->{step};
@@ -1076,8 +1095,10 @@ sub build_run {
         $build_log = rbm_path($build_log);
         unlink $build_log unless $append;
         make_path(dirname($build_log));
-        my $now = localtime;
-        path($build_log)->append_utf8("Starting build: $now\n");
+        if (!-f $build_log) {
+            my $now = localtime;
+            path($build_log)->append_utf8("Opening log file: $now\n");
+        }
         print "Build log: $build_log\n";
     }
     chdir $srcdir;
@@ -1103,7 +1124,10 @@ sub build_run {
                     exec_name => $s,
                     exec_as_root => $scripts_root{$s},
                 });
-            if (run_script($project, $cmd, sub { system_log($build_log, @_) }) != 0) {
+            my $start_time = log_start_time($build_log, $s) if $build_log ne '-';
+            my $res = run_script($project, $cmd, sub { system_log($build_log, @_) });
+            log_end_time($build_log, $s, $start_time) if $build_log ne '-';
+            if ($res != 0) {
                 $error = "Error running $script_name";
                 if (project_config($project, 'debug', $options)) {
                     print STDERR $error, "\nOpening debug shell\n";
@@ -1140,7 +1164,10 @@ sub build_run {
         foreach my $s (@scripts) {
             my $cmd = $scripts_root{$s} ? project_config($project, 'suexec',
                 { suexec_cmd => "$srcdir/$s" }) : "$srcdir/$s";
-            if (run_script($project, $cmd, sub { system_log($build_log, @_) }) != 0) {
+            my $start_time = log_start_time($build_log, $s) if $build_log ne '-';
+            my $res = run_script($project, $cmd, sub { system_log($build_log, @_) });
+            log_end_time($build_log, $s, $start_time) if $build_log ne '-';
+            if ($res != 0) {
                 $error = "Error running $script_name";
                 if (project_config($project, 'debug', $options)) {
                     print STDERR $error, "\nOpening debug shell\n";
diff --git a/test/.gitignore b/test/.gitignore
index 21bd609..bf1211f 100644
--- a/test/.gitignore
+++ b/test/.gitignore
@@ -1,2 +1,3 @@
 out
 hg_clones
+logs
diff --git a/test/projects/test-log/config b/test/projects/test-log/config
new file mode 100644
index 0000000..27c40b7
--- /dev/null
+++ b/test/projects/test-log/config
@@ -0,0 +1,9 @@
+# this project can be used for checking that log files are working
+filename: test-log
+build_log: 'logs/test-log.txt'
+build: |
+  #!/bin/sh
+  echo blablabla
+  sleep 2
+  echo ttttttttt
+  echo Z > [% dest_dir %]/[% c('filename') %]