Re: 3.2.0svn3411
On Thursday, September 23, 2010 03:45:33 am Gene Heskett did opine: On Wednesday, September 22, 2010 08:21:45 am Jean-Louis Martineau did opine: What's the taperalgo? Is it firstfit, largestfit or smallest Have you enabled splitting? LARGESTFIT and no:r...@coyote Daily]# grep split /usr/local/etc/amanda/Daily/amanda.conf # N Kb/Mb/Gb split images in chunks of size N ## tape_splitsize 1G ## split_diskbuffer /dumps # fallback_splitsize 64m Try the attached patch The email I got from this mornings amflush run said 'no file to flush' 32 times. Its working. Not done yet, but it is pouring 100 megs/sec into slot25. Darned typu's are hard to find. ;-) I assume 3435 up will carry these two patches forward? Done, report printed, looks normal. Email from the flush looks normal. We appear to be back to the regularly scheduled programming. Thank you very much. In case the mail daemon doesn't like my other address. 3438 worked just fine last night. -- Cheers, Gene There are four boxes to be used in defense of liberty: soap, ballot, jury, and ammo. Please use in that order. -Ed Howdershelt (Author) L'hazard ne favorise que l'esprit prepare. -- L. Pasteur
Re: 3.2.0svn3411
Am 21.09.2010 19:55, schrieb Jean-Louis Martineau: Attachment included. Jean-Louis Jean-Louis Martineau wrote: I can't find why it flush nothing. Can you upgrade to latest SVN and try the attached patch, it add mode degugging. Add 'debug-driver 1' in amanda.conf Retry amflush and send me the resulting amflush.1 file. Appplied patch, but my initial problem always is: FATAL amlogroll could not get current timestamp at /usr/libexec/amanda/amlogroll line 64. amflush doesn't even start. v3434 now Stefan
Re: 3.2.0svn3411
Stefan, Remove the log, amdump or amflush file from the log dir. Jean-Louis Stefan G. Weichinger wrote: Am 21.09.2010 19:55, schrieb Jean-Louis Martineau: Attachment included. Jean-Louis Jean-Louis Martineau wrote: I can't find why it flush nothing. Can you upgrade to latest SVN and try the attached patch, it add mode degugging. Add 'debug-driver 1' in amanda.conf Retry amflush and send me the resulting amflush.1 file. Appplied patch, but my initial problem always is: FATAL amlogroll could not get current timestamp at /usr/libexec/amanda/amlogroll line 64. amflush doesn't even start. v3434 now Stefan
Re: 3.2.0svn3411
On Wednesday, September 22, 2010 06:01:08 am Jean-Louis Martineau did opine: Attachment included. Jean-Louis Jean-Louis Martineau wrote: I can't find why it flush nothing. Can you upgrade to latest SVN and try the attached patch, it add mode degugging. Add 'debug-driver 1' in amanda.conf Retry amflush and send me the resulting amflush.1 file. 3.2.0.svn.3434 with patch. taper didn't write, 28Gb in holding disk. Ran amflush -f Daily by hand. Returned in about 2 seconds. amflush.20100922060304.debug: Wed Sep 22 06:03:04 2010: amflush: pid 22495 ruid 501 euid 501 version 3.2.0alpha.svn.3434: start at Wed Sep 22 06:03:04 2010 Wed Sep 22 06:03:04 2010: amflush: pid 22495 ruid 501 euid 501 version 3.2.0alpha.svn.3434: rename at Wed Sep 22 06:03:04 2010 Wed Sep 22 06:03:14 2010: amflush: flushing '/usr/dumps/20100922005007/coyote._GenesAmandaHelper-0.6.2' Wed Sep 22 06:03:14 2010: amflush: flushing '/usr/dumps/20100922005007/coyote._bin.1' Wed Sep 22 06:03:14 2010: amflush: flushing '/usr/dumps/20100922005007/coyote._boot.1' Wed Sep 22 06:03:14 2010: amflush: flushing '/usr/dumps/20100922005007/coyote._etc.1' Wed Sep 22 06:03:14 2010: amflush: flushing '/usr/dumps/20100922005007/coyote._home.0' Wed Sep 22 06:03:14 2010: amflush: flushing '/usr/dumps/20100922005007/coyote._lib.2' Wed Sep 22 06:03:14 2010: amflush: flushing '/usr/dumps/20100922005007/coyote._opt.0' Wed Sep 22 06:03:14 2010: amflush: flushing '/usr/dumps/20100922005007/coyote._root.1' Wed Sep 22 06:03:14 2010: amflush: flushing '/usr/dumps/20100922005007/coyote._sbin.1' Wed Sep 22 06:03:14 2010: amflush: flushing '/usr/dumps/20100922005007/coyote._tmp.1' Wed Sep 22 06:03:14 2010: amflush: flushing '/usr/dumps/20100922005007/coyote._usr_X11R6.1' Wed Sep 22 06:03:14 2010: amflush: flushing '/usr/dumps/20100922005007/coyote._usr_bin.1' Wed Sep 22 06:03:14 2010: amflush: flushing '/usr/dumps/20100922005007/coyote._usr_dlds_misc.1' Wed Sep 22 06:03:14 2010: amflush: flushing '/usr/dumps/20100922005007/coyote._usr_dlds_rpms.1' Wed Sep 22 06:03:14 2010: amflush: flushing '/usr/dumps/20100922005007/coyote._usr_dlds_tgzs.1' Wed Sep 22 06:03:14 2010: amflush: flushing '/usr/dumps/20100922005007/coyote._usr_include.1' Wed Sep 22 06:03:14 2010: amflush: flushing '/usr/dumps/20100922005007/coyote._usr_lib.1' Wed Sep 22 06:03:14 2010: amflush: flushing '/usr/dumps/20100922005007/coyote._usr_libexec.1' Wed Sep 22 06:03:14 2010: amflush: flushing '/usr/dumps/20100922005007/coyote._usr_local.2' Wed Sep 22 06:03:14 2010: amflush: flushing '/usr/dumps/20100922005007/coyote._usr_movies.0' Wed Sep 22 06:03:14 2010: amflush: flushing '/usr/dumps/20100922005007/coyote._usr_music.1' Wed Sep 22 06:03:14 2010: amflush: flushing '/usr/dumps/20100922005007/coyote._usr_pix.1' Wed Sep 22 06:03:14 2010: amflush: flushing '/usr/dumps/20100922005007/coyote._usr_sbin.1' Wed Sep 22 06:03:14 2010: amflush: flushing '/usr/dumps/20100922005007/coyote._usr_share.1' Wed Sep 22 06:03:14 2010: amflush: flushing '/usr/dumps/20100922005007/coyote._usr_src.2' Wed Sep 22 06:03:14 2010: amflush: flushing '/usr/dumps/20100922005007/coyote._var.1' Wed Sep 22 06:03:14 2010: amflush: flushing '/usr/dumps/20100922005007/shop._etc.0' Wed Sep 22 06:03:14 2010: amflush: flushing '/usr/dumps/20100922005007/shop._home.0' Wed Sep 22 06:03:14 2010: amflush: flushing '/usr/dumps/20100922005007/shop._usr_lib_amanda.0' Wed Sep 22 06:03:14 2010: amflush: flushing '/usr/dumps/20100922005007/shop._usr_local.0' Wed Sep 22 06:03:14 2010: amflush: flushing '/usr/dumps/20100922005007/shop._usr_src.0' Wed Sep 22 06:03:14 2010: amflush: flushing '/usr/dumps/20100922005007/shop._var_lib_amanda.0' amflush.1: amflush: start at Wed Sep 22 06:03:14 EDT 2010 amflush: datestamp 20100922060304 amflush: starttime 20100922060304 amflush: starttime-locale-independent 2010-09-22 06:03:14 EDT FLUSH coyote /GenesAmandaHelper-0.6 20100922005007 2 /usr/dumps/20100922005007/coyote._GenesAmandaHelper-0.6.2 FLUSH coyote /bin 20100922005007 1 /usr/dumps/20100922005007/coyote._bin.1 FLUSH coyote /boot 20100922005007 1 /usr/dumps/20100922005007/coyote._boot.1 FLUSH coyote /etc 20100922005007 1 /usr/dumps/20100922005007/coyote._etc.1 FLUSH coyote /home 20100922005007 0 /usr/dumps/20100922005007/coyote._home.0 FLUSH coyote /lib 20100922005007 2 /usr/dumps/20100922005007/coyote._lib.2 FLUSH coyote /opt 20100922005007 0 /usr/dumps/20100922005007/coyote._opt.0 FLUSH coyote /root 20100922005007 1 /usr/dumps/20100922005007/coyote._root.1 FLUSH coyote /sbin 20100922005007 1 /usr/dumps/20100922005007/coyote._sbin.1 FLUSH coyote /tmp 20100922005007 1 /usr/dumps/20100922005007/coyote._tmp.1 FLUSH coyote /usr/X11R6 20100922005007 1 /usr/dumps/20100922005007/coyote._usr_X11R6.1 FLUSH coyote /usr/bin 20100922005007 1 /usr/dumps/20100922005007/coyote._usr_bin.1 FLUSH coyote /usr/dlds/misc 20100922005007 1 /usr/dumps/20100922005007/coyote._usr_dlds_misc.1 FLUSH coyote /usr/dlds/rpms
Re: 3.2.0svn3411
What's the taperalgo? Is it firstfit, largestfit or smallest
Have you enabled splitting?
Try the attached patch
Jean-Louis
Gene Heskett wrote:
On Wednesday, September 22, 2010 06:01:08 am Jean-Louis Martineau did opine:
Attachment included.
Jean-Louis
Jean-Louis Martineau wrote:
I can't find why it flush nothing.
Can you upgrade to latest SVN and try the attached patch, it add mode
degugging.
Add 'debug-driver 1' in amanda.conf
Retry amflush and send me the resulting amflush.1 file.
3.2.0.svn.3434 with patch. taper didn't write, 28Gb in holding disk.
Ran amflush -f Daily by hand. Returned in about 2 seconds.
diff --git a/server-src/driver.c b/server-src/driver.c
index 6182ee0..148449f 100644
--- a/server-src/driver.c
+++ b/server-src/driver.c
@@ -780,6 +780,7 @@ startaflush_tape(
disk_t *fit = NULL;
char *datestamp;
off_t extra_tapes_size = 0;
+off_t taper_left;
char *qname;
TapeAction result_tape_action;
char *why_no_new_tape = NULL;
@@ -847,6 +848,11 @@ startaflush_tape(
}
}
+ if (taper-state TAPER_STATE_TAPE_STARTED) {
+ taper_left = taper-left;
+ } else {
+ taper_left = tape_length;
+ }
dp = NULL;
datestamp = sched(tapeq.head)-datestamp;
switch(taperalgo) {
@@ -857,7 +863,7 @@ startaflush_tape(
fit = tapeq.head;
while (fit != NULL) {
if (sched(fit)-act_size =
- (fit-splitsize ? extra_tapes_size : taper-left)
+ (fit-splitsize ? extra_tapes_size : taper_left)
strcmp(sched(fit)-datestamp, datestamp) = 0) {
dp = fit;
fit = NULL;
@@ -883,9 +889,10 @@ startaflush_tape(
fit = tapeq.head;
while (fit != NULL) {
if(sched(fit)-act_size =
- (fit-splitsize ? extra_tapes_size : taper-left)
+ (fit-splitsize ? extra_tapes_size : taper_left)
(!dp || sched(fit)-act_size sched(dp)-act_size)
strcmp(sched(fit)-datestamp, datestamp) = 0) {
+g_debug(%ld %ld %ld, fit-splitsize, extra_tapes_size, taper-left);
dp = fit;
}
fit = fit-next;
@@ -907,7 +914,7 @@ startaflush_tape(
fit = dp = tapeq.head;
while (fit != NULL) {
if (sched(fit)-act_size =
- (fit-splitsize ? extra_tapes_size : taper-left)
+ (fit-splitsize ? extra_tapes_size : taper_left)
(!dp || sched(fit)-act_size sched(dp)-act_size)
strcmp(sched(fit)-datestamp, datestamp) = 0) {
dp = fit;
@@ -924,7 +931,7 @@ startaflush_tape(
fit = tapeq.tail;
while (fit != NULL) {
if (sched(fit)-act_size =
- (fit-splitsize ? extra_tapes_size : taper-left)
+ (fit-splitsize ? extra_tapes_size : taper_left)
(!dp || sched(fit)-act_size sched(dp)-act_size)
strcmp(sched(fit)-datestamp, datestamp) = 0) {
dp = fit;
Re: 3.2.0svn3411
On Wednesday, September 22, 2010 08:21:45 am Jean-Louis Martineau did opine: What's the taperalgo? Is it firstfit, largestfit or smallest Have you enabled splitting? LARGESTFIT and no:r...@coyote Daily]# grep split /usr/local/etc/amanda/Daily/amanda.conf # N Kb/Mb/Gb split images in chunks of size N ## tape_splitsize 1G ## split_diskbuffer /dumps # fallback_splitsize 64m Try the attached patch The email I got from this mornings amflush run said 'no file to flush' 32 times. Its working. Not done yet, but it is pouring 100 megs/sec into slot25. Darned typu's are hard to find. ;-) I assume 3435 up will carry these two patches forward? Done, report printed, looks normal. Email from the flush looks normal. We appear to be back to the regularly scheduled programming. Thank you very much. -- Cheers, Gene There are four boxes to be used in defense of liberty: soap, ballot, jury, and ammo. Please use in that order. -Ed Howdershelt (Author) The rose of yore is but a name, mere names are left to us.
Re: 3.2.0svn3411
Am 22.09.2010 12:11, schrieb Jean-Louis Martineau: Stefan, Remove the log, amdump or amflush file from the log dir. see attachment. nothing taped. Stefan amdump.1.gz Description: GNU Zip compressed data
Re: 3.2.0svn3411
What's your flush-threshold setting? amgetconf CONF flush-threshold-scheduled amgetconf CONF flush-threshold-dumped amgetconf CONF taperflush Stefan G. Weichinger wrote: Am 21.09.2010 00:09, schrieb Jean-Louis Martineau: Can you provide the complete amflush.1 or amdump.1 files attached. Stefan
Re: 3.2.0svn3411
Am 21.09.2010 00:09, schrieb Jean-Louis Martineau: Can you provide the complete amflush.1 or amdump.1 files attached. Stefan jlm.tgz Description: application/compressed-tar
Re: 3.2.0svn3411
On Mon, Sep 20, 2010 at 11:20 PM, gene heskett ghesk...@wdtv.com wrote: with taper_debug 9 I had a 174 meg taper log, which still didn't make any sense as it was reporting about 6 lines for every 32k write, so I dropped it to 2. I grepped for the differences in the man tree but didn't see anything about the verbosity diffs. So now it's writing to tape. So the problem is solved. Does it not write to tape with a lower debug level? Dustin -- Open Source Storage Engineer http://www.zmanda.com
Re: 3.2.0svn3411
On Tuesday, September 21, 2010 11:34:54 am Dustin J. Mitchell did opine: On Mon, Sep 20, 2010 at 11:20 PM, gene heskett ghesk...@wdtv.com wrote: with taper_debug 9 I had a 174 meg taper log, which still didn't make any sense as it was reporting about 6 lines for every 32k write, so I dropped it to 2. I grepped for the differences in the man tree but didn't see anything about the verbosity diffs. So now it's writing to tape. So the problem is solved. Does it not write to tape with a lower debug level? Dustin No, it ceases to write to the 'tape' after 3402, I think. Yes, 3402 worked, 3411 failed. See my previous reply where the 3 amgetconf lines were asked about. I read ChangeLogs, and this is the first I'd heard of those 3 new variables. This stuff belongs in the ChangeLog! With a line saying new amanda.conf vars, listing them comma separated. That would have been trigger enough to go read the man page. dumps has been moved to a much larger playground, and 3427 installed just to check my theory that zero detection is thwarted by a holding disk smaller than the vtape. Ergo no flush by taper. Even when amflush is called by hand. Also, a separate squawk, starting at about svn3388 I think, the emailed report is suddenly being spammed by a hundred lines or so of stuff about in- accessible sockets and such in /home/gene/tmp, which contains other stuff I would rather were included in the backups. But that's a different problem. Sorry if I come across a bit grouchy, I've been taking antibiotics for a strep throat the last few days. And I'm about worn out trying to get this place put back together for the winter after a 112 mph wind came through the neighborhood on June 24th, demolishing or uprooting most of the trees. We lost 3 of 4 40 year old pines, the roof, parts of the back porch and all the privacy fencing. Amazingly a 60 foot pin oak in the front yard stood. The replacement fencing I built post hole by post hole and screw by screw, and it can be seen at http://gene.homelinux.net:85/gene/fence I'll be 76 in another few days, and folks keep telling me I should retire. I keep trying to, but such as this gets in the way... The bottom of my fishing boat hasn't been wet since summer 2009. And right now I am working on its shed, which although tattered, didn't blow away in the wind as it was below the house on the lee side. Pix in the camera I'll put up when I'm done with that. I used to have a life, but its about used up I think. -- Cheers, Gene There are four boxes to be used in defense of liberty: soap, ballot, jury, and ammo. Please use in that order. -Ed Howdershelt (Author) Your happiness is intertwined with your outlook on life.
Re: 3.2.0svn3411
gene heskett wrote: Butting in here, but a nice bright light bulb just came on. I get a big fat 0 for all three amgetconf's above. Izzat my problem? [r...@coyote amanda]# amgetconf Daily flush-threshold-scheduled 0 [r...@coyote amanda]# amgetconf Daily flush-threshold-dumped 0 [r...@coyote amanda]# amgetconf Daily taperflush 0 A value of 0 is good, amanda should try to flush everything. Jean-Louis
Re: 3.2.0svn3411
Gene, this is counterproductive at this point. You've named a few things that seem to be wrong, all of which are unrelated. You've changed things between each email, and claimed a number of different symptoms. PLEASE: slow down. Find *one* failure, describe it fully, and track it down to its cause, using logfiles if possible. Be as methodical as possible. Dustin -- Open Source Storage Engineer http://www.zmanda.com
Re: 3.2.0svn3411
I can't find why it flush nothing. Can you upgrade to latest SVN and try the attached patch, it add mode degugging. Add 'debug-driver 1' in amanda.conf Retry amflush and send me the resulting amflush.1 file. Jean-Louis Stefan G. Weichinger wrote: Am 21.09.2010 00:09, schrieb Jean-Louis Martineau: Can you provide the complete amflush.1 or amdump.1 files attached. Stefan
Re: 3.2.0svn3411
Attachment included.
Jean-Louis
Jean-Louis Martineau wrote:
I can't find why it flush nothing.
Can you upgrade to latest SVN and try the attached patch, it add mode
degugging.
Add 'debug-driver 1' in amanda.conf
Retry amflush and send me the resulting amflush.1 file.
Jean-Louis
Stefan G. Weichinger wrote:
Am 21.09.2010 00:09, schrieb Jean-Louis Martineau:
Can you provide the complete amflush.1 or amdump.1 files
attached.
Stefan
diff --git a/server-src/driver.c b/server-src/driver.c
index 6182ee0..ea66006 100644
--- a/server-src/driver.c
+++ b/server-src/driver.c
@@ -3735,18 +3735,30 @@ tape_action(
}
}
if (nb_taper_active = 1) {
-my_flush_threshold_dumped = flush_threshold_dumped +
-(nb_taper_active-nb_taper_active) * tape_length;
-my_flush_threshold_scheduled = flush_threshold_scheduled +
- (nb_taper_active-nb_taper_active) * tape_length;
-my_taperflush = taperflush + (nb_taper_active-nb_taper_active) * tape_length;
+ my_flush_threshold_dumped = flush_threshold_dumped;
+ my_flush_threshold_scheduled = flush_threshold_scheduled;
+ my_taperflush = taperflush;
} else {
-my_flush_threshold_dumped = flush_threshold_dumped +
-nb_taper_active * tape_length;
-my_flush_threshold_scheduled = flush_threshold_scheduled +
- nb_taper_active * tape_length;
-my_taperflush = taperflush + nb_taper_active * tape_length;
-}
+ my_flush_threshold_dumped = flush_threshold_dumped +
+nb_taper_active * tape_length;
+ my_flush_threshold_scheduled = flush_threshold_scheduled +
+ nb_taper_active * tape_length;
+ my_taperflush = taperflush + nb_taper_active * tape_length;
+}
+
+driver_debug(1, _(nb_taper_active: %d\n), nb_taper_active);
+driver_debug(1, _(my_flush_threshold_dumped: %lld\n), (long long)my_flush_threshold_dumped);
+driver_debug(1, _(my_flush_threshold_scheduled: %lld\n), (long long)my_flush_threshold_scheduled);
+driver_debug(1, _(my_taperflush: %lld\n), (long long)my_taperflush);
+driver_debug(1, _(taper state: %d\n), taper-state);
+driver_debug(1, _(taper_nb_scan_volume state: %d\n), taper_nb_scan_volume);
+driver_debug(1, _(degraded_mode: %d\n), degraded_mode);
+driver_debug(1, _(runq: %d\n), empty(runq));
+driver_debug(1, _(directq: %d\n), empty(directq));
+driver_debug(1, _(roomq: %d\n), empty(roomq));
+driver_debug(1, _(idle_reason: %d\n), idle_reason);
+driver_debug(1, _(degraded_mode: %d\n), degraded_mode);
+driver_debug(1, _(force_flush: %d\n), force_flush);
// Changing conditionals can produce a driver hang, take care.
//
Re: 3.2.0svn3411
On Tuesday, September 21, 2010 10:20:53 pm Dustin J. Mitchell did opine: Gene, this is counterproductive at this point. You've named a few things that seem to be wrong, all of which are unrelated. You've changed things between each email, and claimed a number of different symptoms. Only 2 come to mind and the one listed below is the primary one. PLEASE: slow down. Find *one* failure, describe it fully, and track it down to its cause, using logfiles if possible. Be as methodical as possible. Dustin One failure? Nothing later than 3402 will write from the holding disk to the tape. The taper.*.debug log shrinks from 16 or 17k to 794 bytes, and that is the one you have already. From 3411 on, I cannot flush whats in the holding disk even when running amflush by hand, amflush exits about 2 or 3 seconds after tapping the drive with one read, and one small write, probably the status file, and without any further data being added to the taper.debug file. I have 3427 installed for tonights run, with two changes, taper_debug is now set to 2 as 9 made a 170+ megabyte taper.*.debug file last night, and dumps has moved to a partition with 600Gb more space. Tonight's run will test my theory. If it fails, then I back up to 3402 see if I can flush it by hand. I know I can with 3341. More after the run. -- Cheers, Gene There are four boxes to be used in defense of liberty: soap, ballot, jury, and ammo. Please use in that order. -Ed Howdershelt (Author) The temperature of the aqueous content of an unremittingly ogled culinary vessel will not achieve 100 degrees on the Celsius scale.
Re: 3.2.0svn3411
Am 2010-09-20 03:25, schrieb Gene Heskett: On Sunday, September 19, 2010 09:09:32 pm Dustin J. Mitchell did opine: Oops, sorry, it's debug_taper 9 not debug taper That appears to work. We'll see if it enhances the 3341 report tonight, thanks. I think I hit the same issue with my new gentoo-ebuild. Nothing written by amflush -b daily , amflush ... and nothing flushed from amdump. Added that debug-parameter and re-ran amflush, nothing special in the logs. pls advise for other flags to set. greets from the gentoo-tester, Stefan ;-)
Re: 3.2.0svn3411
On Mon, Sep 20, 2010 at 2:44 PM, Stefan G. Weichinger s...@amanda.org wrote: Added that debug-parameter and re-ran amflush, nothing special in the logs. What does this mean? Did the taper start up but not write anything? And what revision are you using? Dustin -- Open Source Storage Engineer http://www.zmanda.com
Re: 3.2.0svn3411
Am 20.09.2010 22:03, schrieb Dustin J. Mitchell: On Mon, Sep 20, 2010 at 2:44 PM, Stefan G. Weichinger s...@amanda.org wrote: Added that debug-parameter and re-ran amflush, nothing special in the logs. What does this mean? Did the taper start up but not write anything? Yep. There is a taper-debugfile, but nothing written. All DLEs marked NO FILE TO FLUSH in the report-mail. And what revision are you using? I think it was 3411, now I am at 3427. amflush -b daily immediately fails .. amreport: process terminated while waiting to flush A bit fast for the driver-process -- $ cat driver.20100920220732.debug Mon Sep 20 22:07:32 2010: driver: pid 8013 ruid 87 euid 87 version 3.2.0alpha: start at Mon Sep 20 22:07:32 2010 Mon Sep 20 22:07:32 2010: driver: pid 8013 ruid 87 euid 87 version 3.2.0alpha: rename at Mon Sep 20 22:07:32 2010 Mon Sep 20 22:07:34 2010: driver: pid 8013 finish time Mon Sep 20 22:07:34 2010 ? taper shows nothing special, afaik: $ cat taper.20100920220733.debug Mon Sep 20 22:07:33 2010: taper: pid 8014 ruid 87 euid 87 version 3.2.0alpha: start at Mon Sep 20 22:07:33 2010 Mon Sep 20 22:07:33 2010: taper: pid 8014 ruid 87 euid 87 version 3.2.0alpha: rename at Mon Sep 20 22:07:33 2010 Mon Sep 20 22:07:33 2010: taper: driver/taper START-TAPER worker0 20100920220732 Mon Sep 20 22:07:33 2010: taper: Amanda::Taper::Scribe: starting Mon Sep 20 22:07:33 2010: taper: Amanda::Taper::Scan::traditional stage 1: search for oldest reusable volume Mon Sep 20 22:07:33 2010: taper: Amanda::Taper::Scan::traditional oldest reusable volume is 'daily04' Mon Sep 20 22:07:33 2010: taper: Amanda::Taper::Scan::traditional changer is not fast-searchable; skipping to stage 2 Mon Sep 20 22:07:33 2010: taper: Amanda::Taper::Scan::traditional stage 2: scan for any reusable volume Mon Sep 20 22:07:33 2010: taper: Amanda::Taper::Scan::traditional result: 'daily04' on tape:/dev/nst0 slot 1, mode 2 Mon Sep 20 22:07:33 2010: taper: driver/taper TAPER-OK worker0 Mon Sep 20 22:07:33 2010: taper: driver/taper QUIT Mon Sep 20 22:07:33 2010: taper: Amanda::Taper::Scribe: quitting Mon Sep 20 22:07:33 2010: taper: pid 8014 finish time Mon Sep 20 22:07:33 2010 I assume debug_driver 9 ?? Stefan
Re: 3.2.0svn3411
with driver_debug 9: $ amcheck -s daily Amanda Tape Server Host Check - Holding disk /mnt/amhold/daily: 36 GB disk space available, using 36 GB WARNING: skipping tape test because amdump or amflush seem to be running WARNING: if they are not, you must run amcleanup Server check took 0.001 seconds (brought to you by Amanda 3.2.0alpha) ama...@mythtv /var/tmp/amanda/server/daily $ amcleanup -k daily /usr/libexec/amanda/amlogroll exited with value 1 256 ama...@mythtv /var/tmp/amanda/server/daily $ ls -lrt amlogroll* [...] -rw-r- 1 amanda amanda 447 Sep 20 22:23 amlogroll.20100920222356.debug ama...@mythtv /var/tmp/amanda/server/daily $ cat amlogroll.20100920222356.debug Mon Sep 20 22:23:56 2010: amlogroll: pid 8193 ruid 87 euid 87 version 3.2.0alpha: start at Mon Sep 20 22:23:56 2010 Mon Sep 20 22:23:56 2010: amlogroll: pid 8193 ruid 87 euid 87 version 3.2.0alpha: rename at Mon Sep 20 22:23:56 2010 Mon Sep 20 22:23:56 2010: amlogroll: warning: no current timestamp found in logfile Mon Sep 20 22:23:56 2010: amlogroll: critical (fatal): could not get current timestamp at /usr/libexec/amanda/amlogroll line 64. does that help? Stefan
Re: 3.2.0svn3411
On Mon, Sep 20, 2010 at 3:25 PM, Stefan G. Weichinger s...@amanda.org wrote: does that help? Perhaps. I'm strongly suspecting that this is a problem with the new multi-tape support. Jean-Louis, do you see anything related here? I've upgrade my production Amanda to the latest trunk (thanks to the handy-dandy ebuild!), so we'll see if I encounter similar problems myself. Dustin -- Open Source Storage Engineer http://www.zmanda.com
Re: 3.2.0svn3411
Can you provide the complete amflush.1 or amdump.1 files Dustin J. Mitchell wrote: On Mon, Sep 20, 2010 at 3:25 PM, Stefan G. Weichinger s...@amanda.org wrote: does that help? Perhaps. I'm strongly suspecting that this is a problem with the new multi-tape support. Jean-Louis, do you see anything related here? I've upgrade my production Amanda to the latest trunk (thanks to the handy-dandy ebuild!), so we'll see if I encounter similar problems myself. Dustin
Re: 3.2.0svn3411
On Sunday, September 19, 2010 05:39:34 am Dustin J. Mitchell did opine: On Sat, Sep 18, 2010 at 11:26 AM, Gene Heskett gene.hesk...@gmail.com wrote: 1. The backup runs normally, to the holding disk, but times out writing to the vtape, so it is all left sitting in the holding disk. I have enough I can do this for several days. It turns out that for this install, that is not the case, and after an additional 1.8G was added to the holding disk, it must have hit the reserve 25% as several DLE's failed, missing, last night. Also, it appears I did convert my amanda.conf's tpchanger line to tpchanger chg-disk:/amandatapes/Dailys at some point far enough back up the log I'd forgotten it. And at svn3416, amflush no longer works, so I an truly stuck now. One thing that catches my eye, in the taper.log, it is searching for: [ama...@coyote Daily]$ cat taper.20100919052724.debug Sun Sep 19 05:27:24 2010: taper: pid 5083 ruid 501 euid 501 version 3.2.0alpha.svn.3416: start at Sun Sep 19 05:27:24 2010 Sun Sep 19 05:27:24 2010: taper: pid 5083 ruid 501 euid 501 version 3.2.0alpha.svn.3416: rename at Sun Sep 19 05:27:24 2010 Sun Sep 19 05:27:24 2010: taper: Amanda::Taper::Scan::traditional stage 1: search for oldest reusable volume Sun Sep 19 05:27:24 2010: taper: Amanda::Taper::Scan::traditional oldest reusable volume is 'Dailys-21' Sun Sep 19 05:27:24 2010: taper: Amanda::Taper::Scan::traditional stage 1: searching oldest reusable volume 'Dailys-21' Sun Sep 19 05:27:24 2010: taper: Amanda::Taper::Scan::traditional result: 'Dailys-21' on file:/amandatapes/Dailys/drive0 slot 21, mode 2 Sun Sep 19 05:27:24 2010: taper: pid 5083 finish time Sun Sep 19 05:27:24 2010 [ama...@coyote Daily]$ Where is that spurious '/drive0' coming from in the file:string? 10 mins later, I have re-installed 3.2.0-svn3341, and amflush is now working. I will leave that version in till you advise. However, I note the spurious drive0 is also in the file:string of the taper-debug log generated by the older taper. False alarm? Or clue... Thanks Dustin. -- Cheers, Gene There are four boxes to be used in defense of liberty: soap, ballot, jury, and ammo. Please use in that order. -Ed Howdershelt (Author) Hildebrant's Principle: If you don't know where you are going, any road will get you there.
Re: 3.2.0svn3411
On Sun, Sep 19, 2010 at 5:32 AM, Gene Heskett gene.hesk...@gmail.com wrote: One thing that catches my eye, in the taper.log, it is searching for: [ama...@coyote Daily]$ cat taper.20100919052724.debug Sun Sep 19 05:27:24 2010: taper: pid 5083 ruid 501 euid 501 version 3.2.0alpha.svn.3416: start at Sun Sep 19 05:27:24 2010 Sun Sep 19 05:27:24 2010: taper: pid 5083 ruid 501 euid 501 version 3.2.0alpha.svn.3416: rename at Sun Sep 19 05:27:24 2010 Sun Sep 19 05:27:24 2010: taper: Amanda::Taper::Scan::traditional stage 1: search for oldest reusable volume Sun Sep 19 05:27:24 2010: taper: Amanda::Taper::Scan::traditional oldest reusable volume is 'Dailys-21' Sun Sep 19 05:27:24 2010: taper: Amanda::Taper::Scan::traditional stage 1: searching oldest reusable volume 'Dailys-21' Sun Sep 19 05:27:24 2010: taper: Amanda::Taper::Scan::traditional result: 'Dailys-21' on file:/amandatapes/Dailys/drive0 slot 21, mode 2 Sun Sep 19 05:27:24 2010: taper: pid 5083 finish time Sun Sep 19 05:27:24 2010 [ama...@coyote Daily]$ Where is that spurious '/drive0' coming from in the file:string? False alarm - that's how the new changer works, and also explains why you were not seeing the data/ link updated. So the driver didn't even *try* to write anything to tape in the run for which you just pasted a debug log. Any idea why? Dustin -- Open Source Storage Engineer http://www.zmanda.com
Re: 3.2.0svn3411
On Sunday, September 19, 2010 06:30:06 pm Dustin J. Mitchell did opine: On Sun, Sep 19, 2010 at 5:32 AM, Gene Heskett gene.hesk...@gmail.com wrote: One thing that catches my eye, in the taper.log, it is searching for: [ama...@coyote Daily]$ cat taper.20100919052724.debug Sun Sep 19 05:27:24 2010: taper: pid 5083 ruid 501 euid 501 version 3.2.0alpha.svn.3416: start at Sun Sep 19 05:27:24 2010 Sun Sep 19 05:27:24 2010: taper: pid 5083 ruid 501 euid 501 version 3.2.0alpha.svn.3416: rename at Sun Sep 19 05:27:24 2010 Sun Sep 19 05:27:24 2010: taper: Amanda::Taper::Scan::traditional stage 1: search for oldest reusable volume Sun Sep 19 05:27:24 2010: taper: Amanda::Taper::Scan::traditional oldest reusable volume is 'Dailys-21' Sun Sep 19 05:27:24 2010: taper: Amanda::Taper::Scan::traditional stage 1: searching oldest reusable volume 'Dailys-21' Sun Sep 19 05:27:24 2010: taper: Amanda::Taper::Scan::traditional result: 'Dailys-21' on file:/amandatapes/Dailys/drive0 slot 21, mode 2 Sun Sep 19 05:27:24 2010: taper: pid 5083 finish time Sun Sep 19 05:27:24 2010 [ama...@coyote Daily]$ Where is that spurious '/drive0' coming from in the file:string? False alarm - that's how the new changer works, and also explains why you were not seeing the data/ link updated. I see. Then it must have been on the 8/29 day shift when I changed the chg-disk in my amanda.conf, because those files are dated 8/29 roughly coincident with the shortly after midnight run time. So the driver didn't even *try* to write anything to tape in the run for which you just pasted a debug log. Any idea why? Dustin Your guess is as good as mine, there simply isn't anything to indicate the failure, or a hint of a reason in the logs I've grepped. All I know at this point is that I have to back up to about svn3341 just to get amflush to work. The current 3419? taps the drive, once for a read that may be the tape header file, and once about 2 seconds later for a very quick write which might be the status file, then exits silently in another second or so even when amflush is run with the -f option. I think it might help if taper was made a lot more chatty. Is there a debug level option I could pass to it? -- Cheers, Gene There are four boxes to be used in defense of liberty: soap, ballot, jury, and ammo. Please use in that order. -Ed Howdershelt (Author) When it comes to helping you, some people stop at nothing.
Re: 3.2.0svn3411
On Sun, Sep 19, 2010 at 5:40 PM, Gene Heskett gene.hesk...@gmail.com wrote: Your guess is as good as mine, there simply isn't anything to indicate the failure, or a hint of a reason in the logs I've grepped. All I know at this point is that I have to back up to about svn3341 just to get amflush to work. The current 3419? taps the drive, once for a read that may be the tape header file, and once about 2 seconds later for a very quick write which might be the status file, then exits silently in another second or so even when amflush is run with the -f option. I think it might help if taper was made a lot more chatty. Is there a debug level option I could pass to it? Sure - add 'debug taper 9' to amanda.conf. But the taper doesn't have anything to chat about - the driver never asks it to do anything after starting it up. Dustin -- Open Source Storage Engineer http://www.zmanda.com
Re: 3.2.0svn3411
On Sunday, September 19, 2010 07:58:13 pm Dustin J. Mitchell did opine: On Sun, Sep 19, 2010 at 5:40 PM, Gene Heskett gene.hesk...@gmail.com wrote: Your guess is as good as mine, there simply isn't anything to indicate the failure, or a hint of a reason in the logs I've grepped. All I know at this point is that I have to back up to about svn3341 just to get amflush to work. The current 3419? taps the drive, once for a read that may be the tape header file, and once about 2 seconds later for a very quick write which might be the status file, then exits silently in another second or so even when amflush is run with the -f option. I think it might help if taper was made a lot more chatty. Is there a debug level option I could pass to it? Sure - add 'debug taper 9' to amanda.conf. But the taper doesn't have anything to chat about - the driver never asks it to do anything after starting it up. Dustin But that kills amcheck, when amcheck is svn3341. How new do I have to be to have that work? [r...@coyote amanda]# su - amanda -c vim /usr/local/etc/amanda/Daily/amanda.conf [r...@coyote amanda]# su - amanda -c amcheck Daily /usr/local/etc/amanda/Daily/amanda.conf, line 116: configuration keyword expected amcheck: errors processing config file -- Cheers, Gene There are four boxes to be used in defense of liberty: soap, ballot, jury, and ammo. Please use in that order. -Ed Howdershelt (Author) I have not yet begun to byte!
Re: 3.2.0svn3411
On Sun, Sep 19, 2010 at 7:00 PM, Gene Heskett gene.hesk...@gmail.com wrote: But that kills amcheck, when amcheck is svn3341. How new do I have to be to have that work? Oops, sorry, it's debug_taper 9 not debug taper Dustin -- Open Source Storage Engineer http://www.zmanda.com
Re: 3.2.0svn3411
On Sunday, September 19, 2010 09:09:32 pm Dustin J. Mitchell did opine: On Sun, Sep 19, 2010 at 7:00 PM, Gene Heskett gene.hesk...@gmail.com wrote: But that kills amcheck, when amcheck is svn3341. How new do I have to be to have that work? Oops, sorry, it's debug_taper 9 not debug taper Dustin Happens in the best regulated families I hear. ;-) That appears to work. We'll see if it enhances the 3341 report tonight, thanks. -- Cheers, Gene There are four boxes to be used in defense of liberty: soap, ballot, jury, and ammo. Please use in that order. -Ed Howdershelt (Author) Such a fine first dream! But they laughed at me; they said I had made it up.
Re: 3.2.0svn3411
On Fri, Sep 17, 2010 at 8:35 PM, Gene Heskett gene.hesk...@gmail.com wrote: At this point I have a WTH expression on my ancient face. Go read changelog if all else fails. I see a lot of changes on about 08/29-30-31 but no mention of chg-disk-slot? And, indeed, that hasn't changed. Now that you've experimented a bit, can you put your finger on exactly what symptoms you're seeing? I assume that you're still using the old chg-disk, or have you changed that somewhere along the line to use chg-disk:/path/to/something? Dustin -- Open Source Storage Engineer http://www.zmanda.com
Re: 3.2.0svn3411
On Saturday, September 18, 2010 12:14:24 pm Dustin J. Mitchell did opine: On Fri, Sep 17, 2010 at 8:35 PM, Gene Heskett gene.hesk...@gmail.com wrote: At this point I have a WTH expression on my ancient face. Go read changelog if all else fails. I see a lot of changes on about 08/29-30-31 but no mention of chg-disk-slot? And, indeed, that hasn't changed. Now that you've experimented a bit, can you put your finger on exactly what symptoms you're seeing? 1. The backup runs normally, to the holding disk, but times out writing to the vtape, so it is all left sitting in the holding disk. I have enough I can do this for several days. 2. amcheck looks like its working just fine, but is not touching /config/chg- disk-slot, nor is it updateing the 'data' link in the vtapes slot# directory. This has been since 08/29 according to the dates on those files in the config dir, and the data link was left pointing at slot2, which would correspond to the 08/30 run. 3. If I fix that (and I haven't tried a flush without fixing them, paranoia reigns), amflush will them finish moving to the vtape, and my subscript can then do its thing, writing the /config/ and compressed indices tree to the end of that vtape, and everything looks normal then. I assume that you're still using the old chg-disk, or have you changed that somewhere along the line to use chg-disk:/path/to/something? I did know I was supposed to be changing this, manpage please? Stuff like this really needs to be in the changelog, at least with a see manpage so-and-so for details line. Dustin Thanks Dustin. -- Cheers, Gene There are four boxes to be used in defense of liberty: soap, ballot, jury, and ammo. Please use in that order. -Ed Howdershelt (Author) There is an innocence in admiration; it is found in those to whom it has not yet occurred that they, too, might be admired some day. -- Friedrich Nietzsche
Re: 3.2.0svn3411
On Sat, 18 Sep 2010 12:26:14 -0400 Gene Heskett gene.hesk...@gmail.com wrote: I assume that you're still using the old chg-disk, or have you changed that somewhere along the line to use chg-disk:/path/to/something? I did know I was supposed to be changing this, manpage please? http://wiki.zmanda.com/man/amanda-changers.7.html -- Charles Curley /\ASCII Ribbon Campaign Looking for fine software \ /Respect for open standards and/or writing? X No HTML/RTF in email http://www.charlescurley.com/ \No M$ Word docs in email Key fingerprint = CE5C 6645 A45A 64E4 94C0 809C FFF6 4C48 4ECD DFDB
Re: 3.2.0svn3411
On Sat, Sep 18, 2010 at 11:26 AM, Gene Heskett gene.hesk...@gmail.com wrote: 1. The backup runs normally, to the holding disk, but times out writing to the vtape, so it is all left sitting in the holding disk. I have enough I can do this for several days. Can you send the taper debug log? Taper doesn't time out, so that's pretty odd. Or is the timeout something you've added externally? 2. amcheck looks like its working just fine, but is not touching /config/chg- disk-slot, nor is it updateing the 'data' link in the vtapes slot# directory. This has been since 08/29 according to the dates on those files in the config dir, and the data link was left pointing at slot2, which would correspond to the 08/30 run. Can you send the amcheck output and `find /my/vtapes`? I did know I was supposed to be changing this, manpage please? Stuff like this really needs to be in the changelog, at least with a see manpage so-and-so for details line. Well, to be clear, I didn't say you should - I just asked if you did, and the answer was no :) In general, we're hoping that new users will use the new changers, and existing users can migrate or not at their option. Dustin -- Open Source Storage Engineer http://www.zmanda.com
Re: 3.2.0svn3411
Big change to the driver and taper was committed yesterday. Can you post the taper debug file and the amdump.1 file. Jean-Louis Gene Heskett wrote: Yesterdays 3411 failed last night, all DEL's timed out waiting for writing to tape. The install, which ends in an amcheck: install done, now running amcheck as the user amanda Amanda Tape Server Host Check - Holding disk /dumps: 21712896 kB disk space available, using 21200896 kB Searching for label 'Dailys-20':found in slot 20: volume 'Dailys-20' Will write to volume 'Dailys-20' in slot 20. NOTE: skipping tape-writable test Server check took 0.312 seconds Amanda Backup Client Hosts Check Client check: 2 hosts checked in 6.333 seconds. 0 problems found. (brought to you by Amanda 3.2.0alpha.svn.3411) == but no mail or printout was received, and my 32 count active disklist comes back as 32 lines of this: coyote:/GenesAmandaHelper-0.6 2141545k dump done (2:01:42), process terminated while waiting for writing to tape coyote:/bin 0 11520k dump done (3:42:09), process terminated while waiting for writing to tape coyote:/boot 0131910k dump done (1:54:59), process terminated while waiting for writing to tape coyote:/etc 0 6660k dump done (3:42:45), process terminated while waiting for writing to tape coyote:/home 0 12775661k dump done (3:33:36), process terminated while waiting for writing to tape coyote:/lib 1 3222k dump done (3:44:36), process terminated while waiting for writing to tape coyote:/opt 1 356k dump done (3:46:23), process terminated while waiting for writing to tape coyote:/root 0 4893k dump done (3:41:55), process terminated while waiting for writing to tape coyote:/sbin 0 21850k dump done (1:55:25), process terminated while waiting for writing to tape coyote:/tmp 1 3819k dump done (3:33:39), process terminated while waiting for writing to tape coyote:/usr/X11R6 1 1k dump done (3:42:24), process terminated while waiting for writing to tape coyote:/usr/bin 1160490k dump done (3:43:46), process terminated while waiting for writing to tape coyote:/usr/dlds/misc 140k dump done (3:44:09), process terminated while waiting for writing to tape coyote:/usr/dlds/rpms 0273580k dump done (1:54:53), process terminated while waiting for writing to tape coyote:/usr/dlds/tgzs 110k dump done (3:48:00), process terminated while waiting for writing to tape coyote:/usr/include 0 4349k dump done (3:42:57), process terminated while waiting for writing to tape coyote:/usr/lib 0666070k dump done (3:41:53), process terminated while waiting for writing to tape coyote:/usr/libexec 1 4k dump done (3:48:15), process terminated while waiting for writing to tape coyote:/usr/local 1 19114k dump done (3:43:22), process terminated while waiting for writing to tape coyote:/usr/movies140k dump done (3:43:54), process terminated while waiting for writing to tape coyote:/usr/music 0103340k dump done (1:55:13), process terminated while waiting for writing to tape coyote:/usr/pix 1 140k dump done (3:43:25), process terminated while waiting for writing to tape coyote:/usr/sbin 0 20424k dump done (3:34:04), process terminated while waiting for writing to tape coyote:/usr/share 1153125k dump done (3:46:09), process terminated while waiting for writing to tape coyote:/usr/src 1 4233k dump done (3:48:00), process terminated while waiting for writing to tape coyote:/var 0 3187338k dump done (2:01:18), process terminated while waiting for writing to tape shop:/etc 120k dump done (1:55:54), process terminated while waiting for writing to tape shop:/home1 768k dump done (1:55:11), process terminated while waiting for writing to tape shop:/usr/lib/amanda 1 2k dump done (1:55:00), process terminated while waiting for writing to tape shop:/usr/local 1 1k dump done (1:55:30), process terminated while waiting for writing to tape shop:/usr/src 1 121k dump done (1:54:45), process terminated while waiting for writing to tape shop:/var/lib/amanda 1 115k dump done (1:55:40), process terminated while waiting for writing to tape And I have 18Gb sitting in /dumps. pclos updated 352 packages last night before amanda was scheduled to run, so I am going to reboot and try a flush, reporting back when I have done that.
Re: 3.2.0svn3411
On Friday, September 17, 2010 09:00:27 pm Jean-Louis Martineau did opine: Big change to the driver and taper was committed yesterday. Can you post the taper debug file and the amdump.1 file. Jean-Louis [...] After changing the group on the whole thing from adm(id=4) to disk(id=6), and manually fixing both the /amandatapes/Dailys/slot linkage and the config/chg-disk-slot file so everything pointed at the correct slot, I did this: [r...@coyote Daily]# su - amanda -c amflush -f -b Daily and it flushed at about 100megs/sec with no output to the cli I ran it from, and sent me a plumb normal looking email. This was the 3.2.0.svn.3341 version. But my script could not do that. Now to see if a subscript that script calls that adds the rest of the config and other data will work. Yes, just fine. What I am getting out of this is that somewhere along the line you have switched from using the 'data' link in the vtapes root directory as a link to the correct vtape to use, and are somehow using the data in chg-disk- slot instead. But no, that cannot be right, I just ran amcheck, it reported: Searching for label 'Dailys-21':found in slot 21: volume 'Dailys-21' Will write to volume 'Dailys-21' in slot 21. But both the 'data' link, and the chg-disk-slot file still say 20. At this point I have a WTH expression on my ancient face. Go read changelog if all else fails. I see a lot of changes on about 08/29-30-31 but no mention of chg-disk-slot? -- Cheers, Gene There are four boxes to be used in defense of liberty: soap, ballot, jury, and ammo. Please use in that order. -Ed Howdershelt (Author) Great Moments in History: #3 August 27, 1949: A Hall of Fame opened to honor outstanding members of the Women's Air Corp. It was a WAC's Museum.
