1 # Copyright (c) 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 => 269;
23 use lib '@amperldir@';
24 use Installcheck::Run;
25 use Installcheck::Mock;
30 use POSIX ":sys_wait_h";
34 use Amanda::Header qw( :constants );
37 use Amanda::Device qw( :constants );
41 # We run a sequence of fixed interactions with the taper, putting it
42 # through its paces. Each message to or from the taper is represented
43 # as a test, for readability. If the taper produces unexpected results,
44 # the script dies, on the assumption that subsequent tests will be
47 # This uses IPC::Open3 instead of Expect mainly because the interactions
48 # are so carefully scripted that Expect is not required.
50 # put the debug messages somewhere
51 Amanda::Debug::dbopen("installcheck");
52 Installcheck::log_test_output();
54 my $test_filename = "$Installcheck::TMP/installcheck-taper-holding-file";
55 my $taper_stderr_file = "$Installcheck::TMP/taper-stderr";
56 my $debug = !exists $ENV{'HARNESS_ACTIVE'};
58 # information on the current run
59 my ($datestamp, $handle);
60 my ($taper_pid, $taper_in, $taper_out, $last_taper_reply, $taper_reply_timeout);
63 my ($length, $description, %params) = @_;
67 unless ($params{'keep_config'}) {
69 if ($params{'new_vtapes'}) {
70 $testconf = Installcheck::Run::setup(1);
72 $testconf = Installcheck::Run::setup();
74 $testconf->add_param('autolabel', '"TESTCONF%%" empty volume_error');
75 if ($params{'notapedev'}) {
76 $testconf->remove_param('tapedev');
77 $testconf->remove_param('tpchanger');
78 } elsif ($params{'ndmp_server'}) {
79 my $ndmp = $params{'ndmp_server'};
81 $ndmp->config($testconf);
83 unless ($params{'leom'} or $params{'ndmp_server'}) {
84 $testconf->add_param('device_property', '"LEOM" "OFF"');
86 $testconf->add_param('debug_taper', '9'); ## TEMPORARY
87 $testconf->add_tapetype('TEST-TAPE', [
88 'length' => "$length",
90 if ($params{'taperscan'}) {
91 $testconf->add_param('taperscan', "\"$params{'taperscan'}\"");
92 $testconf->add_taperscan($params{'taperscan'}, [
93 'comment' => '"my taperscan is mine, not yours"',
94 'plugin' => "\"$params{'taperscan'}\"",
101 open(TAPER_ERR, ">", $taper_stderr_file);
102 $taper_in = $taper_out = '';
103 $taper_pid = open3($taper_in, $taper_out, ">&TAPER_ERR",
104 "$amlibexecdir/taper", "TESTCONF");
106 $taper_in->blocking(1);
107 $taper_out->autoflush();
109 if ($params{'keep_config'}) {
110 pass("spawned new taper for $description (same config)");
112 pass("spawned taper for $description (tape length $length kb)");
115 # define this to get the installcheck to wait and allow you to attach
116 # a gdb instance to the taper
117 if ($params{'use_gdb'}) {
118 $taper_reply_timeout = 0; # no timeouts while debugging
119 diag("attach debugger to pid $taper_pid and press ENTER");
122 $taper_reply_timeout = 120;
125 taper_cmd("START-TAPER worker0 $datestamp");
130 waitpid($taper_pid, 0);
136 -f $test_filename and unlink($test_filename);
137 -f $taper_stderr_file and unlink($taper_stderr_file);
139 # make a small effort to collect zombies
141 if (waitpid($taper_pid, WNOHANG) == $taper_pid) {
150 diag(">>> $cmd") if $debug;
151 print $taper_in "$cmd\n";
155 local $SIG{ALRM} = sub { die "Timeout while waiting for reply\n" };
156 alarm($taper_reply_timeout);
157 $last_taper_reply = $taper_out->getline();
160 if (!$last_taper_reply) {
161 die("wrong pid") unless ($taper_pid == waitpid($taper_pid, 0));
162 my $exit_status = $?;
164 open(my $fh, "<", $taper_stderr_file) or die("open $taper_stderr_file: $!");
165 my $stderr = do { local $/; <$fh> };
168 diag("taper stderr:\n$stderr") if $stderr;
169 die("taper (pid $taper_pid) died unexpectedly with status $exit_status");
172 # trim trailing whitespace -- C taper outputs an extra ' ' after
173 # single-word replies
174 $last_taper_reply =~ s/\s*$//;
175 diag("<<< $last_taper_reply") if $debug;
177 return $last_taper_reply;
181 my ($expected, $msg) = @_;
185 # must contain a pid line at the beginning and end
186 unshift @$expected, qr/^INFO taper taper pid \d+$/;
187 push @$expected, qr/^INFO taper pid-done \d+$/;
189 open(my $logfile, "<", "$CONFIG_DIR/TESTCONF/log/log")
190 or die("opening log: $!");
191 my @logfile = grep(/^\S+ taper /, <$logfile>);
194 while (@logfile and @$expected) {
195 my $logline = shift @logfile;
196 my $expline = shift @$expected;
198 if ($logline !~ $expline) {
199 like($logline, $expline, $msg);
204 fail("$msg (extra trailing log lines)");
208 fail("$msg (logfile ends early)");
209 diag("first missing line should match ");
210 diag("".$expected->[0]);
218 my $logfile = "$CONFIG_DIR/TESTCONF/log/log";
219 -f $logfile and unlink($logfile);
222 # functions to create dumpfiles
224 sub write_dumpfile_header_to {
225 my ($fh, $size, $hostname, $disk, $expect_failure) = @_;
227 my $hdr = Amanda::Header->new();
228 $hdr->{'type'} = $Amanda::Header::F_DUMPFILE;
229 $hdr->{'datestamp'} = $datestamp;
230 $hdr->{'dumplevel'} = 0;
231 $hdr->{'compressed'} = 0;
232 $hdr->{'comp_suffix'} = ".foo";
233 $hdr->{'name'} = $hostname;
234 $hdr->{'disk'} = $disk;
235 $hdr->{'program'} = "INSTALLCHECK";
236 $hdr = $hdr->to_string(32768,32768);
238 $fh->syswrite($hdr, 32768);
241 sub write_dumpfile_data_to {
242 my ($fh, $size, $hostname, $disk, $expect_failure) = @_;
244 my $bytes_to_write = $size;
245 my $bufbase = substr((('='x127)."\n".('-'x127)."\n") x 4, 8, -3) . "1K\n";
246 die length($bufbase) unless length($bufbase) == 1024-8;
248 while ($bytes_to_write > 0) {
249 my $buf = sprintf("%08x", $k++).$bufbase;
250 my $written = $fh->syswrite($buf, $bytes_to_write);
251 if (!defined($written)) {
252 die "writing: $!" unless $expect_failure;
255 $bytes_to_write -= $written;
259 # make a new holding-like file in test_filename
260 sub make_holding_file {
261 my ($size, $hostname, $disk) = @_;
262 open(my $fh, ">", $test_filename);
263 write_dumpfile_header_to($fh, $size, $hostname, $disk);
264 write_dumpfile_data_to($fh, $size, $hostname, $disk);
267 # connect to the given port and write a dumpfile; this *will* create
268 # zombies, but it's OK -- installchecks aren't daemons.
270 my ($port_cmd, $size, $hostname, $disk, $expect_error) = @_;
272 my ($header_port, $data_addr) =
273 ($last_taper_reply =~ /^PORT worker0 $handle (\d+) "?(\d+\.\d+\.\d+\.\d+:\d+)/);
275 # just run this in the child
276 return unless fork() == 0;
278 my $sock = IO::Socket::INET->new(
279 PeerAddr => "127.0.0.1:$header_port",
284 write_dumpfile_header_to($sock, $size, $hostname, $disk, $expect_error);
287 $sock = IO::Socket::INET->new(
288 PeerAddr => $data_addr,
293 write_dumpfile_data_to($sock, $size, $hostname, $disk, $expect_error);
300 # A simple, one-part FILE-WRITE
301 $handle = "11-11111";
302 $datestamp = "20070102030405";
303 run_taper(4096, "single-part and multipart FILE-WRITE");
304 like(taper_reply, qr/^TAPER-OK worker0$/,
305 "got TAPER-OK") or die;
306 make_holding_file(1024*1024, "localhost", "/home");
307 taper_cmd("FILE-WRITE worker0 $handle \"$test_filename\" localhost /home 0 $datestamp \"\" \"\" \"\" \"\" \"\" \"\" \"\" \"\" 12");
308 like(taper_reply, qr/^REQUEST-NEW-TAPE $handle$/,
309 "got REQUEST-NEW-TAPE worker0 $handle") or die;
310 taper_cmd("START-SCAN worker0 $handle");
311 taper_cmd("NEW-TAPE worker0 $handle");
312 like(taper_reply, qr/^NEW-TAPE $handle TESTCONF01$/,
313 "got proper NEW-TAPE worker0 $handle") or die;
314 like(taper_reply, qr/^PARTDONE $handle TESTCONF01 1 1024 "\[sec [\d.]+ bytes 1048576 kps [\d.]+ orig-kb 12\]"$/,
315 "got PARTDONE") or die;
316 like(taper_reply, qr/^DONE $handle INPUT-GOOD TAPE-GOOD "\[sec [\d.]+ bytes 1048576 kps [\d.]+ orig-kb 12\]" "" ""$/,
320 # A multipart FILE-WRITE, using the same taper instance
321 # (note that the third part is of length 0, and is not logged)
323 $handle = '11-22222';
324 make_holding_file(1024*1024, "localhost", "/usr");
325 taper_cmd("FILE-WRITE worker0 $handle \"$test_filename\" localhost /usr 0 $datestamp 524288 \"\" \"\" 1 \"\" \"\" \"\" \"\" 512");
326 like(taper_reply, qr/^PARTDONE $handle TESTCONF01 2 512 "\[sec [\d.]+ bytes 524288 kps [\d.]+ orig-kb 512\]"$/,
327 "got PARTDONE for filenum 2") or die;
328 like(taper_reply, qr/^PARTDONE $handle TESTCONF01 3 512 "\[sec [\d.]+ bytes 524288 kps [\d.]+ orig-kb 512\]"$/,
329 "got PARTDONE for filenum 3") or die;
330 like(taper_reply, qr/^DONE $handle INPUT-GOOD TAPE-GOOD "\[sec [\d.]+ bytes 1048576 kps [\d.]+ orig-kb 512\]" "" ""$/,
336 qr(^INFO taper Slot 1 without label can be labeled$),
337 qr(^START taper datestamp $datestamp label TESTCONF01 tape 1$),
338 qr(^PART taper TESTCONF01 1 localhost /home $datestamp 1/-1 0 \[sec [\d.]+ bytes 1048576 kps [\d.]+ orig-kb 12\]$),
339 qr(^DONE taper localhost /home $datestamp 1 0 \[sec [\d.]+ bytes 1048576 kps [\d.]+ orig-kb 12\]$),
340 qr(^PART taper TESTCONF01 2 localhost /usr $datestamp 1/-1 0 \[sec [\d.]+ bytes 524288 kps [\d.]+ orig-kb 512\]$),
341 qr(^PART taper TESTCONF01 3 localhost /usr $datestamp 2/-1 0 \[sec [\d.]+ bytes 524288 kps [\d.]+ orig-kb 512\]$),
342 qr(^DONE taper localhost /usr $datestamp 2 0 \[sec [\d.]+ bytes 1048576 kps [\d.]+ orig-kb 512\]$),
343 qr(^INFO taper tape TESTCONF01 kb 2048 fm 4 \[OK\]$),
344 ], "single-part and multi-part dump logged correctly");
346 # check out the headers on those files, just to be sure
348 my $dev = Amanda::Device->new("file:" . Installcheck::Run::vtape_dir());
349 die("bad device: " . $dev->error_or_status()) unless $dev->status == $DEVICE_STATUS_SUCCESS;
351 $dev->start($ACCESS_READ, undef, undef)
352 or die("can't start device: " . $dev->error_or_status());
355 my ($hdr, $expected, $msg) = @_;
357 for (keys %$expected) { $got->{$_} = "".$hdr->{$_}; }
358 if (!is_deeply($got, $expected, $msg)) {
359 diag("got: " . Dumper($got));
363 is_hdr($dev->seek_file(1), {
364 type => $F_SPLIT_DUMPFILE,
365 datestamp => $datestamp,
368 }, "header on file 1 is correct");
370 is_hdr($dev->seek_file(2), {
371 type => $F_SPLIT_DUMPFILE,
372 datestamp => $datestamp,
377 }, "header on file 2 is correct");
379 is_hdr($dev->seek_file(3), {
380 type => $F_SPLIT_DUMPFILE,
381 datestamp => $datestamp,
386 }, "header on file 3 is correct");
388 is_hdr($dev->seek_file(4), {
389 type => $F_SPLIT_DUMPFILE,
390 datestamp => $datestamp,
395 }, "header on file 4 is correct");
399 # A PORT-WRITE with no disk buffer
401 $handle = "11-33333";
402 $datestamp = "19780615010203";
403 run_taper(4096, "multipart PORT-WRITE");
404 like(taper_reply, qr/^TAPER-OK worker0$/,
405 "got TAPER-OK") or die;
406 taper_cmd("PORT-WRITE worker0 $handle localhost /var 0 $datestamp 524288 \"\" 393216 1 0 \"\" \"\" 0 AMANDA");
407 like(taper_reply, qr/^PORT worker0 $handle (\d+) "?(\d+\.\d+\.\d+\.\d+:\d+;?)+"?$/,
408 "got PORT with data address");
409 write_to_port($last_taper_reply, 63*32768, "localhost", "/var", 0);
410 like(taper_reply, qr/^REQUEST-NEW-TAPE $handle$/,
411 "got REQUEST-NEW-TAPE worker0 $handle") or die;
412 taper_cmd("START-SCAN worker0 $handle");
413 taper_cmd("NEW-TAPE worker0 $handle");
414 like(taper_reply, qr/^NEW-TAPE $handle TESTCONF01$/,
415 "got proper NEW-TAPE worker0 $handle") or die;
416 like(taper_reply, qr/^PARTDONE $handle TESTCONF01 1 384 "\[sec [\d.]+ bytes 393216 kps [\d.]+\]"$/,
417 "got PARTDONE for filenum 1") or die;
418 like(taper_reply, qr/^PARTDONE $handle TESTCONF01 2 384 "\[sec [\d.]+ bytes 393216 kps [\d.]+\]"$/,
419 "got PARTDONE for filenum 2") or die;
420 like(taper_reply, qr/^PARTDONE $handle TESTCONF01 3 384 "\[sec [\d.]+ bytes 393216 kps [\d.]+\]"$/,
421 "got PARTDONE for filenum 3") or die;
422 like(taper_reply, qr/^PARTDONE $handle TESTCONF01 4 384 "\[sec [\d.]+ bytes 393216 kps [\d.]+\]"$/,
423 "got PARTDONE for filenum 4") or die;
424 like(taper_reply, qr/^PARTDONE $handle TESTCONF01 5 384 "\[sec [\d.]+ bytes 393216 kps [\d.]+\]"$/,
425 "got PARTDONE for filenum 5") or die;
426 like(taper_reply, qr/^PARTDONE $handle TESTCONF01 6 96 "\[sec [\d.]+ bytes 98304 kps [\d.]+\]"$/,
427 "got PARTDONE for filenum 6") or die;
428 like(taper_reply, qr/^DUMPER-STATUS $handle$/,
429 "got DUMPER-STATUS request") or die;
430 taper_cmd("DONE worker0 $handle 712");
431 like(taper_reply, qr/^DONE $handle INPUT-GOOD TAPE-GOOD "\[sec [\d.]+ bytes 2064384 kps [\d.]+ orig-kb 712\]" "" ""$/,
437 qr(^INFO taper Slot 1 without label can be labeled$),
438 qr(^START taper datestamp $datestamp label TESTCONF01 tape 1$),
439 qr(^PART taper TESTCONF01 1 localhost /var $datestamp 1/-1 0 \[sec [\d.]+ bytes 393216 kps [\d.]+\]$),
440 qr(^PART taper TESTCONF01 2 localhost /var $datestamp 2/-1 0 \[sec [\d.]+ bytes 393216 kps [\d.]+\]$),
441 qr(^PART taper TESTCONF01 3 localhost /var $datestamp 3/-1 0 \[sec [\d.]+ bytes 393216 kps [\d.]+\]$),
442 qr(^PART taper TESTCONF01 4 localhost /var $datestamp 4/-1 0 \[sec [\d.]+ bytes 393216 kps [\d.]+\]$),
443 qr(^PART taper TESTCONF01 5 localhost /var $datestamp 5/-1 0 \[sec [\d.]+ bytes 393216 kps [\d.]+\]$),
444 qr(^PART taper TESTCONF01 6 localhost /var $datestamp 6/-1 0 \[sec [\d.]+ bytes 98304 kps [\d.]+\]$),
445 qr(^DONE taper localhost /var $datestamp 6 0 \[sec [\d.]+ bytes 2064384 kps [\d.]+ orig-kb 712\]$),
446 qr(^INFO taper tape TESTCONF01 kb 2016 fm 6 \[OK\]$),
447 ], "multipart PORT-WRITE logged correctly");
452 $handle = "11-44444";
453 $datestamp = "19411207000000";
454 run_taper(4096, "testing NO-NEW-TAPE from the driver on 1st request");
455 like(taper_reply, qr/^TAPER-OK worker0$/,
456 "got TAPER-OK") or die;
457 make_holding_file(1024*1024, "localhost", "/home");
458 taper_cmd("FILE-WRITE worker0 $handle \"$test_filename\" localhost /home 0 $datestamp 0 \"\" 0 1 0 \"\" \"\" 0 912");
459 like(taper_reply, qr/^REQUEST-NEW-TAPE $handle$/,
460 "got REQUEST-NEW-TAPE worker0 $handle") or die;
461 taper_cmd("NO-NEW-TAPE worker0 $handle sorry");
462 like(taper_reply, qr/^FAILED $handle INPUT-GOOD TAPE-ERROR "" "?sorry"?.*$/,
463 "got FAILED") or die;
468 qr(^INFO taper Slot 1 without label can be labeled$),
469 qr(^ERROR taper no-tape config \[sorry\]$),
470 qr(^FAIL taper localhost /home $datestamp 0 config sorry$),
471 ], "NO-NEW-TAPE logged correctly");
474 # Test retrying on EOT (via PORT-WRITE with a mem cache)
476 $handle = "11-55555";
477 $datestamp = "19750711095836";
478 run_taper(1024, "PORT-WRITE retry on EOT (mem cache)");
479 like(taper_reply, qr/^TAPER-OK worker0$/,
480 "got TAPER-OK") or die;
481 taper_cmd("PORT-WRITE worker0 $handle localhost /usr/local 0 $datestamp 786432 \"\" 786432 1 0 \"\" \"\" 0 AMANDA");
482 like(taper_reply, qr/^PORT worker0 $handle (\d+) "?(\d+\.\d+\.\d+\.\d+:\d+;?)+"?$/,
483 "got PORT with data address");
484 write_to_port($last_taper_reply, 1575936, "localhost", "/usr/local", 0);
485 like(taper_reply, qr/^REQUEST-NEW-TAPE $handle$/,
486 "got REQUEST-NEW-TAPE worker0 $handle") or die;
487 taper_cmd("START-SCAN worker0 $handle");
488 taper_cmd("NEW-TAPE worker0 $handle");
489 like(taper_reply, qr/^NEW-TAPE $handle TESTCONF01$/,
490 "got proper NEW-TAPE worker0 $handle") or die;
491 like(taper_reply, qr/^PARTDONE $handle TESTCONF01 1 768 "\[sec [\d.]+ bytes 786432 kps [\d.]+\]"$/,
492 "got PARTDONE for filenum 1") or die;
493 like(taper_reply, qr/^REQUEST-NEW-TAPE $handle$/,
494 "got REQUEST-NEW-TAPE worker0 $handle") or die;
495 taper_cmd("START-SCAN worker0 $handle");
496 taper_cmd("NEW-TAPE worker0 $handle");
497 like(taper_reply, qr/^NEW-TAPE $handle TESTCONF02$/,
498 "got proper NEW-TAPE worker0 $handle") or die;
499 like(taper_reply, qr/^PARTDONE $handle TESTCONF02 1 768 "\[sec [\d.]+ bytes 786432 kps [\d.]+\]"$/,
500 "got PARTDONE for filenum 1 on second tape") or die;
501 like(taper_reply, qr/^PARTDONE $handle TESTCONF02 2 3 "\[sec [\d.]+ bytes 3072 kps [\d.]+\]"$/,
502 "got PARTDONE for filenum 2 on second tape") or die;
503 like(taper_reply, qr/^DUMPER-STATUS $handle$/,
504 "got DUMPER-STATUS request") or die;
505 taper_cmd("DONE worker0 $handle 1012");
506 like(taper_reply, qr/^DONE $handle INPUT-GOOD TAPE-GOOD "\[sec [\d.]+ bytes 1575936 kps [\d.]+ orig-kb 1012\]" "" ""$/,
512 qr(^INFO taper Slot 1 without label can be labeled$),
513 qr(^START taper datestamp $datestamp label TESTCONF01 tape 1$),
514 qr(^PART taper TESTCONF01 1 localhost /usr/local $datestamp 1/-1 0 \[sec [\d.]+ bytes 786432 kps [\d.]+\]$),
515 qr(^PARTPARTIAL taper TESTCONF01 2 localhost /usr/local $datestamp 2/-1 0 \[sec [\d.]+ bytes 163840 kps [\d.]+\] "No space left on device"$),
516 qr(^INFO taper Will request retry of failed split part\.$),
517 qr(^INFO taper tape TESTCONF01 kb 768 fm 2 \[OK\]$),
518 qr(^INFO taper Slot 2 without label can be labeled$),
519 qr(^START taper datestamp $datestamp label TESTCONF02 tape 2$),
520 qr(^PART taper TESTCONF02 1 localhost /usr/local $datestamp 2/-1 0 \[sec [\d.]+ bytes 786432 kps [\d.]+\]$),
521 qr(^PART taper TESTCONF02 2 localhost /usr/local $datestamp 3/-1 0 \[sec [\d.]+ bytes 3072 kps [\d.]+\]$),
522 qr(^DONE taper localhost /usr/local $datestamp 3 0 \[sec [\d.]+ bytes 1575936 kps [\d.]+ orig-kb 1012\]$),
523 qr(^INFO taper tape TESTCONF02 kb 771 fm 2 \[OK\]$),
524 ], "multivolume PORT-WRITE logged correctly");
527 # Test retrying on EOT (via FILE-WRITE)
529 $handle = "11-66666";
530 $datestamp = "19470815000000";
531 run_taper(1024, "FILE-WRITE retry on EOT");
532 like(taper_reply, qr/^TAPER-OK worker0$/,
533 "got TAPER-OK") or die;
534 make_holding_file(1575936, "localhost", "/usr");
535 taper_cmd("FILE-WRITE worker0 $handle \"$test_filename\" localhost /usr 0 $datestamp \"\" \"\" \"\" 1 786432 \"\" \"\" \"\" 1112");
536 like(taper_reply, qr/^REQUEST-NEW-TAPE $handle$/,
537 "got REQUEST-NEW-TAPE worker0 $handle") or die;
538 taper_cmd("START-SCAN worker0 $handle");
539 taper_cmd("NEW-TAPE worker0 $handle");
540 like(taper_reply, qr/^NEW-TAPE $handle TESTCONF01$/,
541 "got proper NEW-TAPE worker0 $handle") or die;
542 like(taper_reply, qr/^PARTDONE $handle TESTCONF01 1 768 "\[sec [\d.]+ bytes 786432 kps [\d.]+ orig-kb 1112\]"$/,
543 "got PARTDONE for filenum 1") or die;
544 like(taper_reply, qr/^REQUEST-NEW-TAPE $handle$/,
545 "got REQUEST-NEW-TAPE worker0 $handle") or die;
546 taper_cmd("START-SCAN worker0 $handle");
547 taper_cmd("NEW-TAPE worker0 $handle");
548 like(taper_reply, qr/^NEW-TAPE $handle TESTCONF02$/,
549 "got proper NEW-TAPE worker0 $handle") or die;
550 like(taper_reply, qr/^PARTDONE $handle TESTCONF02 1 768 "\[sec [\d.]+ bytes 786432 kps [\d.]+ orig-kb 1112\]"$/,
551 "got PARTDONE for filenum 1 on second tape") or die;
552 like(taper_reply, qr/^PARTDONE $handle TESTCONF02 2 3 "\[sec [\d.]+ bytes 3072 kps [\d.]+ orig-kb 1112\]"$/,
553 "got PARTDONE for filenum 2 on second tape") or die;
554 like(taper_reply, qr/^DONE $handle INPUT-GOOD TAPE-GOOD "\[sec [\d.]+ bytes 1575936 kps [\d.]+ orig-kb 1112\]" "" ""$/,
560 qr(^INFO taper Slot 1 without label can be labeled$),
561 qr(^START taper datestamp $datestamp label TESTCONF01 tape 1$),
562 qr(^PART taper TESTCONF01 1 localhost /usr $datestamp 1/-1 0 \[sec [\d.]+ bytes 786432 kps [\d.]+ orig-kb 1112\]$),
563 qr(^PARTPARTIAL taper TESTCONF01 2 localhost /usr $datestamp 2/-1 0 \[sec [\d.]+ bytes 163840 kps [\d.]+ orig-kb 1112\] "No space left on device"$),
564 qr(^INFO taper Will request retry of failed split part\.$),
565 qr(^INFO taper tape TESTCONF01 kb 768 fm 2 \[OK\]$),
566 qr(^INFO taper Slot 2 without label can be labeled$),
567 qr(^START taper datestamp $datestamp label TESTCONF02 tape 2$),
568 qr(^PART taper TESTCONF02 1 localhost /usr $datestamp 2/-1 0 \[sec [\d.]+ bytes 786432 kps [\d.]+ orig-kb 1112\]$),
569 qr(^PART taper TESTCONF02 2 localhost /usr $datestamp 3/-1 0 \[sec [\d.]+ bytes 3072 kps [\d.]+ orig-kb 1112\]$),
570 qr(^DONE taper localhost /usr $datestamp 3 0 \[sec [\d.]+ bytes 1575936 kps [\d.]+ orig-kb 1112\]$),
571 qr(^INFO taper tape TESTCONF02 kb 771 fm 2 \[OK\]$),
572 ], "multivolume FILE-WRITE logged correctly");
575 # Test retrying on EOT (via PORT-WRITE with a disk cache)
577 $handle = "11-77777";
578 $datestamp = "20090427212500";
579 run_taper(1024, "PORT-WRITE retry on EOT (disk cache)");
580 like(taper_reply, qr/^TAPER-OK worker0$/,
581 "got TAPER-OK") or die;
582 taper_cmd("PORT-WRITE worker0 $handle localhost /usr/local 0 $datestamp 786432 \"$Installcheck::TMP\" 786432 1 0 \"\" \"\" 0 AMANDA");
583 like(taper_reply, qr/^PORT worker0 $handle (\d+) "?(\d+\.\d+\.\d+\.\d+:\d+;?)+"?$/,
584 "got PORT with data address");
585 write_to_port($last_taper_reply, 1575936, "localhost", "/usr/local", 0);
586 like(taper_reply, qr/^REQUEST-NEW-TAPE $handle$/,
587 "got REQUEST-NEW-TAPE worker0 $handle") or die;
588 taper_cmd("START-SCAN worker0 $handle");
589 taper_cmd("NEW-TAPE worker0 $handle");
590 like(taper_reply, qr/^NEW-TAPE $handle TESTCONF01$/,
591 "got proper NEW-TAPE worker0 $handle") or die;
592 like(taper_reply, qr/^PARTDONE $handle TESTCONF01 1 768 "\[sec [\d.]+ bytes 786432 kps [\d.]+\]"$/,
593 "got PARTDONE for filenum 1") or die;
594 like(taper_reply, qr/^REQUEST-NEW-TAPE $handle$/,
595 "got REQUEST-NEW-TAPE worker0 $handle") or die;
596 taper_cmd("START-SCAN worker0 $handle");
597 taper_cmd("NEW-TAPE worker0 $handle");
598 like(taper_reply, qr/^NEW-TAPE $handle TESTCONF02$/,
599 "got proper NEW-TAPE worker0 $handle") or die;
600 like(taper_reply, qr/^PARTDONE $handle TESTCONF02 1 768 "\[sec [\d.]+ bytes 786432 kps [\d.]+\]"$/,
601 "got PARTDONE for filenum 1 on second tape") or die;
602 like(taper_reply, qr/^PARTDONE $handle TESTCONF02 2 3 "\[sec [\d.]+ bytes 3072 kps [\d.]+\]"$/,
603 "got PARTDONE for filenum 2 on second tape") or die;
604 like(taper_reply, qr/^DUMPER-STATUS $handle$/,
605 "got DUMPER-STATUS request") or die;
606 taper_cmd("DONE worker0 $handle 1212");
607 like(taper_reply, qr/^DONE $handle INPUT-GOOD TAPE-GOOD "\[sec [\d.]+ bytes 1575936 kps [\d.]+ orig-kb 1212\]" "" ""$/,
613 qr(^INFO taper Slot 1 without label can be labeled$),
614 qr(^START taper datestamp $datestamp label TESTCONF01 tape 1$),
615 qr(^PART taper TESTCONF01 1 localhost /usr/local $datestamp 1/-1 0 \[sec [\d.]+ bytes 786432 kps [\d.]+\]$),
616 qr(^PARTPARTIAL taper TESTCONF01 2 localhost /usr/local $datestamp 2/-1 0 \[sec [\d.]+ bytes 163840 kps [\d.]+\] "No space left on device"$),
617 qr(^INFO taper Will request retry of failed split part\.$),
618 qr(^INFO taper tape TESTCONF01 kb 768 fm 2 \[OK\]$),
619 qr(^INFO taper Slot 2 without label can be labeled$),
620 qr(^START taper datestamp $datestamp label TESTCONF02 tape 2$),
621 qr(^PART taper TESTCONF02 1 localhost /usr/local $datestamp 2/-1 0 \[sec [\d.]+ bytes 786432 kps [\d.]+\]$),
622 qr(^PART taper TESTCONF02 2 localhost /usr/local $datestamp 3/-1 0 \[sec [\d.]+ bytes 3072 kps [\d.]+\]$),
623 qr(^DONE taper localhost /usr/local $datestamp 3 0 \[sec [\d.]+ bytes 1575936 kps [\d.]+ orig-kb 1212\]$),
624 qr(^INFO taper tape TESTCONF02 kb 771 fm 2 \[OK\]$),
625 ], "multivolume PORT-WRITE (disk cache) logged correctly");
628 # Test failure on EOT (via PORT-WRITE with no cache), and a new try on the
631 $handle = "11-88888";
632 $datestamp = "20090424173000";
633 run_taper(1024, "PORT-WRITE failure on EOT (no cache)");
634 like(taper_reply, qr/^TAPER-OK worker0$/,
635 "got TAPER-OK") or die;
636 taper_cmd("PORT-WRITE worker0 $handle localhost /var/log 0 $datestamp 0 \"\" 0 0 0 \"\" \"\" 0 AMANDA");
637 like(taper_reply, qr/^PORT worker0 $handle (\d+) "?(\d+\.\d+\.\d+\.\d+:\d+;?)+"?$/,
638 "got PORT with data address");
639 write_to_port($last_taper_reply, 1575936, "localhost", "/var/log", 1);
640 like(taper_reply, qr/^REQUEST-NEW-TAPE $handle$/,
641 "got REQUEST-NEW-TAPE worker0 $handle") or die;
642 taper_cmd("START-SCAN worker0 $handle");
643 taper_cmd("NEW-TAPE worker0 $handle");
644 like(taper_reply, qr/^NEW-TAPE $handle TESTCONF01$/,
645 "got proper NEW-TAPE worker0 $handle") or die;
646 like(taper_reply, qr/^PARTIAL $handle INPUT-GOOD TAPE-ERROR "\[sec [\d.]+ bytes 0 kps [\d.]+\]" "" "No space left on device, splitting not enabled"$/,
647 "got PARTIAL") or die;
648 # retry on the next tape
649 $handle = "11-88899";
650 taper_cmd("PORT-WRITE worker0 $handle localhost /boot 0 $datestamp 0 \"\" 0 0 0 \"\" \"\" 0 AMANDA");
651 like(taper_reply, qr/^PORT worker0 $handle (\d+) "?(\d+\.\d+\.\d+\.\d+:\d+;?)+"?$/,
652 "got PORT with data address");
653 write_to_port($last_taper_reply, 65536, "localhost", "/boot", 0);
654 like(taper_reply, qr/^REQUEST-NEW-TAPE $handle$/,
655 "got REQUEST-NEW-TAPE worker0 $handle") or die;
656 taper_cmd("START-SCAN worker0 $handle");
657 taper_cmd("NEW-TAPE worker0 $handle");
658 like(taper_reply, qr/^NEW-TAPE $handle TESTCONF02$/,
659 "got proper NEW-TAPE worker0 $handle") or die;
660 like(taper_reply, qr/^PARTDONE $handle TESTCONF02 1 64 "\[sec [\d.]+ bytes 65536 kps [\d.]+\]"$/,
661 "got PARTDONE for filenum 1 on second tape") or die;
662 like(taper_reply, qr/^DUMPER-STATUS $handle$/,
663 "got DUMPER-STATUS request") or die;
664 taper_cmd("DONE worker0 $handle 64");
665 like(taper_reply, qr/^DONE $handle INPUT-GOOD TAPE-GOOD "\[sec [\d.]+ bytes 65536 kps [\d.]+ orig-kb 64\]" "" ""$/,
671 qr(^INFO taper Slot 1 without label can be labeled$),
672 qr(^START taper datestamp $datestamp label TESTCONF01 tape 1$),
673 qr(^PARTPARTIAL taper TESTCONF01 1 localhost /var/log $datestamp 1/-1 0 \[sec [\d.]+ bytes 983040 kps [\d.]+\] "No space left on device"$),
674 qr(^PARTIAL taper localhost /var/log $datestamp 1 0 \[sec [\d.]+ bytes 0 kps [\d.]+\] "No space left on device, splitting not enabled"$),
675 qr(^INFO taper tape TESTCONF01 kb 0 fm 1 \[OK\]$),
676 qr(^INFO taper Slot 2 without label can be labeled$),
677 qr(^START taper datestamp $datestamp label TESTCONF02 tape 2$),
678 qr(^PART taper TESTCONF02 1 localhost /boot $datestamp 1/-1 0 \[sec [\d.]+ bytes 65536 kps [\d.]+\]$),
679 qr(^DONE taper localhost /boot $datestamp 1 0 \[sec [\d.]+ bytes 65536 kps [\d.]+ orig-kb 64\]$),
680 qr(^INFO taper tape TESTCONF02 kb 64 fm 1 \[OK\]$),
681 ], "failure on EOT (no cache) with subsequent dump logged correctly");
684 # Test running out of tapes (second REQUEST-NEW-TAPE fails)
686 $handle = "11-99999";
687 $datestamp = "20100101000000";
688 run_taper(512, "FILE-WRITE runs out of tapes");
689 like(taper_reply, qr/^TAPER-OK worker0$/,
690 "got TAPER-OK") or die;
691 make_holding_file(512*1024, "localhost", "/music");
692 taper_cmd("FILE-WRITE worker0 $handle \"$test_filename\" localhost /music 0 $datestamp \"\" \"\" \"\" 1 262144 \"none\" \"\" 10240 1312");
693 like(taper_reply, qr/^REQUEST-NEW-TAPE $handle$/,
694 "got REQUEST-NEW-TAPE worker0 $handle") or die;
695 taper_cmd("START-SCAN worker0 $handle");
696 taper_cmd("NEW-TAPE worker0 $handle");
697 like(taper_reply, qr/^NEW-TAPE $handle TESTCONF01$/,
698 "got proper NEW-TAPE worker0 $handle") or die;
699 like(taper_reply, qr/^PARTDONE $handle TESTCONF01 1 256 "\[sec [\d.]+ bytes 262144 kps [\d.]+ orig-kb 1312\]"$/,
700 "got PARTDONE for filenum 1 on first tape") or die;
701 like(taper_reply, qr/^REQUEST-NEW-TAPE $handle$/,
702 "got REQUEST-NEW-TAPE worker0 $handle") or die;
703 taper_cmd("NO-NEW-TAPE worker0 $handle \"that's enough\"");
704 like(taper_reply, qr/^PARTIAL $handle INPUT-GOOD TAPE-ERROR "\[sec [\d.]+ bytes 262144 kps [\d.]+ orig-kb 1312\]" "" "that's enough"$/,
705 "got PARTIAL") or die;
710 qr(^INFO taper Slot 1 without label can be labeled$),
711 qr(^START taper datestamp $datestamp label TESTCONF01 tape 1$),
712 qr(^PART taper TESTCONF01 1 localhost /music $datestamp 1/-1 0 \[sec [\d.]+ bytes 262144 kps [\d.]+ orig-kb 1312\]$),
713 qr(^PARTPARTIAL taper TESTCONF01 2 localhost /music $datestamp 2/-1 0 \[sec [\d.]+ bytes 163840 kps [\d.]+ orig-kb 1312\] "No space left on device"$),
714 qr(^INFO taper Will request retry of failed split part\.$),
715 qr(^INFO taper tape TESTCONF01 kb 256 fm 2 \[OK\]$),
716 qr(^ERROR taper no-tape config \[that's enough\]$),
717 qr(^PARTIAL taper localhost /music $datestamp 2 0 \[sec [\d.]+ bytes 262144 kps [\d.]+ orig-kb 1312\] "that's enough"$),
718 ], "running out of tapes (simulating runtapes=1) logged correctly");
721 # A PORT-WRITE with no disk buffer
723 $handle = "22-00000";
724 $datestamp = "20200202222222";
725 run_taper(4096, "multipart PORT-WRITE");
726 like(taper_reply, qr/^TAPER-OK worker0$/,
727 "got TAPER-OK") or die;
728 taper_cmd("PORT-WRITE worker0 $handle localhost /sbin 0 $datestamp 999999 \"\" 655360 1 \"\" \"\" \"\" \"\" AMANDA");
729 like(taper_reply, qr/^PORT worker0 $handle (\d+) "?(\d+\.\d+\.\d+\.\d+:\d+;?)+"?$/,
730 "got PORT with data address");
731 write_to_port($last_taper_reply, 63*32768, "localhost", "/sbin", 0);
732 like(taper_reply, qr/^REQUEST-NEW-TAPE $handle$/,
733 "got REQUEST-NEW-TAPE worker0 $handle") or die;
734 taper_cmd("START-SCAN worker0 $handle");
735 taper_cmd("NEW-TAPE worker0 $handle");
736 like(taper_reply, qr/^NEW-TAPE $handle TESTCONF01$/,
737 "got proper NEW-TAPE worker0 $handle") or die;
738 like(taper_reply, qr/^PARTDONE $handle TESTCONF01 1 640 "\[sec [\d.]+ bytes 655360 kps [\d.]+\]"$/,
739 "got PARTDONE for filenum 1") or die;
740 like(taper_reply, qr/^PARTDONE $handle TESTCONF01 2 640 "\[sec [\d.]+ bytes 655360 kps [\d.]+\]"$/,
741 "got PARTDONE for filenum 2") or die;
742 like(taper_reply, qr/^PARTDONE $handle TESTCONF01 3 640 "\[sec [\d.]+ bytes 655360 kps [\d.]+\]"$/,
743 "got PARTDONE for filenum 3") or die;
744 like(taper_reply, qr/^PARTDONE $handle TESTCONF01 4 96 "\[sec [\d.]+ bytes 98304 kps [\d.]+\]"$/,
745 "got PARTDONE for filenum 4") or die;
746 like(taper_reply, qr/^DUMPER-STATUS $handle$/,
747 "got DUMPER-STATUS request") or die;
748 taper_cmd("FAILED worker0 $handle");
749 like(taper_reply, qr/^DONE $handle INPUT-GOOD TAPE-GOOD "\[sec [\d.]+ bytes 2064384 kps [\d.]+\]" "" ""$/,
755 qr(^INFO taper Slot 1 without label can be labeled$),
756 qr(^START taper datestamp $datestamp label TESTCONF01 tape 1$),
757 qr(^PART taper TESTCONF01 1 localhost /sbin $datestamp 1/-1 0 \[sec [\d.]+ bytes 655360 kps [\d.]+\]$),
758 qr(^PART taper TESTCONF01 2 localhost /sbin $datestamp 2/-1 0 \[sec [\d.]+ bytes 655360 kps [\d.]+\]$),
759 qr(^PART taper TESTCONF01 3 localhost /sbin $datestamp 3/-1 0 \[sec [\d.]+ bytes 655360 kps [\d.]+\]$),
760 qr(^PART taper TESTCONF01 4 localhost /sbin $datestamp 4/-1 0 \[sec [\d.]+ bytes 98304 kps [\d.]+\]$),
761 qr(^PARTIAL taper localhost /sbin $datestamp 4 0 \[sec [\d.]+ bytes 2064384 kps [\d.]+\]$), # note no error message
762 qr(^INFO taper tape TESTCONF01 kb 2016 fm 4 \[OK\]$),
763 ], "DUMPER_STATUS => FAILED logged correctly");
766 # Test a sequence of writes to the same set of tapes
768 $handle = "33-11111";
769 $datestamp = "20090101010000";
770 run_taper(1024, "first in a sequence");
771 like(taper_reply, qr/^TAPER-OK worker0$/,
772 "got TAPER-OK") or die;
773 make_holding_file(500000, "localhost", "/u01");
774 taper_cmd("FILE-WRITE worker0 $handle \"$test_filename\" localhost /u01 0 $datestamp 262144 \"\" \"\" \"\" \"\" \"\" \"\" \"\" 1412");
775 like(taper_reply, qr/^REQUEST-NEW-TAPE $handle$/,
776 "got REQUEST-NEW-TAPE worker0 $handle") or die;
777 taper_cmd("START-SCAN worker0 $handle");
778 taper_cmd("NEW-TAPE worker0 $handle");
779 like(taper_reply, qr/^NEW-TAPE $handle TESTCONF01$/,
780 "got proper NEW-TAPE worker0 $handle") or die;
781 like(taper_reply, qr/^PARTDONE $handle TESTCONF01 1 256 "\[sec [\d.]+ bytes 262144 kps [\d.]+ orig-kb 1412\]"$/,
782 "got PARTDONE for filenum 1") or die;
783 like(taper_reply, qr/^PARTDONE $handle TESTCONF01 2 232 "\[sec [\d.]+ bytes 237856 kps [\d.]+ orig-kb 1412\]"$/,
784 "got PARTDONE for filenum 2") or die;
785 like(taper_reply, qr/^DONE $handle INPUT-GOOD TAPE-GOOD "\[sec [\d.]+ bytes 500000 kps [\d.]+ orig-kb 1412\]" "" ""$/,
787 $handle = "33-22222";
788 make_holding_file(614400, "localhost", "/u02");
789 taper_cmd("FILE-WRITE worker0 $handle \"$test_filename\" localhost /u02 0 $datestamp 262144 \"\" \"\" \"\" \"\" \"\" \"\" \"\" 1512");
790 like(taper_reply, qr/^PARTDONE $handle TESTCONF01 3 256 "\[sec [\d.]+ bytes 262144 kps [\d.]+ orig-kb 1512\]"$/,
791 "got PARTDONE for filenum 3") or die;
792 like(taper_reply, qr/^REQUEST-NEW-TAPE $handle$/,
793 "got REQUEST-NEW-TAPE worker0 $handle") or die;
794 taper_cmd("START-SCAN worker0 $handle");
795 taper_cmd("NEW-TAPE worker0 $handle");
796 like(taper_reply, qr/^NEW-TAPE $handle TESTCONF02$/,
797 "got proper NEW-TAPE worker0 $handle") or die;
798 like(taper_reply, qr/^PARTDONE $handle TESTCONF02 1 256 "\[sec [\d.]+ bytes 262144 kps [\d.]+ orig-kb 1512\]"$/,
799 "got PARTDONE for filenum 1 on second tape") or die;
800 like(taper_reply, qr/^PARTDONE $handle TESTCONF02 2 88 "\[sec [\d.]+ bytes 90112 kps [\d.]+ orig-kb 1512\]"$/,
801 "got PARTDONE for filenum 2 on second tape") or die;
802 like(taper_reply, qr/^DONE $handle INPUT-GOOD TAPE-GOOD "\[sec [\d.]+ bytes 614400 kps [\d.]+ orig-kb 1512\]" "" ""$/,
808 qr(^INFO taper Slot 1 without label can be labeled$),
809 qr(^START taper datestamp $datestamp label TESTCONF01 tape 1$),
810 qr(^PART taper TESTCONF01 1 localhost /u01 $datestamp 1/-1 0 \[sec [\d.]+ bytes 262144 kps [\d.]+ orig-kb 1412\]$),
811 qr(^PART taper TESTCONF01 2 localhost /u01 $datestamp 2/-1 0 \[sec [\d.]+ bytes 237856 kps [\d.]+ orig-kb 1412\]$),
812 qr(^DONE taper localhost /u01 $datestamp 2 0 \[sec [\d.]+ bytes 500000 kps [\d.]+ orig-kb 1412\]$),
813 qr(^PART taper TESTCONF01 3 localhost /u02 $datestamp 1/-1 0 \[sec [\d.]+ bytes 262144 kps [\d.]+ orig-kb 1512\]$),
814 qr(^PARTPARTIAL taper TESTCONF01 4 localhost /u02 $datestamp 2/-1 0 \[sec [\d.]+ bytes 98304 kps [\d.]+ orig-kb 1512\] "No space left on device"$),
815 qr(^INFO taper Will request retry of failed split part\.$),
816 qr(^INFO taper tape TESTCONF01 kb 744 fm 4 \[OK\]$),
817 qr(^INFO taper Slot 2 without label can be labeled$),
818 qr(^START taper datestamp $datestamp label TESTCONF02 tape 2$),
819 qr(^PART taper TESTCONF02 1 localhost /u02 $datestamp 2/-1 0 \[sec [\d.]+ bytes 262144 kps [\d.]+ orig-kb 1512\]$),
820 qr(^PART taper TESTCONF02 2 localhost /u02 $datestamp 3/-1 0 \[sec [\d.]+ bytes 90112 kps [\d.]+ orig-kb 1512\]$),
821 qr(^DONE taper localhost /u02 $datestamp 3 0 \[sec [\d.]+ bytes 614400 kps [\d.]+ orig-kb 1512\]$),
822 qr(^INFO taper tape TESTCONF02 kb 344 fm 2 \[OK\]$),
823 ], "first taper invocation in sequence logged correctly");
826 $handle = "33-33333";
827 $datestamp = "20090202020000";
828 run_taper(1024, "second in a sequence", keep_config => 1);
829 like(taper_reply, qr/^TAPER-OK worker0$/,
830 "got TAPER-OK") or die;
831 make_holding_file(300000, "localhost", "/u01");
832 taper_cmd("FILE-WRITE worker0 $handle \"$test_filename\" localhost /u01 0 $datestamp 262144 \"\" \"\" \"\" \"\" \"\" \"\" \"\" 1612");
833 like(taper_reply, qr/^REQUEST-NEW-TAPE $handle$/,
834 "got REQUEST-NEW-TAPE worker0 $handle") or die;
835 taper_cmd("START-SCAN worker0 $handle");
836 taper_cmd("NEW-TAPE worker0 $handle");
837 like(taper_reply, qr/^NEW-TAPE $handle TESTCONF03$/,
838 "got proper NEW-TAPE worker0 $handle") or die;
839 like(taper_reply, qr/^PARTDONE $handle TESTCONF03 1 256 "\[sec [\d.]+ bytes 262144 kps [\d.]+ orig-kb 1612\]"$/,
840 "got PARTDONE for filenum 1") or die;
841 like(taper_reply, qr/^PARTDONE $handle TESTCONF03 2 36 "\[sec [\d.]+ bytes 37856 kps [\d.]+ orig-kb 1612\]"$/,
842 "got PARTDONE for filenum 2") or die;
843 like(taper_reply, qr/^DONE $handle INPUT-GOOD TAPE-GOOD "\[sec [\d.]+ bytes 300000 kps [\d.]+ orig-kb 1612\]" "" ""$/,
845 $handle = "33-44444";
846 make_holding_file(614400, "localhost", "/u02");
847 taper_cmd("FILE-WRITE worker0 $handle \"$test_filename\" localhost /u02 0 $datestamp 262144 \"\" \"\" \"\" \"\" \"\" \"\" \"\" 1712");
848 like(taper_reply, qr/^PARTDONE $handle TESTCONF03 3 256 "\[sec [\d.]+ bytes 262144 kps [\d.]+ orig-kb 1712\]"$/,
849 "got PARTDONE for filenum 3") or die;
850 like(taper_reply, qr/^PARTDONE $handle TESTCONF03 4 256 "\[sec [\d.]+ bytes 262144 kps [\d.]+ orig-kb 1712\]"$/,
851 "got PARTDONE for filenum 4") or die;
852 like(taper_reply, qr/^REQUEST-NEW-TAPE $handle$/,
853 "got REQUEST-NEW-TAPE worker0 $handle") or die;
854 taper_cmd("START-SCAN worker0 $handle");
855 taper_cmd("NEW-TAPE worker0 $handle");
856 like(taper_reply, qr/^NEW-TAPE $handle TESTCONF01$/,
857 "got proper NEW-TAPE worker0 $handle") or die;
858 like(taper_reply, qr/^PARTDONE $handle TESTCONF01 1 88 "\[sec [\d.]+ bytes 90112 kps [\d.]+ orig-kb 1712\]"$/,
859 "got PARTDONE for filenum 1 on second tape") or die;
860 like(taper_reply, qr/^DONE $handle INPUT-GOOD TAPE-GOOD "\[sec [\d.]+ bytes 614400 kps [\d.]+ orig-kb 1712\]" "" ""$/,
866 qr(^INFO taper Slot 2 with label TESTCONF02 is not reusable$),
867 qr(^INFO taper Slot 3 without label can be labeled$),
868 qr(^START taper datestamp $datestamp label TESTCONF03 tape 1$),
869 qr(^PART taper TESTCONF03 1 localhost /u01 $datestamp 1/-1 0 \[sec [\d.]+ bytes 262144 kps [\d.]+ orig-kb 1612\]$),
870 qr(^PART taper TESTCONF03 2 localhost /u01 $datestamp 2/-1 0 \[sec [\d.]+ bytes 37856 kps [\d.]+ orig-kb 1612\]$),
871 qr(^DONE taper localhost /u01 $datestamp 2 0 \[sec [\d.]+ bytes 300000 kps [\d.]+ orig-kb 1612\]$),
872 qr(^PART taper TESTCONF03 3 localhost /u02 $datestamp 1/-1 0 \[sec [\d.]+ bytes 262144 kps [\d.]+ orig-kb 1712\]$),
873 qr(^PART taper TESTCONF03 4 localhost /u02 $datestamp 2/-1 0 \[sec [\d.]+ bytes 262144 kps [\d.]+ orig-kb 1712\]$),
874 qr(^PARTPARTIAL taper TESTCONF03 5 localhost /u02 $datestamp 3/-1 0 \[sec [\d.]+ bytes 0 kps [\d.]+ orig-kb 1712\] "No space left on device"$),
875 qr(^INFO taper Will request retry of failed split part\.$),
876 qr(^INFO taper tape TESTCONF03 kb 804 fm 5 \[OK\]$),
877 qr(^INFO taper Slot 1 with label TESTCONF01 is usable$),
878 qr(^START taper datestamp $datestamp label TESTCONF01 tape 2$),
879 qr(^PART taper TESTCONF01 1 localhost /u02 $datestamp 3/-1 0 \[sec [\d.]+ bytes 90112 kps [\d.]+ orig-kb 1712\]$),
880 qr(^DONE taper localhost /u02 $datestamp 3 0 \[sec [\d.]+ bytes 614400 kps [\d.]+ orig-kb 1712\]$),
881 qr(^INFO taper tape TESTCONF01 kb 88 fm 1 \[OK\]$),
882 ], "second taper invocation in sequence logged correctly");
886 # test failure to overwrite a tape label
888 $handle = "33-55555";
889 $datestamp = "20090303030000";
890 run_taper(1024, "failure to overwrite a volume", keep_config => 1);
891 like(taper_reply, qr/^TAPER-OK worker0$/,
892 "got TAPER-OK") or die;
893 make_holding_file(32768, "localhost", "/u03");
894 taper_cmd("FILE-WRITE worker0 $handle \"$test_filename\" localhost /u03 0 $datestamp 262144 \"\" \"\" \"\" \"\" \"\" \"\" \"\" 1812");
895 like(taper_reply, qr/^REQUEST-NEW-TAPE $handle$/,
896 "got REQUEST-NEW-TAPE worker0 $handle") or die;
897 # we've secretly replaced the tape in slot 1 with a read-only tape.. let's see
898 # if anyone can tell the difference!
899 chmod(0555, Installcheck::Run::vtape_dir(2));
900 taper_cmd("START-SCAN worker0 $handle");
901 taper_cmd("NEW-TAPE worker0 $handle");
902 # NO-NEW-TAPE indicates it did *not* overwrite the tape
903 like(taper_reply, qr/^NO-NEW-TAPE $handle$/,
904 "got proper NO-NEW-TAPE worker0 $handle"); # no "die" here, so we can restore perms
905 chmod(0755, Installcheck::Run::vtape_dir(2));
906 like(taper_reply, qr/^REQUEST-NEW-TAPE $handle$/,
907 "got REQUEST-NEW-TAPE worker0 $handle") or die;
908 taper_cmd("NO-NEW-TAPE worker0 $handle \"sorry\"");
909 like(taper_reply, qr/^FAILED $handle INPUT-GOOD TAPE-ERROR "" "?sorry"?.*$/,
910 "got FAILED") or die;
914 # (logs aren't that interesting here - filled with VFS-specific error messages)
916 # TODO: simulate an "erased" tape, to which taper should reply with "NEW-TAPE worker0 $handle" and
917 # immediately REQUEST-NEW-TAPE. I can't see a way to make the VFS device erase a
918 # volume without start_device succeeding.
921 # A run with a bogus tapedev/tpchanger
922 $handle = "44-11111";
923 $datestamp = "20070102030405";
924 run_taper(4096, "no tapedev", notapedev => 1);
925 like(taper_reply, qr/^TAPE-ERROR SETUP "You must specify one of 'tapedev' or 'tpchanger'"$/,
926 "got TAPE-ERROR") or die;
930 # A run with 2 workers
931 my $handle0 = "66-00000";
932 my $handle1 = "66-11111";
933 $datestamp = "20090202020000";
934 run_taper(1024, "with 2 workers", new_vtapes => 1);
935 like(taper_reply, qr/^TAPER-OK worker0$/,
936 "got TAPER-OK") or die;
937 taper_cmd("START-TAPER worker1 $datestamp");
938 like(taper_reply, qr/^TAPER-OK worker1$/,
939 "got TAPER-OK") or die;
940 make_holding_file(300000, "localhost", "/u01");
941 taper_cmd("FILE-WRITE worker0 $handle0 \"$test_filename\" localhost /u01 0 $datestamp 262144 \"\" \"\" \"\" \"\" \"\" \"\" \"\" 1612");
942 like(taper_reply, qr/^REQUEST-NEW-TAPE $handle0$/,
943 "got REQUEST-NEW-TAPE worker0 $handle0") or die;
944 taper_cmd("START-SCAN worker0 $handle0");
945 taper_cmd("NEW-TAPE worker0 $handle0");
946 like(taper_reply, qr/^NEW-TAPE $handle0 TESTCONF01$/,
947 "got proper NEW-TAPE worker0 $handle0") or die;
948 like(taper_reply, qr/^PARTDONE $handle0 TESTCONF01 1 256 "\[sec [\d.]+ bytes 262144 kps [\d.]+ orig-kb 1612\]"$/,
949 "got PARTDONE for filenum 1") or die;
950 like(taper_reply, qr/^PARTDONE $handle0 TESTCONF01 2 36 "\[sec [\d.]+ bytes 37856 kps [\d.]+ orig-kb 1612\]"$/,
951 "got PARTDONE for filenum 2") or die;
952 like(taper_reply, qr/^DONE $handle0 INPUT-GOOD TAPE-GOOD "\[sec [\d.]+ bytes 300000 kps [\d.]+ orig-kb 1612\]" "" ""$/,
954 make_holding_file(614400, "localhost", "/u02");
955 taper_cmd("FILE-WRITE worker1 $handle1 \"$test_filename\" localhost /u02 0 $datestamp 262144 \"\" \"\" \"\" \"\" \"\" \"\" \"\" 1712");
956 like(taper_reply, qr/^REQUEST-NEW-TAPE $handle1$/,
957 "got REQUEST-NEW-TAPE worker1 $handle1") or die;
958 taper_cmd("START-SCAN worker1 $handle1");
959 taper_cmd("NEW-TAPE worker1 $handle1");
960 like(taper_reply, qr/^NEW-TAPE $handle1 TESTCONF02$/,
961 "got proper NEW-TAPE worker1 $handle1") or die;
962 like(taper_reply, qr/^PARTDONE $handle1 TESTCONF02 1 256 "\[sec [\d.]+ bytes 262144 kps [\d.]+ orig-kb 1712\]"$/,
963 "got PARTDONE for filenum 1 on second tape") or die;
964 like(taper_reply, qr/^PARTDONE $handle1 TESTCONF02 2 256 "\[sec [\d.]+ bytes 262144 kps [\d.]+ orig-kb 1712\]"$/,
965 "got PARTDONE for filenum 2 on second tape") or die;
966 like(taper_reply, qr/^PARTDONE $handle1 TESTCONF02 3 88 "\[sec [\d.]+ bytes 90112 kps [\d.]+ orig-kb 1712\]"$/,
967 "got PARTDONE for filenum 3 on second tape") or die;
968 like(taper_reply, qr/^DONE $handle1 INPUT-GOOD TAPE-GOOD "\[sec [\d.]+ bytes 614400 kps [\d.]+ orig-kb 1712\]" "" ""$/,
974 qr(^INFO taper Slot 1 without label can be labeled$),
975 qr(^INFO taper Slot 2 without label can be labeled$),
976 qr(^START taper datestamp $datestamp label TESTCONF01 tape 1$),
977 qr(^PART taper TESTCONF01 1 localhost /u01 $datestamp 1/-1 0 \[sec [\d.]+ bytes 262144 kps [\d.]+ orig-kb 1612\]$),
978 qr(^PART taper TESTCONF01 2 localhost /u01 $datestamp 2/-1 0 \[sec [\d.]+ bytes 37856 kps [\d.]+ orig-kb 1612\]$),
979 qr(^DONE taper localhost /u01 $datestamp 2 0 \[sec [\d.]+ bytes 300000 kps [\d.]+ orig-kb 1612\]$),
980 qr(^START taper datestamp $datestamp label TESTCONF02 tape 2$),
981 qr(^PART taper TESTCONF02 1 localhost /u02 $datestamp 1/-1 0 \[sec [\d.]+ bytes 262144 kps [\d.]+ orig-kb 1712\]$),
982 qr(^PART taper TESTCONF02 2 localhost /u02 $datestamp 2/-1 0 \[sec [\d.]+ bytes 262144 kps [\d.]+ orig-kb 1712\]$),
983 qr(^PART taper TESTCONF02 3 localhost /u02 $datestamp 3/-1 0 \[sec [\d.]+ bytes 90112 kps [\d.]+ orig-kb 1712\]$),
984 qr(^DONE taper localhost /u02 $datestamp 3 0 \[sec [\d.]+ bytes 614400 kps [\d.]+ orig-kb 1712\]$),
985 qr(^INFO taper tape TESTCONF01 kb 292 fm 2 \[OK\]$),
986 qr(^INFO taper tape TESTCONF02 kb 600 fm 3 \[OK\]$),
987 ], "two workers logged correctly");
991 # A run with 2 workers and a take_scribe
992 $handle = "66-22222";
993 $datestamp = "20090202020000";
994 run_taper(1024, "with 2 workers and a take_scribe", new_vtapes => 1);
995 like(taper_reply, qr/^TAPER-OK worker0$/,
996 "got TAPER-OK") or die;
997 taper_cmd("START-TAPER worker1 $datestamp");
998 like(taper_reply, qr/^TAPER-OK worker1$/,
999 "got TAPER-OK") or die;
1000 make_holding_file(1000000, "localhost", "/u01");
1001 taper_cmd("FILE-WRITE worker0 $handle \"$test_filename\" localhost /u01 0 $datestamp 262144 \"\" \"\" \"\" \"\" \"\" \"\" \"\" 1612");
1002 like(taper_reply, qr/^REQUEST-NEW-TAPE $handle$/,
1003 "got REQUEST-NEW-TAPE worker0 $handle") or die;
1004 taper_cmd("START-SCAN worker0 $handle");
1005 taper_cmd("NEW-TAPE worker0 $handle");
1006 like(taper_reply, qr/^NEW-TAPE $handle TESTCONF01$/,
1007 "got proper NEW-TAPE worker0 $handle") or die;
1008 like(taper_reply, qr/^PARTDONE $handle TESTCONF01 1 256 "\[sec [\d.]+ bytes 262144 kps [\d.]+ orig-kb 1612\]"$/,
1009 "got PARTDONE for filenum 1") or die;
1010 like(taper_reply, qr/^PARTDONE $handle TESTCONF01 2 256 "\[sec [\d.]+ bytes 262144 kps [\d.]+ orig-kb 1612\]"$/,
1011 "got PARTDONE for filenum 2") or die;
1012 like(taper_reply, qr/^PARTDONE $handle TESTCONF01 3 256 "\[sec [\d.]+ bytes 262144 kps [\d.]+ orig-kb 1612\]"$/,
1013 "got PARTDONE for filenum 3") or die;
1014 like(taper_reply, qr/^REQUEST-NEW-TAPE $handle$/,
1015 "got REQUEST-NEW-TAPE worker0 $handle") or die;
1016 taper_cmd("TAKE-SCRIBE-FROM worker0 $handle worker1");
1017 like(taper_reply, qr/^REQUEST-NEW-TAPE $handle$/,
1018 "got REQUEST-NEW-TAPE worker0 $handle") or die;
1019 taper_cmd("START-SCAN worker0 $handle");
1020 taper_cmd("NEW-TAPE worker0 $handle");
1021 like(taper_reply, qr/^NEW-TAPE $handle TESTCONF02$/,
1022 "got proper NEW-TAPE worker0 $handle") or die;
1023 like(taper_reply, qr/^PARTDONE $handle TESTCONF02 1 208 "\[sec [\d.]+ bytes 213568 kps [\d.]+ orig-kb 1612\]"$/,
1024 "got PARTDONE for filenum 4") or die;
1025 like(taper_reply, qr/^DONE $handle INPUT-GOOD TAPE-GOOD "\[sec [\d.]+ bytes 1000000 kps [\d.]+ orig-kb 1612\]" "" ""$/,
1031 qr(^INFO taper Slot 1 without label can be labeled$),
1032 qr(^INFO taper Slot 2 without label can be labeled$),
1033 qr(^START taper datestamp $datestamp label TESTCONF01 tape 1$),
1034 qr(^PART taper TESTCONF01 1 localhost /u01 $datestamp 1/-1 0 \[sec [\d.]+ bytes 262144 kps [\d.]+ orig-kb 1612\]$),
1035 qr(^PART taper TESTCONF01 2 localhost /u01 $datestamp 2/-1 0 \[sec [\d.]+ bytes 262144 kps [\d.]+ orig-kb 1612\]$),
1036 qr(^PART taper TESTCONF01 3 localhost /u01 $datestamp 3/-1 0 \[sec [\d.]+ bytes 262144 kps [\d.]+ orig-kb 1612\]$),
1037 qr(^PARTPARTIAL taper TESTCONF01 4 localhost /u01 $datestamp 4/-1 0 \[sec [\d.]+ bytes 98304 kps [\d.]+ orig-kb 1612\] \"No space left on device\"$),
1038 qr(^INFO taper Will request retry of failed split part.$),
1039 qr(^INFO taper tape TESTCONF01 kb 768 fm 4 \[OK\]$),
1040 qr(^START taper datestamp $datestamp label TESTCONF02 tape 2$),
1041 qr(^PART taper TESTCONF02 1 localhost /u01 $datestamp 4/-1 0 \[sec [\d.]+ bytes 213568 kps [\d.]+ orig-kb 1612\]$),
1042 qr(^DONE taper localhost /u01 $datestamp 4 0 \[sec [\d.]+ bytes 1000000 kps [\d.]+ orig-kb 1612\]$),
1043 qr(^INFO taper tape TESTCONF02 kb 208 fm 1 \[OK\]$),
1044 ], "TAKE-SCRIBE logged correctly");
1048 # Test with NDMP device (DirectTCP)
1051 skip "not built with NDMP", 33 unless Amanda::Util::built_with_component("ndmp");
1053 my $ndmp = Installcheck::Mock::NdmpServer->new(tape_limit => 1024*1024);
1054 my $ndmp_port = $ndmp->{'port'};
1055 my $drive = $ndmp->{'drive'};
1057 $handle = "55-11111";
1058 $datestamp = "19780615010305";
1059 run_taper(4096, "multipart directtcp PORT-WRITE",
1060 ndmp_server => $ndmp);
1061 like(taper_reply, qr/^TAPER-OK worker0$/,
1062 "got TAPER-OK") or die;
1063 # note that, with the addition of the new splitting params, this does the "sensible"
1064 # thing and uses the tape_splitsize, not the fallback_splitsize (this is a change from
1066 taper_cmd("PORT-WRITE worker0 $handle localhost /var 0 $datestamp 393216 \"\" 327680 \"\" \"\" \"\" \"\" \"\" DIRECTTCP");
1067 like(taper_reply, qr/^PORT worker0 $handle (\d+) "?(\d+\.\d+\.\d+\.\d+:\d+;?)+"?$/,
1068 "got PORT with data address");
1069 write_to_port($last_taper_reply, 1230*1024, "localhost", "/var", 0);
1070 like(taper_reply, qr/^REQUEST-NEW-TAPE $handle$/,
1071 "got REQUEST-NEW-TAPE worker0 $handle") or die;
1072 taper_cmd("START-SCAN worker0 $handle");
1073 taper_cmd("NEW-TAPE worker0 $handle");
1074 like(taper_reply, qr/^NEW-TAPE $handle TESTCONF01$/,
1075 "got proper NEW-TAPE worker0 $handle") or die;
1076 like(taper_reply, qr/^PARTDONE $handle TESTCONF01 1 384 "\[sec [\d.]+ bytes 393216 kps [\d.]+\]"$/,
1077 "got PARTDONE for part 1") or die;
1078 like(taper_reply, qr/^PARTDONE $handle TESTCONF01 2 384 "\[sec [\d.]+ bytes 393216 kps [\d.]+\]"$/,
1079 "got PARTDONE for part 2") or die;
1080 like(taper_reply, qr/^PARTDONE $handle TESTCONF01 3 64 "\[sec [\d.]+ bytes 65536 kps [\d.]+\]"$/,
1081 "got PARTDONE for part 3 (short part)") or die;
1082 like(taper_reply, qr/^REQUEST-NEW-TAPE $handle$/,
1083 "got REQUEST-NEW-TAPE worker0 $handle") or die;
1084 taper_cmd("START-SCAN worker0 $handle");
1085 taper_cmd("NEW-TAPE worker0 $handle");
1086 like(taper_reply, qr/^NEW-TAPE $handle TESTCONF02$/,
1087 "got proper NEW-TAPE worker0 $handle") or die;
1088 like(taper_reply, qr/^PARTDONE $handle TESTCONF02 1 384 "\[sec [\d.]+ bytes 393216 kps [\d.]+\]"$/,
1089 "got PARTDONE for part 4") or die;
1090 like(taper_reply, qr/^PARTDONE $handle TESTCONF02 2 32 "\[sec [\d.]+ bytes 32768 kps [\d.]+\]"$/,
1091 "got PARTDONE for part 5") or die;
1092 like(taper_reply, qr/^DUMPER-STATUS $handle$/,
1093 "got DUMPER-STATUS request") or die;
1094 taper_cmd("DONE worker0 $handle 1912");
1095 like(taper_reply, qr/^DONE $handle INPUT-GOOD TAPE-GOOD "\[sec [\d.]+ bytes 1277952 kps [\d.]+ orig-kb 1912\]" "" ""$/,
1097 $handle = "55-22222";
1098 taper_cmd("PORT-WRITE worker0 $handle localhost /etc 0 $datestamp 524288 \"\" 393216 \"\" \"\" \"\" \"\" \"\" DIRECTTCP");
1099 like(taper_reply, qr/^PORT worker0 $handle (\d+) "?(\d+\.\d+\.\d+\.\d+:\d+;?)+"?$/,
1100 "got PORT with data address");
1101 write_to_port($last_taper_reply, 300*1024, "localhost", "/etc", 0);
1102 like(taper_reply, qr/^PARTDONE $handle TESTCONF02 3 320 "\[sec [\d.]+ bytes 327680 kps [\d.]+\]"$/,
1103 "got PARTDONE for part 1") or die;
1104 like(taper_reply, qr/^DUMPER-STATUS $handle$/,
1105 "got DUMPER-STATUS request") or die;
1106 taper_cmd("DONE worker0 $handle 2012");
1107 like(taper_reply, qr/^DONE $handle INPUT-GOOD TAPE-GOOD "\[sec [\d.]+ bytes 327680 kps [\d.]+ orig-kb 2012\]" "" ""$/,
1113 qr(^INFO taper Slot 3 without label can be labeled$),
1114 qr(^START taper datestamp $datestamp label TESTCONF01 tape 1$),
1115 qr(^PART taper TESTCONF01 1 localhost /var $datestamp 1/-1 0 \[sec [\d.]+ bytes 393216 kps [\d.]+\]$),
1116 qr(^PART taper TESTCONF01 2 localhost /var $datestamp 2/-1 0 \[sec [\d.]+ bytes 393216 kps [\d.]+\]$),
1117 qr(^PART taper TESTCONF01 3 localhost /var $datestamp 3/-1 0 \[sec [\d.]+ bytes 65536 kps [\d.]+\]$),
1118 # note no "Will retry.."
1119 qr(^INFO taper tape TESTCONF01 kb 832 fm 3 \[OK\]$),
1120 qr(^INFO taper Slot 4 without label can be labeled$),
1121 qr(^START taper datestamp $datestamp label TESTCONF02 tape 2$),
1122 qr(^PART taper TESTCONF02 1 localhost /var $datestamp 4/-1 0 \[sec [\d.]+ bytes 393216 kps [\d.]+\]$),
1123 qr(^PART taper TESTCONF02 2 localhost /var $datestamp 5/-1 0 \[sec [\d.]+ bytes 32768 kps [\d.]+\]$),
1124 qr(^DONE taper localhost /var $datestamp 5 0 \[sec [\d.]+ bytes 1277952 kps [\d.]+ orig-kb 1912\]$),
1125 qr(^PART taper TESTCONF02 3 localhost /etc $datestamp 1/-1 0 \[sec [\d.]+ bytes 327680 kps [\d.]+\]$),
1126 qr(^DONE taper localhost /etc $datestamp 1 0 \[sec [\d.]+ bytes 327680 kps [\d.]+ orig-kb 2012\]$),
1127 qr(^INFO taper tape TESTCONF02 kb 736 fm 3 \[OK\]$),
1128 ], "multipart directtcp PORT-WRITE logged correctly");
1130 $handle = "55-33333";
1131 $datestamp = "19780615010305";
1132 run_taper(4096, "multipart directtcp PORT-WRITE, with a zero-byte part",
1133 ndmp_server => $ndmp);
1134 like(taper_reply, qr/^TAPER-OK worker0$/,
1135 "got TAPER-OK") or die;
1136 # use a different part size this time, to hit EOM "on the head"
1137 taper_cmd("PORT-WRITE worker0 $handle localhost /var 0 $datestamp 425984 \"\" 327680 \"\" \"\" \"\" \"\" \"\" DIRECTTCP");
1138 like(taper_reply, qr/^PORT worker0 $handle (\d+) "?(\d+\.\d+\.\d+\.\d+:\d+;?)+"?$/,
1139 "got PORT with data address");
1140 write_to_port($last_taper_reply, 1632*1024, "localhost", "/var", 0);
1141 like(taper_reply, qr/^REQUEST-NEW-TAPE $handle$/,
1142 "got REQUEST-NEW-TAPE worker0 $handle") or die;
1143 taper_cmd("START-SCAN worker0 $handle");
1144 taper_cmd("NEW-TAPE worker0 $handle");
1145 like(taper_reply, qr/^NEW-TAPE $handle TESTCONF01$/,
1146 "got proper NEW-TAPE worker0 $handle") or die;
1147 like(taper_reply, qr/^PARTDONE $handle TESTCONF01 1 416 "\[sec [\d.]+ bytes 425984 kps [\d.]+\]"$/,
1148 "got PARTDONE for part 1") or die;
1149 like(taper_reply, qr/^PARTDONE $handle TESTCONF01 2 416 "\[sec [\d.]+ bytes 425984 kps [\d.]+\]"$/,
1150 "got PARTDONE for part 2") or die;
1151 # note: zero-byte part is not reported as PARTDONE
1152 like(taper_reply, qr/^REQUEST-NEW-TAPE $handle$/,
1153 "got REQUEST-NEW-TAPE worker0 $handle") or die;
1154 taper_cmd("START-SCAN worker0 $handle");
1155 taper_cmd("NEW-TAPE worker0 $handle");
1156 like(taper_reply, qr/^NEW-TAPE $handle TESTCONF02$/,
1157 "got proper NEW-TAPE worker0 $handle") or die;
1158 like(taper_reply, qr/^PARTDONE $handle TESTCONF02 1 416 "\[sec [\d.]+ bytes 425984 kps [\d.]+\]"$/,
1159 "got PARTDONE for part 3") or die;
1160 like(taper_reply, qr/^PARTDONE $handle TESTCONF02 2 384 "\[sec [\d.]+ bytes 393216 kps [\d.]+\]"$/,
1161 "got PARTDONE for part 4") or die;
1162 like(taper_reply, qr/^DUMPER-STATUS $handle$/,
1163 "got DUMPER-STATUS request") or die;
1164 taper_cmd("DONE worker0 $handle 2112");
1165 like(taper_reply, qr/^DONE $handle INPUT-GOOD TAPE-GOOD "\[sec [\d.]+ bytes 1671168 kps [\d.]+ orig-kb 2112\]" "" ""$/,
1171 qr(^INFO taper Slot 3 without label can be labeled$),
1172 qr(^START taper datestamp $datestamp label TESTCONF01 tape 1$),
1173 qr(^PART taper TESTCONF01 1 localhost /var $datestamp 1/-1 0 \[sec [\d.]+ bytes 425984 kps [\d.]+\]$),
1174 qr(^PART taper TESTCONF01 2 localhost /var $datestamp 2/-1 0 \[sec [\d.]+ bytes 425984 kps [\d.]+\]$),
1175 # Note: zero-byte part is not logged, but is counted in this INFO line's 'fm' field
1176 qr(^INFO taper tape TESTCONF01 kb 832 fm 3 \[OK\]$),
1177 qr(^INFO taper Slot 4 without label can be labeled$),
1178 qr(^START taper datestamp $datestamp label TESTCONF02 tape 2$),
1179 qr(^PART taper TESTCONF02 1 localhost /var $datestamp 3/-1 0 \[sec [\d.]+ bytes 425984 kps [\d.]+\]$),
1180 qr(^PART taper TESTCONF02 2 localhost /var $datestamp 4/-1 0 \[sec [\d.]+ bytes 393216 kps [\d.]+\]$),
1181 qr(^DONE taper localhost /var $datestamp 4 0 \[sec [\d.]+ bytes 1671168 kps [\d.]+ orig-kb 2112\]$),
1182 qr(^INFO taper tape TESTCONF02 kb 800 fm 2 \[OK\]$),
1183 ], "multipart directtcp PORT-WRITE with a zero-byte part logged correctly");
1187 } # end of ndmp SKIP
1190 # A run without LEOM and without allow-split
1191 $handle = "77-11111";
1192 $datestamp = "20090302020000";
1193 run_taper(1024, "without LEOM and without allow-split", new_vtapes => 1);
1194 make_holding_file(1024*1024, "localhost", "/usr");
1195 like(taper_reply, qr/^TAPER-OK worker0$/,
1196 "got TAPER-OK") or die;
1197 taper_cmd("FILE-WRITE worker0 $handle \"$test_filename\" localhost /usr 0 $datestamp 262144 \"\" \"\" \"0\" \"\" \"\" \"\" \"\" 1612");
1198 like(taper_reply, qr/^REQUEST-NEW-TAPE $handle$/,
1199 "got REQUEST-NEW-TAPE worker0 $handle") or die;
1200 taper_cmd("START-SCAN worker0 $handle");
1201 taper_cmd("NEW-TAPE worker0 $handle");
1202 like(taper_reply, qr/^NEW-TAPE $handle TESTCONF01$/,
1203 "got proper NEW-TAPE worker0 $handle") or die;
1204 like(taper_reply, qr/^PARTIAL $handle INPUT-GOOD TAPE-ERROR "\[sec [\d.]+ bytes \d* kps [\d.]+ orig-kb 1612\]" "" "No space left on device, splitting not enabled"$/,
1205 "got PARTIAL for filenum 1") or die;
1210 qr(^INFO taper Slot 1 without label can be labeled$),
1211 qr(^START taper datestamp $datestamp label TESTCONF01 tape 1$),
1212 qr(^PARTPARTIAL taper TESTCONF01 1 localhost /usr $datestamp 1/-1 0 \[sec [\d.]+ bytes 983040 kps [\d.]+ orig-kb 1612\] \"No space left on device\"$),
1213 qr(^PARTIAL taper localhost /usr $datestamp 1 0 \[sec [\d.]+ bytes 0 kps [\d.]+ orig-kb 1612\] "No space left on device, splitting not enabled"$),
1214 qr(^INFO taper tape TESTCONF01 kb 0 fm 1 \[OK\]$),
1215 ], "without LEOM and without allow-split logged correctly");
1219 # A run with LEOM and without allow-split
1220 $handle = "77-11112";
1221 $datestamp = "20090303020000";
1222 run_taper(1024, "with LEOM and without allow-split", new_vtapes => 1, leom => 1);
1223 make_holding_file(1024*1024, "localhost", "/usr");
1224 like(taper_reply, qr/^TAPER-OK worker0$/,
1225 "got TAPER-OK") or die;
1226 taper_cmd("FILE-WRITE worker0 $handle \"$test_filename\" localhost /usr 0 $datestamp 262144 \"\" \"\" \"0\" \"\" \"\" \"\" \"\" 1612");
1227 like(taper_reply, qr/^REQUEST-NEW-TAPE $handle$/,
1228 "got REQUEST-NEW-TAPE worker0 $handle") or die;
1229 taper_cmd("START-SCAN worker0 $handle");
1230 taper_cmd("NEW-TAPE worker0 $handle");
1231 like(taper_reply, qr/^NEW-TAPE $handle TESTCONF01$/,
1232 "got proper NEW-TAPE worker0 $handle") or die;
1233 like(taper_reply, qr/^PARTDONE $handle TESTCONF01 1 864 "\[sec [\d.]+ bytes 884736 kps [\d.]+ orig-kb 1612\]"$/,
1234 "got PARTDONE for filenum 1") or die;
1235 like(taper_reply, qr/^PARTIAL $handle INPUT-GOOD TAPE-ERROR "\[sec [\d.]+ bytes 884736 kps [\d.]+ orig-kb 1612\]" "" "No space left on device, splitting not enabled"$/,
1236 "got PARTIAL") or die;
1241 qr(^INFO taper Slot 1 without label can be labeled$),
1242 qr(^START taper datestamp $datestamp label TESTCONF01 tape 1$),
1243 qr(^PART taper TESTCONF01 1 localhost /usr $datestamp 1/-1 0 \[sec [\d.]+ bytes 884736 kps [\d.]+ orig-kb 1612\]$),
1244 qr(^PARTIAL taper localhost /usr $datestamp 1 0 \[sec [\d.]+ bytes 884736 kps [\d.]+ orig-kb 1612\] "No space left on device, splitting not enabled"$),
1245 qr(^INFO taper tape TESTCONF01 kb 864 fm 1 \[OK\]$),
1246 ], "with LEOM and without allow-split logged correctly");
1249 ## test lexical with new changer
1252 # A simple, one-part FILE-WRITE
1253 $handle = "11-11111";
1254 $datestamp = "20070102030405";
1255 run_taper(4096, "single-part and multipart FILE-WRITE", taperscan => "lexical", new_vtapes => 1);
1256 like(taper_reply, qr/^TAPER-OK worker0$/,
1257 "got TAPER-OK") or die;
1258 make_holding_file(1024*1024, "localhost", "/home");
1259 taper_cmd("FILE-WRITE worker0 $handle \"$test_filename\" localhost /home 0 $datestamp \"\" \"\" \"\" \"\" \"\" \"\" \"\" \"\" 12");
1260 like(taper_reply, qr/^REQUEST-NEW-TAPE $handle$/,
1261 "got REQUEST-NEW-TAPE worker0 $handle") or die;
1262 taper_cmd("START-SCAN worker0 $handle");
1263 taper_cmd("NEW-TAPE worker0 $handle");
1264 like(taper_reply, qr/^NEW-TAPE $handle TESTCONF01$/,
1265 "got proper NEW-TAPE worker0 $handle") or die;
1266 like(taper_reply, qr/^PARTDONE $handle TESTCONF01 1 1024 "\[sec [\d.]+ bytes 1048576 kps [\d.]+ orig-kb 12\]"$/,
1267 "got PARTDONE") or die;
1268 like(taper_reply, qr/^DONE $handle INPUT-GOOD TAPE-GOOD "\[sec [\d.]+ bytes 1048576 kps [\d.]+ orig-kb 12\]" "" ""$/,
1272 # A multipart FILE-WRITE, using the same taper instance
1273 # (note that the third part is of length 0, and is not logged)
1275 $handle = '11-22222';
1276 make_holding_file(1024*1024, "localhost", "/usr");
1277 taper_cmd("FILE-WRITE worker0 $handle \"$test_filename\" localhost /usr 0 $datestamp 524288 \"\" \"\" 1 \"\" \"\" \"\" \"\" 512");
1278 like(taper_reply, qr/^PARTDONE $handle TESTCONF01 2 512 "\[sec [\d.]+ bytes 524288 kps [\d.]+ orig-kb 512\]"$/,
1279 "got PARTDONE for filenum 2") or die;
1280 like(taper_reply, qr/^PARTDONE $handle TESTCONF01 3 512 "\[sec [\d.]+ bytes 524288 kps [\d.]+ orig-kb 512\]"$/,
1281 "got PARTDONE for filenum 3") or die;
1282 like(taper_reply, qr/^DONE $handle INPUT-GOOD TAPE-GOOD "\[sec [\d.]+ bytes 1048576 kps [\d.]+ orig-kb 512\]" "" ""$/,
1288 qr(^INFO taper Slot 1 without label can be labeled$),
1289 qr(^START taper datestamp $datestamp label TESTCONF01 tape 1$),
1290 qr(^PART taper TESTCONF01 1 localhost /home $datestamp 1/-1 0 \[sec [\d.]+ bytes 1048576 kps [\d.]+ orig-kb 12\]$),
1291 qr(^DONE taper localhost /home $datestamp 1 0 \[sec [\d.]+ bytes 1048576 kps [\d.]+ orig-kb 12\]$),
1292 qr(^PART taper TESTCONF01 2 localhost /usr $datestamp 1/-1 0 \[sec [\d.]+ bytes 524288 kps [\d.]+ orig-kb 512\]$),
1293 qr(^PART taper TESTCONF01 3 localhost /usr $datestamp 2/-1 0 \[sec [\d.]+ bytes 524288 kps [\d.]+ orig-kb 512\]$),
1294 qr(^DONE taper localhost /usr $datestamp 2 0 \[sec [\d.]+ bytes 1048576 kps [\d.]+ orig-kb 512\]$),
1295 qr(^INFO taper tape TESTCONF01 kb 2048 fm 4 \[OK\]$),
1296 ], "single-part and multi-part dump logged correctly");
1299 # Test a sequence of writes to the same set of tapes
1301 $handle = "33-11111";
1302 $datestamp = "20090101010000";
1303 run_taper(1024, "first in a sequence", taperscan => "lexical", new_vtapes => 1);
1304 like(taper_reply, qr/^TAPER-OK worker0$/,
1305 "got TAPER-OK") or die;
1306 make_holding_file(500000, "localhost", "/u01");
1307 taper_cmd("FILE-WRITE worker0 $handle \"$test_filename\" localhost /u01 0 $datestamp 262144 \"\" \"\" \"\" \"\" \"\" \"\" \"\" 1412");
1308 like(taper_reply, qr/^REQUEST-NEW-TAPE $handle$/,
1309 "got REQUEST-NEW-TAPE worker0 $handle") or die;
1310 taper_cmd("START-SCAN worker0 $handle");
1311 taper_cmd("NEW-TAPE worker0 $handle");
1312 like(taper_reply, qr/^NEW-TAPE $handle TESTCONF01$/,
1313 "got proper NEW-TAPE worker0 $handle") or die;
1314 like(taper_reply, qr/^PARTDONE $handle TESTCONF01 1 256 "\[sec [\d.]+ bytes 262144 kps [\d.]+ orig-kb 1412\]"$/,
1315 "got PARTDONE for filenum 1") or die;
1316 like(taper_reply, qr/^PARTDONE $handle TESTCONF01 2 232 "\[sec [\d.]+ bytes 237856 kps [\d.]+ orig-kb 1412\]"$/,
1317 "got PARTDONE for filenum 2") or die;
1318 like(taper_reply, qr/^DONE $handle INPUT-GOOD TAPE-GOOD "\[sec [\d.]+ bytes 500000 kps [\d.]+ orig-kb 1412\]" "" ""$/,
1320 $handle = "33-22222";
1321 make_holding_file(614400, "localhost", "/u02");
1322 taper_cmd("FILE-WRITE worker0 $handle \"$test_filename\" localhost /u02 0 $datestamp 262144 \"\" \"\" \"\" \"\" \"\" \"\" \"\" 1512");
1323 like(taper_reply, qr/^PARTDONE $handle TESTCONF01 3 256 "\[sec [\d.]+ bytes 262144 kps [\d.]+ orig-kb 1512\]"$/,
1324 "got PARTDONE for filenum 3") or die;
1325 like(taper_reply, qr/^REQUEST-NEW-TAPE $handle$/,
1326 "got REQUEST-NEW-TAPE worker0 $handle") or die;
1327 taper_cmd("START-SCAN worker0 $handle");
1328 taper_cmd("NEW-TAPE worker0 $handle");
1329 like(taper_reply, qr/^NEW-TAPE $handle TESTCONF02$/,
1330 "got proper NEW-TAPE worker0 $handle") or die;
1331 like(taper_reply, qr/^PARTDONE $handle TESTCONF02 1 256 "\[sec [\d.]+ bytes 262144 kps [\d.]+ orig-kb 1512\]"$/,
1332 "got PARTDONE for filenum 1 on second tape") or die;
1333 like(taper_reply, qr/^PARTDONE $handle TESTCONF02 2 88 "\[sec [\d.]+ bytes 90112 kps [\d.]+ orig-kb 1512\]"$/,
1334 "got PARTDONE for filenum 2 on second tape") or die;
1335 like(taper_reply, qr/^DONE $handle INPUT-GOOD TAPE-GOOD "\[sec [\d.]+ bytes 614400 kps [\d.]+ orig-kb 1512\]" "" ""$/,
1341 qr(^INFO taper Slot 1 without label can be labeled$),
1342 qr(^START taper datestamp $datestamp label TESTCONF01 tape 1$),
1343 qr(^PART taper TESTCONF01 1 localhost /u01 $datestamp 1/-1 0 \[sec [\d.]+ bytes 262144 kps [\d.]+ orig-kb 1412\]$),
1344 qr(^PART taper TESTCONF01 2 localhost /u01 $datestamp 2/-1 0 \[sec [\d.]+ bytes 237856 kps [\d.]+ orig-kb 1412\]$),
1345 qr(^DONE taper localhost /u01 $datestamp 2 0 \[sec [\d.]+ bytes 500000 kps [\d.]+ orig-kb 1412\]$),
1346 qr(^PART taper TESTCONF01 3 localhost /u02 $datestamp 1/-1 0 \[sec [\d.]+ bytes 262144 kps [\d.]+ orig-kb 1512\]$),
1347 qr(^PARTPARTIAL taper TESTCONF01 4 localhost /u02 $datestamp 2/-1 0 \[sec [\d.]+ bytes 98304 kps [\d.]+ orig-kb 1512\] "No space left on device"$),
1348 qr(^INFO taper Will request retry of failed split part\.$),
1349 qr(^INFO taper tape TESTCONF01 kb 744 fm 4 \[OK\]$),
1350 qr(^INFO taper Slot 2 without label can be labeled$),
1351 qr(^START taper datestamp $datestamp label TESTCONF02 tape 2$),
1352 qr(^PART taper TESTCONF02 1 localhost /u02 $datestamp 2/-1 0 \[sec [\d.]+ bytes 262144 kps [\d.]+ orig-kb 1512\]$),
1353 qr(^PART taper TESTCONF02 2 localhost /u02 $datestamp 3/-1 0 \[sec [\d.]+ bytes 90112 kps [\d.]+ orig-kb 1512\]$),
1354 qr(^DONE taper localhost /u02 $datestamp 3 0 \[sec [\d.]+ bytes 614400 kps [\d.]+ orig-kb 1512\]$),
1355 qr(^INFO taper tape TESTCONF02 kb 344 fm 2 \[OK\]$),
1356 ], "first taper invocation in sequence logged correctly");
1359 $handle = "33-33333";
1360 $datestamp = "20090202020000";
1361 run_taper(1024, "second in a sequence", keep_config => 1);
1362 like(taper_reply, qr/^TAPER-OK worker0$/,
1363 "got TAPER-OK") or die;
1364 make_holding_file(300000, "localhost", "/u01");
1365 taper_cmd("FILE-WRITE worker0 $handle \"$test_filename\" localhost /u01 0 $datestamp 262144 \"\" \"\" \"\" \"\" \"\" \"\" \"\" 1612");
1366 like(taper_reply, qr/^REQUEST-NEW-TAPE $handle$/,
1367 "got REQUEST-NEW-TAPE worker0 $handle") or die;
1368 taper_cmd("START-SCAN worker0 $handle");
1369 taper_cmd("NEW-TAPE worker0 $handle");
1370 like(taper_reply, qr/^NEW-TAPE $handle TESTCONF03$/,
1371 "got proper NEW-TAPE worker0 $handle") or die;
1372 like(taper_reply, qr/^PARTDONE $handle TESTCONF03 1 256 "\[sec [\d.]+ bytes 262144 kps [\d.]+ orig-kb 1612\]"$/,
1373 "got PARTDONE for filenum 1") or die;
1374 like(taper_reply, qr/^PARTDONE $handle TESTCONF03 2 36 "\[sec [\d.]+ bytes 37856 kps [\d.]+ orig-kb 1612\]"$/,
1375 "got PARTDONE for filenum 2") or die;
1376 like(taper_reply, qr/^DONE $handle INPUT-GOOD TAPE-GOOD "\[sec [\d.]+ bytes 300000 kps [\d.]+ orig-kb 1612\]" "" ""$/,
1378 $handle = "33-44444";
1379 make_holding_file(614400, "localhost", "/u02");
1380 taper_cmd("FILE-WRITE worker0 $handle \"$test_filename\" localhost /u02 0 $datestamp 262144 \"\" \"\" \"\" \"\" \"\" \"\" \"\" 1712");
1381 like(taper_reply, qr/^PARTDONE $handle TESTCONF03 3 256 "\[sec [\d.]+ bytes 262144 kps [\d.]+ orig-kb 1712\]"$/,
1382 "got PARTDONE for filenum 3") or die;
1383 like(taper_reply, qr/^PARTDONE $handle TESTCONF03 4 256 "\[sec [\d.]+ bytes 262144 kps [\d.]+ orig-kb 1712\]"$/,
1384 "got PARTDONE for filenum 4") or die;
1385 like(taper_reply, qr/^REQUEST-NEW-TAPE $handle$/,
1386 "got REQUEST-NEW-TAPE worker0 $handle") or die;
1387 taper_cmd("START-SCAN worker0 $handle");
1388 taper_cmd("NEW-TAPE worker0 $handle");
1389 like(taper_reply, qr/^NEW-TAPE $handle TESTCONF01$/,
1390 "got proper NEW-TAPE worker0 $handle") or die;
1391 like(taper_reply, qr/^PARTDONE $handle TESTCONF01 1 88 "\[sec [\d.]+ bytes 90112 kps [\d.]+ orig-kb 1712\]"$/,
1392 "got PARTDONE for filenum 1 on second tape") or die;
1393 like(taper_reply, qr/^DONE $handle INPUT-GOOD TAPE-GOOD "\[sec [\d.]+ bytes 614400 kps [\d.]+ orig-kb 1712\]" "" ""$/,
1399 qr(^INFO taper Slot 3 without label can be labeled$),
1400 qr(^START taper datestamp $datestamp label TESTCONF03 tape 1$),
1401 qr(^PART taper TESTCONF03 1 localhost /u01 $datestamp 1/-1 0 \[sec [\d.]+ bytes 262144 kps [\d.]+ orig-kb 1612\]$),
1402 qr(^PART taper TESTCONF03 2 localhost /u01 $datestamp 2/-1 0 \[sec [\d.]+ bytes 37856 kps [\d.]+ orig-kb 1612\]$),
1403 qr(^DONE taper localhost /u01 $datestamp 2 0 \[sec [\d.]+ bytes 300000 kps [\d.]+ orig-kb 1612\]$),
1404 qr(^PART taper TESTCONF03 3 localhost /u02 $datestamp 1/-1 0 \[sec [\d.]+ bytes 262144 kps [\d.]+ orig-kb 1712\]$),
1405 qr(^PART taper TESTCONF03 4 localhost /u02 $datestamp 2/-1 0 \[sec [\d.]+ bytes 262144 kps [\d.]+ orig-kb 1712\]$),
1406 qr(^PARTPARTIAL taper TESTCONF03 5 localhost /u02 $datestamp 3/-1 0 \[sec [\d.]+ bytes 0 kps [\d.]+ orig-kb 1712\] "No space left on device"$),
1407 qr(^INFO taper Will request retry of failed split part\.$),
1408 qr(^INFO taper tape TESTCONF03 kb 804 fm 5 \[OK\]$),
1409 qr(^INFO taper Slot 1 with label TESTCONF01 is usable$),
1410 qr(^START taper datestamp $datestamp label TESTCONF01 tape 2$),
1411 qr(^PART taper TESTCONF01 1 localhost /u02 $datestamp 3/-1 0 \[sec [\d.]+ bytes 90112 kps [\d.]+ orig-kb 1712\]$),
1412 qr(^DONE taper localhost /u02 $datestamp 3 0 \[sec [\d.]+ bytes 614400 kps [\d.]+ orig-kb 1712\]$),
1413 qr(^INFO taper tape TESTCONF01 kb 88 fm 1 \[OK\]$),
1414 ], "second taper invocation in sequence logged correctly");
1418 # A run with a bogus tapedev/tpchanger
1419 $handle = "44-11111";
1420 $datestamp = "20070102030405";
1421 run_taper(4096, "no tapedev", notapedev => 1, taperscan => "lexical", new_vtapes => 1);
1422 like(taper_reply, qr/^TAPE-ERROR SETUP "You must specify one of 'tapedev' or 'tpchanger'"$/,
1423 "got TAPE-ERROR") or die;
1427 # A run with 2 workers
1428 $handle0 = "66-00000";
1429 $handle1 = "66-11111";
1430 $datestamp = "20090202020000";
1431 run_taper(1024, "with 2 workers", new_vtapes => 1, taperscan => "lexical", new_vtapes => 1);
1432 like(taper_reply, qr/^TAPER-OK worker0$/,
1433 "got TAPER-OK") or die;
1434 taper_cmd("START-TAPER worker1 $datestamp");
1435 like(taper_reply, qr/^TAPER-OK worker1$/,
1436 "got TAPER-OK") or die;
1437 make_holding_file(300000, "localhost", "/u01");
1438 taper_cmd("FILE-WRITE worker0 $handle0 \"$test_filename\" localhost /u01 0 $datestamp 262144 \"\" \"\" \"\" \"\" \"\" \"\" \"\" 1612");
1439 like(taper_reply, qr/^REQUEST-NEW-TAPE $handle0$/,
1440 "got REQUEST-NEW-TAPE worker0 $handle0") or die;
1441 taper_cmd("START-SCAN worker0 $handle0");
1442 taper_cmd("NEW-TAPE worker0 $handle0");
1443 like(taper_reply, qr/^NEW-TAPE $handle0 TESTCONF01$/,
1444 "got proper NEW-TAPE worker0 $handle0") or die;
1445 like(taper_reply, qr/^PARTDONE $handle0 TESTCONF01 1 256 "\[sec [\d.]+ bytes 262144 kps [\d.]+ orig-kb 1612\]"$/,
1446 "got PARTDONE for filenum 1") or die;
1447 like(taper_reply, qr/^PARTDONE $handle0 TESTCONF01 2 36 "\[sec [\d.]+ bytes 37856 kps [\d.]+ orig-kb 1612\]"$/,
1448 "got PARTDONE for filenum 2") or die;
1449 like(taper_reply, qr/^DONE $handle0 INPUT-GOOD TAPE-GOOD "\[sec [\d.]+ bytes 300000 kps [\d.]+ orig-kb 1612\]" "" ""$/,
1451 make_holding_file(614400, "localhost", "/u02");
1452 taper_cmd("FILE-WRITE worker1 $handle1 \"$test_filename\" localhost /u02 0 $datestamp 262144 \"\" \"\" \"\" \"\" \"\" \"\" \"\" 1712");
1453 like(taper_reply, qr/^REQUEST-NEW-TAPE $handle1$/,
1454 "got REQUEST-NEW-TAPE worker1 $handle1") or die;
1455 taper_cmd("START-SCAN worker1 $handle1");
1456 taper_cmd("NEW-TAPE worker1 $handle1");
1457 like(taper_reply, qr/^NEW-TAPE $handle1 TESTCONF02$/,
1458 "got proper NEW-TAPE worker1 $handle1") or die;
1459 like(taper_reply, qr/^PARTDONE $handle1 TESTCONF02 1 256 "\[sec [\d.]+ bytes 262144 kps [\d.]+ orig-kb 1712\]"$/,
1460 "got PARTDONE for filenum 1 on second tape") or die;
1461 like(taper_reply, qr/^PARTDONE $handle1 TESTCONF02 2 256 "\[sec [\d.]+ bytes 262144 kps [\d.]+ orig-kb 1712\]"$/,
1462 "got PARTDONE for filenum 2 on second tape") or die;
1463 like(taper_reply, qr/^PARTDONE $handle1 TESTCONF02 3 88 "\[sec [\d.]+ bytes 90112 kps [\d.]+ orig-kb 1712\]"$/,
1464 "got PARTDONE for filenum 3 on second tape") or die;
1465 like(taper_reply, qr/^DONE $handle1 INPUT-GOOD TAPE-GOOD "\[sec [\d.]+ bytes 614400 kps [\d.]+ orig-kb 1712\]" "" ""$/,
1471 qr(^INFO taper Slot 1 without label can be labeled$),
1472 qr(^INFO taper Slot 1 is already in use by drive.*$),
1473 qr(^INFO taper Slot 2 without label can be labeled$),
1474 qr(^START taper datestamp $datestamp label TESTCONF01 tape 1$),
1475 qr(^PART taper TESTCONF01 1 localhost /u01 $datestamp 1/-1 0 \[sec [\d.]+ bytes 262144 kps [\d.]+ orig-kb 1612\]$),
1476 qr(^PART taper TESTCONF01 2 localhost /u01 $datestamp 2/-1 0 \[sec [\d.]+ bytes 37856 kps [\d.]+ orig-kb 1612\]$),
1477 qr(^DONE taper localhost /u01 $datestamp 2 0 \[sec [\d.]+ bytes 300000 kps [\d.]+ orig-kb 1612\]$),
1478 qr(^START taper datestamp $datestamp label TESTCONF02 tape 2$),
1479 qr(^PART taper TESTCONF02 1 localhost /u02 $datestamp 1/-1 0 \[sec [\d.]+ bytes 262144 kps [\d.]+ orig-kb 1712\]$),
1480 qr(^PART taper TESTCONF02 2 localhost /u02 $datestamp 2/-1 0 \[sec [\d.]+ bytes 262144 kps [\d.]+ orig-kb 1712\]$),
1481 qr(^PART taper TESTCONF02 3 localhost /u02 $datestamp 3/-1 0 \[sec [\d.]+ bytes 90112 kps [\d.]+ orig-kb 1712\]$),
1482 qr(^DONE taper localhost /u02 $datestamp 3 0 \[sec [\d.]+ bytes 614400 kps [\d.]+ orig-kb 1712\]$),
1483 qr(^INFO taper tape TESTCONF01 kb 292 fm 2 \[OK\]$),
1484 qr(^INFO taper tape TESTCONF02 kb 600 fm 3 \[OK\]$),
1485 ], "two workers logged correctly");