git.gag.com Git - debian/amanda/blob - installcheck/Amanda_Logfile.pl

   1 # Copyright (c) 2005-2008 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 Mathlida Ave, Suite 300
  17 # Sunnyvale, CA 94086, USA, or: http://www.zmanda.com
  18
  19 use Test::More tests => 30;
  20 use File::Path;
  21 use strict;
  22
  23 use lib "@amperldir@";
  24 use Installcheck::Config;
  25 use Amanda::Paths;
  26 use Amanda::Tapelist;
  27 use Amanda::Cmdline;
  28 use Amanda::Logfile qw(:logtype_t :program_t open_logfile get_logline close_logfile);
  29 use Amanda::Config qw( :init :getconf config_dir_relative );
  30
  31 my $log_filename = "$AMANDA_TMPDIR/Amanda_Logfile_test.log";
  32
  33 # write a logfile and return the filename
  34 sub write_logfile {
  35     my ($contents) = @_;
  36
  37     if (!-e $AMANDA_TMPDIR) {
  38         mkpath($AMANDA_TMPDIR);
  39     }
  40
  41     open my $logfile, ">", $log_filename or die("Could not create temporary log file '$log_filename': $!");
  42     print $logfile $contents;
  43     close $logfile;
  44
  45     return $log_filename;
  46 }
  47
  48 sub unlink_logfile {
  49     unlink($log_filename);
  50 }
  51
  52 ####
  53 ## RAW LOGFILE ACCESS
  54
  55 my $logfile;
  56 my $logdata;
  57
  58 ##
  59 # Test out the constant functions
  60
  61 is(logtype_t_to_string($L_MARKER), "L_MARKER", "logtype_t_to_string works");
  62 is(program_t_to_string($P_DRIVER), "P_DRIVER", "program_t_to_string works");
  63
  64 ##
  65 # Test a simple logfile
  66
  67 $logdata = <<END;
  68 START planner date 20071026183200
  69 END
  70
  71 $logfile = open_logfile(write_logfile($logdata));
  72 ok($logfile, "can open a simple logfile");
  73 is_deeply([ get_logline($logfile) ],
  74           [ $L_START, $P_PLANNER, "date 20071026183200" ],
  75           "reads START line correctly");
  76 ok(!get_logline($logfile), "no second line");
  77 close_logfile($logfile);
  78
  79 ##
  80 # Test continuation lines
  81
  82 $logdata = <<END;
  83 INFO chunker line1
  84   line2
  85 END
  86
  87 $logfile = open_logfile(write_logfile($logdata));
  88 ok($logfile, "can open a logfile containing conitinuation lines");
  89 is_deeply([ get_logline($logfile) ],
  90           [ $L_INFO, $P_CHUNKER, "line1" ],
  91           "can read INFO line");
  92 is_deeply([ get_logline($logfile) ],
  93           [ $L_CONT, $P_CHUNKER, "line2" ],
  94           "can read continuation line");
  95 ok(!get_logline($logfile), "no third line");
  96 close_logfile($logfile);
  97
  98 ##
  99 # Test skipping blank lines
 100
 101 # (retain the two blank lines in the following:)
 102 $logdata = <<END;
 103
 104 STATS taper foo
 105
 106 END
 107
 108 $logfile = open_logfile(write_logfile($logdata));
 109 ok($logfile, "can open a logfile containing blank lines");
 110 is_deeply([ get_logline($logfile) ],
 111           [ $L_STATS, $P_TAPER, "foo" ],
 112           "reads non-blank line correctly");
 113 ok(!get_logline($logfile), "no second line");
 114 close_logfile($logfile);
 115
 116 ##
 117 # Test BOGUS values and short lines
 118
 119 $logdata = <<END;
 120 SOMETHINGWEIRD somerandomprog bar
 121 MARKER amflush
 122 MARKER amflush put something in curstr
 123 PART
 124 END
 125
 126 $logfile = open_logfile(write_logfile($logdata));
 127 ok($logfile, "can open a logfile containing bogus entries");
 128 is_deeply([ get_logline($logfile) ],
 129           [ $L_BOGUS, $P_UNKNOWN, "bar" ],
 130           "can read line with bogus program and logtype");
 131 is_deeply([ get_logline($logfile) ],
 132           [ $L_MARKER, $P_AMFLUSH, "" ],
 133           "can read line with an empty string");
 134 ok(get_logline($logfile), "can read third line (to fill in curstr with some text)");
 135 is_deeply([ get_logline($logfile) ],
 136           [ $L_PART, $P_UNKNOWN, "" ],
 137           "can read a one-word line, with P_UNKNOWN");
 138 ok(!get_logline($logfile), "no next line");
 139 close_logfile($logfile);
 140
 141 ## HIGHER-LEVEL FUNCTIONS
 142
 143 # a utility function for is_deeply checks, below.  Converts a hash to
 144 # an array, for more succinct comparisons
 145 sub res2arr {
 146     my ($res) = @_;
 147     return [
 148         $res->{'timestamp'},
 149         $res->{'hostname'},
 150         $res->{'diskname'},
 151         "$res->{'level'}",
 152         $res->{'label'},
 153         "$res->{'filenum'}",
 154         $res->{'status'},
 155         $res->{'partnum'}
 156     ];
 157 }
 158
 159 # set up a basic config
 160 my $testconf = Installcheck::Config->new();
 161 $testconf->add_param("tapecycle", "20");
 162 $testconf->write();
 163
 164 # load the config
 165 config_init($CONFIG_INIT_EXPLICIT_NAME, "TESTCONF") == $CFGERR_OK
 166     or die("Could not load config");
 167 my $tapelist = config_dir_relative("tapelist");
 168
 169 # set up and read the tapelist (we don't use Amanda::Tapelist to write this,
 170 # in case it's broken)
 171 open my $tlf, ">", $tapelist or die("Could not write tapelist");
 172 print $tlf "20071111010002 TESTCONF006 reuse\n";
 173 print $tlf "20071110010002 TESTCONF005 reuse\n";
 174 print $tlf "20071109010002 TESTCONF004 reuse\n";
 175 print $tlf "20071109010002 TESTCONF003 reuse\n";
 176 print $tlf "20071109010002 TESTCONF002 reuse\n";
 177 print $tlf "20071108010001 TESTCONF001 reuse\n";
 178 close $tlf;
 179 Amanda::Tapelist::read_tapelist($tapelist);
 180
 181 # set up a number of logfiles in logdir.
 182 my $logf;
 183 my $logdir = $testconf->{'logdir'};
 184
 185 # (an old log file that should be ignored)
 186 open $logf, ">", "$logdir/log.20071106010002.0" or die("Could not write logfile");
 187 print $logf "START taper datestamp 20071107010002 label TESTCONF017 tape 1\n";
 188 close $logf;
 189
 190 # (a logfile with two tapes)
 191 open $logf, ">", "$logdir/log.20071106010002.0" or die("Could not write logfile");
 192 print $logf "START taper datestamp 20071106010002 label TESTCONF018 tape 1\n";
 193 print $logf "START taper datestamp 20071106010002 label TESTCONF019 tape 2\n";
 194 close $logf;
 195
 196 open $logf, ">", "$logdir/log.20071108010001.0" or die("Could not write logfile");
 197 print $logf "START taper datestamp 20071108010001 label TESTCONF001 tape 1\n";
 198 close $logf;
 199
 200 # a logfile with some detail, to run search_logfile against
 201 open $logf, ">", "$logdir/log.20071109010002.0" or die("Could not write logfile");
 202 print $logf <<EOF;
 203 START taper datestamp 20071109010002 label TESTCONF002 tape 1
 204 PART taper TESTCONF002 1 clihost /usr 20071109010002 1 0 [regular single part PART]
 205 DONE taper clihost /usr 20071109010002 1 0 [regular single part DONE]
 206 PART taper TESTCONF002 2 clihost "/my documents" 20071109010002 1 0 [diskname quoting]
 207 DONE taper clihost "/my documents" 20071109010002 1 0 [diskname quoting]
 208 PART taper TESTCONF002 3 thatbox /var 1 [regular 'old style' PART]
 209 DONE taper thatbox /var 1 [regular 'old style' DONE]
 210 PART taper TESTCONF002 4 clihost /home 20071109010002 1/5 0 [multi-part dump]
 211 PART taper TESTCONF002 5 clihost /home 20071109010002 2/5 0 [multi-part dump]
 212 PART taper TESTCONF002 6 clihost /home 20071109010002 3/5 0 [multi-part dump]
 213 PART taper TESTCONF002 7 clihost /home 20071109010002 4/5 0 [multi-part dump]
 214 PART taper TESTCONF002 8 clihost /home 20071109010002 5/5 0 [multi-part dump]
 215 DONE taper clihost /home 20071109010002 5 0 [multi-part dump]
 216 PART taper TESTCONF002 9 thatbox /u_lose 20071109010002 1/4 2 [multi-part failure]
 217 PART taper TESTCONF002 10 thatbox /u_lose 20071109010002 2/4 2 [multi-part failure]
 218 PARTPARTIAL taper TESTCONF002 11 thatbox /u_lose 20071109010002  3/4 2 [multi-part retry]
 219 START taper datestamp 20071109010002 label TESTCONF003 tape 1
 220 PART taper TESTCONF003 1 thatbox /u_lose 20071109010002 3/4 2 [multi-part failure]
 221 FAIL taper thatbox /u_lose 20071109010002 2 "Oh no!"
 222 PART taper TESTCONF003 2 thatbox /u_win 20071109010002 1/4 3 [multi-part retry]
 223 PART taper TESTCONF003 3 thatbox /u_win 20071109010002 2/4 3 [multi-part retry]
 224 PARTPARTIAL taper TESTCONF003 4 thatbox /u_win 20071109010002  3/4 3 [multi-part retry]
 225 START taper datestamp 20071109010002 label TESTCONF004 tape 1
 226 PART taper TESTCONF004 1 thatbox /u_win 20071109010002 3/4 3 [multi-part retry]
 227 PART taper TESTCONF004 2 thatbox /u_win 20071109010002 4/4 3 [multi-part retry]
 228 DONE taper thatbox /u_win 20071109010002 4 3 [multi-part retry]
 229 EOF
 230 close $logf;
 231
 232 # "old-style amflush log"
 233 open $logf, ">", "$logdir/log.20071110010002.amflush" or die("Could not write logfile");
 234 print $logf "START taper datestamp 20071110010002 label TESTCONF005 tape 1\n";
 235 close $logf;
 236
 237 # "old-style main log"
 238 open $logf, ">", "$logdir/log.20071111010002" or die("Could not write logfile");
 239 print $logf "START taper datestamp 20071111010002 label TESTCONF006 tape 1\n";
 240 close $logf;
 241
 242 is_deeply([ Amanda::Logfile::find_log() ],
 243           [ "log.20071111010002", "log.20071110010002.amflush",
 244             "log.20071109010002.0", "log.20071108010001.0" ],
 245           "find_log returns correct logfiles in the correct order");
 246
 247 my @results;
 248 my @results2;
 249 my @results3;
 250 my @results4;
 251 my @results_arr;
 252
 253 @results2 = Amanda::Logfile::search_logfile("TESTCONF002", "20071109010002",
 254                                            "$logdir/log.20071109010002.0", 1);
 255 @results3 = Amanda::Logfile::search_logfile("TESTCONF003", "20071109010002",
 256                                            "$logdir/log.20071109010002.0", 1);
 257 @results4 = Amanda::Logfile::search_logfile("TESTCONF004", "20071109010002",
 258                                            "$logdir/log.20071109010002.0", 1);
 259 @results = ();
 260 push @results, @results2, @results3, @results4;
 261 is($#results+1, 17, "search_logfile returned 15 results");
 262
 263 # sort by filenum so we can compare each to what it should be
 264 @results = sort { $a->{'label'} cmp $b->{'label'} ||
 265                   $a->{'filenum'} <=> $b->{'filenum'} } @results;
 266
 267 # and convert the hashes to arrays for easy comparison
 268 @results_arr = map { res2arr($_) } @results;
 269
 270 is_deeply(\@results_arr,
 271         [
 272           [ '20071109010002', 'clihost', '/usr',            0, 'TESTCONF002', 1,  'OK', '1'   ],
 273           [ '20071109010002', 'clihost', '/my documents',   0, 'TESTCONF002', 2,  'OK', '1'   ],
 274           [ '20071109010002', 'thatbox', '/var',            1, 'TESTCONF002', 3,  'OK', '--'  ],
 275           [ '20071109010002', 'clihost', '/home',           0, 'TESTCONF002', 4,  'OK', '1/5' ],
 276           [ '20071109010002', 'clihost', '/home',           0, 'TESTCONF002', 5,  'OK', '2/5' ],
 277           [ '20071109010002', 'clihost', '/home',           0, 'TESTCONF002', 6,  'OK', '3/5' ],
 278           [ '20071109010002', 'clihost', '/home',           0, 'TESTCONF002', 7,  'OK', '4/5' ],
 279           [ '20071109010002', 'clihost', '/home',           0, 'TESTCONF002', 8,  'OK', '5/5' ],
 280           [ '20071109010002', 'thatbox', '/u_lose',   2, 'TESTCONF002', 9,  'OK', '1/4' ],
 281           [ '20071109010002', 'thatbox', '/u_lose',   2, 'TESTCONF002', 10, 'OK', '2/4' ],
 282           [ '20071109010002', 'thatbox', '/u_lose',   2, 'TESTCONF002', 11, 'PARTIAL', '3/4' ],
 283           [ '20071109010002', 'thatbox', '/u_lose',   2, 'TESTCONF003', 1,  '"Oh no!"', '3/4' ],
 284           [ '20071109010002', 'thatbox', '/u_win',    3, 'TESTCONF003', 2, 'OK', '1/4' ],
 285           [ '20071109010002', 'thatbox', '/u_win',    3, 'TESTCONF003', 3, 'OK', '2/4' ],
 286           [ '20071109010002', 'thatbox', '/u_win',    3, 'TESTCONF003', 4, 'PARTIAL', '3/4' ],
 287           [ '20071109010002', 'thatbox', '/u_win',    3, 'TESTCONF004', 1, 'OK', '3/4' ],
 288           [ '20071109010002', 'thatbox', '/u_win',    3, 'TESTCONF004', 2, 'OK', '4/4' ],
 289         ], "results are correct");
 290
 291 my @filtered;
 292 my @filtered_arr;
 293
 294 @filtered = Amanda::Logfile::dumps_match([@results], "thatbox", undef, undef, undef, 0);
 295 is($#filtered+1, 10, "ten results match 'thatbox'");
 296 @filtered = sort { $a->{'label'} cmp $b->{'label'} ||
 297                    $a->{'filenum'} <=> $b->{'filenum'} } @filtered;
 298
 299 @filtered_arr = map { res2arr($_) } @filtered;
 300
 301 is_deeply(\@filtered_arr,
 302         [
 303           [ '20071109010002', 'thatbox', '/var',      1, 'TESTCONF002', 3,  'OK',       '--' ],
 304           [ '20071109010002', 'thatbox', '/u_lose',   2, 'TESTCONF002', 9,  'OK',       '1/4' ],
 305           [ '20071109010002', 'thatbox', '/u_lose',   2, 'TESTCONF002', 10, 'OK',       '2/4' ],
 306           [ '20071109010002', 'thatbox', '/u_lose',   2, 'TESTCONF002', 11, 'PARTIAL',  '3/4' ],
 307           [ '20071109010002', 'thatbox', '/u_lose',   2, 'TESTCONF003', 1,  '"Oh no!"', '3/4' ],
 308           [ '20071109010002', 'thatbox', '/u_win',    3, 'TESTCONF003', 2,  'OK',       '1/4' ],
 309           [ '20071109010002', 'thatbox', '/u_win',    3, 'TESTCONF003', 3,  'OK',       '2/4' ],
 310           [ '20071109010002', 'thatbox', '/u_win',    3, 'TESTCONF003', 4,  'PARTIAL',  '3/4' ],
 311           [ '20071109010002', 'thatbox', '/u_win',    3, 'TESTCONF004', 1,  'OK',       '3/4' ],
 312           [ '20071109010002', 'thatbox', '/u_win',    3, 'TESTCONF004', 2,  'OK',       '4/4' ],
 313         ], "results are correct");
 314
 315 @filtered = Amanda::Logfile::dumps_match([@results], "thatbox", "/var", undef, undef, 0);
 316 is($#filtered+1, 1, "only one result matches 'thatbox:/var'");
 317
 318 @filtered = Amanda::Logfile::dumps_match([@results], undef, undef, "20071109010002", undef, 0);
 319 is($#filtered+1, 17, "all 17 results match '20071109010002'");
 320
 321 @filtered = Amanda::Logfile::dumps_match([@results], undef, undef, "20071109010002", undef, 1);
 322 is($#filtered+1, 14, "of those, 14 results are 'OK'");
 323
 324 @filtered = Amanda::Logfile::dumps_match([@results], undef, undef, undef, "2", 0);
 325 is($#filtered+1, 4, "4 results are at level 2");
 326
 327 # test dumps_match_dumpspecs
 328
 329 my @dumpspecs;
 330
 331 @dumpspecs = Amanda::Cmdline::parse_dumpspecs(["thatbox", "/var"], 0);
 332 @filtered = Amanda::Logfile::dumps_match_dumpspecs([@results], [@dumpspecs], 0);
 333 is_deeply([ map { res2arr($_) } @filtered ],
 334         [
 335           [ '20071109010002', 'thatbox', '/var',            1, 'TESTCONF002', 3,  'OK', '--'  ],
 336         ], "filter with dumpspecs 'thatbox /var'");
 337
 338 @dumpspecs = Amanda::Cmdline::parse_dumpspecs(["thatbox", "/var", "clihost"], 0);
 339 @filtered = Amanda::Logfile::dumps_match_dumpspecs([@results], [@dumpspecs], 0);
 340 @filtered = sort { $a->{'label'} cmp $b->{'label'} ||
 341                    $a->{'filenum'} <=> $b->{'filenum'} } @filtered;
 342 is_deeply([ map { res2arr($_) } @filtered ],
 343         [
 344           [ '20071109010002', 'clihost', '/usr',            0, 'TESTCONF002', 1,  'OK', '1'   ],
 345           [ '20071109010002', 'clihost', '/my documents',   0, 'TESTCONF002', 2,  'OK', '1'   ],
 346           [ '20071109010002', 'thatbox', '/var',            1, 'TESTCONF002', 3,  'OK', '--'  ],
 347           [ '20071109010002', 'clihost', '/home',           0, 'TESTCONF002', 4,  'OK', '1/5' ],
 348           [ '20071109010002', 'clihost', '/home',           0, 'TESTCONF002', 5,  'OK', '2/5' ],
 349           [ '20071109010002', 'clihost', '/home',           0, 'TESTCONF002', 6,  'OK', '3/5' ],
 350           [ '20071109010002', 'clihost', '/home',           0, 'TESTCONF002', 7,  'OK', '4/5' ],
 351           [ '20071109010002', 'clihost', '/home',           0, 'TESTCONF002', 8,  'OK', '5/5' ],
 352         ], "filter with dumpspecs 'thatbox /var clihost' (union of two disjoint sets)");
 353
 354 # if multiple dumpspecs specify the same dump, it will be included in the output multiple times
 355 @dumpspecs = Amanda::Cmdline::parse_dumpspecs([".*", "/var", "thatbox"], 0);
 356 @filtered = Amanda::Logfile::dumps_match_dumpspecs([@results], [@dumpspecs], 0);
 357 @filtered = sort { $a->{'label'} cmp $b->{'label'} ||
 358                    $a->{'filenum'} <=> $b->{'filenum'} } @filtered;
 359 is_deeply([ map { res2arr($_) } @filtered ],
 360         [
 361           [ '20071109010002', 'thatbox', '/var',      1, 'TESTCONF002', 3,  'OK',       '--'  ],
 362           [ '20071109010002', 'thatbox', '/u_lose',   2, 'TESTCONF002', 9,  'OK',       '1/4' ],
 363           [ '20071109010002', 'thatbox', '/u_lose',   2, 'TESTCONF002', 10, 'OK',       '2/4' ],
 364           [ '20071109010002', 'thatbox', '/u_lose',   2, 'TESTCONF002', 11, 'PARTIAL',  '3/4' ],
 365           [ '20071109010002', 'thatbox', '/u_lose',   2, 'TESTCONF003', 1,  '"Oh no!"', '3/4' ],
 366           [ '20071109010002', 'thatbox', '/u_win',    3, 'TESTCONF003', 2,  'OK',       '1/4' ],
 367           [ '20071109010002', 'thatbox', '/u_win',    3, 'TESTCONF003', 3,  'OK',       '2/4' ],
 368           [ '20071109010002', 'thatbox', '/u_win',    3, 'TESTCONF003', 4,  'PARTIAL',  '3/4' ],
 369           [ '20071109010002', 'thatbox', '/u_win',    3, 'TESTCONF004', 1,  'OK',       '3/4' ],
 370           [ '20071109010002', 'thatbox', '/u_win',    3, 'TESTCONF004', 2,  'OK',       '4/4' ],
 371         ], "filter with dumpspecs '.* /var thatbox' (union of two overlapping sets includes dupes)");
 372
 373 unlink_logfile();