f94b0fc6dfecab3aedb15b0467c9d92ddabfc7db
[debian/amanda] / perl / Amanda / Report.pm
1 # Copyright (c) 2010 Zmanda, Inc.  All Rights Reserved.
2 #
3 # This program is free software; you can redistribute it and/or modify it
4 # under the terms of the GNU General Public License version 2 as published
5 # by the Free Software Foundation.
6 #
7 # This program is distributed in the hope that it will be useful, but
8 # WITHOUT ANY WARRANTY; without even the implied warranty of MERCHANTABILITY
9 # or FITNESS FOR A PARTICULAR PURPOSE.  See the GNU General Public License
10 # for more details.
11 #
12 # You should have received a copy of the GNU General Public License along
13 # with this program; if not, write to the Free Software Foundation, Inc.,
14 # 59 Temple Place, Suite 330, Boston, MA  02111-1307 USA
15 #
16 # Contact information: Zmanda Inc., 465 S. Mathilda Ave., Suite 300
17 # Sunnyvale, CA 94085, USA, or: http://www.zmanda.com
18
19 package Amanda::Report;
20 use strict;
21 use warnings;
22 use Data::Dumper;
23
24 use Amanda::Disklist;
25 use Amanda::Logfile qw/:logtype_t :program_t/;
26 use Amanda::Util;
27 use Amanda::Debug qw( debug warning );
28
29 =head1 NAME
30
31 Amanda::Report -- module for representing report data from logfiles
32
33 =head1 SYNOPSIS
34
35     use Amanda::Report;
36
37     my $report = Amanda::Report->new($logfile);
38     my @hosts  = keys %{$report->{data}{disklist}};
39
40 =head1 INTERFACE
41
42 This module reads the logfile passed to it and aggregates the data in
43 a format of nested hashes for convenient output.  All data read in is
44 stored in C<< $report->{data} >>.
45
46 =head2 Creating a Report
47
48   my $report = Amanda::Report->new($logfile, $historical);
49
50 The constructor reads the logfile and produces the report, which can then be
51 queried with the other methods.  C<$logfile> should specify the path to the
52 logfile from which the report is prepared.  If the logfile is not the "current"
53 logfile, then C<$historical> should be false.  Non-historical reports may draw
54 information from the current Amanda environment, e.g., holding disks and info
55 files.
56
57 =head2 Summary Information
58
59 Note that most of the data provided by these methods is simply a reference to
60 data stored within the report, and should thus be considered read-only.  For
61 example, do not use C<shift> or C<pop> to destructively consume lists.
62
63   my $datestamp = $report->get_timestamp();
64
65 This returns the run timestamp for this dump run.  This is determined from one
66 of several START entries.  This returns a full 14-digit timestamp regardless of
67 the setting of C<usetimestamps> now or during the dump run.
68
69   my @hosts = $report->get_hosts();
70
71 This method returns a list containing the hosts that have been seen in
72 a logfile.  In a scalar context, C<get_hosts> returns the number of
73 hosts seen.
74
75   my @disks = $report->get_disks($hostname);
76
77 This method returns a list of disks that were archived under the given
78 C<$hostname>.  In a scalar context, this method returns the number of
79 disks seen, belonging to the hostname.
80
81   my @dles = $report->get_dles();
82
83 This method returns a list of list references.  Each referenced list
84 contains a hostname & disk pair that has been reported by either the
85 planner or amflush.  The DLEs are stored in the order that they appear
86 in the logfile.
87
88     @dles = (
89         [ 'example1', '/home' ],
90         [ 'example1', '/var/log' ],
91         [ 'example2', '/etc' ],
92         [ 'example2', '/home' ],
93         [ 'example3', '/var/www' ],
94     );
95
96   if ( $report->get_flag($flag) ) { ... }
97
98 The C<get_flag> method accesses a number of flags that represent the state of
99 the dump.  A true value is returned if the flag is set, and undef otherwise.
100 The available flags are:
101
102 =over
103
104 =item C<got_finish>
105
106 This flag is true when the driver finished
107 correctly.  It indicates that the dump run has finished and cleaned
108 up.
109
110 =item C<degraded_mode>
111
112 This flag is set if the taper encounters an
113 error that forces it into degraded mode.
114
115 =item C<amflush_run>
116
117 This flag is set if amflush is run instead of planner.
118
119 =item C<amvault_run>
120
121 This flag is set if the run was by amvault.
122
123 =item C<normal_run>
124
125 This flag is set when planner is run.  Its value
126 should be opposite of C<amflush_run>.
127
128 =item C<dump_failed>
129
130 If a dump failed.
131
132 =item C<dump_strange>
133
134 If a dump end in strange result.
135
136 =item C<results_missing>
137
138 If this was a normal run, but some DLEs named by the
139 planner do not have any results, then this flag is set.  Users should look for
140 DLEs with an empty C<dump> key to enumerate the missing results.
141
142 =item C<historical>
143
144 This flag is set if this is a "historical" report.  It is
145 based on the value passed to the constructor.
146
147 =back
148
149 =head2 Report Data
150
151   my $dle = $report->get_dle_info($hostname, $disk [,$field] );
152
153 This method returns the DLE information for the given C<$hostname> and C<disk>,
154 or if C<$field> is given, returns that field of the DLE information.  See the
155 DATA DESCRIPTION section for the format of this information.
156
157   my $info = $report->get_program_info($program [,$field] );
158
159 This method returns the program information for the given C<$program>, or if
160 C<$field> is given, returns that field of the DLE information.  See the DATA
161 DESCRIPTION section for the format of this information.
162
163 =head1 DATA DESCRIPTION
164
165 =head2 Top Level
166
167 The data in the logfile is stored in the module at C<< $report->{data} >>.
168 Beneath that, there are a number of subdivisions that track both global and
169 per-host status of the given Amanda run that the logfile represents.  Note that
170 these subdivisions are usually accessed via C<get_dle_info> and
171 C<get_program_info>, as described above.
172
173   $data->{programs}
174
175 the C<programs> key of the data points to a hash of global program
176 information, with one element per program.  See the Programs section, below.
177
178   $data->{boguses}
179
180 The C<boguses> key refers to a list of arrayrefs of the form
181
182   [$prog, $type, $str]
183
184 as returned directly by C<Amanda::Logfile::get_logline>.  These lines are not
185 in a recognized trace log format.
186
187   $data->{disklist}
188
189 The C<disklist> key points to a two-level hash of hostnames and
190 disknames as present in the logfile.  It looks something like this:
191
192     $report->{data}{disklist} = {
193         "server.example.org" => {
194             "/home" => {...},
195             "/var"  => {...},
196         },
197         "workstation.example.org" => {
198             "/etc"     => {...},
199             "/var/www" => {...},
200         },
201     };
202
203 Each C<{...}> in the above contains information about the corresponding DLE.  See DLEs, below.
204
205 =head2 Programs
206
207 Each program involved in a dump has a hash giving information about its
208 performance during the run.  A number of fields are common across all of the
209 different programs:
210
211 =over
212
213 =item C<start>
214
215 the numeric timestamp at which the process was started.
216
217 =item C<time>
218
219 the length of time (in seconds) that the program ran.
220
221 =item C<notes>
222
223 a list which stores all notes reported to the logfile
224 by the corresponding program.
225
226 =item C<errors>
227
228 a list which stores all errors reported to the
229 logfile by the corresponding program.
230
231 =back
232
233 Program-specific fields are described in the following sections.
234
235 =head3 planner
236
237 The planner logs very little information other than determining what will be
238 backed up.  It has no special fields other than those given above.
239
240 =head3 driver
241
242 The driver has one field that the other program-specific
243 entries do not:
244
245 =over
246
247 =item C<start_time> - the time it takes for the driver to start up.
248
249 =back
250
251 =head3 amflush and amdump
252
253 No special fields.
254
255 =head3 dumper and chunker
256
257 Most of the chunker's output and the dumper's output can be tied to a
258 particular DLE, so their C<programs> hashes are limited to C<notes> and
259 C<errors>.
260
261 =head3 taper
262
263 The taper hash holds notes and errors for the per-instance runs of the taper
264 program, but also tracks the tapes seen in the logfile:
265
266 =over
267
268 =item C<tapes>
269
270 This field is a hash reference keyed by the label of the tape.
271 each value of the key is another hash which stores date, size, and the
272 number of files seen by this backup on the tape.  For example:
273
274     $report->{data}{programs}{taper}{tapes} = {
275         FakeTape01 => {
276             label => "FakeTape01",
277             date  => "20100318141930",
278             kb    => 7894769,          # data written to tape this session
279             files => 14,               # parts written to tape this session
280             dle   => 13,               # number of dumps that begin on this tape
281             time  => 2.857,            # time spent writing to this tape
282         },
283     };
284
285 =item C<tape_labels>
286
287 The C<tape_labels> field is a reference to a list which records the
288 order that the tapes have been seen.  This list should be used as an
289 ordered index for C<tapes>.
290
291 =back
292
293 =head2 DLEs
294
295 In the below, C<$dle> is the hash representing one disklist entry.
296
297 The C<estimate> key describes the estimate given by the planner.  For
298 example:
299
300     $dle->{estimate} = {
301         level => 0,     # the level of the backup
302         sec   => 20,    # estimated time to back up (seconds)
303         nkb   => 2048,  # expected uncompressed size (kb)
304         ckb   => 1293,  # expected compressed size (kb)
305         kps   => 934.1, # speed of the backup (kb/sec)
306     };
307
308 Each dump of the DLE is represented in C<< $dle->{dumps} >>.  This is a hash,
309 keyed by dump timestamp with a list of tries as the value for each dump.  Each
310 try represents a specific attempt to finish writing this dump to a volume.  If
311 an error occurs during the backup of a DLE and is retried, a second try is
312 pushed to the tries list.  For example:
313
314     $dle->{dumps} = {
315         '20100317142122' => [ $try1 ],
316         '20100318141930' => [ $try1, $try2 ],
317     };
318
319 =head3 Tries
320
321 A try is a hash with at least one dumper, taper, and/or chunker DLE program as
322 a key.  These entries contain the results from the associated program during
323 try.
324
325 There are a number of common fields between all three elements:
326
327 =over
328
329 =item C<date>
330
331 a timestamp of when the program finished (if the program exited)
332
333 =item C<status>
334
335 the status of the dump at this program on this try ("success", "partial",
336 "done", or "failed").  The planner adds an extra "skipped" status which is
337 added when the planner decides to skip a DLE due to user configuration (e.g.,
338 C<skipincr>).
339
340 =item C<level>
341
342 the incremental level of the backup.
343
344 =item C<sec>
345
346 the time in seconds for the program to finish.
347
348 =item C<kb>
349
350 the size of the data dumped in kb.
351
352 =item C<kps>
353
354 the rate at which the program was able to process data,
355 in kb/sec.
356
357 =item C<error>
358
359 if the program fails, this field contains the error message
360
361 =back
362
363 The C<dumper> hash has an C<orig_kb> field, giving the size of the data dumped
364 from the source, before any compression. If encountered, the C<dumper> hash may
365 also contain a C<stranges> field, which is a list of all the messages of type
366 C<L_STRANGE> encountered during the process.
367
368 The C<taper> hash contains all the exit status data given by the taper.
369 Because the same taper process handles multiple dumps, it does not have a
370 C<date> field.  However, the taper does have an additional field, C<parts>,
371 containing a list of parts written for this dump.
372
373 =head3 Parts
374
375 Each item in the list of taper parts is a hash with the following
376 fields:
377
378 =over
379
380 =item C<label>
381
382 the name of the tape that the part was written to.
383
384 =item C<date>
385
386 the datestamp at which this part was written.
387
388 =item C<file>
389
390 the filename of the part.
391
392 =item C<part>
393
394 the sequence number of the part for the DLE that the
395 part is archiving.
396
397 =item C<sec>
398
399 the length of time, in seconds, that the part took to
400 be written.
401
402 =item C<kb>
403
404 the total size of the part.
405
406 =item C<kps>
407
408 the speed at which the part was written.
409
410 =back
411
412 =cut
413
414 use constant STATUS_STRANGE => 2;
415 use constant STATUS_FAILED  => 4;
416 use constant STATUS_MISSING => 8;
417 use constant STATUS_TAPE    => 16;
418
419 sub new
420 {
421     my $class = shift @_;
422     my ($logfname, $historical) = @_;
423
424     my $self = {
425         data => {},
426
427         ## inputs
428         _logfname => $logfname,
429         _historical => $historical,
430
431         ## logfile-parsing state
432
433         # the tape currently being writen
434         _current_tape => undef,
435     };
436     bless $self, $class;
437
438     $self->read_file();
439     return $self;
440 }
441
442
443 sub read_file
444 {
445     my $self       = shift @_;
446     my $data       = $self->{data} = {};
447     my $logfname   = $self->{_logfname};
448
449     # clear the program and DLE data
450     $data->{programs} = {};
451     $data->{disklist} = {};
452     $self->{cache}    = {};
453     $self->{flags}    = {};
454     $self->{run_timestamp} = '00000000000000';
455
456     my $logfh = Amanda::Logfile::open_logfile($logfname)
457       or die "cannot open '$logfname': $!";
458
459     $self->{flags}{exit_status} = 0;
460     $self->{flags}{results_missing} = 0;
461     $self->{flags}{dump_failed} = 0;
462     $self->{flags}{dump_strange} = 0;
463
464     while ( my ( $type, $prog, $str ) = Amanda::Logfile::get_logline($logfh) ) {
465         $self->read_line( $type, $prog, $str );
466     }
467
468     ## set post-run flags
469
470     $self->{flags}{historical} = $self->{_historical};
471     $self->{flags}{amflush_run} = 0;
472     $self->{flags}{amvault_run} = 0;
473     if (!$self->get_flag("normal_run")) {
474         if (   ( defined $self->get_program_info("amflush") )
475             && ( scalar %{ $self->get_program_info("amflush") } ) ) {
476             debug("detected an amflush run");
477             $self->{flags}{amflush_run} = 1;
478         } elsif (   ( defined $self->get_program_info("amvault") )
479                  && ( scalar %{ $self->get_program_info("amvault") } ) ) {
480             debug("detected an amvault run");
481             $self->{flags}{amvault_run} = 1;
482         }
483     }
484
485     # check for missing, fail and strange results
486     $self->check_missing_fail_strange() if $self->get_flag('normal_run');
487
488     # clean up any temporary values in the data
489     $self->cleanup();
490 }
491
492 sub cleanup
493 {
494     my $self = shift;
495
496     #remove last_label field
497     foreach my $dle ($self->get_dles()) {
498         my $dle_info = $self->get_dle_info(@$dle);
499         delete $dle_info->{last_label};
500     }
501
502     return;
503 }
504
505
506 sub read_line
507 {
508     my $self = shift @_;
509     my ( $type, $prog, $str ) = @_;
510
511     if ( $type == $L_CONT ) {
512         ${$self->{nbline_ref}}++;
513         if ($str =~ /^\|/) {
514             $self->{nb_strange}++;
515             push @{$self->{contline}}, $str if $self->{nb_strange} + $self->{nb_error} <= 100;
516         } elsif ($str =~ /^\?/) {
517             $self->{nb_error}++;
518             push @{$self->{contline}}, $str if $self->{nb_error} <= 100;
519         } else {
520             $self->{nb_normal}++;
521             push @{$self->{contline}}, $str if ${$self->{nbline_ref}} <= 100;
522         }
523         return;
524     }
525     $self->{contline} = undef;
526     $self->{nb_normal} = 0;
527     $self->{nb_strange} = 0;
528     $self->{nb_error} = 0;
529
530     if ( $prog == $P_PLANNER ) {
531         return $self->_handle_planner_line( $type, $str );
532
533     } elsif ( $prog == $P_DRIVER ) {
534         return $self->_handle_driver_line( $type, $str );
535
536     } elsif ( $prog == $P_DUMPER ) {
537         return $self->_handle_dumper_line( $type, $str );
538
539     } elsif ( $prog == $P_CHUNKER ) {
540         return $self->_handle_chunker_line( $type, $str );
541
542     } elsif ( $prog == $P_TAPER ) {
543         return $self->_handle_taper_line( $type, $str );
544
545     } elsif ( $prog == $P_AMFLUSH ) {
546         return $self->_handle_amflush_line( $type, $str );
547
548     } elsif ( $prog == $P_AMVAULT ) {
549         return $self->_handle_amvault_line( $type, $str );
550
551     } elsif ( $prog == $P_AMDUMP ) {
552         return $self->_handle_amdump_line( $type, $str );
553
554     } elsif ( $prog == $P_REPORTER ) {
555         return $self->_handle_reporter_line( $type, $str );
556
557     } else {
558         return $self->_handle_bogus_line( $prog, $type, $str );
559     }
560 }
561
562 sub get_timestamp
563 {
564     my $self = shift;
565     return $self->{'run_timestamp'};
566 }
567
568 sub get_hosts
569 {
570     my $self  = shift @_;
571     my $cache = $self->{cache};
572
573     $cache->{hosts} = [ keys %{ $self->{data}{disklist} } ]
574       if ( !defined $cache->{hosts} );
575
576     return @{ $cache->{hosts} };
577 }
578
579 sub get_disks
580 {
581     my $self = shift @_;
582     my ($hostname) = @_;
583     return keys %{ $self->{data}{disklist}{$hostname} };
584 }
585
586 sub get_dles
587 {
588     my $self  = shift @_;
589     my $cache = $self->{cache};
590     my @dles;
591
592     if ( !defined $cache->{dles} ) {
593         foreach my $hostname ( $self->get_hosts() ) {
594             map { push @dles, [ $hostname, $_ ] } $self->get_disks($hostname);
595         }
596         $cache->{dles} = \@dles;
597     }
598     return @{ $cache->{dles} };
599 }
600
601 sub xml_output
602 {
603     my ( $self, $org, $config ) = @_;
604     use Amanda::Report::xml;
605     return Amanda::Report::xml::make_amreport_xml( $self, $org, $config );
606 }
607
608 sub get_dle_info
609 {
610     my $self = shift @_;
611     my ( $hostname, $disk, $field ) = @_;
612
613     return ( defined $field )
614       ? $self->{data}{disklist}{$hostname}{$disk}{$field}
615       : $self->{data}{disklist}{$hostname}{$disk};
616 }
617
618 sub get_program_info
619 {
620     my ($self, $program, $field, $default) = @_;
621     my $prog = $self->{data}{programs}{$program};
622
623     $prog->{$field} = $default if (defined $field && !defined $prog->{$field});
624
625     return (defined $field) ? $prog->{$field} : $prog;
626 }
627
628 sub get_tape
629 {
630     my ($self, $label) = @_;
631
632     my $taper       = $self->get_program_info("taper");
633     my $tapes       = $taper->{tapes}       ||= {};
634     my $tape_labels = $taper->{tape_labels} ||= [];
635
636     if (!exists $tapes->{$label}) {
637         push @$tape_labels, $label;
638         $tapes->{$label} = {date => "",
639                             kb => 0,
640                             files => 0,
641                             dle => 0,
642                             time => 0};
643     }
644
645     return $tapes->{$label};
646 }
647
648 sub get_flag
649 {
650     my ( $self, $flag ) = @_;
651     return $self->{flags}{$flag};
652 }
653
654 sub _handle_planner_line
655 {
656     my $self = shift @_;
657     my ( $type, $str ) = @_;
658     my $data     = $self->{data};
659     my $programs = $data->{programs};
660     my $disklist = $data->{disklist} ||= {};
661     my $planner  = $programs->{planner} ||= {};
662
663     if ( $type == $L_INFO ) {
664         return $self->_handle_info_line( "planner", $str );
665
666     } elsif ( $type == $L_WARNING ) {
667         return $self->_handle_warning_line( "planner", $str );
668
669     } elsif ( $type == $L_START ) {
670
671         $self->{flags}{normal_run} = 1;
672         return $self->_handle_start_line( "planner", $str );
673
674     } elsif ( $type == $L_FINISH ) {
675
676         my @info = Amanda::Util::split_quoted_strings($str);
677         return $planner->{time} = $info[3];
678
679     } elsif ( $type == $L_DISK ) {
680         return $self->_handle_disk_line( "planner", $str );
681
682     } elsif ( $type == $L_SUCCESS ) {
683         return $self->_handle_success_line( "planner", $str );
684
685     } elsif ( $type == $L_ERROR ) {
686         return $self->_handle_error_line( "planner", $str );
687
688     } elsif ( $type == $L_FATAL ) {
689         return $self->_handle_fatal_line( "planner", $str );
690
691     } elsif ( $type == $L_FAIL ) {
692
693         # TODO: these are not like other failure messages: later
694         # handle here
695         return $self->_handle_fail_line( "planner", $str );
696
697     } else {
698         return $self->_handle_bogus_line( $P_PLANNER, $type, $str );
699     }
700 }
701
702
703 sub _handle_driver_line
704 {
705     my $self = shift @_;
706     my ( $type, $str ) = @_;
707     my $data     = $self->{data};
708     my $disklist = $data->{disklist};
709     my $programs = $data->{programs};
710     my $driver_p = $programs->{driver} ||= {};
711
712     if ( $type == $L_INFO ) {
713         return $self->_handle_info_line( "driver", $str );
714
715     } elsif ( $type == $L_START ) {
716         return $self->_handle_start_line( "driver", $str );
717
718     } elsif ( $type == $L_FINISH ) {
719
720         my @info = Amanda::Util::split_quoted_strings($str);
721         $self->{flags}{got_finish} = 1;
722         return $driver_p->{time} = $info[3];
723
724     } elsif ( $type == $L_STATS ) {
725
726         my @info = Amanda::Util::split_quoted_strings($str);
727         if ( $info[0] eq "hostname" ) {
728
729             return $self->{hostname} = $info[1];
730
731         } elsif ( $info[0] eq "startup" ) {
732
733             my @info = Amanda::Util::split_quoted_strings($str);
734             return $driver_p->{start_time} = $info[2];
735
736         } elsif ( $info[0] eq "estimate" ) {
737
738             # estimate format:
739             # STATS driver estimate <hostname> <disk> <timestamp>
740             # <level> [sec <sec> nkb <nkb> ckb <ckb> jps <kps>]
741             # note that the [..] section is *not* quoted properly
742             my ($hostname, $disk, $timestamp, $level) = @info[ 1 .. 4 ];
743
744             # if the planner didn't define the DLE then this is a bad
745             # line
746             unless (exists $disklist->{$hostname}{$disk}) {
747                 return $self->_handle_bogus_line($P_DRIVER, $type, $str);
748             }
749
750             my $dle = $self->get_dle_info($hostname, $disk);
751             my ($sec, $nkb, $ckb, $kps) = @info[ 6, 8, 10, 12 ];
752             $kps =~ s{\]}{};    # strip trailing "]"
753
754             $dle->{estimate} = {
755                 level => $level,
756                 sec   => $sec,
757                 nkb   => $nkb,
758                 ckb   => $ckb,
759                 kps   => $kps,
760             };
761
762         } else {
763             return $self->_handle_bogus_line( $P_DRIVER, $type, $str );
764         }
765
766     } elsif ( $type == $L_WARNING ) {
767
768         $self->{flags}{exit_status} |= STATUS_TAPE
769           if ($str eq "Taper protocol error");
770
771         return $self->_handle_warning_line("driver", $str);
772
773     } elsif ( $type == $L_ERROR ) {
774         return $self->_handle_error_line( "driver", $str );
775
776     } elsif ( $type == $L_FATAL ) {
777         return $self->_handle_fatal_line( "driver", $str );
778
779     } elsif ( $type == $L_FAIL ) {
780         return $self->_handle_fail_line( "driver", $str );
781
782     } else {
783         return $self->_handle_bogus_line( $P_DRIVER, $type, $str );
784     }
785 }
786
787
788 sub _handle_dumper_line
789 {
790     my $self = shift @_;
791     my ( $type, $str ) = @_;
792     my $data     = $self->{data};
793     my $disklist = $data->{disklist};
794     my $programs = $data->{programs};
795     my $dumper_p = $programs->{dumper} ||= {};
796
797     if ( $type == $L_INFO ) {
798         return $self->_handle_info_line( "dumper", $str );
799
800     } elsif ( $type == $L_STRANGE ) {
801
802         my @info = Amanda::Util::split_quoted_strings($str);
803         my ( $hostname, $disk, $level ) = @info[ 0 .. 2 ];
804         my ( $sec, $kb, $kps, $orig_kb ) = @info[ 4, 6, 8, 10 ];
805         $kb = int($kb/1024) if $info[4] eq 'bytes';
806         $orig_kb =~ s{\]$}{};
807
808         my $dle    = $disklist->{$hostname}->{$disk};
809         my $try    = $self->_get_try( $dle, "dumper", $self->{'run_timestamp'});
810         my $dumper = $try->{dumper} ||= {};
811         $dumper->{level} = $level;
812         $dumper->{status} = 'strange';
813         $dumper->{sec}       = $sec;
814         $dumper->{kb}        = $kb;
815         $dumper->{kps}       = $kps;
816         $dumper->{orig_kb}   = $orig_kb;
817
818         $self->{contline} = $dumper->{stranges} ||= [];
819         $dumper->{nb_stranges} = 0;
820         $self->{nbline_ref} = \$dumper->{nb_stranges};
821         $self->{nb_normal} = 0;
822         $self->{nb_strange} = 0;
823         $self->{nb_error} = 0;
824
825         return $self->{flags}{exit_status} |= STATUS_STRANGE
826
827     } elsif ( $type == $L_WARNING ) {
828
829         return $self->_handle_warning_line("dumper", $str);
830
831     } elsif ( $type == $L_SUCCESS ) {
832
833         my @info = Amanda::Util::split_quoted_strings($str);
834         my ( $hostname, $disk, $timestamp, $level ) = @info[ 0 .. 3 ];
835         my ( $sec, $kb, $kps, $orig_kb ) = @info[ 5, 7, 9, 11 ];
836         $kb = int($kb/1024) if $info[6] eq 'bytes';
837         $orig_kb =~ s{\]$}{};
838
839         my $dle    = $disklist->{$hostname}->{$disk};
840         my $try    = $self->_get_try( $dle, "dumper", $timestamp );
841         my $dumper = $try->{dumper} ||= {};
842
843         $dumper->{date}      = $timestamp;
844         $dumper->{level}     = $level;
845         $dumper->{sec}       = $sec;
846         $dumper->{kb}        = $kb;
847         $dumper->{kps}       = $kps;
848         $dumper->{orig_kb}   = $orig_kb;
849
850         return $dumper->{status} = "success";
851
852     } elsif ( $type == $L_ERROR ) {
853         return $self->_handle_error_line( "dumper", $str );
854
855     } elsif ( $type == $L_FATAL ) {
856         return $self->_handle_fatal_line( "dumper", $str );
857
858     } elsif ( $type == $L_FAIL ) {
859         return $self->_handle_fail_line( "dumper", $str );
860
861     } else {
862         return $self->_handle_bogus_line( $P_DUMPER, $type, $str );
863     }
864 }
865
866
867 sub _handle_chunker_line
868 {
869     my $self = shift @_;
870     my ( $type, $str ) = @_;
871     my $data      = $self->{data};
872     my $disklist  = $data->{disklist};
873     my $programs  = $data->{programs};
874     my $chunker_p = $programs->{chunker} ||= {};
875
876     if ( $type == $L_INFO ) {
877         return $self->_handle_info_line( "chunker", $str );
878
879     } elsif ( $type == $L_SUCCESS || $type == $L_PARTIAL ) {
880
881         my @info = Amanda::Util::split_quoted_strings($str);
882         my ( $hostname, $disk, $timestamp, $level ) = @info[ 0 .. 3 ];
883         my ( $sec, $kb, $kps ) = @info[ 5, 7, 9 ];
884         $kb = int($kb/1024) if $info[6] eq 'bytes';
885         $kps =~ s{\]$}{};
886
887         my $dle     = $disklist->{$hostname}->{$disk};
888         my $try     = $self->_get_try( $dle, "chunker", $timestamp );
889         my $chunker = $try->{chunker} ||= {};
890
891         $chunker->{date}  = $timestamp;
892         $chunker->{level} = $level;
893         $chunker->{sec}   = $sec;
894         $chunker->{kb}    = $kb;
895         $chunker->{kps}   = $kps;
896
897         return $chunker->{status} =
898           ( $type == $L_SUCCESS ) ? "success" : "partial";
899
900     } elsif ( $type == $L_ERROR ) {
901         return $self->_handle_error_line( "chunker", $str );
902
903     } elsif ( $type == $L_FATAL ) {
904         return $self->_handle_fatal_line( "chunker", $str );
905
906     } elsif ( $type == $L_FAIL ) {
907         return $self->_handle_fail_line( "chunker", $str );
908
909     } else {
910         return $self->_handle_bogus_line( $P_CHUNKER, $type, $str );
911     }
912 }
913
914
915 sub _handle_taper_line
916 {
917     my $self = shift @_;
918     my ( $type, $str ) = @_;
919     my $data     = $self->{data};
920     my $disklist = $data->{disklist};
921     my $programs = $data->{programs};
922     my $taper_p  = $programs->{taper} ||= {};
923
924     if ( $type == $L_START ) {
925         # format is:
926         # START taper datestamp <start> label <label> tape <tapenum>
927         my @info = Amanda::Util::split_quoted_strings($str);
928         my ($datestamp, $label, $tapenum) = @info[ 1, 3, 5 ];
929         my $tape = $self->get_tape($label);
930         $tape->{date} = $datestamp;
931         $tape->{label} = $label;
932
933         # keep this tape for later
934         $self->{'_current_tape'} = $tape;
935
936         # call through to the generic start line function
937         $self->_handle_start_line( "taper", $str );
938     } elsif ( $type == $L_PART || $type == $L_PARTPARTIAL ) {
939
940 # format is:
941 # <label> <tapefile> <hostname> <disk> <timestamp> <currpart>/<predparts> <level> [sec <sec> kb <kb> kps <kps>]
942 #
943 # format for $L_PARTPARTIAL is the same as $L_PART, plus <err> at the end
944         my @info = Amanda::Util::split_quoted_strings($str);
945         my ($label, $tapefile, $hostname, $disk, $timestamp) = @info[ 0 .. 4 ];
946
947         $info[5] =~ m{^(\d+)\/(-?\d+)$};
948         my ( $currpart, $predparts ) = ( $1, $2 );
949
950         my ($level, $sec, $kb, $kps, $orig_kb) = @info[ 6, 8, 10, 12, 14 ];
951         $kb = int($kb/1024) if $info[9] eq 'bytes';
952         $kps =~ s{\]$}{};
953         $orig_kb =~ s{\]$}{} if defined($orig_kb);
954
955         my $dle   = $disklist->{$hostname}{$disk};
956         my $try   = $self->_get_try($dle, "taper", $timestamp);
957         my $taper = $try->{taper} ||= {};
958         my $parts = $taper->{parts} ||= [];
959
960         my $part = {
961             label => $label,
962             date  => $timestamp,
963             file  => $tapefile,
964             sec   => $sec,
965             kb    => $kb,
966             kps   => $kps,
967             partnum  => $currpart,
968         };
969
970         $taper->{orig_kb} = $orig_kb;
971
972         push @$parts, $part;
973
974         my $tape = $self->get_tape($label);
975         # count this as a filesystem if this is the first part
976         $tape->{dle}++ if $currpart == 1;
977         $tape->{kb}   += $kb;
978         $tape->{time} += $sec;
979         $tape->{files}++;
980
981     } elsif ( $type == $L_DONE || $type == $L_PARTIAL ) {
982
983 # format is:
984 # $type = DONE | PARTIAL
985 # $type taper <hostname> <disk> <timestamp> <part> <level> [sec <sec> kb <kb> kps <kps>]
986         my @info = Amanda::Util::split_quoted_strings($str);
987         my ( $hostname, $disk, $timestamp, $part_ct, $level ) = @info[ 0 .. 4 ];
988         my ( $sec, $kb, $kps, $orig_kb ) = @info[ 6, 8, 10, 12 ];
989         $kb = int($kb/1024) if $info[7] eq 'bytes';
990         my $error;
991         if ($type == $L_PARTIAL) {
992             if ($kps =~ /\]$/) {
993                 $error = join " ", @info[ 11 .. $#info ];
994             } else {
995                 $error = join " ", @info[ 13 .. $#info ];
996             }
997         }
998         $kps =~ s{\]$}{};
999         $orig_kb =~ s{\]$}{} if defined $orig_kb;
1000
1001         my $dle   = $disklist->{$hostname}->{$disk};
1002         my $try   = $self->_get_try($dle, "taper", $timestamp);
1003         my $taper = $try->{taper} ||= {};
1004         my $parts = $taper->{parts};
1005
1006         if ($part_ct - $#$parts != 1) {
1007             ## this should always be true; do nothing right now
1008         }
1009
1010         $taper->{level} = $level;
1011         $taper->{sec}   = $sec;
1012         $taper->{kb}    = $kb;
1013         $taper->{kps}   = $kps;
1014
1015         $taper->{status} = ( $type == $L_DONE ) ? "done" : "partial";
1016         $taper->{error} = $error if $type == $L_PARTIAL;
1017
1018     } elsif ( $type == $L_INFO ) {
1019         $self->_handle_info_line("taper", $str);
1020
1021     } elsif ( $type == $L_WARNING ) {
1022         $self->_handle_warning_line("taper", $str);
1023
1024     } elsif ( $type == $L_ERROR ) {
1025
1026         if ($str =~ m{^no-tape}) {
1027
1028             my @info = Amanda::Util::split_quoted_strings($str);
1029             my $failure_from = $info[1];
1030             my $error = join " ", @info[ 2 .. $#info ];
1031
1032             $self->{flags}{exit_status} |= STATUS_TAPE;
1033             $self->{flags}{degraded_mode} = 1;
1034             $taper_p->{failure_from} = $failure_from;
1035             $taper_p->{tape_error} = $error;
1036
1037         } else {
1038             $self->_handle_error_line("taper", $str);
1039         }
1040
1041     } elsif ( $type == $L_FATAL ) {
1042         return $self->_handle_fatal_line( "taper", $str );
1043
1044     } elsif ( $type == $L_FAIL ) {
1045         $self->_handle_fail_line( "taper", $str );
1046
1047     } else {
1048         $self->_handle_bogus_line( $P_TAPER, $type, $str );
1049     }
1050 }
1051
1052
1053 sub _handle_amflush_line
1054 {
1055     my $self = shift @_;
1056     my ( $type, $str ) = @_;
1057     my $data      = $self->{data};
1058     my $disklist  = $data->{disklist};
1059     my $programs  = $data->{programs};
1060     my $amflush_p = $programs->{amflush} ||= {};
1061
1062     if ( $type == $L_DISK ) {
1063         return $self->_handle_disk_line( "amflush", $str );
1064
1065     } elsif ( $type == $L_START ) {
1066         return $self->_handle_start_line( "amflush", $str );
1067
1068     } elsif ( $type == $L_INFO ) {
1069         return $self->_handle_info_line( "amflush", $str );
1070
1071     } else {
1072         return $self->_handle_bogus_line( $P_AMFLUSH, $type, $str );
1073     }
1074 }
1075
1076 sub _handle_amvault_line
1077 {
1078     my $self = shift @_;
1079     my ( $type, $str ) = @_;
1080     my $data      = $self->{data};
1081     my $disklist  = $data->{disklist};
1082     my $programs  = $data->{programs};
1083     my $amvault_p = $programs->{amvault} ||= {};
1084
1085     if ( $type == $L_START ) {
1086         return $self->_handle_start_line( "amvault", $str );
1087
1088     } elsif ( $type == $L_INFO ) {
1089         return $self->_handle_info_line( "amvault", $str );
1090
1091     } elsif ( $type == $L_ERROR ) {
1092         return $self->_handle_error_line( "amvault", $str );
1093
1094     } elsif ( $type == $L_FATAL ) {
1095         return $self->_handle_fatal_line( "amvault", $str );
1096
1097     } elsif ( $type == $L_DISK ) {
1098         return $self->_handle_disk_line( "amvault", $str );
1099
1100     } else {
1101         return $self->_handle_bogus_line( $P_AMFLUSH, $type, $str );
1102     }
1103 }
1104
1105
1106 sub _handle_amdump_line
1107 {
1108     my $self = shift;
1109     my ( $type, $str ) = @_;
1110     my $data     = $self->{data};
1111     my $disklist = $data->{disklist};
1112     my $programs = $data->{programs};
1113     my $amdump = $programs->{amdump} ||= {};
1114
1115     if ( $type == $L_INFO ) {
1116         $self->_handle_info_line("amdump", $str);
1117
1118     } elsif ( $type == $L_START ) {
1119         $self->_handle_start_line("amdump", $str);
1120
1121     } elsif ( $type == $L_FATAL ) {
1122         return $self->_handle_fatal_line( "amdump", $str );
1123
1124     } elsif ( $type == $L_ERROR ) {
1125         $self->_handle_error_line("amdump", $str);
1126     }
1127 }
1128
1129
1130 sub _handle_fail_line
1131 {
1132     my ($self, $program, $str) = @_;
1133
1134     my @info = Amanda::Util::split_quoted_strings($str);
1135     my ($hostname, $disk, $timestamp, $level) = @info;
1136     my $error;
1137     my $failure_from;
1138     if ($program eq 'taper') {
1139         $failure_from = $info[4];
1140         $error = join " ", @info[ 5 .. $#info ];
1141     } else {
1142         $error = join " ", @info[ 4 .. $#info ];
1143     }
1144
1145     #TODO: verify that this reaches the right try.  Also, DLE or
1146     #program?
1147     my $dle = $self->get_dle_info($hostname, $disk);
1148
1149     my $program_d;
1150     if ($program eq "planner" ||
1151         $program eq "driver") {
1152         $program_d = $dle->{$program} ||= {};
1153     } else {
1154         my $try = $self->_get_try($dle, $program, $timestamp);
1155         $program_d = $try->{$program} ||= {};
1156     }
1157
1158     $program_d->{level}  = $level;
1159     $program_d->{status} = "fail";
1160     $program_d->{failure_from}  = $failure_from;
1161     $program_d->{error}  = $error;
1162
1163     my $errors = $self->get_program_info("program", "errors", []);
1164     push @$errors, $error;
1165
1166     $self->{flags}{exit_status} |= STATUS_FAILED;
1167     if ($program eq "dumper") {
1168         $self->{contline} = $program_d->{errors} ||= [];
1169         $program_d->{nb_errors} = 0;
1170         $self->{nbline_ref} = \$program_d->{nb_errors};
1171         $self->{nb_normal} = 0;
1172         $self->{nb_strange} = 0;
1173         $self->{nb_error} = 0;
1174     }
1175 }
1176
1177
1178 sub _handle_error_line
1179 {
1180     my $self = shift @_;
1181     my ( $program, $str ) = @_;
1182
1183     my $data      = $self->{data};
1184     my $programs  = $data->{programs};
1185     my $program_p = $programs->{$program};
1186     my $errors_p  = $program_p->{errors} ||= [];
1187
1188     $self->{flags}{exit_status} |= 1;
1189
1190     push @$errors_p, $str;
1191 }
1192
1193
1194 sub _handle_fatal_line
1195 {
1196     my $self = shift @_;
1197     my ( $program, $str ) = @_;
1198
1199     my $data      = $self->{data};
1200     my $programs  = $data->{programs};
1201     my $program_p = $programs->{$program};
1202     my $fatal_p  = $program_p->{fatal} ||= [];
1203
1204     $self->{flags}{exit_status} |= 1;
1205
1206     push @$fatal_p, $str;
1207 }
1208
1209
1210 sub _handle_start_line
1211 {
1212     my $self = shift @_;
1213     my ( $program, $str ) = @_;
1214
1215     my $data     = $self->{data};
1216     my $disklist = $data->{disklist};
1217     my $programs = $data->{programs};
1218
1219     my $program_p = $programs->{$program} ||= {};
1220
1221     my @info = Amanda::Util::split_quoted_strings($str);
1222     my $timestamp = $info[1];
1223     $program_p->{start} = $info[1];
1224
1225     if ($self->{'run_timestamp'} ne '00000000000000'
1226                 and $self->{'run_timestamp'} ne $timestamp) {
1227         warning("not all timestamps in this file are the same; "
1228                 . "$self->{run_timestamp}; $timestamp");
1229     }
1230     $self->{'run_timestamp'} = $timestamp;
1231 }
1232
1233
1234 sub _handle_disk_line
1235 {
1236     my $self = shift @_;
1237     my ($program, $str) = @_;
1238
1239     my $data     = $self->{data};
1240     my $disklist = $data->{disklist};
1241     my $hosts    = $self->{cache}{hosts} ||= [];
1242     my $dles     = $self->{cache}{dles}  ||= [];
1243
1244     my @info = Amanda::Util::split_quoted_strings($str);
1245     my ($hostname, $disk) = @info;
1246
1247     if (!exists $disklist->{$hostname}) {
1248
1249         $disklist->{$hostname} = {};
1250         push @$hosts, $hostname;
1251     }
1252
1253     if (!exists $disklist->{$hostname}{$disk}) {
1254
1255         push @$dles, [ $hostname, $disk ];
1256         my $dle = $disklist->{$hostname}{$disk} = {};
1257         $dle->{'estimate'} = undef;
1258         $dle->{'dumps'}    = {};
1259     }
1260     return;
1261 }
1262
1263 sub _handle_success_line
1264 {
1265     my $self = shift @_;
1266     my ($program, $str) = @_;
1267
1268     my $data     = $self->{data};
1269     my $disklist = $data->{disklist};
1270     my $hosts    = $self->{cache}{hosts} ||= [];
1271     my $dles     = $self->{cache}{dles}  ||= [];
1272
1273     my @info = Amanda::Util::split_quoted_strings($str);
1274     my ($hostname, $disk, $timestamp, $level, $stat1, $stat2) = @info;
1275
1276     if ($stat1 =~ /skipped/) {
1277         $disklist->{$hostname}{$disk}->{$program}->{'status'} = 'skipped';
1278     }
1279     return;
1280 }
1281
1282
1283 sub _handle_info_line
1284 {
1285     my $self = shift @_;
1286     my ( $program, $str ) = @_;
1287
1288     my $data     = $self->{data};
1289     my $disklist = $data->{disklist};
1290     my $programs = $data->{programs};
1291
1292     my $program_p = $programs->{$program} ||= {};
1293
1294     if ( $str =~ m/^\w+ pid \d+/ || $str =~ m/^pid-done \d+/ ) {
1295
1296         #do not report pid lines
1297         return;
1298
1299     } else {
1300         my $notes = $program_p->{notes} ||= [];
1301         push @$notes, $str;
1302     }
1303 }
1304
1305 sub _handle_warning_line
1306 {
1307     my $self = shift @_;
1308     my ( $program, $str ) = @_;
1309
1310     $self->_handle_info_line($program, $str);
1311 }
1312
1313 sub _handle_bogus_line
1314 {
1315     my $self = shift @_;
1316     my ( $prog, $type, $str ) = @_;
1317
1318     my $data = $self->{data};
1319     my $boguses = $data->{boguses} ||= [];
1320     push @$boguses, [ $prog, $type, $str ];
1321 }
1322
1323 sub check_missing_fail_strange
1324 {
1325     my ($self) = @_;
1326     my @dles = $self->get_dles();
1327
1328     foreach my $dle_entry (@dles) {
1329         my $alldumps = $self->get_dle_info(@$dle_entry, 'dumps');
1330         my $driver = $self->get_dle_info(@$dle_entry, 'driver');
1331         my $planner = $self->get_dle_info(@$dle_entry, 'planner');
1332
1333         if ($planner && $planner->{'status'} eq 'fail') {
1334             $self->{flags}{dump_failed} = 1;
1335         } elsif ($planner && $planner->{'status'} eq 'skipped') {
1336             # We don't want these to be counted as missing below
1337         } elsif (!defined $alldumps->{$self->{'run_timestamp'}} and
1338                  !$driver and
1339                  !$planner) {
1340             $self->{flags}{results_missing} = 1;
1341             $self->{flags}{exit_status} |= STATUS_MISSING;
1342         } else {
1343             #get latest try
1344             my $tries = $alldumps->{$self->{'run_timestamp'}};
1345             my $try = @$tries[-1];
1346
1347             if (exists $try->{dumper} && $try->{dumper}->{status} eq 'fail') {
1348                 $self->{flags}{dump_failed} = 1;
1349             } elsif ((defined($try->{'chunker'}) &&
1350                  $try->{'chunker'}->{status} eq 'success') ||
1351                 (defined($try->{'taper'}) &&
1352                  $try->{'taper'}->{status} eq 'done')) {
1353                 #chunker or taper success, use dumper status
1354                 if (exists $try->{dumper} && $try->{dumper}->{status} eq 'strange') {
1355                     $self->{flags}{dump_strange} = 1;
1356                 }
1357             } else {
1358                 #chunker or taper failed, the dump is not valid.
1359                 $self->{flags}{dump_failed} = 1;
1360             }
1361         }
1362     }
1363 }
1364
1365 #
1366 # NOTE: there may be a complicated state diagram lurking in the midst
1367 # of taper and chunker.  You have been warned.
1368 #
1369 sub _get_try
1370 {
1371     my $self = shift @_;
1372     my ( $dle, $program, $timestamp ) = @_;
1373     my $tries = $dle->{'dumps'}{$timestamp} ||= [];
1374
1375     if (
1376         !@$tries    # no tries
1377         || defined $tries->[-1]->{$program}->{status}
1378         && $self->_program_finished(    # program has finished
1379             $program, $tries->[-1]->{$program}->{status}
1380         )
1381       ) {
1382         push @$tries, {};
1383     }
1384     return $tries->[-1];
1385 }
1386
1387
1388 sub _program_finished
1389 {
1390     my $self = shift @_;
1391     my ( $program, $status ) = @_;
1392
1393     if ( $program eq "chunker" ) {
1394
1395         if ( $status eq "partial" ) {
1396             return;
1397         } else {
1398             return 1;
1399         }
1400
1401     } elsif ( $status eq "done"
1402         || $status eq "success"
1403         || $status eq "fail"
1404         || $status eq "partial" ) {
1405         return 1;
1406
1407     } else {
1408         return 0;
1409     }
1410 }
1411
1412 1;