5af9293f60ca873b8e633f02163a9b09839cd735
[buildd-scripts.git] / bin / analyze_results
1 #! /usr/bin/perl
2 #
3 # analyze_results
4 #
5 # Script to analyze failed build logs. Look for specific regexps to
6 # classify things
7 #
8 #
9 # (c) 2018 Steve McIntyre <steve@einval.com> GPL v2+
10
11 use strict;
12 use warnings;
13 use POSIX qw(strftime);
14 use Data::Dumper;
15 use Getopt::Std;
16 use HTTP::Tiny;
17 use URI::Encode qw(uri_encode uri_decode);
18
19 my $name = "analyze_results";
20 my $repo = "https://git.einval.com/cgi-bin/gitweb.cgi?p=buildd-scripts.git";
21 my $hostname;
22 my $date;
23 my $time_start = time();
24 my $time_end;
25 my $time_taken;
26 my $num_fail = 0;
27 my $awaiting_analysis = 0;
28 my $lines_read = 0;
29 my $existing_bugs = 0;
30 my $buildd_base_url="https://buildd.debian.org/status/package.php?p=";
31
32 use constant {
33     ERR_ARCH_MISMATCH      => 1,
34     ERR_NO_SOURCE          => 2,
35     ERR_INFRA              => 3,
36     ERR_BD_PROBLEM         => 4,
37     ERR_DETECT_WRONG_ARCH  => 5,
38     ERR_CRASH              => 6,
39     ERR_BUILD_PROBLEM      => 7,
40     ERR_TEST_PROBLEM       => 8,
41     ERR_BUILD_TIMEOUT      => 9,
42 };
43
44 my @err_descriptions;
45 $err_descriptions [ERR_ARCH_MISMATCH]     = "Architecture mismatches";
46 $err_descriptions [ERR_NO_SOURCE]         = "No source found";
47 $err_descriptions [ERR_INFRA]             = "Infrastructure errors";
48 $err_descriptions [ERR_BD_PROBLEM]        = "Problems with build-deps";
49 $err_descriptions [ERR_DETECT_WRONG_ARCH] = "Builds detected wrong architecture";
50 $err_descriptions [ERR_CRASH]             = "Crashes detected";
51 $err_descriptions [ERR_BUILD_PROBLEM]     = "Problems detected during build phase";
52 $err_descriptions [ERR_TEST_PROBLEM]      = "Problems detected during test phase";
53 $err_descriptions [ERR_BUILD_TIMEOUT]     = "Package builds timed out";
54
55 # Known failure modes to look for
56 my @logcheck = (
57     {
58         # "rchitecture mismatch" -> should never build on this arch
59         # Stop working on this log at this point
60         string   => 'rchitecture mismatch',
61         message  => 'Architecture mismatch',
62         check    => 1,
63         stop     => 1,
64         analyze  => 0,
65         type     => ERR_ARCH_MISMATCH,
66     },
67     {
68         string   => 'not in arch list or does not match any',
69         message  => 'Architecture mismatch',
70         check    => 1,
71         stop     => 1,
72         analyze  => 0,
73         type     => ERR_ARCH_MISMATCH,
74     },
75     {
76         # "binary build with no binary artifacts found" -> no packages
77         # built. Why not picked up already above?.
78         # Stop working on this log at this point
79         string   => 'binary build with no binary artifacts found',
80         message  => 'No binaries built',
81         check    => 1,
82         stop     => 1,
83         analyze  => 1,
84         type     => ERR_ARCH_MISMATCH,
85     },
86     {
87         string   => 'E: Can not find version \S+ of package',
88         message  => 'Could not find specified source package',
89         check    => 1,
90         stop     => 1,
91         analyze  => 0,
92         type     => ERR_NO_SOURCE,
93     },
94     {
95         string   => 'schroot.*File is not owned by user root',
96         message  => 'Schroot setup failure',
97         check    => 1,
98         stop     => 1,
99         analyze  => 0,
100         type     => ERR_INFRA,
101     },
102     {
103         string   => 'No space left on device',
104         message  => 'Build ran out of disk space',
105         check    => 1,
106         stop     => 1,
107         analyze  => 0,
108         type     => ERR_INFRA,
109     },
110     {
111         string   => 'The system has no more ptys',
112         message  => 'Build ran out of ptys',
113         check    => 1,
114         stop     => 1,
115         analyze  => 0,
116         type     => ERR_INFRA,
117     },
118     {
119         string   => 'aarch64-unknown-linux-gnu',
120         message  => 'Wrong arch detected',
121         check    => 1,
122         stop     => 1,
123         analyze  => 1,
124         type     => ERR_DETECT_WRONG_ARCH,
125     },
126     {
127         string   => 'binutils-aarch64',
128         message  => 'Wrong arch detected',
129         check    => 0,
130         stop     => 1,
131         analyze  => 1,
132         type     => ERR_DETECT_WRONG_ARCH,
133     },
134     {
135         string   => 'lib.linux-aarch64',
136         message  => 'Wrong arch detected',
137         check    => 1,
138         stop     => 1,
139         analyze  => 1,
140         type     => ERR_DETECT_WRONG_ARCH,
141     },
142     {
143         # "Bus error" -> alignment bug
144         string   => 'Bus error',
145         message  => 'Alignment problem',
146         check    => 1,
147         stop     => 1,
148         analyze  => 1,
149         type     => ERR_CRASH,
150     },
151     {
152         # "SIGBUS" -> alignment bug
153         string   => 'SIGBUS',
154         message  => 'Alignment problem',
155         check    => 1,
156         stop     => 1,
157         analyze  => 1,
158         type     => ERR_CRASH,
159     },
160     {
161         # "Segmentation fault" -> code problem
162         string   => 'Segmentation fault',
163         pstring  => 'Setting up (\S+)',
164         message  => 'Segmentation fault when installing RESULT',
165         check    => 1,
166         stop     => 1,
167         analyze  => 1,
168         type     => ERR_CRASH,
169     },
170     {
171         # "Segmentation fault" -> code problem
172         string   => 'Segmentation fault',
173         message  => 'Segmentation fault',
174         check    => 1,
175         stop     => 1,
176         analyze  => 1,
177         type     => ERR_CRASH,
178     },
179     {
180         # "Illegal instruction" -> bad build target?
181         string   => 'Illegal instruction',
182         pstring  => 'Setting up (\S+)',
183         message  => 'Illegal instruction when installing RESULT',
184         check    => 1,
185         stop     => 1,
186         analyze  => 1,
187         type     => ERR_CRASH,
188     },
189     {
190         # "Illegal instruction" -> bad build target?
191         string   => 'Illegal instruction',
192         message  => 'Illegal instruction',
193         check    => 1,
194         stop     => 1,
195         analyze  => 1,
196         type     => ERR_CRASH,
197     },
198     {
199         # Installing build-deps failed
200         string   => 'dpkg: error processing package (\S+)',
201         message  => 'Build-dep failed to install (RESULT)',
202         check    => 1,
203         stop     => 0,
204         analyze  => 0,
205         type     => ERR_BD_PROBLEM,
206     },
207     {
208         # Installing build-deps failed
209         string   => 'E: pbuilder-satisfydepends failed.',
210         message  => 'Pbuilder build-deps failed',
211         check    => 1,
212         stop     => 1,
213         analyze  => 0,
214         type     => ERR_BD_PROBLEM,
215     },
216     {
217         # Installing build-deps failed
218         string   => 'E: Unmet dependencies',
219         message  => 'Build-deps failed',
220         check    => 1,
221         stop     => 1,
222         analyze  => 0,
223         type     => ERR_BD_PROBLEM,
224     },
225     {
226         # Installing build-deps failed
227         string   => 'unsat-dependency: (\S+)',
228         message  => 'Missing build-dep (RESULT)',
229         check    => 1,
230         stop     => 1,
231         analyze  => 0,
232         type     => ERR_BD_PROBLEM,
233     },
234     {
235         # Installing build-deps failed
236         string   => 'unsat-conflict: (\S+)',
237         message  => 'Unsatisfiable build-dep conflict (RESULT)',
238         check    => 1,
239         stop     => 1,
240         analyze  => 0,
241         type     => ERR_BD_PROBLEM,
242     },
243     {
244         # Build failed - missing build-dep?
245         string   => 'build dependencies/conflicts unsatisfied',
246         message  => 'Build-deps not satisfiable',
247         check    => 1,
248         stop     => 1,
249         analyze  => 0,
250         type     => ERR_BD_PROBLEM,
251     },
252     {
253         # Build failed
254         string   => 'dpkg-source: error: unrepresentable changes to source',
255         message  => 'dpkg-source failure',
256         check    => 1,
257         stop     => 1,
258         analyze  => 0,
259         type     => ERR_BUILD_PROBLEM,
260     },
261     {
262         # Build failed - missing build-dep?
263         string   => 'ld: cannot find',
264         message  => 'Build failure: missing library - missing build-dep?',
265         check    => 1,
266         stop     => 1,
267         analyze  => 0,
268         type     => ERR_BUILD_PROBLEM,
269     },
270     {
271         # Build failed - missing build-dep?
272         string   => 'fatal error:.*No such file or directory',
273         message  => 'Build failure: missing header - missing build-dep?',
274         check    => 1,
275         stop     => 1,
276         analyze  => 0,
277         type     => ERR_BUILD_PROBLEM,
278     },
279     {
280         # Build failed - missing build-dep?
281         string   => 'SEVERE: Cannot resolve dependencies',
282         message  => 'Build failure - missing build-dep?',
283         check    => 1,
284         stop     => 1,
285         analyze  => 0,
286         type     => ERR_BUILD_PROBLEM,
287     },
288     {
289         # Build failed - can't exec something...
290         string   => 'error trying to exec.*execvp: No',
291         message  => 'Build failure (missing binary)',
292         check    => 1,
293         stop     => 1,
294         analyze  => 1,
295         type     => ERR_BUILD_PROBLEM,
296     },
297     {
298         # Build failed
299         string   => 'BUILD FAIL',
300         message  => 'Build failure (java/javadoc)',
301         check    => 1,
302         stop     => 1,
303         analyze  => 0,
304         type     => ERR_BUILD_PROBLEM,
305     },
306     {
307         # Build failed
308         string   => '^make.*\*\*\*.* \[debian/rules.*Error \d+$',
309         message  => 'Build failure (other)',
310         check    => 1,
311         stop     => 1,
312         analyze  => 1,
313         type     => ERR_BUILD_PROBLEM,
314     },
315     {
316         # Build failed
317         string   => 'make.*returned exit code',
318         message  => 'Build failure (other)',
319         check    => 1,
320         stop     => 0,
321         analyze  => 1,
322         type     => ERR_BUILD_PROBLEM,
323     },
324     {
325         # Build failure
326         string   => 'dh_auto_build:.*returned exit code \d+',
327         message  => 'Build failure (other)',
328         check    => 1,
329         stop     => 1,
330         analyze  => 1,
331         type     => ERR_BUILD_PROBLEM,
332     },
333     {
334         # Build failure
335         string   => 'dh_auto_clean:.*returned exit code \d+',
336         message  => 'Build failure (clean failed)',
337         check    => 1,
338         stop     => 1,
339         analyze  => 0,
340         type     => ERR_BUILD_PROBLEM,
341     },
342     {
343         # Build failure
344         string   => 'dh_auto_install:.*returned exit code \d+',
345         message  => 'Build failure (install failed)',
346         check    => 1,
347         stop     => 1,
348         analyze  => 1,
349         type     => ERR_BUILD_PROBLEM,
350     },
351     {
352         # Build failure
353         string   => 'dh_auto_configure:.*returned exit code \d+',
354         message  => 'Build failure (configure failed)',
355         check    => 1,
356         stop     => 1,
357         analyze  => 1,
358         type     => ERR_BUILD_PROBLEM,
359     },
360     {
361         # Build failed
362         string   => '^debian/.*recipe for target (\S+) failed',
363         message  => 'Build failure (RESULT)',
364         check    => 1,
365         stop     => 1,
366         analyze  => 1,
367         type     => ERR_BUILD_PROBLEM,
368     },
369     {
370         # Build failed
371         string   => '^debian/.*\*\*\* (.*).  Stop.',
372         message  => 'Build error (RESULT)',
373         check    => 1,
374         stop     => 1,
375         analyze  => 1,
376         type     => ERR_BUILD_PROBLEM,
377     },
378     {
379         # Build failed
380         string   => 'dpkg-buildpackage: error:.*(debian/rules \S+) subprocess returned exit status 2',
381         message  => 'Build error (RESULT)',
382         check    => 1,
383         stop     => 1,
384         analyze  => 1,
385         type     => ERR_BUILD_PROBLEM,
386     },
387     {
388         # Build failed
389         string   => 'fakeroot debian/rules binary',
390         message  => 'Build failure (other)',
391         check    => 0,
392         stop     => 1,
393         analyze  => 1,
394         type     => ERR_BUILD_PROBLEM,
395     },
396     {
397         # Build failure
398         string   => 'constant \d+ overflows.*int',
399         message  => 'Go 32-bit integer overflow',
400         check    => 1,
401         stop     => 0,
402         analyze  => 1,
403         type     => ERR_BUILD_PROBLEM,
404     },
405     {
406         # Test failure
407         string   => 'OSError: \[Errno 13\] Permission denied',
408         message  => 'Python EPERM test failure',
409         check    => 1,
410         stop     => 1,
411         analyze  => 1,
412         type     => ERR_TEST_PROBLEM,
413     },
414     {
415         # Test failure
416         string   => 'dh_auto_test:.*returned exit code \d+',
417         message  => 'Test failure',
418         check    => 1,
419         stop     => 1,
420         analyze  => 1,
421         type     => ERR_TEST_PROBLEM,
422     },
423     {
424         # Timeout. pbuilder is too dumb to do this properly :-(
425         string   => 'I: Terminating build process due to timeout',
426         message  => 'Pbuilder build timeout',
427         check    => 1,
428         stop     => 1,
429         analyze  => 0,
430         type     => ERR_BUILD_TIMEOUT,
431     },
432     {
433         # Timeout from sbuild
434         string   => 'Build killed with signal TERM after \d+ minutes of inactivity',
435         message  => 'Sbuild build timeout',
436         check    => 1,
437         stop     => 1,
438         analyze  => 0,
439         type     => ERR_BUILD_TIMEOUT,
440     },
441 );
442
443 my %log_results;
444 my %udd;
445
446 #foreach my $checktmp (@logcheck) {
447 #    my %check = %$checktmp;
448 #    print "looking for \"$check{string}\"\n";
449 #    print "  with log message \"$check{message}\"\n";
450 #    print "  check this regexp: $check{check}\n";
451 #    print "  stop if found: $check{stop}\n";
452 #}
453
454 print "<html>\n";
455 print "<head>\n";
456 print "<title>Build log analysis</title>\n";
457 print "</head>\n";
458 print "<body>\n";
459 print "<h1>Build log analysis</h1>\n";
460 print "<p><a href=\"#summary\">Summary</a></p>\n";
461 print "<h2>Packages</h2>\n";
462 print "<ol>\n";
463
464 my $line;
465
466 our($opt_u);
467 getopts('u:') or die "getopts failure\n";
468
469 if (defined $opt_u) {
470     open (UDD, "< $opt_u") or die "Can't open UDD list file $opt_u for reading\n";
471     while (defined ($line = <UDD>)) {
472         chomp $line;
473         my ($pkg, $bugno, $bugsubj) = split (/ /, $line, 3);
474         my @buglist;
475         my $tmp = $udd{"$pkg"};
476         if ($tmp) {
477             @buglist = @$tmp;
478         }
479         push (@buglist, "$bugno: $bugsubj");
480         $udd{"$pkg"} = \@buglist;
481     }
482     close UDD;
483
484 #    foreach my $key (keys %udd) {
485 #       my $tmp = $udd{$key};
486 #       my $num = scalar (@$tmp);
487 #       print "$key has $num bugs:\n";
488 #       foreach my $entry (@$tmp) {
489 #           print "  $entry\n";
490 #       }
491 #    }
492 }
493
494 sub check_buildd_status {
495     my $pkg = shift;
496     my $version = shift;
497     my $arch = shift;
498
499     my $url = "$buildd_base_url$pkg";
500
501 #    print "Looking at URL $url\n";
502
503     my $built_on_arches = "";
504     my $built_my_arch = 0;
505     my $ftbfs_my_arch = 0;
506     my $not_my_arch = 0;
507     my $current_version = "";
508
509 #    print "Checking buildd data for package $pkg, arch $arch\n";
510
511     my $response = HTTP::Tiny->new->get($url);
512
513     if ($response->{success}) {
514 #       print "$response->{status} $response->{reason}\n";
515         my $content = $response->{content};
516 #       print "$content\n";
517
518         # Split the content up into lines
519         my @lines = split("\n", $content);
520
521         # Now look for two things:
522         # 1. how many arches have built this package?
523         # 2. has *our* arch built it?
524 #       print "we tried $version on arch $arch\n";
525         foreach my $line (@lines) {
526             chomp $line;
527             $line = uri_decode($line);
528             if ($line =~ /https:\/\/buildd.debian.org\/stats\/graph/) {
529                 my @info = split (/<\/td>/, $line);
530                 # Grab the info from our fields
531                 my $this_arch = "";
532                 if ($info[0] =~ /architecture.php\?a=([^&]*)&amp/) {
533                     $this_arch = $1;
534 #                   print "Found entry for arch $this_arch\n";
535                 } else {
536                     print "  <li>FAILED TO PARSE $url\n";
537                 }
538                 $current_version = $info[1];
539                 $current_version =~ s/^<td>//;
540 #               print "current_version for $this_arch is $current_version, we tried $version\n";
541                 my $status = "";
542                 if ($info[2] =~ /class="status status-([a-z]*)/) {
543                     $status = $1;
544 #                   print "Found status $status\n";
545                 } else {
546                     print "  <li>FAILED TO PARSE $url\n";
547                 }
548 #               foreach my $field(@info) {
549 #                   print "$field\n";
550 #               }
551 #               print "  On $this_arch we have version $current_version, status $status\n";
552                 if ($arch =~ /^\Q$this_arch\E$/) {
553                     if ($status =~ /installed/) {
554                         $built_my_arch++;
555                     } else {
556                         $ftbfs_my_arch++;
557                     }
558                 }
559                 if ($status =~ /installed/) {
560                     $built_on_arches .= "$this_arch ";
561                 }
562             }
563
564             if ($line =~ /$arch is not present in the architecture list set by the maintainer/) {
565                 $not_my_arch++;
566             }
567             if ($line =~ /No entry in $arch database/) {
568                 $not_my_arch++;
569             }
570         }
571         print "  <li>Built on this arch: $built_my_arch\n";
572         print "  <li>Built on arches: $built_on_arches\n";
573         if ($not_my_arch) {
574             print "  <li>Not set to build on $arch\n";
575         }
576         if ($ftbfs_my_arch) {
577             print "  <li>Already seen to FTBFS on $arch\n";
578         }
579         if (length($current_version) < 2) {
580             print "  <li>No current version found - has this been removed?\n";
581         } elsif (! ($current_version =~ /\Q$version\E/)) {
582             print "  <li><strong>New version $current_version available - retry?</strong>\n";
583         }
584     } else {
585         print "  <LI>FAILED TO RETRIEVE buildd URL $url\n";
586     }
587 }
588     
589
590 foreach my $input (@ARGV) {
591     open (IN, "< $input") or die "Can't read $input: $!\n";
592     $num_fail++;
593     my $stop = 0;
594     my $lineno = 0;
595     my $errors = 0;
596     my $errors_need_analysis = 0;
597     my $oldline = "";
598     my %file_results;
599     my $pav;
600     my $pkg;
601     my $arch;
602     my $version;
603
604     $pav = $input;
605     $pav =~ s,^.*/,,g;
606     $pav =~ s,\.log,,g;
607     ($pkg, $version, $arch) = split (/_/, $pav);
608
609     print "<li>Looking at <a href=\"$input\">$pkg version $version on arch $arch</a>:\n";
610     print "<ul>\n";
611     while (defined ($line = <IN>) and !$stop) {
612         $lineno++;
613         $lines_read++;
614         foreach my $checktmp (@logcheck) {
615             my %check = %$checktmp;
616             if ($check{check}) {
617                 if (!$stop
618                     and ($line =~ m/$check{string}/)
619                     and (!$check{pstring} or $oldline =~ m/$check{pstring}/)) {
620 #                   print "  Line $lineno: found \"$check{string}\"\n";
621                     my $match = $1;
622                     my $message = $check{message};
623                     $message =~ s,RESULT,$match,g;
624                     $file_results{$message} = $check{type};
625                     if (($check{type} == ERR_BUILD_TIMEOUT) and ($errors == 0)) {
626                         print "  <li>Line $lineno: $message\n";
627                         print "  <li>Build killed by timeout before any errors at line $lineno\n";
628                     } else {
629                         print "  <li>Line $lineno: $message\n";
630                         $errors++;
631                     }
632                     if ($check{analyze}) {
633                         $errors_need_analysis++;
634                     }
635                     if ($check{stop}) {
636 #                       print "  stopping processing\n";
637                         $stop = 1;
638                     }
639                 }
640             }
641         }
642         $oldline = $line;
643     }
644     close IN;
645     # End of checking this package
646     print "  <li><strong>Found errors: $errors</strong>\n";
647     if (!$errors) {
648         print " (maybe just timed out during build?)\n";
649     }
650
651     # Look for a note for manually-added logfile analysis
652     my $note = $input;
653     $note =~ s,\.log$,.note,;
654     if (-f $note) {
655         open (IN, "< $note") or die "Can't open $note for reading: $!\n";
656         while (defined (my $line = <IN>)) {
657             chomp $line;
658             if ($line =~ m,#(\d+),) {
659                 my $bugno = $1;
660                 $existing_bugs++;
661                 $line =~ s,#(\d+),<a href="https://bugs.debian.org/$1">#$1</a>,g;
662             }
663             print "  <li>$line\n";
664         }
665         close IN;
666     } else {
667         if ($errors_need_analysis) {
668             print "  <li><strong>Needs analysis</strong>\n";
669             if ($udd{$pkg}) {
670                 my $tmp = $udd{$pkg};
671                 my $num = scalar (@$tmp);
672                 print "  <li>$num reported FTBFS bugs:\n";
673                 print "  <ul>\n";
674                 foreach my $entry (@$tmp) {
675                     print "    <li>#$entry\n";
676                 }
677                 print "  </ul>\n";
678             }
679             check_buildd_status($pkg, $version, $arch);
680             $awaiting_analysis++;
681         }
682     }
683
684     print "</ul>\n";
685     foreach my $key (keys %file_results) {
686         $log_results{$file_results{$key}}{$key} += 1;
687 #       print "now have $log_results{$key} for \"$key\"\n";
688     }
689 }
690 print "</ol>\n";
691
692 print "<a name=\"summary\"</a>\n";
693 print "<h2>Summary of results from $num_fail failed builds:</h2>\n";
694 print "<p>$awaiting_analysis logs still need analysis</p>\n";
695 print "<ul>\n";
696 print "  <li>Linked to $existing_bugs bugs in the Debian BTS</li>\n";
697 foreach my $type (sort keys %log_results) {
698     print "  <h3>$err_descriptions[$type]</h3>\n";
699     my $tmp = $log_results{$type};
700     my %result = %$tmp;
701     foreach my $key (sort { $result{$b} <=> $result{$a} }keys %result) {
702         print "  <li>Found $result{$key} log(s) showing $key\n";
703     }
704 }
705 print "</ul>\n";
706
707 $time_end = time();
708 $time_taken = $time_end - $time_start;
709 $date = strftime "%a %b %e %H:%M:%S %Z %Y", localtime;
710 $hostname = `hostname`;
711 chomp $hostname;
712
713 print "<hr>\n";
714 print "<p>Log analysis generated on $hostname, $date.\n";
715 print "<br>Output from $name - see <a href=\"$repo\">$repo</a> for source.\n";
716 print "<br>Read $lines_read lines of logs and took $time_taken seconds to complete.\n";
717
718 print "</body>\n";
719 print "</html>\n";