Re: 3.2.0svn3411

2010-09-19 Thread Gene Heskett
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: Not found in archive with Fedora's tar?

2010-09-19 Thread Albrecht Dreß

Am 16.09.10 19:52 schrieb(en) Dustin J. Mitchell:

On Thu, Sep 16, 2010 at 12:13 PM, Albrecht Dreß albrecht.dr...@arcor.de wrote:

Does anyone know about the reason (and maybe a workaround) for this issue, or 
is this something for Fedora support?  I don't have a Fedora box, but of course 
this might also be caused by either the Ubuntu libs and/or be a 64-bit problem. 
 Any insight would be highly appreciated!


I don't know much about the various tar formats, but I do know that GNU tar 
supports a few variants, some of which work better with very long filenames 
than others.


It looks a if this behaviour is a bug - see 
https://bugzilla.redhat.com/show_bug.cgi?id=634866.

Thanks, Albrecht.


pgpAm8ZvD6ZsB.pgp
Description: PGP signature


Re: 3.2.0svn3411

2010-09-19 Thread Dustin J. Mitchell
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: My 3.1.2 server starts ok, but taper never writes anything

2010-09-19 Thread Stephen Corbesero

The saga continues.

I changed my debugging statements to the Amanda::Debug::debug method
as your suggested, so my messages are the SGC:'s in the taper debug
log file below.  I also added some of these debug calls to the
Amanda::Taper::Scribe routines, but I don't see much more information.

It still seems to hang right after the message about the 'Final
linkage'.  That is coming from the link_elements() subroutine in
xfer-src/xfer.c.

I am not sure what to do next to get more evidence.






Sep 19 11:49:19 2010: taper: pid 3545 ruid 601 euid 601 version 3.1.2: rename 
at Sun Sep 19 11:49:19 2010
Sun Sep 19 11:49:19 2010: taper: SGC: main::Controller::new()

Sun Sep 19 11:49:19 2010: taper: SGC: main::Controller::start()

Sun Sep 19 11:49:19 2010: taper: SGC: main::Controller::_assert_in_state(init)

Sun Sep 19 11:49:19 2010: taper: Amanda::Changer::compat initialized with 
script /usr/local/libexec/amanda/chg-disk, temporary directory 
/usr/local/etc/amanda/daily
Sun Sep 19 11:49:19 2010: taper: SGC: Amanda::Taper::Scribe::new()

Sun Sep 19 11:49:19 2010: taper: SGC: Amanda::Taper::Scribe::Dev_Handling::new()

Sun Sep 19 11:49:19 2010: taper: driver/taper  START-TAPER 20100919114917
Sun Sep 19 11:49:19 2010: taper: SGC: main::Controller::_assert_in_state(init)

Sun Sep 19 11:49:19 2010: taper: SGC: Amanda::Taper::Scribe::start()

Sun Sep 19 11:49:19 2010: taper: Amanda::Taper::Scribe: starting
Sun Sep 19 11:49:19 2010: taper: SGC: 
Amanda::Taper::Scribe::Dev_Handling::start()

Sun Sep 19 11:49:19 2010: taper: SGC: 
Amanda::Taper::Scribe::Dev_Handling::_start_scanning()

Sun Sep 19 11:49:19 2010: taper: Amanda::Taper::Scan::traditional stage 1: 
search for oldest reusable volume
Sun Sep 19 11:49:19 2010: taper: Amanda::Taper::Scan::traditional no oldest 
reusable volume
Sun Sep 19 11:49:19 2010: taper: Amanda::Taper::Scan::traditional stage 2: scan 
for any reusable volume
Sun Sep 19 11:49:19 2010: taper: Amanda::Changer::compat: invoking 
/usr/local/libexec/amanda/chg-disk with -info
Sun Sep 19 11:49:21 2010: taper: Amanda::Changer::compat: Got response '1 12 1' 
with exit status 0
Sun Sep 19 11:49:21 2010: taper: Amanda::Changer::compat: invoking 
/usr/local/libexec/amanda/chg-disk with -slot current
Sun Sep 19 11:49:22 2010: taper: Amanda::Changer::compat: Got response '1 
file:/amanda/vtl/daily' with exit status 0
Sun Sep 19 11:49:22 2010: taper: Amanda::Taper::Scan::traditional result: 
'DAILY-1' on file:/amanda/vtl/daily slot 1, mode 2
Sun Sep 19 11:49:22 2010: taper: SGC: 
Amanda::Taper::Scribe::Dev_Handling::_maybe_callback()

Sun Sep 19 11:49:22 2010: taper: SGC: main::Controller::_scribe_started_cb()

Sun Sep 19 11:49:22 2010: taper: driver/taper  TAPER-OK
Sun Sep 19 11:50:12 2010: taper: driver/taper  FILE-WRITE 00-2 
/amanda/holding-b/20100919114917/galadriel.corbesero.net._.2 
galadriel.corbesero.net / 2 20100919114917 0 130875
Sun Sep 19 11:50:12 2010: taper: SGC: main::Controller::_assert_in_state(idle)

Sun Sep 19 11:50:12 2010: taper: SGC: main::Controller::setup_and_start_dump()

Sun Sep 19 11:50:12 2010: taper: SGC: main::Controller::_assert_in_state(idle)

Sun Sep 19 11:50:12 2010: taper: SGC: main::Controller::get_splitting_config()

Sun Sep 19 11:50:12 2010: taper: warning: Use of uninitialized value 
$params{data_path} in string eq at /usr/local/libexec/amanda/taper line 606.

Sun Sep 19 11:50:12 2010: taper: SGC: Amanda::Taper::Scribe::get_xfer_dest()

Sun Sep 19 11:50:12 2010: taper: Amanda::Taper::Scribe: 
get_xfer_dest(split_method=none)
Sun Sep 19 11:50:12 2010: taper: Amanda::Taper::Scribe setting up a transfer 
with split method none
Sun Sep 19 11:50:12 2010: taper: SGC: Amanda::Taper::Scribe::get_device()

Sun Sep 19 11:50:12 2010: taper: SGC: 
Amanda::Taper::Scribe::Dev_Handling::peek_device() - 
Amanda::Device::Device=HASH(0x29f7c71c)

Sun Sep 19 11:50:12 2010: taper: XDT thd-0x298ecf70: using slab_size 32768 and 
max_slabs 2
Sun Sep 19 11:50:12 2010: taper: Starting x...@0x29f178e0 
(xfersourcehold...@0x284cac00 - xferdesttapersplit...@0x29a37820)
Sun Sep 19 11:50:12 2010: taper: Final linkage: xfersourcehold...@0x284cac00 
-(PULL_BUFFER)- xferelementg...@0x29a38038 -(PUSH_BUFFER)- 
xferdesttapersplit...@0x29a37820





On Sat, Sep 18, 2010 at 04:43:53PM -0500, Dustin J. Mitchell wrote:
 On Sat, Sep 18, 2010 at 4:17 PM, Stephen Corbesero corbes...@ptd.net wrote:
  Also, if it is worth anything, the state of the process is listed as
  'umtxn' from top/ps.  (This is a FreeBSD 8.1 system.)
 
 Huh, so that sounds like a kernel lock:
   http://old.nabble.com/what-is-umtxn-td20860047.html
 
 Can you identify further the last few lines of perl executed?  You
 should use Amanda::Debug::debug instead, so that your logging will be
 intermixed with the other information from taper_debug, in the taper
 debug log.  You mentioned that you enabled taper_debug, but never sent
 along the debug log - can you do that now?
 



-- 
Stephen CorbeseroIt's 

Re: My 3.1.2 server starts ok, but taper never writes anything

2010-09-19 Thread Dustin J. Mitchell
On Sun, Sep 19, 2010 at 11:16 AM, Stephen Corbesero corbes...@ptd.net wrote:
 It still seems to hang right after the message about the 'Final
 linkage'.  That is coming from the link_elements() subroutine in
 xfer-src/xfer.c.

Which is basically where the threading starts..

 I am not sure what to do next to get more evidence.

Have you checked that libc_r, glib, perl, and Amanda are all compiled
with the same threading library?  John Hein dug up a thread from when
we tried to work this out back in March:

  http://lists.freebsd.org/pipermail/freebsd-perl/2010-March/002511.html

the thread went un-answered at the time.  The solution we found was to
build a threaded perl, using the same underlying threading library
that everything else is built against.  If I recall, John ended up
doing a *lot* of custom builds for this.  I'm not sure what the
right solution is here.

Dustin

-- 
Open Source Storage Engineer
http://www.zmanda.com



Re: My 3.1.2 server starts ok, but taper never writes anything

2010-09-19 Thread Stephen Corbesero

That did it Or may have done it.

I upgraded my FreeBSD sources to the latest 8.x stable and recompiled
the world (and kernel).  I then compiled and installed Perl-5.10.1 for
my FreeBSD by hand, specifically enabling its threaded option.
Finally, I recompiled and reinstalled Amanda 3.1.2.

I made a single virtual tape disk and tested the new configuration.
The taper process was accumulating run time in that configuration and
the single file system was backed up and transferred to 'tape'.  :)

I re-enabled my virtual tape configuration and the chg-disk changer,
and as I type this, I am flushing all the backup files that have been
accumulating from my tests over the last week. That appears to be
working as well.

Thank you.



On Sun, Sep 19, 2010 at 11:58:04AM -0500, Dustin J. Mitchell wrote:
 On Sun, Sep 19, 2010 at 11:16 AM, Stephen Corbesero corbes...@ptd.net wrote:
  It still seems to hang right after the message about the 'Final
  linkage'.  That is coming from the link_elements() subroutine in
  xfer-src/xfer.c.
 
 Which is basically where the threading starts..
 
  I am not sure what to do next to get more evidence.
 
 Have you checked that libc_r, glib, perl, and Amanda are all compiled
 with the same threading library?  John Hein dug up a thread from when
 we tried to work this out back in March:
 
   http://lists.freebsd.org/pipermail/freebsd-perl/2010-March/002511.html
 
 the thread went un-answered at the time.  The solution we found was to
 build a threaded perl, using the same underlying threading library
 that everything else is built against.  If I recall, John ended up
 doing a *lot* of custom builds for this.  I'm not sure what the
 right solution is here.
 
 Dustin
 
 -- 
 Open Source Storage Engineer
 http://www.zmanda.com
 

-- 
Stephen CorbeseroIt's always darkest 
Bethlehem, PA 18015  before pitch black.
corbes...@ptd.net


Re: My 3.1.2 server starts ok, but taper never writes anything

2010-09-19 Thread Dustin J. Mitchell
On Sun, Sep 19, 2010 at 4:48 PM, Stephen Corbesero corbes...@ptd.net wrote:
 I upgraded my FreeBSD sources to the latest 8.x stable and recompiled
 the world (and kernel).  I then compiled and installed Perl-5.10.1 for
 my FreeBSD by hand, specifically enabling its threaded option.
 Finally, I recompiled and reinstalled Amanda 3.1.2.

I'm glad it worked!

There's some info at
  
http://wiki.zmanda.com/index.php/Installation/OS_Specific_Notes/Installing_Amanda_on_FreeBSD

which apparently could use some additional information.  Can you fill
in what you know there, to help the next guy?

Dustin

-- 
Open Source Storage Engineer
http://www.zmanda.com



Re: 3.2.0svn3411

2010-09-19 Thread Gene Heskett
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

2010-09-19 Thread Dustin J. Mitchell
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

2010-09-19 Thread Gene Heskett
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: Nitpick: Enterprise features

2010-09-19 Thread Dustin J. Mitchell
On Thu, Sep 9, 2010 at 9:24 PM, Dustin J. Mitchell dus...@zmanda.com wrote:
 So I'm invoking my that's complicated escape clause.  The only one
 of these that I could conceivably accomplish in the 3.2 timeframe is
 #2.  I could add 'amadmin $conf hosts' to list all of the hosts,
 avoiding the need to grep the multiline output of 'amadmin $conf
 disklist'.  I'll put that in my queue right behind Chris H's
 suggestion (with which I'm almost finished).

And I've done this now.  Please have a look at:
  http://github.com/djmitche/amanda/commit/z11906
and let me know if you think this will meet your needs.

Dustin

-- 
Open Source Storage Engineer
http://www.zmanda.com



Re: 3.2.0svn3411

2010-09-19 Thread Dustin J. Mitchell
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

2010-09-19 Thread Gene Heskett
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: My 3.1.2 server starts ok, but taper never writes anything

2010-09-19 Thread Dustin J. Mitchell
On Sun, Sep 19, 2010 at 11:05 PM, John Hein jh...@symmetricom.com wrote:
 (Currently, I
 don't think the amanda client executes threaded code, but that may
 change in the future - or may have already in 3.1/3.2 code - Dustin?).

There is now a good bit of Perl running on the client side, but none
of it uses threads.  We haven't foresworn threads on the client,
though, so I would expect that to change eventually.

At some point, there were a few folks thinking about branching an
older version of Amanda like 2.5.2 to create a maintained minimal
client that could be installed quite widely, even if it didn't
support fancy features like the Application API.  I'm not sure what
happened to that particular project, but it could be a way around
problems with increasing client-side requirements.

Dustin

-- 
Open Source Storage Engineer
http://www.zmanda.com