fbackup hangs then restarts

[Lisa Mauer]

Hi:
HP 9000/893/T600 - DLT 8000
We are having a problem with our fbackups that have run without problems for 4 years. fbackup to a DLT8000. Things we have done - research the script, changed the tape and replaced the DLT tape drive with a new one and rebooted the server. The last thing we noticed is that it seems to hang in the same directory each time, we don't know if it was on the same file for not. The odd thing is, that you go to the hung directory and do an "ls" that worked yesterday, but not today, today I ran a script that goes through specific directories (that one included) and removes files that are older then x amount of days. The fbackup just started on it's merry way again somewhere in the middle of that script processing. I am starting to wonder if it isn't a bad spot on the disk? I have run the Exercise on that disk through stm and received no errors, I am currently running
dd if=/dev/dsk/c4t0d1 of=/dev/null bs=1024k which hasn't finished yet, it's a 20 gig drive. Does anyone have any suggestions on more troubleshooting? I can not run anything that would take down processing on this box, ie - can not umount etc....
Thanks!
Lisa

[Bill McNAMARA_1]

It could be a number of things, NFS springs to mind, user id look ups etc..

The filesystem may be heavily defragmented or worse still corrupt.. check with fsadm if you have onlineJFS.

what mount options are active:
mount -p

what is your echo $PATH..

just sprouting off really, but the more info the better ;)

Later,
Bill

[Patrick Wallek]

Have you checked your system logs (dmesg, /var/adm/syslog/syslog.log) for any errors that occurred at the same time that the backup hangs?

Are you getting any messages from fbackup when it hangs?

[James R. Ferguson]

Hi Lisa:

Does the tape light flash, suggesting that tape is being transited?

My first thought is that you have some very large file that is in the process of changing as 'fbackup' tries to copy it. 'fbackup' notes the modification timestamp of a file as it begins to copy it from disk to tape. Once a copy has been written to the tape, 'fbackup' compares the timestamp it last noted to the timestamp of the file on *disk*. If they differ, 'fbackup' marks the file on *tape* as "bad" and proceeds to retry the copy. This will occur up to 'maxretries' as defined in the 'config' file (default=5) [see the man pages for 'fbackup' for more details]. Not only does this kind of situation greatly increase the backup time but it also wastes tape.

I suggest that you set the 'v'erbose logging options of 'fbackup' and redirect the output into a file. In that way you will see if any "retries" are occuring and for what file(s).

Regards!

...JRF...

[Paula J Frazer-Campbell]

Hi

Things to try:-

ls -lrt from thr root of that file system and look for hangs.

Does fbackup give any errors in its logs.

Does EMS give any errors.

Use glance to watch the fbackup (open files etc)

Use TUSC and attach to fbackup when a hang occurs.

Send output of fbackup to log:-

/usr/sam/lbin/br_backup DAT FULL Y /dev/rmt/c4t0d0B gaphRCAa18305 root Y 1 N > /var/sam/SAM_br_msgs 2>&1 #sambackup

Use glance to monitor the disk which this file system is on.

Use sar to do the same.

if you have online jfs defrag the disks.

Just a few ideas.

paula

[A. Clay Stephenson]

Rather than a bad disk, I would suspect a corrupt filesystem. You need to run fsck on the unmounted filesystem. If this is a vxfs filesystem then you should use the -o full (and possibly nolog) to force a full fsck.

[Lisa Mauer]

fbackup doesn't return any errors and there is absolutley nothing in the fbackup log that we write too or syslog.log or mail.

We don't have online JFS. The filesystem is hfs. Nothing would be written to this directory as we kill all processes before we do backups. The directory it is getting stuck in is a data directory, only written to by our scripts which are not running at the time of the backups.
I ran a grep at the time it was hung:
ps -ef |grep fback
root 20458 20453 0 23:14:54 console 0:36 /usr/sbin/fbackuprdr 88068 4 419
4304 C 0 0
root 20453 17748 0 23:14:54 console 6:25 /etc/fbackup -0nvf /dev/rmt/2m -
g /home/devback/config/devba
root 20457 20453 0 23:14:54 console 0:40 /usr/sbin/fbackuprdr 88068 3 419
4304 C 0 0
root 20459 20453 0 23:14:54 console 0:37 /usr/sbin/fbackuprdr 88068 5 419
4304 C 0 0
root 20456 20453 0 23:14:54 console 0:36 /usr/sbin/fbackuprdr 88068 2 419
4304 C 0 0
root 20455 20453 0 23:14:54 console 0:37 /usr/sbin/fbackuprdr 88068 1 419
4304 C 0 0
root 20454 20453 0 23:14:54 console 0:36 /usr/sbin/fbackuprdr 88068 0 419
4304 C 0 0
root 20460 20453 0 23:14:54 console 1:45 /usr/sbin/fbackupwrtr 88068 4194
304 4 C 0 0 /dev/rmt/2m
root 21518 21271 2 00:05:37 pts/ta 0:00 grep fback

It didn't show up in top...... Thanks for all the information, at least I know I am on the right track of troubleshooting this :)
When you say use glance to look at the open files, how do I do that exactly? I could only do this if the backup hung.. our backups take 3 - 4 hours to run and they page me at 3am if it hangs....I can't watch it for 3 hours :)

[James R. Ferguson]

Hi (again) Lisa:

OK, so you indicate that 'fbackup' doesn't return errors nor warnings and that file retries are not indicted from the 'fbackup' logs (using 'v'erbose option?).

Given that, I also noticed that you are running with six reader processes. Are you memory-constrained during the time 'fbackup' runs?

I suggest that you 'cron' something to capture some performance indicators during the 'fbackup' period. You could use 'sar', 'vmstat' and 'swapinfo'.

Regards!

...JRF...

[Lisa Mauer]

I did run glance while the fbackup was hung and it showed this:
B3692A GlancePlus C.02.40.00 00:07:22 fargo 9000/893 Current Avg High
--------------------------------------------------------------------------------
CPU Util | 1% 1% 6%
Disk Util | 0% 2% 12%
Mem Util S SU UB B | 28% 28% 28%
Swap Util RR | 3% 3% 3%
--------------------------------------------------------------------------------
DISK REPORT Users= 2
Req Type Requests % Rate Bytes Cum Req % Cum Rate Cum Byte
--------------------------------------------------------------------------------
Local Logl Rds 7 100.0 1.3 1kb 191 100.0 5.3 5.8mb
Logl Wts 0 0.0 0.0 0kb 0 0.0 0.0 0kb
Phys Rds 0 0.0 0.0 0kb 34 45.9 0.9 532kb
Phys Wts 2 100.0 0.3 16kb 40 54.1 1.1 223kb
User 0 0.0 0.0 0kb 9 12.2 0.2 17kb
Virt Mem 0 0.0 0.0 0kb 31 41.9 0.8 508kb
System 2 100.0 0.3 16kb 34 45.9 0.9 230kb
Raw 0 0.0 0.0 0kb 0 0.0 0.0 0kb
Remote Logl Rds 0 0.0 0.0 0kb 0 0.0 0.0 0kb
Logl Wts 0 0.0 0.0 0kb 0 0.0 0.0 0kb
Phys Rds 0 0.0 0.0 0kb 11 100.0 0.3 0kb
Phys Wts 0 0.0 0.0 0kb 0 0.0 0.0 0kb
Page 1 of 2
ProcList CPU Rpt Mem Rpt Disk Rpt NextKeys SlctProc Help Exit

yes, we do run it in verbose mode
fbackup -0nvf ${TAPEDRIVE} -g ${GRAPH} -c ${FBKUP_CONFIG} 2>>$
MASTERLOG

Nothing listed in the log except files and then this at the end - like usual
fbackup(1005): run time: 7997 seconds
fbackup(1030): warnings encountered during backup
fbackup(3055): total file blocks read for backup: 45714674
fbackup(3056): total blocks written to output file /dev/rmt/2m: 46824073

[James R. Ferguson]

Hi Lisa:

To make sure of the log, the warning that you would see for a "changing-file" would be:

fbackup(3007): WARNING: File number ) was active during attempt number

These warnings appear in the log file where the file being copied is recorded.

Regards!

...JRF...

[A. Clay Stephenson]

While you seem to be concerned about the behavior of fbackup, I am much more concerned about the hanging of ls. That could be the result of an extremely busy system and impatience on your part but there is a very real possibilty that you have a ticking time bomb (in the way of a corrupt filesystem) on your hands. It is even possible that the same block has been handed out to more than 1 file.
While you can force fsck to run on a mounted filesystem, by far the best answer is too schedule some down time and run fsck. This could very well be a case of pay me now or pay me really big later. If it is the case of the same filesystem block in use by more than one file, many of your backups could already be useless.

[James R. Ferguson]

Hi (again) Lisa:

Since Clay mentioned your reference to a "hung ls" command, NFS mountpoints crossed my mind. It appears from your command that you *have* optioned 'fbackup' to cross these mountpoinnts. I suggest that you test without this enabled (the default). This could be the reason for the sluggish response and backup.

Regards!

...JRF...

[Lisa Mauer]

I'm sorry I didn't say that very well about the "ls".
What I meant to say is that once the backup was hung up, if you looked at the fbackup log, saw what directory and file it was hung up on and did an "ls" - the "ls" command magically freed the backup and it started again. That was yesterday, today when the same thing happened in the same directory (different file) I ran the "ls" command and it did not free up the fbackup as it did previously, I then ran a script that cleans up files dated older then 7 days and that magically cleared the backup and it started again.... the "ls" command didn't hang - it "unhung" the fbackup process for some reason... that is what is so confusing. Sorry about the bad explanation on that earlier.

[Tom Dawson]

Lisa,

You mentioned earlier that this directory is "only written to by our scripts which are not running at the time of the backups".

As a possibly simple solution, I would carefully look through the directory and see if there is a file with an invalid filename. They CAN be created. I'm certainly guilty of this. An invalid filename could possibly hang fbackup.

If you don't see anything peculiar, certainly follow what the others have suggested.

HTH,
Tom

[Diadina Cotte]

Hi

I did had some issues with backup and it turns out that we had problems with 2 faulty disks and the backup stalled for a while then finish in 30 mins (full backup).

We test every directory and the ones that hang were excluded and everything ran ok again.

Do a manual backup and check and see what directory hangs the backup process.
#fbackup

regards!