[ADSM-L] Strange behavior on DB(?) or Log(?)

We've got two machines which are identical in every way, same hardware, same 
AIX, same TSM level, same options set, same storage pools, domains, everything 
except one has the DB and Log on local disk.  On this box things run very 
slowly: expiration may take a week, filespace deletion creeps, and we see this 
as the normal behavior

Date/Time                Message
--------------------     
----------------------------------------------------------
01/21/09   07:03:39      ANR0984I Process 1118 for DATABASE BACKUP started in 
the
                          FOREGROUND at 07:03:39. (SESSION: 571283, PROCESS: 
1118)
01/21/09   07:03:39      ANR2753I (DBDUMP):ANR0984I Process 1118 for DATABASE
                          BACKUP started (SESSION: 571283)
01/21/09   07:03:39      ANR2281I Incremental database backup started as process
                          1118. (SESSION: 571283, PROCESS: 1118)
01/21/09   07:03:39      ANR2753I (DBDUMP):process 1118.  (SESSION: 571283)
01/21/09   07:03:40      ANR0408I Session 571322 started for server NECLM
                          (AIX-RS/6000) (Tcp/Ip) for library sharing.  (SESSION:
                          571283, PROCESS: 1118)
01/21/09   07:03:40      ANR0409I Session 571322 ended for server NECLM
                          (AIX-RS/6000). (SESSION: 571283, PROCESS: 1118)
01/21/09   07:03:40      ANR0408I Session 571323 started for server NECLM
                          (AIX-RS/6000) (Tcp/Ip) for library sharing.  (SESSION:
                          571283, PROCESS: 1118)
01/21/09   07:04:12      ANR0409I Session 571323 ended for server NECLM
                          (AIX-RS/6000). (SESSION: 571283, PROCESS: 1118)
01/21/09   07:04:13      ANR8337I 3592 volume C30127 mounted in drive DR0049
                          (/dev/rmt8). (SESSION: 571283, PROCESS: 1118)
01/21/09   07:04:15      ANR0513I Process 1118 opened output volume C30127.
                          (SESSION: 571283, PROCESS: 1118)
01/21/09   07:04:21      ANR1360I Output volume C30127 opened (sequence number 
1).
                          (SESSION: 571283, PROCESS: 1118)
01/21/09   07:21:08      ANR4554I Backed up 5312 of 310783 database pages.
                          (SESSION: 571283, PROCESS: 1118)

That's 17 minutes between mount and first tape write.  But on the twin machine

01/21/09   07:01:46  ANR0984I Process 314 for DATABASE BACKUP started in the
                      FOREGROUND at 07:01:46. (SESSION: 115364, PROCESS: 314)
01/21/09   07:01:46  ANR2281I Incremental database backup started as process
                      314. (SESSION: 115364, PROCESS: 314)
01/21/09   07:01:46  ANR0408I Session 115369 started for server NECLM
                      (AIX-RS/6000) (Tcp/Ip) for library sharing.  (SESSION:
                      115364, PROCESS: 314)
01/21/09   07:01:46  ANR0409I Session 115369 ended for server NECLM
                      (AIX-RS/6000). (SESSION: 115364, PROCESS: 314)
01/21/09   07:01:46  ANR0408I Session 115370 started for server NECLM
                      (AIX-RS/6000) (Tcp/Ip) for library sharing.  (SESSION:
                      115364, PROCESS: 314)
01/21/09   07:02:08  ANR0409I Session 115370 ended for server NECLM
                      (AIX-RS/6000). (SESSION: 115364, PROCESS: 314)
01/21/09   07:02:08  ANR8337I 3592 volume C30073 mounted in drive DR5475
                      (/dev/rmt12). (SESSION: 115364, PROCESS: 314)
01/21/09   07:02:08  ANR0513I Process 314 opened output volume C30073.
                      (SESSION: 115364, PROCESS: 314)
01/21/09   07:02:11  ANR1360I Output volume C30073 opened (sequence number 1).
                      (SESSION: 115364, PROCESS: 314)
01/21/09   07:04:17  ANR4554I Backed up 15040 of 267889 database pages. 

That's two minutes from mount to write.

The DBTRIGGER behavior is odder yet:

Date/Time                Message
--------------------     
----------------------------------------------------------
01/21/09   13:25:43      ANR0984I Process 11 for DATABASE BACKUP started in the
                          BACKGROUND at 13:25:43. (PROCESS: 11)
01/21/09   13:25:43      ANR4553I Incremental database backup triggered; 
started as
                          process 11. (PROCESS: 11)
01/21/09   13:26:06      ANR8337I 3592 volume A00065 mounted in drive DR5467
                          (/dev/rmt2). (SESSION: 1782, PROCESS: 11)
01/21/09   13:26:06      ANR0513I Process 11 opened output volume A00065. 
(SESSION:
                          1782, PROCESS: 11)
01/21/09   13:26:09      ANR1360I Output volume A00065 opened (sequence number 
1).
                          (SESSION: 1782, PROCESS: 11)
01/21/09   13:46:00      ANR4554I Backed up 11776 of 354278 database pages.
                          (SESSION: 1782, PROCESS: 11)  

That's 20 minutes from mount to write, and even though the logtrigger is 45%, 
the log at the time the process begins is 60% and going higher (the highest for 
a triggered incremental is 93%).

After weeks of looking, we're at a loss at what this may be: is it AIX? Or TSM? 
Or hardware?

Any thoughts or insights are greatly appreciated.  

Fred Johanson
TSM Administrator
University of Chicago

773-702-8464