1 # Copyright (c) 2007, 2008, 2009, 2010 Zmanda, Inc. All Rights Reserved.
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.
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
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
16 # Contact information: Zmanda Inc, 465 S. Mathilda Ave., Suite 300
17 # Sunnyvale, CA 94086, USA, or: http://www.zmanda.com
19 use Test::More tests => 35;
23 use lib "@amperldir@";
25 use Installcheck::Config;
31 use Amanda::Debug qw( :logging );
32 use Amanda::Logfile qw(:logtype_t :program_t open_logfile get_logline
33 close_logfile log_add $amanda_log_trace_log );
34 use Amanda::Config qw( :init :getconf config_dir_relative );
36 Amanda::Debug::dbopen("installcheck");
38 my $log_filename = "$Installcheck::TMP/Amanda_Logfile_test.log";
40 # write a logfile and return the filename
44 if (!-e $Installcheck::TMP) {
45 mkpath($Installcheck::TMP);
48 open my $logfile, ">", $log_filename or die("Could not create temporary log file '$log_filename': $!");
49 print $logfile $contents;
62 # Test out the constant functions
64 is(logtype_t_to_string($L_MARKER), "L_MARKER", "logtype_t_to_string works");
65 is(program_t_to_string($P_DRIVER), "P_DRIVER", "program_t_to_string works");
68 # Regression test for previously missing program types
69 is( program_t_to_string($P_AMDUMP),
70 "P_AMDUMP", "program type for amdump defined" );
71 is( program_t_to_string($P_AMIDXTAPED),
72 "P_AMIDXTAPED", "program type for amidxtaped defined" );
73 is( program_t_to_string($P_AMFETCHDUMP),
74 "P_AMFETCHDUMP", "program type for amfetchdump defined" );
75 is( program_t_to_string($P_AMCHECKDUMP),
76 "P_AMCHECKDUMP", "program type for amcheckdump defined" );
79 # Test a simple logfile
82 START planner date 20071026183200
85 $logfile = open_logfile(write_logfile($logdata));
86 ok($logfile, "can open a simple logfile");
87 is_deeply([ get_logline($logfile) ],
88 [ $L_START, $P_PLANNER, "date 20071026183200" ],
89 "reads START line correctly");
90 ok(!get_logline($logfile), "no second line");
91 close_logfile($logfile);
94 # Test continuation lines
101 $logfile = open_logfile(write_logfile($logdata));
102 ok($logfile, "can open a logfile containing continuation lines");
103 is_deeply([ get_logline($logfile) ],
104 [ $L_INFO, $P_CHUNKER, "line1" ],
105 "can read INFO line");
106 is_deeply([ get_logline($logfile) ],
107 [ $L_CONT, $P_CHUNKER, "line2" ],
108 "can read continuation line");
109 ok(!get_logline($logfile), "no third line");
110 close_logfile($logfile);
113 # Test skipping blank lines
115 # (retain the two blank lines in the following:)
122 $logfile = open_logfile(write_logfile($logdata));
123 ok($logfile, "can open a logfile containing blank lines");
124 is_deeply([ get_logline($logfile) ],
125 [ $L_STATS, $P_TAPER, "foo" ],
126 "reads non-blank line correctly");
127 ok(!get_logline($logfile), "no second line");
128 close_logfile($logfile);
131 # Test BOGUS values and short lines
134 SOMETHINGWEIRD somerandomprog bar
136 MARKER amflush put something in curstr
140 $logfile = open_logfile(write_logfile($logdata));
141 ok($logfile, "can open a logfile containing bogus entries");
142 is_deeply([ get_logline($logfile) ],
143 [ $L_BOGUS, $P_UNKNOWN, "bar" ],
144 "can read line with bogus program and logtype");
145 is_deeply([ get_logline($logfile) ],
146 [ $L_MARKER, $P_AMFLUSH, "" ],
147 "can read line with an empty string");
148 ok(get_logline($logfile), "can read third line (to fill in curstr with some text)");
149 is_deeply([ get_logline($logfile) ],
150 [ $L_PART, $P_UNKNOWN, "" ],
151 "can read a one-word line, with P_UNKNOWN");
152 ok(!get_logline($logfile), "no next line");
153 close_logfile($logfile);
155 ## HIGHER-LEVEL FUNCTIONS
157 # a utility function for is_deeply checks, below. Converts a hash to
158 # an array, for more succinct comparisons
169 $res->{'dump_status'},
172 "$res->{'totalparts'}"
176 # set up a basic config
177 my $testconf = Installcheck::Config->new();
178 $testconf->add_param("tapecycle", "20");
182 config_init($CONFIG_INIT_EXPLICIT_NAME, "TESTCONF") == $CFGERR_OK
183 or die("Could not load config");
184 my $tapelist = config_dir_relative("tapelist");
185 my $logdir = $testconf->{'logdir'};
189 my $filename = "$logdir/log";
191 -f "$filename" and unlink("$filename");
192 log_add($L_INFO, "This is my info");
194 open(my $fh, "<", $filename) or die("open $filename: $!");
195 my $logdata = do { local $/; <$fh> };
198 like($logdata, qr/^INFO Amanda_Logfile This is my info/, "log_add works");
201 # set up and read the tapelist (we don't use Amanda::Tapelist to write this,
202 # in case it's broken)
203 open my $tlf, ">", $tapelist or die("Could not write tapelist");
204 print $tlf "20071111010002 TESTCONF006 reuse\n";
205 print $tlf "20071110010002 TESTCONF005 reuse\n";
206 print $tlf "20071109010002 TESTCONF004 reuse\n";
207 print $tlf "20071109010002 TESTCONF003 reuse\n";
208 print $tlf "20071109010002 TESTCONF002 reuse\n";
209 print $tlf "20071108010001 TESTCONF001 reuse\n";
211 Amanda::Tapelist::read_tapelist($tapelist);
213 # set up a number of logfiles in logdir.
216 # (an old log file that should be ignored)
217 open $logf, ">", "$logdir/log.20071106010002.0" or die("Could not write logfile");
218 print $logf "START taper datestamp 20071107010002 label TESTCONF017 tape 1\n";
221 # (a logfile with two tapes)
222 open $logf, ">", "$logdir/log.20071106010002.0" or die("Could not write logfile");
223 print $logf "START taper datestamp 20071106010002 label TESTCONF018 tape 1\n";
224 print $logf "START taper datestamp 20071106010002 label TESTCONF019 tape 2\n";
227 open $logf, ">", "$logdir/log.20071108010001.0" or die("Could not write logfile");
228 print $logf "START taper datestamp 20071108010001 label TESTCONF001 tape 1\n";
231 # a logfile with some detail, to run search_logfile against
232 open $logf, ">", "$logdir/log.20071109010002.0" or die("Could not write logfile");
234 START taper datestamp 20071109010002 label TESTCONF002 tape 1
235 PART taper TESTCONF002 1 clihost /usr 20071109010002 1 0 [regular single part PART]
236 DONE taper clihost /usr 20071109010002 1 0 [regular single part DONE]
237 PART taper TESTCONF002 2 clihost "/my documents" 20071109010002 1 0 [diskname quoting]
238 DONE taper clihost "/my documents" 20071109010002 1 0 [diskname quoting]
239 PART taper TESTCONF002 3 thatbox /var 1 [regular 'old style' PART]
240 DONE taper thatbox /var 1 [regular 'old style' DONE]
241 PART taper TESTCONF002 4 clihost /home 20071109010002 1/5 0 [multi-part dump]
242 PART taper TESTCONF002 5 clihost /home 20071109010002 2/5 0 [multi-part dump]
243 PART taper TESTCONF002 6 clihost /home 20071109010002 3/5 0 [multi-part dump]
244 PART taper TESTCONF002 7 clihost /home 20071109010002 4/5 0 [multi-part dump]
245 PART taper TESTCONF002 8 clihost /home 20071109010002 5/5 0 [multi-part dump]
246 DONE taper clihost /home 20071109010002 5 0 [multi-part dump]
247 PART taper TESTCONF002 9 thatbox /u_lose 20071109010002 1/4 2 [multi-part failure]
248 PART taper TESTCONF002 10 thatbox /u_lose 20071109010002 2/4 2 [multi-part failure]
249 PARTPARTIAL taper TESTCONF002 11 thatbox /u_lose 20071109010002 3/4 2 [multi-part retry]
250 START taper datestamp 20071109010002 label TESTCONF003 tape 1
251 PART taper TESTCONF003 1 thatbox /u_lose 20071109010002 3/4 2 [multi-part failure]
252 FAIL taper thatbox /u_lose 20071109010002 2 "Oh no!"
253 PART taper TESTCONF003 2 thatbox /u_win 20071109010002 1/4 3 [multi-part retry]
254 PART taper TESTCONF003 3 thatbox /u_win 20071109010002 2/4 3 [multi-part retry]
255 PARTPARTIAL taper TESTCONF003 4 thatbox /u_win 20071109010002 3/4 3 [multi-part retry]
256 START taper datestamp 20071109010002 label TESTCONF004 tape 1
257 PART taper TESTCONF004 1 thatbox /u_win 20071109010002 3/4 3 [multi-part retry]
258 PART taper TESTCONF004 2 thatbox /u_win 20071109010002 4/4 3 [multi-part retry]
259 DONE taper thatbox /u_win 20071109010002 4 3 [multi-part retry]
263 # "old-style amflush log"
264 open $logf, ">", "$logdir/log.20071110010002.amflush" or die("Could not write logfile");
265 print $logf "START taper datestamp 20071110010002 label TESTCONF005 tape 1\n";
268 # "old-style main log"
269 open $logf, ">", "$logdir/log.20071111010002" or die("Could not write logfile");
270 print $logf "START taper datestamp 20071111010002 label TESTCONF006 tape 1\n";
273 is_deeply([ Amanda::Logfile::find_log() ],
274 [ "log.20071111010002", "log.20071110010002.amflush",
275 "log.20071109010002.0", "log.20071108010001.0" ],
276 "find_log returns correct logfiles in the correct order");
281 @results = Amanda::Logfile::search_logfile(undef, "20071109010002",
282 "$logdir/log.20071109010002.0", 1);
283 is($#results+1, 17, "search_logfile returned 17 results");
285 # sort by filenum so we can compare each to what it should be
286 @results = sort { $a->{'label'} cmp $b->{'label'} ||
287 $a->{'filenum'} <=> $b->{'filenum'} } @results;
289 # and convert the hashes to arrays for easy comparison
290 @results_arr = map { res2arr($_) } @results;
291 is_deeply(\@results_arr,
293 [ '20071109010002', 'clihost', '/usr', 0, 'TESTCONF002', 1, 'OK', 'OK', '', 1, 1 ],
294 [ '20071109010002', 'clihost', '/my documents', 0, 'TESTCONF002', 2, 'OK', 'OK', '', 1, 1 ],
295 [ '20071109010002', 'thatbox', '/var', 1, 'TESTCONF002', 3, 'OK', 'OK', '', 1, 1 ],
296 [ '20071109010002', 'clihost', '/home', 0, 'TESTCONF002', 4, 'OK', 'OK', '', 1, 5 ],
297 [ '20071109010002', 'clihost', '/home', 0, 'TESTCONF002', 5, 'OK', 'OK', '', 2, 5 ],
298 [ '20071109010002', 'clihost', '/home', 0, 'TESTCONF002', 6, 'OK', 'OK', '', 3, 5 ],
299 [ '20071109010002', 'clihost', '/home', 0, 'TESTCONF002', 7, 'OK', 'OK', '', 4, 5 ],
300 [ '20071109010002', 'clihost', '/home', 0, 'TESTCONF002', 8, 'OK', 'OK', '', 5, 5 ],
301 [ '20071109010002', 'thatbox', '/u_lose', 2, 'TESTCONF002', 9, 'OK', 'FAIL', '"Oh no!"', 1, 4 ],
302 [ '20071109010002', 'thatbox', '/u_lose', 2, 'TESTCONF002', 10, 'OK', 'FAIL', '"Oh no!"', 2, 4 ],
303 [ '20071109010002', 'thatbox', '/u_lose', 2, 'TESTCONF002', 11, 'PARTIAL', 'FAIL', '"Oh no!"', 3, 4 ],
304 [ '20071109010002', 'thatbox', '/u_lose', 2, 'TESTCONF003', 1, 'OK', 'FAIL', '"Oh no!"', 3, 4 ],
305 [ '20071109010002', 'thatbox', '/u_win', 3, 'TESTCONF003', 2, 'OK', 'OK', '', 1, 4 ],
306 [ '20071109010002', 'thatbox', '/u_win', 3, 'TESTCONF003', 3, 'OK', 'OK', '', 2, 4 ],
307 [ '20071109010002', 'thatbox', '/u_win', 3, 'TESTCONF003', 4, 'PARTIAL', 'OK', '', 3, 4 ],
308 [ '20071109010002', 'thatbox', '/u_win', 3, 'TESTCONF004', 1, 'OK', 'OK', '', 3, 4 ],
309 [ '20071109010002', 'thatbox', '/u_win', 3, 'TESTCONF004', 2, 'OK', 'OK', '', 4, 4 ],
310 ], "results are correct");
315 @filtered = Amanda::Logfile::dumps_match([@results], "thatbox", undef, undef, undef, 0);
316 is($#filtered+1, 10, "ten results match 'thatbox'");
317 @filtered = sort { $a->{'label'} cmp $b->{'label'} ||
318 $a->{'filenum'} <=> $b->{'filenum'} } @filtered;
320 @filtered_arr = map { res2arr($_) } @filtered;
322 is_deeply(\@filtered_arr,
324 [ '20071109010002', 'thatbox', '/var', 1, 'TESTCONF002', 3, 'OK', 'OK', '', 1, 1 ],
325 [ '20071109010002', 'thatbox', '/u_lose', 2, 'TESTCONF002', 9, 'OK', 'FAIL', '"Oh no!"', 1, 4 ],
326 [ '20071109010002', 'thatbox', '/u_lose', 2, 'TESTCONF002', 10, 'OK', 'FAIL', '"Oh no!"', 2, 4 ],
327 [ '20071109010002', 'thatbox', '/u_lose', 2, 'TESTCONF002', 11, 'PARTIAL', 'FAIL', '"Oh no!"', 3, 4 ],
328 [ '20071109010002', 'thatbox', '/u_lose', 2, 'TESTCONF003', 1, 'OK', 'FAIL', '"Oh no!"', 3, 4 ],
329 [ '20071109010002', 'thatbox', '/u_win', 3, 'TESTCONF003', 2, 'OK', 'OK', '', 1, 4 ],
330 [ '20071109010002', 'thatbox', '/u_win', 3, 'TESTCONF003', 3, 'OK', 'OK', '', 2, 4 ],
331 [ '20071109010002', 'thatbox', '/u_win', 3, 'TESTCONF003', 4, 'PARTIAL', 'OK', '', 3, 4 ],
332 [ '20071109010002', 'thatbox', '/u_win', 3, 'TESTCONF004', 1, 'OK', 'OK', '', 3, 4 ],
333 [ '20071109010002', 'thatbox', '/u_win', 3, 'TESTCONF004', 2, 'OK', 'OK', '', 4, 4 ],
334 ], "results are correct");
336 @filtered = Amanda::Logfile::dumps_match([@results], "thatbox", "/var", undef, undef, 0);
337 is($#filtered+1, 1, "only one result matches 'thatbox:/var'");
339 @filtered = Amanda::Logfile::dumps_match([@results], undef, undef, "20071109010002", undef, 0);
340 is($#filtered+1, 17, "all 17 results match '20071109010002'");
342 @filtered = Amanda::Logfile::dumps_match([@results], undef, undef, "20071109010002", undef, 1);
343 is($#filtered+1, 12, "of those, 12 results are 'OK'");
345 @filtered = Amanda::Logfile::dumps_match([@results], undef, undef, undef, "2", 0);
346 is($#filtered+1, 4, "4 results are at level 2");
348 # test dumps_match_dumpspecs
352 @dumpspecs = Amanda::Cmdline::parse_dumpspecs(["thatbox", "/var"], 0);
353 @filtered = Amanda::Logfile::dumps_match_dumpspecs([@results], [@dumpspecs], 0);
354 is_deeply([ map { res2arr($_) } @filtered ],
356 [ '20071109010002', 'thatbox', '/var', 1, 'TESTCONF002', 3, 'OK', 'OK', '', 1, 1 ],
357 ], "filter with dumpspecs 'thatbox /var'");
359 @dumpspecs = Amanda::Cmdline::parse_dumpspecs(["thatbox", "/var", "clihost"], 0);
360 @filtered = Amanda::Logfile::dumps_match_dumpspecs([@results], [@dumpspecs], 0);
361 @filtered = sort { $a->{'label'} cmp $b->{'label'} ||
362 $a->{'filenum'} <=> $b->{'filenum'} } @filtered;
363 is_deeply([ map { res2arr($_) } @filtered ],
365 [ '20071109010002', 'clihost', '/usr', 0, 'TESTCONF002', 1, 'OK', 'OK', '', 1, 1 ],
366 [ '20071109010002', 'clihost', '/my documents', 0, 'TESTCONF002', 2, 'OK', 'OK', '', 1, 1 ],
367 [ '20071109010002', 'thatbox', '/var', 1, 'TESTCONF002', 3, 'OK', 'OK', '', 1, 1 ],
368 [ '20071109010002', 'clihost', '/home', 0, 'TESTCONF002', 4, 'OK', 'OK', '', 1, 5 ],
369 [ '20071109010002', 'clihost', '/home', 0, 'TESTCONF002', 5, 'OK', 'OK', '', 2, 5 ],
370 [ '20071109010002', 'clihost', '/home', 0, 'TESTCONF002', 6, 'OK', 'OK', '', 3, 5 ],
371 [ '20071109010002', 'clihost', '/home', 0, 'TESTCONF002', 7, 'OK', 'OK', '', 4, 5 ],
372 [ '20071109010002', 'clihost', '/home', 0, 'TESTCONF002', 8, 'OK', 'OK', '', 5, 5 ],
373 ], "filter with dumpspecs 'thatbox /var clihost' (union of two disjoint sets)");
375 # if multiple dumpspecs specify the same dump, it will be included in the output multiple times
376 @dumpspecs = Amanda::Cmdline::parse_dumpspecs([".*", "/var", "thatbox"], 0);
377 @filtered = Amanda::Logfile::dumps_match_dumpspecs([@results], [@dumpspecs], 0);
378 @filtered = sort { $a->{'label'} cmp $b->{'label'} ||
379 $a->{'filenum'} <=> $b->{'filenum'} } @filtered;
380 is_deeply([ map { res2arr($_) } @filtered ],
382 [ '20071109010002', 'thatbox', '/var', 1, 'TESTCONF002', 3, 'OK', 'OK' , '', 1, 1 ],
383 [ '20071109010002', 'thatbox', '/u_lose', 2, 'TESTCONF002', 9, 'OK', 'FAIL', '"Oh no!"', 1, 4 ],
384 [ '20071109010002', 'thatbox', '/u_lose', 2, 'TESTCONF002', 10, 'OK', 'FAIL', '"Oh no!"', 2, 4 ],
385 [ '20071109010002', 'thatbox', '/u_lose', 2, 'TESTCONF002', 11, 'PARTIAL', 'FAIL', '"Oh no!"', 3, 4 ],
386 [ '20071109010002', 'thatbox', '/u_lose', 2, 'TESTCONF003', 1, 'OK', 'FAIL', '"Oh no!"', 3, 4 ],
387 [ '20071109010002', 'thatbox', '/u_win', 3, 'TESTCONF003', 2, 'OK', 'OK' , '', 1, 4 ],
388 [ '20071109010002', 'thatbox', '/u_win', 3, 'TESTCONF003', 3, 'OK', 'OK' , '', 2, 4 ],
389 [ '20071109010002', 'thatbox', '/u_win', 3, 'TESTCONF003', 4, 'PARTIAL', 'OK' , '', 3, 4 ],
390 [ '20071109010002', 'thatbox', '/u_win', 3, 'TESTCONF004', 1, 'OK', 'OK' , '', 3, 4 ],
391 [ '20071109010002', 'thatbox', '/u_win', 3, 'TESTCONF004', 2, 'OK', 'OK' , '', 4, 4 ],
392 ], "filter with dumpspecs '.* /var thatbox' (union of two overlapping sets includes dupes)");
394 unlink($log_filename);
396 # search_holding_disk and match_* are tested via Amanda::DB::Catalog's installcheck