Results 1 to 3 of 3

Thread: amrecover: Error locking '/etc/amanda/monetra/changer'

  1. #1

    Default amrecover: Error locking '/etc/amanda/monetra/changer'

    Hello, I'm running amanda-server as well as amanda-client 3.3.3 on CentOS 7 and backups seem to be working fine.
    Now I'm testing the recovery side of things and running into this problem when trying an amrecover as root from the client:

    [[email protected] recovered]# amrecover
    AMRECOVER Version 3.3.3. Contacting server on amanda-server ...
    220 amanda-server AMANDA index server (3.3.3) ready.
    Setting restore date to today (2015-05-18)
    200 Working date set to 2015-05-18.
    200 Config set to monetra.
    200 Dump host set to amanda-client.
    Use the setdisk command to choose dump disk to recover
    amrecover> setdisk /etc
    200 Disk set to /etc.
    amrecover> ls
    2015-05-18-12-44-16 yum/
    ... truncated
    amrecover> add hosts
    Added file /hosts
    amrecover> extract

    Extracting files using tape drive changer on host amanda-server.
    The following tapes are needed: Tape-01

    Extracting files using tape drive changer on host amanda-server.
    Load tape Tape-01 now
    Continue [?/Y/n/s/d]? y
    Error locking '/etc/amanda/monetra/changer'
    Got no header and data from server, check in amidxtaped.*.debug and amandad.*.debug files on server
    amrecover> quit


    ----------------------------------------------------------
    The amidxtaped.debug file is here:
    -bash-4.2$ more amidxtaped.20150518125958.debug
    Mon May 18 12:59:58 2015: thd-0x1e26600: amidxtaped: pid 23757 ruid 33 euid 33 version 3.3.3: start at Mon May 18 12:59:58 2015
    Mon May 18 12:59:58 2015: thd-0x1e26600: amidxtaped: CTL << FEATURES=ffffffff9efefbffffffffff1f
    Mon May 18 12:59:58 2015: thd-0x1e26600: amidxtaped: CTL << CONFIG=monetra
    Mon May 18 12:59:58 2015: thd-0x1e26600: amidxtaped: CTL << LABEL=Tape-01:2
    Mon May 18 12:59:58 2015: thd-0x1e26600: amidxtaped: CTL << FSF=2
    Mon May 18 12:59:58 2015: thd-0x1e26600: amidxtaped: CTL << HEADER
    Mon May 18 12:59:58 2015: thd-0x1e26600: amidxtaped: CTL << DEVICE=changer
    Mon May 18 12:59:58 2015: thd-0x1e26600: amidxtaped: CTL << HOST=^amanda-client$
    Mon May 18 12:59:58 2015: thd-0x1e26600: amidxtaped: CTL << DISK=^/etc$
    Mon May 18 12:59:58 2015: thd-0x1e26600: amidxtaped: CTL << DATESTAMP=20150518124416
    Mon May 18 12:59:58 2015: thd-0x1e26600: amidxtaped: CTL << END
    Mon May 18 12:59:58 2015: thd-0x1e26600: amidxtaped: pid 23757 ruid 33 euid 33 version 3.3.3: rename at Mon May 18 12:59:58 2015
    Mon May 18 12:59:58 2015: thd-0x1e26600: amidxtaped: new Amanda::Changer::Error: type='fatal', message='Error locking '/etc/amanda/monetra/change
    r''
    Mon May 18 12:59:58 2015: thd-0x1e26600: amidxtaped: Amanda::Recovery::Clerk: loading volume 'Tape-01'
    Mon May 18 12:59:58 2015: thd-0x1e26600: amidxtaped: find_volume labeled 'Tape-01'
    Mon May 18 12:59:58 2015: thd-0x1e26600: amidxtaped: ignoring spurious Amanda::Recovery::Scan abort call
    Mon May 18 12:59:58 2015: thd-0x1e26600: amidxtaped: CTL >> MESSAGE Error locking '/etc/amanda/monetra/changer'
    Mon May 18 12:59:58 2015: thd-0x1e26600: amidxtaped: exiting with 0
    Mon May 18 12:59:58 2015: thd-0x1e26600: amidxtaped: pid 23757 finish time Mon May 18 12:59:58 2015

    --------------------------------------------------------------------------
    The amindexd file is even less useful, but here it is:
    -bash-4.2$ more amindexd.20150518125816.debug
    Mon May 18 12:58:16 2015: thd-0x7f38d6b8f200: amindexd: pid 23752 ruid 33 euid 33 version 3.3.3: start at Mon May 18 12:58:16 2015
    Mon May 18 12:58:16 2015: thd-0x7f38d6b8f200: amindexd: version 3.3.3
    Mon May 18 12:58:16 2015: thd-0x7f38d6b8f200: amindexd: < 220 amanda-server AMANDA index server (3.3.3) ready.
    Mon May 18 12:58:16 2015: thd-0x7f38d6b8f200: amindexd: > FEATURES ffffffff9efefbffffffffff1f
    Mon May 18 12:58:16 2015: thd-0x7f38d6b8f200: amindexd: < 200 FEATURES ffffffff9efefbffffffffff1f
    Mon May 18 12:58:16 2015: thd-0x7f38d6b8f200: amindexd: > DATE 2015-05-18
    Mon May 18 12:58:16 2015: thd-0x7f38d6b8f200: amindexd: < 200 Working date set to 2015-05-18.
    Mon May 18 12:58:16 2015: thd-0x7f38d6b8f200: amindexd: > SCNF monetra
    Mon May 18 12:58:16 2015: thd-0x7f38d6b8f200: amindexd: pid 23752 ruid 33 euid 33 version 3.3.3: rename at Mon May 18 12:58:16 2015
    Mon May 18 12:58:16 2015: thd-0x7f38d6b8f200: amindexd: < 200 Config set to monetra.
    Mon May 18 12:58:16 2015: thd-0x7f38d6b8f200: amindexd: > HOST amanda-client
    Mon May 18 12:58:16 2015: thd-0x7f38d6b8f200: amindexd: < 200 Dump host set to amanda-client.
    Mon May 18 12:58:32 2015: thd-0x7f38d6b8f200: amindexd: > DISK /etc
    Mon May 18 12:58:32 2015: thd-0x7f38d6b8f200: amindexd: no recovery limit found; allowing access
    Mon May 18 12:58:32 2015: thd-0x7f38d6b8f200: amindexd: append_to_tapelist(tapelist=(nil), label='Tape-01', file=2, partnum=1, isafile=0)
    Mon May 18 12:58:32 2015: thd-0x7f38d6b8f200: amindexd: - 2015-05-18-12-44-16 0 Tape-01 2 1 1
    Mon May 18 12:58:32 2015: thd-0x7f38d6b8f200: amindexd: < 200 Disk set to /etc.
    Mon May 18 12:58:32 2015: thd-0x7f38d6b8f200: amindexd: > OISD /
    Mon May 18 12:58:32 2015: thd-0x7f38d6b8f200: amindexd: Spawning "/usr/bin/gzip /usr/bin/gzip -dc /etc/amanda/state/index/amanda-client/_etc/2015
    0518124416_0.gz" in pipeline
    Mon May 18 12:58:32 2015: thd-0x7f38d6b8f200: amindexd: Spawning "/usr/bin/sort /usr/bin/sort" in pipeline
    Mon May 18 12:58:32 2015: thd-0x7f38d6b8f200: amindexd: f /etc/amanda/state/index/amanda-client/_etc/20150518124416_0
    Mon May 18 12:58:32 2015: thd-0x7f38d6b8f200: amindexd: < 200 "/" is a valid directory
    Mon May 18 12:58:32 2015: thd-0x7f38d6b8f200: amindexd: > OLSD /
    Mon May 18 12:58:32 2015: thd-0x7f38d6b8f200: amindexd: < 200- Opaque list of /
    Mon May 18 12:58:32 2015: thd-0x7f38d6b8f200: amindexd: < 200 Opaque list of /
    Mon May 18 12:58:32 2015: thd-0x7f38d6b8f200: amindexd: > DLE
    Mon May 18 12:58:32 2015: thd-0x7f38d6b8f200: amindexd: < 200 "<dle>\n <program>GNUTAR</program>\n <disk>/etc</disk>\n <auth>BSDTCP</auth>\n
    <compress>FAST</compress>\n <record>YES</record>\n <index>YES</index>\n <datapath>AMANDA</datapath>\n</dle>\n"
    Mon May 18 12:59:57 2015: thd-0x7f38d6b8f200: amindexd: > TAPE
    Mon May 18 12:59:57 2015: thd-0x7f38d6b8f200: amindexd: tapedev_is amrecover_changer: changer
    Mon May 18 12:59:57 2015: thd-0x7f38d6b8f200: amindexd: < 200 changer
    Mon May 18 13:00:22 2015: thd-0x7f38d6b8f200: amindexd: > QUIT
    Mon May 18 13:00:22 2015: thd-0x7f38d6b8f200: amindexd: removing index file: /etc/amanda/state/index/amanda-client/_etc/20150518124416_0
    Mon May 18 13:00:22 2015: thd-0x7f38d6b8f200: amindexd: < 200 Good bye.
    Mon May 18 13:00:22 2015: thd-0x7f38d6b8f200: amindexd: pid 23752 finish time Mon May 18 13:00:22 2015


    ----------------------------------------------------------------------------------
    And just for fun, here is the amandad.debug file:
    -bash-4.2$ more amandad.20150518125816.debug
    Mon May 18 12:58:16 2015: thd-0x7f8c7dacd200: amandad: pid 23751 ruid 33 euid 33 version 3.3.3: start at Mon May 18 12:58:16 2015
    Mon May 18 12:58:16 2015: thd-0x7f8c7dacd200: amandad: security_getdriver(name=bsdtcp) returns 0x7f8c7d3167e0
    Mon May 18 12:58:16 2015: thd-0x7f8c7dacd200: amandad: version 3.3.3
    Mon May 18 12:58:16 2015: thd-0x7f8c7dacd200: amandad: build: VERSION="Amanda-3.3.3"
    Mon May 18 12:58:16 2015: thd-0x7f8c7dacd200: amandad: BUILT_DATE="Tue Jun 10 01:33:40 UTC 2014" BUILT_MACH=""
    Mon May 18 12:58:16 2015: thd-0x7f8c7dacd200: amandad: BUILT_REV="5099" BUILT_BRANCH="community_3_3_3" CC="gcc"
    Mon May 18 12:58:16 2015: thd-0x7f8c7dacd200: amandad: paths: bindir="/usr/bin" sbindir="/usr/sbin"
    Mon May 18 12:58:16 2015: thd-0x7f8c7dacd200: amandad: libexecdir="/usr/lib64" amlibexecdir="/usr/lib64/amanda"
    Mon May 18 12:58:16 2015: thd-0x7f8c7dacd200: amandad: mandir="/usr/share/man" AMANDA_TMPDIR="/var/log/amanda"
    Mon May 18 12:58:16 2015: thd-0x7f8c7dacd200: amandad: AMANDA_DBGDIR="/var/log/amanda" CONFIG_DIR="/etc/amanda"
    Mon May 18 12:58:16 2015: thd-0x7f8c7dacd200: amandad: DEV_PREFIX="/dev/" RDEV_PREFIX="/dev/" DUMP=UNDEF
    Mon May 18 12:58:16 2015: thd-0x7f8c7dacd200: amandad: RESTORE=UNDEF VDUMP=UNDEF VRESTORE=UNDEF XFSDUMP=UNDEF
    Mon May 18 12:58:16 2015: thd-0x7f8c7dacd200: amandad: XFSRESTORE=UNDEF VXDUMP=UNDEF VXRESTORE=UNDEF
    Mon May 18 12:58:16 2015: thd-0x7f8c7dacd200: amandad: SAMBA_CLIENT="/usr/bin/smbclient" GNUTAR="/bin/tar"
    Mon May 18 12:58:16 2015: thd-0x7f8c7dacd200: amandad: COMPRESS_PATH="/usr/bin/gzip"
    Mon May 18 12:58:16 2015: thd-0x7f8c7dacd200: amandad: UNCOMPRESS_PATH="/usr/bin/gzip" LPRCMD=UNDEF MAILER=UNDEF
    Mon May 18 12:58:16 2015: thd-0x7f8c7dacd200: amandad: listed_incr_dir="/var/lib/amanda/gnutar-lists"
    Mon May 18 12:58:16 2015: thd-0x7f8c7dacd200: amandad: defs: DEFAULT_SERVER="amandahost" DEFAULT_CONFIG="DailySet1"
    Mon May 18 12:58:16 2015: thd-0x7f8c7dacd200: amandad: DEFAULT_TAPE_SERVER="amandahost" DEFAULT_TAPE_DEVICE=""
    Mon May 18 12:58:16 2015: thd-0x7f8c7dacd200: amandad: NEED_STRSTR AMFLOCK_POSIX AMFLOCK_FLOCK AMFLOCK_LOCKF
    Mon May 18 12:58:16 2015: thd-0x7f8c7dacd200: amandad: AMFLOCK_LNLOCK SETPGRP_VOID AMANDA_DEBUG_DAYS=4 BSD_SECURITY
    Mon May 18 12:58:16 2015: thd-0x7f8c7dacd200: amandad: KRB5_SECURITY RSH_SECURITY USE_AMANDAHOSTS
    Mon May 18 12:58:16 2015: thd-0x7f8c7dacd200: amandad: CLIENT_LOGIN="amandabackup" CHECK_USERID HAVE_GZIP
    Mon May 18 12:58:16 2015: thd-0x7f8c7dacd200: amandad: COMPRESS_SUFFIX=".gz" COMPRESS_FAST_OPT="--fast"
    Mon May 18 12:58:16 2015: thd-0x7f8c7dacd200: amandad: COMPRESS_BEST_OPT="--best" UNCOMPRESS_OPT="-dc"
    Mon May 18 12:58:16 2015: thd-0x7f8c7dacd200: amandad: security_handleinit(handle=0x7f8c7dad76d0, driver=0x7f8c7d3167e0 (BSDTCP))
    Mon May 18 12:58:16 2015: thd-0x7f8c7dacd200: amandad: security_streaminit(stream=0x7f8c7dad77e0, driver=0x7f8c7d3167e0 (BSDTCP))
    Mon May 18 12:58:16 2015: thd-0x7f8c7dacd200: amandad: authenticated peer name is 'amanda-client'
    Mon May 18 12:58:16 2015: thd-0x7f8c7dacd200: amandad: accept recv REQ pkt:
    <<<<<
    SERVICE amindexd
    OPTIONS features=ffffffff9efefbffffffffff1f;auth=bsdtcp;
    >>>>>
    Mon May 18 12:58:16 2015: thd-0x7f8c7dacd200: amandad: creating new service: amindexd
    OPTIONS features=ffffffff9efefbffffffffff1f;auth=bsdtcp;

    Mon May 18 12:58:16 2015: thd-0x7f8c7dacd200: amandad: sending ACK pkt:
    <<<<<
    >>>>>
    Mon May 18 12:58:16 2015: thd-0x7f8c7dacd200: amandad: tcpm_send_token: data is still flowing
    Mon May 18 12:58:16 2015: thd-0x7f8c7dacd200: amandad: security_streaminit(stream=0x7f8c7daf05d0, driver=0x7f8c7d3167e0 (BSDTCP))
    Mon May 18 12:58:16 2015: thd-0x7f8c7dacd200: amandad: sending REP pkt:
    <<<<<
    CONNECT MESG 499999

    >>>>>
    Mon May 18 12:58:16 2015: thd-0x7f8c7dacd200: amandad: received ACK pkt:
    <<<<<
    >>>>>
    Mon May 18 12:58:16 2015: thd-0x7f8c7dacd200: amandad: opening security stream for fd 50
    Mon May 18 12:58:16 2015: thd-0x7f8c7dacd200: amandad: security_close(handle=0x7f8c7dad76d0, driver=0x7f8c7d3167e0 (BSDTCP))
    Mon May 18 12:58:16 2015: thd-0x7f8c7dacd200: amandad: security_stream_close(0x7f8c7dad77e0)
    Mon May 18 12:58:32 2015: thd-0x7f8c7dacd200: amandad: stream_read_callback: data is still flowing
    Mon May 18 12:59:57 2015: thd-0x7f8c7dacd200: amandad: stream_read_callback: data is still flowing
    Mon May 18 12:59:58 2015: thd-0x7f8c7dacd200: amandad: security_handleinit(handle=0x7f8c7dad76d0, driver=0x7f8c7d3167e0 (BSDTCP))
    Mon May 18 12:59:58 2015: thd-0x7f8c7dacd200: amandad: security_streaminit(stream=0x7f8c7dad77e0, driver=0x7f8c7d3167e0 (BSDTCP))
    Mon May 18 12:59:58 2015: thd-0x7f8c7dacd200: amandad: authenticated peer name is 'amanda-client'
    Mon May 18 12:59:58 2015: thd-0x7f8c7dacd200: amandad: accept recv REQ pkt:
    <<<<<
    SERVICE amidxtaped
    OPTIONS features=ffffffff9efefbffffffffff1f;auth=bsdtcp;
    >>>>>
    Mon May 18 12:59:58 2015: thd-0x7f8c7dacd200: amandad: creating new service: amidxtaped
    OPTIONS features=ffffffff9efefbffffffffff1f;auth=bsdtcp;

    Mon May 18 12:59:58 2015: thd-0x7f8c7dacd200: amandad: sending ACK pkt:
    <<<<<
    >>>>>
    Mon May 18 12:59:58 2015: thd-0x7f8c7dacd200: amandad: security_streaminit(stream=0x7f8c7db08b70, driver=0x7f8c7d3167e0 (BSDTCP))
    Mon May 18 12:59:58 2015: thd-0x7f8c7dacd200: amandad: security_streaminit(stream=0x7f8c7db10bd0, driver=0x7f8c7d3167e0 (BSDTCP))
    Mon May 18 12:59:58 2015: thd-0x7f8c7dacd200: amandad: sending REP pkt:
    <<<<<
    CONNECT CTL 499998 DATA 499997

    >>>>>
    Mon May 18 12:59:58 2015: thd-0x7f8c7dacd200: amandad: received ACK pkt:
    <<<<<
    >>>>>
    Mon May 18 12:59:58 2015: thd-0x7f8c7dacd200: amandad: opening security stream for fd 50
    Mon May 18 12:59:58 2015: thd-0x7f8c7dacd200: amandad: opening security stream for fd 51
    Mon May 18 12:59:58 2015: thd-0x7f8c7dacd200: amandad: security_close(handle=0x7f8c7dad76d0, driver=0x7f8c7d3167e0 (BSDTCP))
    Mon May 18 12:59:58 2015: thd-0x7f8c7dacd200: amandad: security_stream_close(0x7f8c7dad77e0)
    Mon May 18 12:59:58 2015: thd-0x7f8c7dacd200: amandad: security_stream_close(0x7f8c7db10bd0)
    Mon May 18 12:59:58 2015: thd-0x7f8c7dacd200: amandad: security_stream_close(0x7f8c7db08b70)
    Mon May 18 13:00:22 2015: thd-0x7f8c7dacd200: amandad: stream_read_callback: data is still flowing
    Mon May 18 13:00:22 2015: thd-0x7f8c7dacd200: amandad: security_stream_close(0x7f8c7daf05d0)
    Mon May 18 13:00:22 2015: thd-0x7f8c7dacd200: amandad: pid 23751 finish time Mon May 18 13:00:22 2015



    I have looked through the forums and can't find any solutions to this specific problem. Any suggestions on how to proceed getting a recover to work?

    Rob McKennon
    Unix Admin

  2. #2

    Default

    Nevermind, after disabling SE-Linux (setenforce 0) it's working. Now to figure out exactly how to fix it properly!

    Hopefully this will help someone!

    Rob.

  3. #3

    Default

    So, Here's my fix for the se-linux workaround:

    yum -y install policycoreutils-python
    semanage fcontext -a -t amanda_data_t "/etc/amanda/DailySet1(/.*)?"
    restorecon -R -v /etc/amanda/

    # Then I ran into problems with it trying to write to the backup directory:
    # type=AVC msg=audit(1432070862.516:78034): avc: denied { create } for pid=3610 comm="amidxtaped" name="data"
    scontext=system_u:system_r:amanda_t:s0 tcontext=system_ubject_r:amanda_var_lib_t:s0 tclass=lnk_file
    type=SYSCALL msg=audit(1432070862.516:78034): arch=c000003e syscall=88 success=no exit=-13 a0=1759f80 a1=175b7
    40 a2=16fbe80 a3=1 items=0 ppid=3601 pid=3610 auid=4294967295 uid=33 gid=6 euid=33 suid=33 fsuid=33 egid=6 sgi
    d=6 fsgid=6 tty=(none) ses=4294967295 comm="amidxtaped" exe="/usr/bin/perl" subj=system_u:system_r:amanda_t:s0
    key=(null)

    # So I added this:
    # /var/lib/amanda/backup is where my external drive is mounted.

    semanage fcontext -a -t amanda_data_t '/var/lib/amanda/backup(/.*)?'
    restorecon -Rv /var/lib/amanda/backup

    And now all is well in Amanda-Land.

    Well, at least so far...

    Rob.

    p.s. I don't know if this is the most correct way to fix it or not, but it does work.

Posting Permissions

  • You may not post new threads
  • You may not post replies
  • You may not post attachments
  • You may not edit your posts
  •