On Thu, Jul 29, 2010 at 10:25:22PM -0400, Wouter Verhelst wrote:
> cyrus-sasl2-heimdal_2.1.23.dfsg1-5.1 failed on voltaire. Sbuild sent me
> a mail with 'Log for attempted build' as the subject, but daemon.log
> contains this:
> 
> Jul 29 12:49:09 buildd[2705]: sbuild of cyrus-sasl2-heimdal_2.1.23.dfsg1-5.1 
> failed with status 1 (local problem) -- giving back
> 
> ... which is clearly wrong.
> 
> I've been thinking that, as sbuild needs to interpret exit states which
> aren't exactly reliable, it might be better to have it communicate over
> stdout instead?
> 
> Anyway, regardless, this shouldn't happen :)

Just to keep this bug report in the loop, we have a patch to implement
just this, which is currently a work in progress (attached).  I've
been discussing this with Philipp Kern (CCd).

With the patch the status of each job is passed back on stdout to
buildd as RFC-822-style fields, together with statistics for the
build and other metadata about the job.  This removes all ambiguity
about what the failure was (and what caused it).

The patch should apply to the current master branch in git.

If you have any comments or suggestions, that would be great.


Regards,
Roger

-- 
  .''`.  Roger Leigh
 : :' :  Debian GNU/Linux             http://people.debian.org/~rleigh/
 `. `'   Printing on GNU/Linux?       http://gutenprint.sourceforge.net/
   `-    GPG Public Key: 0x25BFB848   Please GPG sign your mail.
diff --git a/bin/sbuild b/bin/sbuild
index df7baef..6318362 100755
--- a/bin/sbuild
+++ b/bin/sbuild
@@ -107,6 +107,15 @@ sub main () {
     }
 
     close_log($conf);
+
+    if ($conf->get('SBUILD_MODE') eq "buildd") {
+	foreach my $job (sort keys %jobs) {
+	    $jobs{$current_job}->generate_stats();
+	    $jobs{$current_job}->print_stats();
+	    print STDOUT "\n";
+	}
+    }
+
     unlink($conf->get('JOB_FILE'))
 	if $conf->get('BATCH_MODE');
     unlink("SBUILD-FINISHED") if $conf->get('BATCH_MODE');
@@ -336,6 +345,14 @@ sub shutdown ($) {
 	exit 1;
     }
 
+    if ($conf->get('SBUILD_MODE') eq "buildd") {
+	foreach my $job (sort keys %jobs) {
+	    $jobs{$current_job}->generate_stats();
+	    $jobs{$current_job}->print_stats();
+	    print STDOUT "\n";
+	}
+    }
+
     # Restore the signal handler to let a self-kill result in the appropriate
     # exit code.
     $SIG{$signame} = 'DEFAULT';
diff --git a/lib/Buildd/Daemon.pm b/lib/Buildd/Daemon.pm
index f189fce..98c319b 100644
--- a/lib/Buildd/Daemon.pm
+++ b/lib/Buildd/Daemon.pm
@@ -462,7 +462,6 @@ sub do_build {
     my @sbuild_args = ( 'nice', '-n', $self->get_conf('NICE_LEVEL'), 'sbuild',
 			'--apt-update',
 			'--batch',
-			"--stats-dir=" . $self->get_conf('HOME') . "/stats",
 			"--dist=" . $dist_config->get('DIST_NAME') );
     #multi-archive-buildd keeps the mailto configuration in the builddrc, so
     #this needs to be passed over to sbuild. If the buildd config doesn't have
@@ -502,13 +501,71 @@ sub do_build {
 	goto failed;
     }
 
-    #We want to collect the first few lines of sbuild output:
-    my ($sbuild_output_line_count, @sbuild_output_buffer) = (0, ());
+    # Collect the first few lines of sbuild output, and store all
+    # statistics provided by sbuild.
+    my %sbuild_stats = ();
+    my $tmp_stats = undef;
+    my $sbuild_output_line_count = 0;
+    my @sbuild_output_buffer) = ();
     while (<SBUILD_OUT>) {
 	#5 lines are enough:
 	if (++$sbuild_output_line_count < 5) {
 	    push @sbuild_output_buffer, $_;
 	}
+	chomp;
+	} if (/^(\S+): (.*)$/) {
+	    # Record statistics
+	    if (!defined($tmp_stats)) {
+		$tmp_stats = {};
+	    }
+	    $tmp_stats->{$1} = $2;
+	} elsif ($_ = '' && defined($tmp_stats)) {
+	    # End of block, save for later use
+	    if (defined($tmp_stats) && defined($tmp_stats->{'Job'})) {
+		$sbuild_stats{$tmp_stats->{'Job'}} = $tmp_stats;
+	    } else {
+		$self->log("bad statistics block returned from sbuild; no job specified");
+	    }
+	    $tmp_stats = undef;
+	}
+    }
+    # End of output, save for later use
+    if (defined($tmp_stats)) {
+	if (defined($tmp_stats->{'Job'})) {
+	    $sbuild_stats{$tmp_stats->{'Job'}} = $tmp_stats;
+	} else {
+	    $self->log("bad statistics block returned from sbuild; no job specified");
+	}
+	$tmp_stats = {};
+    }
+
+    # Fill in any potentially missing important fields
+    foreach my $stat (keys %sbuild_stats) {
+	$sbuild_stats{'Status'} = 'unknown'
+	    if (!exists($sbuild_stats{'Status'}) ||
+		!defined($sbuild_stats{'Status'}));
+	$sbuild_stats{'Fail-Stage'} = 'unknown'
+	    if (!exists($sbuild_stats{'Fail-Stage'}) ||
+		!defined($sbuild_stats{'Fail-Stage'}));
+	$sbuild_stats{'Build-Time'} = 0
+	    if (!exists($sbuild_stats{'Build-Time'}) ||
+		!defined($sbuild_stats{'Build-Time'}));
+	$sbuild_stats{'Build-Space'} = 0
+	    if (!exists($sbuild_stats{'Build-Space'}) ||
+		!defined($sbuild_stats{'Build-Space'}));
+    }
+
+    # Get stats for the specific job just run:
+    my $job_stats = $sbuild_stats{$todo->{'pv'}};
+    if (!exists($sbuild_stats{$todo->{'pv'}})) {
+	$self->log("can't find statistics for job $todo->{'pv'}");
+	$job_stats = {
+	    'Job' => $todo->{'pv'},
+	    'Status' => 'unknown',
+	    'Fail-Stage' => 'unknown',
+	    'Build-Time' => 0,
+	    'Build-Space' => 0
+	};
     }
 
     #We got enough output, now just wait for sbuild to die:
@@ -535,15 +592,21 @@ sub do_build {
 	my $status = WEXITSTATUS($sbuild_exit_code);
 
 	if ($status == 0) {
-	    $failed = 0;
-	    $giveback = 0;
-	    $self->log("sbuild of $todo->{'pv'} succeeded -- marking as built in wanna-build\n");
-	    $db->run_query('--built', '--dist=' . $dist_config->get('DIST_NAME'), $todo->{'pv'});
-	} elsif ($status ==  2) {
-	    $giveback = 0;
-	    $self->log("sbuild of $todo->{'pv'} failed with status $status (build failed) -- marking as attempted in wanna-build\n");
-	    $db->run_query('--attempted', '--dist=' . $dist_config->get('DIST_NAME'), $todo->{'pv'});
-	    $self->write_stats("failed", 1);
+	    if ($job_stats->{'Status'} eq 'succesful') {
+		$failed = 0;
+		$giveback = 0;
+		$self->log("sbuild of $todo->{'pv'} succeeded -- marking as built in wanna-build\n");
+		$db->run_query('--built', '--dist=' . $dist_config->get('DIST_NAME'), $todo->{'pv'});
+		$self->write_stats('build-time', $job_stats->{'Build-Time'});
+		$self->write_stats('build-space', $job_stats->{'Build-Space'});
+	    } elsif ($job_stats->{'Status'} eq 'attempted') {
+		$giveback = 0;
+		$self->log("sbuild of $todo->{'pv'} failed with status $job_stats->{'Status'} in stage $job_stats->{'Fail-Stage'} (build failed) -- marking as attempted in wanna-build\n");
+		$db->run_query('--attempted', '--dist=' . $dist_config->get('DIST_NAME'), $todo->{'pv'});
+		$self->write_stats("failed", 1);
+	    } else {
+		$self->log("sbuild of $todo->{'pv'} failed with status $job_stats->{'Status'} in stage $job_stats->{'Fail-Stage'} (local problem) -- giving back\n");
+	    }
 	} else {
 	    $self->log("sbuild of $todo->{'pv'} failed with status $status (local problem) -- giving back\n");
 	}
diff --git a/lib/Sbuild/Build.pm b/lib/Sbuild/Build.pm
index d5b0681..3ac08a1 100644
--- a/lib/Sbuild/Build.pm
+++ b/lib/Sbuild/Build.pm
@@ -1305,8 +1305,6 @@ sub build {
     }
     $self->set('Build End Time', time);
     $self->set('Pkg End Time', time);
-    $self->write_stats('build-time',
-		       $self->get('Build End Time')-$self->get('Build Start Time'));
     my $date = strftime("%Y%m%d-%H%M",localtime($self->get('Build End Time')));
     $self->log_sep();
     $self->log("Build finished at $date\n");
@@ -1676,31 +1674,6 @@ sub print_stats {
     }
 }
 
-sub write_stats {
-    my $self = shift;
-
-    return if (!$self->get_conf('BATCH_MODE'));
-
-    my $stats_dir = $self->get_conf('STATS_DIR');
-
-    return if not defined $stats_dir;
-
-    if (! -d $stats_dir &&
-	!mkdir $stats_dir) {
-	$self->log_warning("Could not create $stats_dir: $!\n");
-	return;
-    }
-
-    my ($cat, $val) = @_;
-    local( *F );
-
-    $self->lock_file($stats_dir, 0);
-    open( F, ">>$stats_dir/$cat" );
-    print F "$val\n";
-    close( F );
-    $self->unlock_file($stats_dir);
-}
-
 sub debian_files_list {
     my $self = shift;
     my $files = shift;
diff --git a/lib/Sbuild/Conf.pm b/lib/Sbuild/Conf.pm
index d4e3b80..f1b0b52 100644
--- a/lib/Sbuild/Conf.pm
+++ b/lib/Sbuild/Conf.pm
@@ -203,9 +203,6 @@ sub init_allowed_keys {
 	'AVG_SPACE_DB'				=> {
 	    DEFAULT => "$Sbuild::Sysconfig::paths{'SBUILD_LOCALSTATE_DIR'}/avg-build-space"
 	},
-	'STATS_DIR'				=> {
-	    DEFAULT => "$HOME/stats"
-	},
 	'PACKAGE_CHECKLIST'			=> {
 	    DEFAULT => "$Sbuild::Sysconfig::paths{'SBUILD_LOCALSTATE_DIR'}/package-checklist"
 	},
@@ -565,7 +562,6 @@ sub read_config {
     my $md5sum = undef;
     my $avg_time_db = undef;
     my $avg_space_db = undef;
-    my $stats_dir = undef;
     my $package_checklist = undef;
     my $build_env_cmnd = undef;
     my $pgp_options = undef;
@@ -668,7 +664,6 @@ sub read_config {
     $self->set('MD5SUM', $md5sum);
     $self->set('AVG_TIME_DB', $avg_time_db);
     $self->set('AVG_SPACE_DB', $avg_space_db);
-    $self->set('STATS_DIR', $stats_dir);
     $self->set('PACKAGE_CHECKLIST', $package_checklist);
     $self->set('BUILD_ENV_CMND', $build_env_cmnd);
     $self->set('PGP_OPTIONS', $pgp_options);
diff --git a/lib/Sbuild/Options.pm b/lib/Sbuild/Options.pm
index ed92552..8f3c8a1 100644
--- a/lib/Sbuild/Options.pm
+++ b/lib/Sbuild/Options.pm
@@ -154,9 +154,6 @@ sub set_options {
 		       "archive=s" => sub {
 			   $self->set_conf('ARCHIVE', $_[1]);
 		       },
-		       "stats-dir=s" => sub {
-			   $self->set_conf('STATS_DIR', $_[1]);
-		       },
 		       "setup-hook=s" => sub {
 			my @command = split(/\s+/, $_[1]);
 			push(@{${$self->get_conf('EXTERNAL_COMMANDS')}{"chroot-setup-commands"}},

Attachment: signature.asc
Description: Digital signature

Reply via email to