Amanda-Users

Re: Troubleshooting a slowdown problem?

2004-06-17 19:05:52
Subject: Re: Troubleshooting a slowdown problem?
From: Frank Smith <fsmith AT hoovers DOT com>
To: KEVIN ZEMBOWER <KZEMBOWE AT jhuccp DOT org>, amanda-users AT amanda DOT org
Date: Thu, 17 Jun 2004 17:59:48 -0500
--On Thursday, June 17, 2004 17:08:46 -0400 KEVIN ZEMBOWER <KZEMBOWE AT jhuccp 
DOT org> wrote:

> Ohh, it ended just as I pressed 'send.' Here's the daily report:
> These dumps were to tape DailySet104.
> The next tape Amanda expects to use is: DailySet105.
> 
> FAILURE AND STRANGE DUMP SUMMARY:
>   admin      //db/f$/inetsrv/webpub/images lev 1 STRANGE
>   admin      //db/e$ lev 1 STRANGE
>   admin      //db/f$ lev 1 STRANGE
>   admin      //db/c$ lev 0 STRANGE
> 
> 
> STATISTICS:
>                           Total       Full      Daily
>                         --------   --------   --------
> Estimate Time (hrs:min)    0:04
> Run Time (hrs:min)        21:03
> Dump Time (hrs:min)       29:18      28:55       0:23
> Output Size (meg)       10446.5     7946.7     2499.8
> Original Size (meg)     15747.4    13247.4     2500.0
> Avg Compressed Size (%)    58.5       58.5       23.5   (level:#disks ...)
> Filesystems Dumped           17         13          4   (1:4)
> Avg Dump Rate (k/s)       101.4       78.2     1882.1
> 
> Tape Time (hrs:min)        2:52       2:27       0:25
> Tape Size (meg)         10446.7     7946.9     2499.8
> Tape Used (%)              90.3       68.7       21.6   (level:#disks ...)
> Filesystems Taped            17         13          4   (1:4)
> Avg Tp Write Rate (k/s)  1038.9      922.9     1730.4
> 
> USAGE BY TAPE:
>   Label             Time      Size      %    Nb
>   DailySet104       2:52   10446.7   90.3    17
> 
> 
> FAILED AND STRANGE DUMP DETAILS:
> 
> /-- admin      //db/f$/inetsrv/webpub/images lev 1 STRANGE
> sendbackup: start [admin://db/f$/inetsrv/webpub/images level 1]
> sendbackup: info BACKUP=/usr/bin/smbclient
> sendbackup: info RECOVER_CMD=/usr/bin/smbclient -f... -
> sendbackup: info end
> ? INFO: Debug class all level = 1   (pid 4428 from pid 4428)
>| added interface ip=172.16.2.7 bcast=172.16.255.255 nmask=255.255.0.0
>| tar: dumped 5 files and directories
>| Total bytes written: 22528
> sendbackup: size 22
> sendbackup: end
> \--------
> 
> /-- admin      //db/e$ lev 1 STRANGE
> sendbackup: start [admin://db/e$ level 1]
> sendbackup: info BACKUP=/usr/bin/smbclient
> sendbackup: info RECOVER_CMD=/usr/bin/smbclient -f... -
> sendbackup: info end
> ? INFO: Debug class all level = 1   (pid 4462 from pid 4462)
>| added interface ip=172.16.2.7 bcast=172.16.255.255 nmask=255.255.0.0
>| tar: dumped 9 files and directories
>| Total bytes written: 1536
> sendbackup: size 2
> sendbackup: end
> \--------
> 
> /-- admin      //db/f$ lev 1 STRANGE
> sendbackup: start [admin://db/f$ level 1]
> sendbackup: info BACKUP=/usr/bin/smbclient
> sendbackup: info RECOVER_CMD=/usr/bin/smbclient -f... -
> sendbackup: info end
> ? INFO: Debug class all level = 1   (pid 4482 from pid 4482)
>| added interface ip=172.16.2.7 bcast=172.16.255.255 nmask=255.255.0.0
>| tar: dumped 215 files and directories
>| Total bytes written: 2620979200
> sendbackup: size 2559550
> sendbackup: end
> \--------
> 
> /-- admin      //db/c$ lev 0 STRANGE
> sendbackup: start [admin://db/c$ level 0]
> sendbackup: info BACKUP=/usr/bin/smbclient
> sendbackup: info RECOVER_CMD=/usr/bin/smbclient -f... -
> sendbackup: info end
> ? INFO: Debug class all level = 1   (pid 4486 from pid 4486)
>| added interface ip=172.16.2.7 bcast=172.16.255.255 nmask=255.255.0.0
> ? ERRDOS - ERRbadshare opening remote file \WINNT\system32\config\system 
> (\WINNT\system32\config\)
> ? ERRDOS - ERRbadshare opening remote file \WINNT\system32\config\software 
> (\WINNT\system32\config\)
> ? ERRDOS - ERRbadshare opening remote file \WINNT\system32\config\default 
> (\WINNT\system32\config\)
> ? ERRDOS - ERRbadshare opening remote file 
> \WINNT\system32\config\software.LOG (\WINNT\system32\config\)
> ? ERRDOS - ERRbadshare opening remote file \WINNT\system32\config\default.LOG 
> (\WINNT\system32\config\)
> ? ERRDOS - ERRbadshare opening remote file \WINNT\system32\config\SECURITY 
> (\WINNT\system32\config\)
> ? ERRDOS - ERRbadshare opening remote file 
> \WINNT\system32\config\SECURITY.LOG (\WINNT\system32\config\)
> ? ERRDOS - ERRbadshare opening remote file \WINNT\system32\config\SYSTEM.ALT 
> (\WINNT\system32\config\)
> ? ERRDOS - ERRbadshare opening remote file \WINNT\system32\config\SAM 
> (\WINNT\system32\config\)
> ? ERRDOS - ERRbadshare opening remote file \WINNT\system32\config\SAM.LOG 
> (\WINNT\system32\config\)
> ? ERRDOS - ERRnoaccess opening remote file \pagefile.sys (\)
>| tar: dumped 5941 files and directories
>| Total bytes written: 470870016
> sendbackup: size 459834
> sendbackup: end
> \--------
> 
> 
> NOTES:
>   planner: Last full dump of admin://db/f$ on tape DailySet105 overwritten in 
> 1 run.

This is a big problem.  After your next run  you will no longer be able to do a
full restore of this filesystem.  This is caused by the line below.

>   planner: admin //db/f$ 20040616 0 [dump larger than tape, 12838742 KB, full 
> dump delayed]

Amanda knows its time to do a full, but is unable to because the dump
won't fit on a single tape.  You either need to split this disklist entry
into 2 (or more) subdirectories or experiment with the tape spanning code
still in development (or get bigger tapes).

>   planner: Full dump of centernet:sda2 promoted from 2 days ahead.
>   planner: Full dump of mailinglists:hda2 promoted from 1 day ahead.
>   planner: Full dump of admin:sdb1 promoted from 2 days ahead.
>   planner: Full dump of mailinglists:hda7 promoted from 1 day ahead.
>   planner: Full dump of centernet:sda9 promoted from 2 days ahead.
>   planner: Full dump of admin://db/c$ promoted from 1 day ahead.
>   planner: Full dump of mailinglists:hda1 promoted from 2 days ahead.
>   planner: Full dump of centernet:sda3 promoted from 2 days ahead.
>   planner: Full dump of admin:sda1 promoted from 2 days ahead.
>   planner: Full dump of centernet:sda7 promoted from 2 days ahead.
>   planner: Full dump of centernet:sda1 promoted from 2 days ahead.
>   taper: tape DailySet104 kb 10697984 fm 17 [OK]
> 
> 
> DUMP SUMMARY:
>                                      DUMPER STATS            TAPER STATS 
> HOSTNAME     DISK        L ORIG-KB OUT-KB COMP% MMM:SS  KB/s MMM:SS  KB/s
> -------------------------- --------------------------------- ------------
> admin        //db/c$     0  462720 462720   --    4:191788.1   5:141475.5
> admin        //db/e$     1      10     32   --    0:09   1.1   0:002839.9
> admin        //db/f$     1 25596602559680   --    9:544312.1  24:391730.4
> admin        -pub/images 1      30     32   --   12:34   0.0   0:002822.6
> admin        sda1        0    3410   3424   --    0:013081.9   0:031014.4
> admin        sda3        0 54646573821088  69.9  70:36 902.1  70:37 901.9
> admin        sdb1        0   24270  24288   --    0:055047.4   0:38 640.4

All the rates on admin look good.

> centernet    sda1        0    5670   4864  85.8   1:54  42.5   0:05 887.7
> centernet    sda2        0 1482550 715744  48.3 306:39  38.9  13:14 901.6
> centernet    sda3        0  317710 110912  34.9  37:28  49.3   2:00 920.9
> centernet    sda5        0 20678301818176  87.9 796:47  38.0  33:21 908.7
> centernet    sda6        1     310     96  31.0   0:04  20.2   0:003080.0
> centernet    sda7        0    6090    576   9.5   0:15  37.9   0:003035.6
> centernet    sda9        0  580430  30400   5.2  12:29  40.6   0:33 910.4
> mailinglists hda1        0    2861   2208  77.2   0:54  40.8   0:02 984.9
> mailinglists hda2        0  983941 399360  40.6 171:46  38.7   7:27 892.9
> mailinglists hda7        0 2163157 743840  34.4 332:00  37.3  13:42 905.2

The dumper rates on these others are pretty poor.  Do you have a duplex
mis-match on your server, client or switch?  If you ftp a fair-sized file
both ways between admin and centernet, what transfer rates do you get?
I get a little over twice that rate on the clients I backup over a 4.5 megabit
VPN WAN link, and even my slowest local client (an ancient MIPS-based box) can
dump at around 100KB/s.  Most of my clients dump (client compress tar, actually)
in the 1000-3000KB/s range.

You might want to set columnspec in your config so the numbers don't all
run together.

Frank

> 
> (brought to you by Amanda version 2.4.4)
> 
> I'll take a closer look at this tomorrow. You all have a good evening.
> 
> -Kevin



-- 
Frank Smith                                      fsmith AT hoovers DOT com
Sr. Systems Administrator                       Voice: 512-374-4673
Hoover's Online                                   Fax: 512-374-4501