Veritas-bu

[Veritas-bu] Long time between "requesting resources" and "granting resources"

2008-07-09 18:55:22
Subject: [Veritas-bu] Long time between "requesting resources" and "granting resources"
From: <Mark.Donaldson AT cexp DOT com>
To: <Veritas-bu AT mailman.eng.auburn DOT edu>
Date: Wed, 9 Jul 2008 16:40:55 -0600
Hi all,

I'm seeing some apparently slow backups.  When I dig into the job
details, I see that often there's a long delay between the "requesting
resources" messages and the "granting resources" messages.  

The master server is an 8 CPU, 16G Solaris 8 v880 box.  It's got
NBv6.5.1.

It's running with an average of 50% idle or so but the load average is
kinda high: 


last pid:  8851;  load averages:  4.01,  3.66,  3.60
11:50:46
170 processes: 164 sleeping, 1 zombie, 1 stopped, 4 on cpu
CPU states: 53.2% idle, 13.0% user, 28.8% kernel,  5.0% iowait,  0.0%
swap
Memory: 16G real, 8702M free, 2372M swap in use, 24G swap free



Here's the details of a job that ran slower than I'd like.  36 minutes
from "request" to "granted".  It's a high-priority backup, highest of
all of them, FWIW.  It, and many of my policies now, are backing up to
storage unit groups.   The AP-01 client below is an AIX media server
with NBv6.

07/09/2008 08:36:45 - requesting resource AP01_Pri
07/09/2008 08:36:45 - requesting resource ug-50.NBU_CLIENT.MAXJOBS.ap-01
07/09/2008 08:36:45 - requesting resource
ug-50.NBU_POLICY.MAXJOBS.AP-01_RM_Arch_iprd
07/09/2008 09:12:21 - granted resource  ug-50.NBU_CLIENT.MAXJOBS.ap-01
07/09/2008 09:12:21 - granted resource
ug-50.NBU_POLICY.MAXJOBS.AP-01_RM_Arch_iprd
07/09/2008 09:12:21 - granted resource  005195
07/09/2008 09:12:21 - granted resource  LTO2-06
07/09/2008 09:12:21 - granted resource  AP01-ADIC2
07/09/2008 09:12:25 - started process bpbrm (pid=33284230)
07/09/2008 09:12:26 - connecting
07/09/2008 09:12:37 - connected; connect time: 0:00:00
07/09/2008 09:12:49 - mounted 005195
07/09/2008 09:12:49 - positioning 005195 to file 79
07/09/2008 09:12:51 - positioned 005195; position time: 0:00:02
07/09/2008 09:12:51 - begin writing
07/09/2008 09:13:51 - end writing; write time: 0:01:00
the requested operation was successfully completed (0)

Anybody seeing this?  Any reasons you know of?

-Mark

_______________________________________________
Veritas-bu maillist  -  Veritas-bu AT mailman.eng.auburn DOT edu
http://mailman.eng.auburn.edu/mailman/listinfo/veritas-bu