Re: selfcheck request failed: timeout waiting for ACK
jf...@bnext.stucen.gatech.edu wrote: I have been trying to get this issue resloved all week, and finally decided to ask others. I did searching on the web and tried what I have read, but no success. I am using Amanda 2.5.1. Yes, I know it is old, but it works. Well, it had been working until I moved everything to a different machine. The new machine is running Fedora 14. Amanda is built from source. I used the configuration files (amanda.conf, disklist,...) from my old set up. I am backing up the data to disk. My linux backups work without issue. My Windows boxes all fail with this error when running amcheck: WARNING: tempserv1: selfcheck request failed: timeout waiting for ACK The planner debug file has lines like the following: planner: time 0.099: connect_portrange: connect to 192.168.52.131.10080 failed:\ Connection refused planner: stream_client: Could not bind to port in range 5 - 50040. planner: stream_client: Could not bind to any port: Connection refused security_seterror(handle=0x81d2ea0, driver=0xd27140 (BSDTCP) error=Connection r\ efused) You try to use BSDTCP auth I built the programs with configure options that included the following: --with-udpportrange=850,854 --with-tcpportrange=5,50040 --with-smbclient=/usr/bin/smbclient I did copy over the .amandahosts file from the old machine to the knew. I also made sure that xinetd amanda file was the same. Well, here is the current one: service amanda { disable = no socket_type = dgram protocol= udp wait= yes user= operator group = root server = /usr/lib/amanda/amandad server_args = -auth=bsd amdump } but xinetd is configured for BSD auth I dont think the one from the old machine had the -auth=bsd amdump lines. The ip address, 192.168.52.131, is the localhost. Netstat show the following: tcp0 0 :::10082:::*LIST EN udp0 0 :::10080:::* So the ports are open. I have turned off iptables. Both 127.0.0.1 and 192.168.52.131 are in the hosts.allow file. I do have other older fedora installs with the amanda 2.5.1 that are able to talk to otehr windows boxes without issue. Does anyone have any suggestions on what to try next. I think the problem is simple, but I must have my blinders on and can't see the solution. Thanks Which auth do you want to use? configure both the disklist and xinetd to use the same auth. An xinetd file for bsdtcp: service amanda { disable = no socket_type = stream protocol= tcp wait= no user= operator group = root server = /usr/lib/amanda/amandad server_args = -auth=bsdtcp amdump } Jean-Louis
selfcheck request failed: timeout waiting for ACK
I have been trying to get this issue resloved all week, and finally decided to ask others. I did searching on the web and tried what I have read, but no success. I am using Amanda 2.5.1. Yes, I know it is old, but it works. Well, it had been working until I moved everything to a different machine. The new machine is running Fedora 14. Amanda is built from source. I used the configuration files (amanda.conf, disklist,...) from my old set up. I am backing up the data to disk. My linux backups work without issue. My Windows boxes all fail with this error when running amcheck: WARNING: tempserv1: selfcheck request failed: timeout waiting for ACK The planner debug file has lines like the following: planner: time 0.099: connect_portrange: connect to 192.168.52.131.10080 failed:\ Connection refused planner: stream_client: Could not bind to port in range 5 - 50040. planner: stream_client: Could not bind to any port: Connection refused security_seterror(handle=0x81d2ea0, driver=0xd27140 (BSDTCP) error=Connection r\ efused) I built the programs with configure options that included the following: --with-udpportrange=850,854 --with-tcpportrange=5,50040 --with-smbclient=/usr/bin/smbclient I did copy over the .amandahosts file from the old machine to the knew. I also made sure that xinetd amanda file was the same. Well, here is the current one: service amanda { disable = no socket_type = dgram protocol= udp wait= yes user= operator group = root server = /usr/lib/amanda/amandad server_args = -auth=bsd amdump } I dont think the one from the old machine had the -auth=bsd amdump lines. The ip address, 192.168.52.131, is the localhost. Netstat show the following: tcp0 0 :::10082:::*LIST EN udp0 0 :::10080:::* So the ports are open. I have turned off iptables. Both 127.0.0.1 and 192.168.52.131 are in the hosts.allow file. I do have other older fedora installs with the amanda 2.5.1 that are able to talk to otehr windows boxes without issue. Does anyone have any suggestions on what to try next. I think the problem is simple, but I must have my blinders on and can't see the solution. Thanks
Re: planner bumps to level 4 are actually done as level 0's
It probably did a level 0 because it was time to do it. What's the dumpcycle? When was the last level 0? Post the amdump.1 log file. Gene Heskett wrote: From the canary; Someone using tapes which do have a fixed, finite size, is going to get bitten, but so far my messages appear to be going to a black hole. Whenever planner advances the backup level to a level 4, the rest of the system treats it as if it was a level 0. I can raise the BUMPMULT to prevent that I suppose, but wouldn't it make more sense to fix it? I get the impression there is a modulo 4 someplace in the middle. Last night planner set /home to level 4. But In /tmp/amanda-dbug/server/Daily, [r...@coyote Daily]# grep level *.20101112*.debug|grep /home shows the dumplevel as 0 in all returns. And no returns contain planner hits as planner does not say 'level', just the number. Moving to /tmp/amanda-dbg/client/Daily, that same grep shows the estimate calls only: [r...@coyote Daily]# grep level *.20101112*.debug|grep /home amgtar.20101112005020008.debug:Fri Nov 12 00:51:26 2010: amgtar: estimate time for /home level 0: 65.394 amgtar.20101112005020008.debug:Fri Nov 12 00:51:26 2010: amgtar: estimate size for /home level 0: 20135930 KB amgtar.20101112005020008.debug:Fri Nov 12 00:51:47 2010: amgtar: estimate time for /home level 3: 15.648 amgtar.20101112005020008.debug:Fri Nov 12 00:51:47 2010: amgtar: estimate size for /home level 3: 3414990 KB amgtar.20101112005020008.debug:Fri Nov 12 00:52:08 2010: amgtar: estimate time for /home level 4: 15.496 amgtar.20101112005020008.debug:Fri Nov 12 00:52:08 2010: amgtar: estimate size for /home level 4: 3316150 KB sendsize.20101112005019.debug:Fri Nov 12 00:50:20 2010: sendsize: getting size via application API for /home /home level 0 sendsize.20101112005019.debug:Fri Nov 12 00:50:20 2010: sendsize: getting size via application API for /home /home level 3 sendsize.20101112005019.debug:Fri Nov 12 00:50:20 2010: sendsize: getting size via application API for /home /home level 4 sendsize.20101112005019.debug:Fri Nov 12 00:50:20 2010: sendsize: running: "/usr/local/libexec/amanda/application/amgtar estimate --message line --config Daily --host coyote --device /home --disk /home --level 0 --level 3 --level 4 --exclude-list /GenesAmandaHelper-0.6/excludes --check-device no" sendsize.20101112005019.debug:Fri Nov 12 00:52:08 2010: sendsize: estimate size for /home level 0: 20135930 KB sendsize.20101112005019.debug:Fri Nov 12 00:52:08 2010: sendsize: estimate size for /home level 3: 3414990 KB sendsize.20101112005019.debug:Fri Nov 12 00:52:08 2010: sendsize: estimate size for /home level 4: 3316150 KB sendsize.20101112005019.debug:Fri Nov 12 00:52:08 2010: sendsize: estimate time for /home all level: 107.406 But it actually did the whole 20 gigabyte level 0. gzipped to 12. ?
Re: taper-parallel-write
Is there any way to fool it, or force it to use both drives. I'm not really concerned about filling the tape, but am concerned about improving performance when writing to tape. On Nov 12, 2010, at 11:27 AM, Jean-Louis Martineau wrote: Jack O'Connell wrote: There were no errors reported as shown in the taper log below. There is not enough data to fill one tape in the test disklist I was using but it contain 14 DLEs. I assumed it would use both drives. No, it use only one tape is all the data fit in it. Jean-Louis Thanks, Jack O'Connell ALCF - Storage (630)252-3610 joco...@alcf.anl.gov
planner bumps to level 4 are actually done as level 0's
>From the canary; Someone using tapes which do have a fixed, finite size, is going to get bitten, but so far my messages appear to be going to a black hole. Whenever planner advances the backup level to a level 4, the rest of the system treats it as if it was a level 0. I can raise the BUMPMULT to prevent that I suppose, but wouldn't it make more sense to fix it? I get the impression there is a modulo 4 someplace in the middle. Last night planner set /home to level 4. But In /tmp/amanda-dbug/server/Daily, [r...@coyote Daily]# grep level *.20101112*.debug|grep /home shows the dumplevel as 0 in all returns. And no returns contain planner hits as planner does not say 'level', just the number. Moving to /tmp/amanda-dbg/client/Daily, that same grep shows the estimate calls only: [r...@coyote Daily]# grep level *.20101112*.debug|grep /home amgtar.20101112005020008.debug:Fri Nov 12 00:51:26 2010: amgtar: estimate time for /home level 0: 65.394 amgtar.20101112005020008.debug:Fri Nov 12 00:51:26 2010: amgtar: estimate size for /home level 0: 20135930 KB amgtar.20101112005020008.debug:Fri Nov 12 00:51:47 2010: amgtar: estimate time for /home level 3: 15.648 amgtar.20101112005020008.debug:Fri Nov 12 00:51:47 2010: amgtar: estimate size for /home level 3: 3414990 KB amgtar.20101112005020008.debug:Fri Nov 12 00:52:08 2010: amgtar: estimate time for /home level 4: 15.496 amgtar.20101112005020008.debug:Fri Nov 12 00:52:08 2010: amgtar: estimate size for /home level 4: 3316150 KB sendsize.20101112005019.debug:Fri Nov 12 00:50:20 2010: sendsize: getting size via application API for /home /home level 0 sendsize.20101112005019.debug:Fri Nov 12 00:50:20 2010: sendsize: getting size via application API for /home /home level 3 sendsize.20101112005019.debug:Fri Nov 12 00:50:20 2010: sendsize: getting size via application API for /home /home level 4 sendsize.20101112005019.debug:Fri Nov 12 00:50:20 2010: sendsize: running: "/usr/local/libexec/amanda/application/amgtar estimate --message line --config Daily --host coyote --device /home --disk /home --level 0 --level 3 --level 4 --exclude-list /GenesAmandaHelper-0.6/excludes --check-device no" sendsize.20101112005019.debug:Fri Nov 12 00:52:08 2010: sendsize: estimate size for /home level 0: 20135930 KB sendsize.20101112005019.debug:Fri Nov 12 00:52:08 2010: sendsize: estimate size for /home level 3: 3414990 KB sendsize.20101112005019.debug:Fri Nov 12 00:52:08 2010: sendsize: estimate size for /home level 4: 3316150 KB sendsize.20101112005019.debug:Fri Nov 12 00:52:08 2010: sendsize: estimate time for /home all level: 107.406 But it actually did the whole 20 gigabyte level 0. gzipped to 12. ? -- 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) All work and no pay makes a housewife.
Re: taper-parallel-write
Jack O'Connell wrote: There were no errors reported as shown in the taper log below. There is not enough data to fill one tape in the test disklist I was using but it contain 14 DLEs. I assumed it would use both drives. No, it use only one tape is all the data fit in it. Jean-Louis
Re: taper-parallel-write
There were no errors reported as shown in the taper log below. There is not enough data to fill one tape in the test disklist I was using but it contain 14 DLEs. I assumed it would use both drives. ts2:/var/log/amanda/server/daily$ cat taper.20101110162643.debug Wed Nov 10 16:26:43 2010: taper: pid 22378 ruid 6111 euid 6111 version 3.2.0: start at Wed Nov 10 16:26:43 2010 Wed Nov 10 16:26:43 2010: taper: pid 22378 ruid 6111 euid 6111 version 3.2.0: rename at Wed Nov 10 16:26:43 2010 Wed Nov 10 16:26:43 2010: taper: chg-robot: using statefile '/var/ amanda/chg-robot-dev-sg8' Wed Nov 10 16:26:43 2010: taper: Amanda::Taper::Scan::traditional stage 1: search for oldest reusable volume Wed Nov 10 16:26:43 2010: taper: Amanda::Taper::Scan::traditional oldest reusable volume is 'daily2-0033' Wed Nov 10 16:26:43 2010: taper: Amanda::Taper::Scan::traditional stage 1: searching oldest reusable volume 'daily2-0033' Wed Nov 10 16:26:43 2010: taper: invoking /usr/sbin/mtx -f /dev/sg8 status Wed Nov 10 16:26:43 2010: taper: robot: updating state Wed Nov 10 16:26:43 2010: taper: robot: loading label 'daily2-0033' Wed Nov 10 16:26:43 2010: taper: robot: requested volume is already in drive 3 Wed Nov 10 16:26:43 2010: taper: robot: polling 'tape:/dev/nst0' to see if it's ready Wed Nov 10 16:26:43 2010: taper: robot: setting current slot to 75 Wed Nov 10 16:26:43 2010: taper: Amanda::Taper::Scan::traditional result: 'daily2-0033' on tape:/dev/nst0 slot 75, mode 2 Wed Nov 10 16:26:50 2010: taper: Amanda::Taper::Scribe preparing to write, part size 2147483648, using cache_inform (splitter) (no LEOM) Wed Nov 10 16:26:50 2010: taper: Starting ( -> )> Wed Nov 10 16:26:50 2010: taper: Final linkage: -(PULL_BUFFER)-> -(PUSH_BUFFER)-> Wed Nov 10 16:26:50 2010: taper: Building type TAPESTART header of 32768-32768 bytes with name='daily2-0033' disk='' dumplevel=0 and blocksize=32768 Wed Nov 10 16:26:54 2010: taper: invoking /usr/sbin/mtx -f /dev/sg8 status Wed Nov 10 16:26:54 2010: taper: Amanda::Taper::Scan::traditional stage 1: search for oldest reusable volume Wed Nov 10 16:26:54 2010: taper: Amanda::Taper::Scan::traditional oldest reusable volume is 'daily2-0034' Wed Nov 10 16:26:54 2010: taper: Amanda::Taper::Scan::traditional stage 1: searching oldest reusable volume 'daily2-0034' Wed Nov 10 16:26:54 2010: taper: robot: updating state Wed Nov 10 16:26:54 2010: taper: Building type SPLIT_FILE header of 32768-32768 bytes with name='gs1-data.intrepid.alcf.anl.gov' disk='/ dev/' dumplevel=0 and blocksize=32768 Wed Nov 10 16:26:55 2010: taper: robot: too early for another 'status' invocation Wed Nov 10 16:26:55 2010: taper: robot: loading label 'daily2-0034' Wed Nov 10 16:26:55 2010: taper: robot: requested volume is already in drive 2 Wed Nov 10 16:26:55 2010: taper: robot: polling 'tape:/dev/nst1' to see if it's ready Wed Nov 10 16:26:55 2010: taper: robot: setting current slot to 76 Wed Nov 10 16:26:55 2010: taper: Amanda::Taper::Scan::traditional result: 'daily2-0034' on tape:/dev/nst1 slot 76, mode 2 Wed Nov 10 16:34:09 2010: taper: Amanda::Taper::Scribe preparing to write, part size 2147483648, using cache_inform (splitter) (no LEOM) Wed Nov 10 16:34:09 2010: taper: Starting ( -> )> Wed Nov 10 16:34:09 2010: taper: Final linkage: -(PULL_BUFFER)-> -(PUSH_BUFFER)-> Wed Nov 10 16:34:09 2010: taper: Building type SPLIT_FILE header of 32768-32768 bytes with name='gs2-data.intrepid.alcf.anl.gov' disk='/ dev/' dumplevel=0 and blocksize=32768 Wed Nov 10 16:34:11 2010: taper: Amanda::Taper::Scribe preparing to write, part size 2147483648, using cache_inform (splitter) (no LEOM) Wed Nov 10 16:34:11 2010: taper: Starting ( -> )> Wed Nov 10 16:34:11 2010: taper: Final linkage: -(PULL_BUFFER)-> -(PUSH_BUFFER)-> Wed Nov 10 16:34:11 2010: taper: Building type SPLIT_FILE header of 32768-32768 bytes with name='ts1-mgmt.ether.alcf.anl.gov' disk='/var/ lib/amanda/' dumplevel=0 and blocksize=32768 Wed Nov 10 16:34:13 2010: taper: Amanda::Taper::Scribe preparing to write, part size 2147483648, using cache_inform (splitter) (no LEOM) Wed Nov 10 16:34:13 2010: taper: Starting ( -> )> Wed Nov 10 16:34:13 2010: taper: Final linkage: -(PULL_BUFFER)-> -(PUSH_BUFFER)-> Wed Nov 10 16:34:13 2010: taper: Building type SPLIT_FILE header of 32768-32768 bytes with name='gs1-data.intrepid.alcf.anl.gov' disk='/ tmp/' dumplevel=0 and blocksize=32768 Wed Nov 10 16:34:15 2010: taper: Amanda::Taper::Scribe preparing to write, part size 2147483648, using cache_inform (splitter) (no LEOM) Wed Nov 10 16:34:15 2010: taper: Starting ( -> )> Wed Nov 10 16:34:15 2010: taper: Final linkage: -(PULL_BUFFER)-> -(PUSH_BUFFER)-> Wed Nov 10 16:34:15 2010: taper: Building type SPLIT_FILE header of 32768-32768 bytes with name='gs2-data.intrepid.alcf.anl.gov' disk='/ opt' dumplevel=0 and blocksize=32768 Wed Nov 10 16:34:1