Page 1 of 2 12 LastLast
Results 1 to 10 of 15

Thread: Segmentation Fault During "Extract"

  1. #1
    Join Date
    Jun 2007
    Posts
    27

    Default Segmentation Fault During "Extract"

    When I run the amrecover command from the client machine and attempt to run "extract", I get a segmentation fault. I don't get any faults during the browsing of files, like some other posts have implied.

    Below is the only log file I could find that had changed since the last extract failure. It was found in /tmp/amanda/client/DailySet1/. Sorry, it's lengthy...

    >>
    amrecover: debug 1 pid 6127 ruid 0 euid 0: start at Thu Jun 14 09:44:04 2007
    Reading conf file "/etc/amanda/amanda-client.conf".
    Could not open conf file "/etc/amanda/DailySet1/amanda-client.conf": No such file or directory
    amrecover: debug 1 pid 6127 ruid 0 euid 0: rename at Thu Jun 14 09:44:04 2007
    security_getdriver(name=bsdtcp) returns 0x996140
    security_handleinit(handle=0x9078530, driver=0x996140 (BSDTCP))
    security_streaminit(stream=0x9079188, driver=0x996140 (BSDTCP))
    amrecover: connect_port: Skip port 512: Owned by exec.
    amrecover: connect_port: Skip port 513: Owned by login.
    amrecover: connect_port: Skip port 514: Owned by shell.
    amrecover: connect_port: Skip port 515: Owned by printer.
    amrecover: connect_port: Try port 516: Available -
    amrecover: connected to 192.168.100.228.10080
    amrecover: our side is 0.0.0.0.516
    amrecover: try_socksize: send buffer size is 65536
    amrecover: try_socksize: receive buffer size is 65536
    security_streaminit(stream=0x90822e8, driver=0x996140 (BSDTCP))
    security_close(handle=0x9078530, driver=0x996140 (BSDTCP))
    security_stream_close(0x9079188)
    add_dir_list_item: Adding "2007-06-13-08-54-08" "0" "DailySet1-02:1" "1" "/.bash_logout"
    add_dir_list_item: Adding "2007-06-13-08-54-08" "0" "DailySet1-02:1" "1" "/.bash_profile"
    add_dir_list_item: Adding "2007-06-13-08-54-08" "0" "DailySet1-02:1" "1" "/.bashrc"
    add_dir_list_item: Adding "2007-06-13-08-54-08" "0" "DailySet1-02:1" "1" "/.emacs"
    add_dir_list_item: Adding "2007-06-13-08-54-08" "0" "DailySet1-02:1" "1" "/.gtkrc"
    add_dir_list_item: Adding "2007-06-14-09-44-19" "2" "DailySet1-10:1" "1" "/."
    add_dir_list_item: Adding "2007-06-14-09-44-19" "2" "DailySet1-10:1" "1" "/.am_passphrase"
    add_dir_list_item: Adding "2007-06-14-09-44-19" "2" "DailySet1-10:1" "1" "/.bash_history"
    add_dir_list_item: Adding "2007-06-14-09-44-19" "2" "DailySet1-10:1" "1" "/.ssh/"
    add_dir_list_item: Adding "2007-06-14-09-44-19" "2" "DailySet1-10:1" "1" "/amrecover.20070614091529.debug"
    add_dir_list_item: Adding "2007-06-14-09-44-19" "2" "DailySet1-10:1" "1" "/disk"
    add_dir_list_item: Adding "2007-06-14-09-44-19" "2" "DailySet1-10:1" "1" "/testfile2.txt"
    add_glob (testfile2.txt) -> ^testfile2\.txt$
    add_file: Looking for "testfile2\.txt[/]*$"
    add_file: Converted path="testfile2\.txt[/]*$" to path_on_disk="/testfile2\.txt[/]*$"
    add_file: Pondering ditem->path=/testfile2.txt
    add_file: (Successful) Added /testfile2.txt
    add_file: Pondering ditem->path=/disk
    add_file: Pondering ditem->path=/amrecover.20070614091529.debug
    add_file: Pondering ditem->path=/.ssh/
    add_file: Pondering ditem->path=/.bash_history
    add_file: Pondering ditem->path=/.am_passphrase
    add_file: Pondering ditem->path=/.
    add_file: Pondering ditem->path=/.gtkrc
    add_file: Pondering ditem->path=/.emacs
    add_file: Pondering ditem->path=/.bashrc
    add_file: Pondering ditem->path=/.bash_profile
    add_file: Pondering ditem->path=/.bash_logout
    append_to_tapelist(tapelist=(nil), label='DailySet1-10', , file=-1, isafile=0)
    dump_tapelist(0x90788d8):
    0x90788d8->next = (nil)
    0x90788d8->label = DailySet1-10
    0x90788d8->isafile = 0
    0x90788d8->numfiles = 0
    0x90788d8 count = 1
    append_to_tapelist(tapelist=0x90788d8, label='DailySet1-10', , file=1, isafile=0)
    dump_tapelist(0x90788d8):
    0x90788d8->next = (nil)
    0x90788d8->label = DailySet1-10
    0x90788d8->isafile = 0
    0x90788d8->numfiles = 1
    0x90788d8->files[0] = 1
    0x90788d8 count = 1
    append_to_tapelist(tapelist=(nil), label='DailySet1-10', , file=-1, isafile=0)
    dump_tapelist(0x90788c0):
    0x90788c0->next = (nil)
    0x90788c0->label = DailySet1-10
    0x90788c0->isafile = 0
    0x90788c0->numfiles = 0
    0x90788c0 count = 1
    security_getdriver(name=bsdtcp) returns 0x996140
    security_handleinit(handle=0x9079990, driver=0x996140 (BSDTCP))
    security_seterror(handle=0x9079990, driver=0x996140 (BSDTCP) error=DailySet1-10: could not resolve hostname)
    security_close(handle=0x9079990, driver=0x996140 (BSDTCP))
    security_handleinit(handle=0x9079990, driver=0x996140 (BSDTCP))
    security_seterror(handle=0x9079990, driver=0x996140 (BSDTCP) error=DailySet1-10: could not resolve hostname)
    security_close(handle=0x9079990, driver=0x996140 (BSDTCP))
    security_handleinit(handle=0x9079990, driver=0x996140 (BSDTCP))
    security_seterror(handle=0x9079990, driver=0x996140 (BSDTCP) error=DailySet1-10: could not resolve hostname)
    <<

    The first few lines are interesting, becuase the /etc/amanda/amanda-client.conf file does exist, is owned by amandabackup:disk, and has read and execute permissions for everyone. The last few lines have me baffled. From the client I can ping the IP of the server as well as the hostname and FDQN. It works from the server to the client as well. I even edited the amanda-client.conf to have the IP of the index server instead of the name, but that made no difference. And again, everything up to this point has worked.

    Thanks for any assistance.
    Last edited by ddenton; June 14th, 2007 at 08:06 AM.

  2. #2
    Join Date
    Mar 2007
    Location
    Chicago, IL
    Posts
    688

    Default

    This is actually a known bug, fixed in 2.5.2p1. If you can upgrade, please do so. If not, what are you specifying as the tape to use?

    It looks like you're specifying something like
    DailySet1-10:1
    The colon in there causes the first part of the string to be used as a hostname, which fails, and that caused a segmentation fault in 2.5.2.

    If I'm not clear, please post a transcript of your amrecover session starting with 'extract'.

  3. #3
    Join Date
    Jun 2007
    Posts
    27

    Default

    If I don't specify the tape, then I get the following:

    Load tape DailySet1-10 now
    Continue [?/Y/n/s/t]?
    tar: ./testfile2.txt: Not found in archive
    tar: Error exit delayed from previous errors
    Extractor child exited with status 2

    I was using DailySet1-10:1 in the settape command because this was listed in the history output:

    201- 2007-06-14-09-44-19 2 DailySet1-10:1

    I'd rather not contend with an upgrade right now because it was a 2-week long slog just to get to this point with the current version. If possible, I'd like to get it working and then worry about the upgrade. Below is a transcript of my commands, using the syntax that gives the above error.

    FYI - TESTBED001 is my server, TESTBED002 is my client.

    [root@TESTBED002 amanda]# /usr/sbin/amrecover
    AMRECOVER Version 2.5.1p2. Contacting server on TESTBED001 ...
    220 TESTBED001 AMANDA index server (2.5.1p2) ready.
    Setting restore date to today (2007-06-14)
    200 Working date set to 2007-06-14.
    200 Config set to DailySet1.
    501 Host TESTBED002 is not in your disklist.
    Trying host TESTBED002 ...
    501 Host TESTBED002 is not in your disklist.
    Trying host localhost.localdomain ...
    501 Host localhost.localdomain is not in your disklist.
    Trying host localhost ...
    501 Host localhost is not in your disklist.
    Use the sethost command to choose a host to recover

    <<output snipped>>

    amrecover> extract

    Extracting files using tape drive chg-disk on host TESTBED001.
    The following tapes are needed: DailySet1-10

    Restoring files into directory /etc/amanda
    Continue [?/Y/n]? y

    Extracting files using tape drive chg-disk on host TESTBED001.
    Load tape DailySet1-10 now
    Continue [?/Y/n/s/t]? y
    tar: ./testfile2.txt: Not found in archive
    tar: Error exit delayed from previous errors
    Extractor child exited with status 2
    amrecover>


    I left the beginning of the amrecover command in this post because it doesn't look like it belongs, by specifying the host using sethost afterward seems to work...
    Last edited by ddenton; June 14th, 2007 at 09:47 AM.

  4. #4
    Join Date
    Mar 2007
    Location
    Chicago, IL
    Posts
    688

    Default

    I was using DailySet1-10:1 in the settape command because this was listed in the history output:

    201- 2007-06-14-09-44-19 2 DailySet1-10:1
    OK, that was the segfault problem -- settape should actually be given the tape device (despite the name).

    I'll try to take a look at the new error in a bit.

  5. #5
    Join Date
    Jun 2007
    Posts
    27

    Default

    Could it have to do with the GPG errors in the emails from the amanda server from each amdump?
    I know you said before that they were warnings, but thought I'd ask, just in case.

    ? gpg: failed to create temporary file `/var/lib/amanda/.gnupg/.#lk0xa67188.TESTBED002.6118': No such file or directory ? gpg: keyblock resource `/var/lib/amanda/.gnupg/pubring.gpg': general error
    | Total bytes written: 20480 (20KiB, ?/s)
    ? gpg: can't create `/var/lib/amanda/.gnupg/random_seed': No such file or directory

  6. #6
    Join Date
    Jun 2007
    Posts
    27

    Default

    Dustin,

    Just wondering if you had been able to find anything new about that error?

    No progress here. I keep getting the same error.

  7. #7
    Join Date
    Mar 2007
    Location
    Chicago, IL
    Posts
    688

    Default

    Sorry -- I thought you had figured it out with your second-to-last post. It's very likely your GPG problems are the reason that the dumps aren't complete.

    It looks like the permissions are wrong on your GPG configuration. Check the configuration, look through some of the encryption material on the wiki, and try to run parts of it manually.

  8. #8
    Join Date
    Jun 2007
    Posts
    27

    Default

    Ok, not getting the strange GPG errors anymore, but still failing, but I did find a debug log that may shed some light.

    >>
    security_getdriver(name=bsdtcp) returns 0x996140
    security_handleinit(handle=0x8786b50, driver=0x996140 (BSDTCP))
    security_streaminit(stream=0x87952f0, driver=0x996140 (BSDTCP))
    security_streaminit(stream=0x879d328, driver=0x996140 (BSDTCP))
    amidxtaped_streams[0].fd = 0x879d328
    security_streaminit(stream=0x87a5360, driver=0x996140 (BSDTCP))
    amidxtaped_streams[1].fd = 0x87a5360
    security_close(handle=0x8786b50, driver=0x996140 (BSDTCP))
    security_stream_close(0x87952f0)
    Exec'ing /bin/tar with arguments:
    tar
    --numeric-owner
    -xpGvf
    -
    ./testfile3.txt
    security_stream_seterr(0x87a5360, EOF)
    security_stream_close(0x87a5360)
    security_stream_seterr(0x879d328, EOF)
    security_stream_close(0x879d328)
    <<

    From this log, it looks like the file was in the process of extracting the file and something happened to the tcp stream. The was never extracted.

    tar: ./testfile3.txt: Not found in archive
    tar: Error exit delayed from previous errors
    Extractor child exited with status 2

    This is the end of the error code from the extract. I'm at a loss, because this error doesn't really say a file or process that may be at fault...

  9. #9
    Join Date
    Mar 2007
    Location
    Chicago, IL
    Posts
    688

    Default

    How did the GPG errors disappear? Are you restoring from a dump after you fixed that, or one of the old dumps?

    Is testfile3.txt in the dump file you're restoring from? What do the files in your vtape directories look like? Have you tried manually untarring them to see what's in them?

  10. #10
    Join Date
    Jun 2007
    Posts
    27

    Default

    The only thing I did to resolve the GPG errors is temporarily change the perms on /var/lib/amanda/.gnupg to 777. After that, I got an error saying the perms on .gnupg were dangerous, so I changes it back to 750 and while the "dangerous permissions" message still shows up in the backup email alerts, the error for pubring.gpg is gone. Strange.

    For my testing, I took a brand new backup with testfile3.txt tried restoring from that, resulting in the same error.

    Here's a list of the files in /space/vtapes/DailySet1/slots/slot16:

    -rw------- 1 amandabackup disk 10 Jun 18 16:19 00000-DailySet1-16
    -rw------- 1 amandabackup disk 32768 Jun 18 16:19 00000.DailySet1-16
    -rw------- 1 amandabackup disk 10 Jun 18 16:19 00001-TESTBED002.mydomain.com
    -rw------- 1 amandabackup disk 65536 Jun 18 16:19 00001.TESTBED002.mydomain.com
    -rw------- 1 amandabackup disk 10 Jun 18 16:19 00002-TAPEEND
    -rw------- 1 amandabackup disk 32768 Jun 18 16:19 00002.TAPEEND

    I've tried untarring the 3 files that had any size to them, and tar won't open them.

    I'm going to try and disable encryption, but can you tell me if any of this looks awry?
    Last edited by ddenton; June 19th, 2007 at 12:11 PM.

Posting Permissions

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