Link to home
Start Free TrialLog in
Avatar of John Pope
John PopeFlag for United Kingdom of Great Britain and Northern Ireland

asked on

Shared TSM library and scratch volumes for library client

Hi

I have setup what I believe is a working shared library environment between one library manager and one library client.  I can do all the usual querying from either side, the shared library is defined to the library client, the drive  paths to the library client on the shared library are defined on the library manager.

The reason for a shared library is to use the simultaneous write function on a stgpool on the library client to send client data, during the disk pool migration, to a local tape pool and simultaneously to a tape pool on the shared library.

When the data starts to migrate from the disk pool the library successfully contacts the library manager and requests a mount of a scratch tape.  On the library client I can see that there is a request for a mount point (DRLTO is the devclass);

tsm: TSM01>q mo
ANR8379I Mount point in device class DRLTO is waiting for the volume mount to
complete, status: WAITING FOR VOLUME.

Open in new window


Then a moment later I see;

tsm: TSM01>q mo
ANR8376I Mount point reserved in device class DRLTO, status: RESERVED.

Open in new window


On the library manager I get;

08/27/2014 12:57:27      ANR8379I Mount point in device class DRLTO is waiting for
                          the volume mount to complete, status: WAITING FOR VOLUME.
                          (SESSION: 72)
08/27/2014 12:57:27      ANR8334I         1 matches found. (SESSION: 72)
08/27/2014 12:58:04      ANR8337I LTO volume 100172L4 mounted in drive DRV1
                          (mt0.0.0.3). (SESSION: 74)
08/27/2014 12:58:04      ANR9791I Volume 100172L4 in library DR-LIB ownership is
                          changing from DRTSM01 to TSM01.  (SESSION: 74)
08/27/2014 12:58:04      ANR8336I Verifying label of LTO volume 100172L4 in drive
                          DRV1 (mt0.0.0.3). (SESSION: 74)
08/27/2014 12:58:48      ANR8468I LTO volume 100172L4 dismounted from drive DRV1
                          (mt0.0.0.3) in library DR-LIB. (SESSION: 74)
08/27/2014 12:58:48      ANR0409I Session 74 ended for server TSM01 (Windows).
                          (SESSION: 74)

Open in new window


The library manager mount/dismount messages happen 3 times, (the library manager must try to mount 3 scratch volumes and then give up).  One each occasion, the volume is a scratch volume checked in to the shared library.

Oddly, for each of the times the volume is mounted I can see that the volume status changes temporarily from scratch to private and containing data, according to 'q libv' and then reverts back to scratch;

tsm: DRTSM01>q libv

Library Name    Volume Name    Status              Owner         Last Use     Home       Device
                                                                              Element    Type
------------    -----------    ----------------    ----------    ---------    -------    ------
DR-LIB          100172L4       Scratch                                        4,104
DR-LIB          100175L4       Scratch                                        4,113
DR-LIB          100176L4       Private             TSM01      Data         4,109

Open in new window


Once the library manager messages are logged, on the library client there are the following messages saying that scratch volumes mount request denied and the autocopy fails;

08/27/2014 13:03:16  ANR1404W Scratch volume mount request denied - mount
                      failed. (SESSION: 7475, PROCESS: 833)
08/27/2014 13:18:14  ANR1917E Autocopy process 833 failed for storage pool

Open in new window


Hence my simultaneous write function does not complete.

I ran an audit library from the library client to the shared library, this logged as successful, however the time  taken to complete the process, according to the activity log was less than a second.  Perhaps TSM just registers the fact that the request was a success rather than the actual audit process completing successfully.

Thanks for your help.

Cheers, JP.
Avatar of John Pope
John Pope
Flag of United Kingdom of Great Britain and Northern Ireland image

ASKER

I wonder, should it matter about domains/policies/mgmt classes on the shared library side?

Also, is it a requirement to register the library client to the library manager as a 'server' node like for virtual volumes (how I understand it)...

The TSM instance that is the library manager is an old instance that has previously been used but no longer has any client backin up to it.  Might it be that fact that is causing this anomaly?

Cheers, JP.
Further tracing when trying a DB backup from the library client to a device class pointing to the shared library shows;

14:29:20.580 [38][trace.c][1700][TrBegin]:TRACE to file c:\tmp\trace\belib3.trc started.14:29:20.580 [38][trace.c][1702][TrBegin]: --> Active Trace Classes:   ASALLOC, ASRTRV, ASDEALLOC, ASMOUNT, ASVOL, ASTXN, ASSD, ADDMSG
14:29:20.581 [38][trace.c][1793][TrBegin]: Optimized 6.3.4.0 TSM Server (Driver 0000, Build 03143.1055)
14:29:20.581 [38][output.c][7531][PutConsoleMsg]:ANR9687W Cannot load the Microsoft dll NTMSAPI.DLL. Removable Media Support will not be available.~
14:29:46.940 [38][output.c][7531][PutConsoleMsg]:ANR2017I Administrator DRADMIN issued command: BACKUP DB devc=drlto type=full ~
14:29:47.002 [38][output.c][7531][PutConsoleMsg]:ANR4976W The device class DRLTO is not the same as device class LTO defined for the serverbackup node $$_TSMDBMGR_$$.~
14:29:47.003 [38][output.c][7531][PutConsoleMsg]:ANR0984I Process 212 for Database Backup started in the BACKGROUND at 15:29:49.~
14:29:47.004 [38][output.c][7531][PutConsoleMsg]:ANR4559I Backup DB is in progress.~
14:29:47.004 [38][output.c][7531][PutConsoleMsg]:ANR2280I Full database backup started as process 212.~
14:29:47.031 [39][asvolmnt.c][970][AsWaitMP]:Entry.
14:29:47.031 [39][asvolmnt.c][5797][TestSharedMpReq]:Trying first shared MP request (class = 5)
14:29:51.755 [39][output.c][7531][PutConsoleMsg]:ANR0408I Session 1972 started for server DRTSM01 (Windows) (Tcp/Ip) for library sharing. ~
14:29:51.842 [39][output.c][7531][PutConsoleMsg]:ANR0409I Session 1972 ended for server DRTSM01 (Windows).~
14:29:51.842 [39][asvolmnt.c][5828][TestSharedMpReq]:Result 0 for shared MP request.
14:29:51.842 [39][asvolmnt.c][1298][AsWaitMP]:Obtained output mpHandle of 0000000009AD4A00.
14:29:51.842 [39][asvolmnt.c][1299][AsWaitMP]:Exit (waited = 0), rc = 0.
14:29:51.842 [39][assd.c][2518][GetOutputVol]:Acquiring scratch sequential data volume.
14:29:51.843 [39][assd.c][2521][GetOutputVol]:Acquiring next scratch sequential data volume.
14:29:51.843 [39][asvolacq.c][3951][AsAcquireSdVol]:Session 664 acquiring sequential data scratch volume (1), intendedUse=2.
14:29:51.854 [39][asvolmnt.c][4831][OpenSdVol]:Mounting sequential data volume "", side 0, sequence number 1.
14:29:51.854 [39][asvolmnt.c][4855][OpenSdVol]:Setting open in progress for (2178).
14:29:56.572 [39][output.c][7531][PutConsoleMsg]:ANR0408I Session 1973 started for server DRTSM01 (Windows) (Tcp/Ip) for library sharing. ~
14:31:22.291 [39][output.c][7531][PutConsoleMsg]:ANR0409I Session 1973 ended for server DRTSM01 (Windows).~
14:31:22.292 [39][output.c][7531][PutConsoleMsg]:ANR1404W Scratch volume mount request denied - mount failed.~
14:31:22.292 [39][asvolmnt.c][3334][AsOpenVol]:Signalling volOpenDone for (2178).
14:31:22.292 [39][asvolacq.c][4321][AsAcquireSdVol]:Mount failed, rc=3028, volP=0000000009C76CF0
14:31:22.292 [39][asvolacq.c][9663][FreeVolDesc]:Freeing volume descriptor 0000000009C76CF0()
14:31:22.292 [39][asvolacq.c][4386][AsAcquireSdVol]:Exit: rc=3011, *volPP=0000000000000000
14:31:27.166 [39][output.c][7531][PutConsoleMsg]:ANR0408I Session 1974 started for server DRTSM01 (Windows) (Tcp/Ip) for library sharing. ~
14:31:27.182 [39][output.c][7531][PutConsoleMsg]:ANR0409I Session 1974 ended for server DRTSM01 (Windows).~
14:31:27.183 [16][asvolmnt.c][2228][AsMPAgent]:Mount point agent active.
14:31:27.183 [39][asvolmnt.c][970][AsWaitMP]:Entry.
14:31:27.183 [16][asvolmnt.c][2309][AsMPAgent]:Mount point agent waiting.
14:31:27.183 [39][asvolmnt.c][5797][TestSharedMpReq]:Trying first shared MP request (class = 5)
14:31:31.892 [39][output.c][7531][PutConsoleMsg]:ANR0408I Session 1975 started for server DRTSM01 (Windows) (Tcp/Ip) for library sharing. ~
14:31:31.910 [39][output.c][7531][PutConsoleMsg]:ANR0409I Session 1975 ended for server DRTSM01 (Windows).~
14:31:31.911 [39][asvolmnt.c][5828][TestSharedMpReq]:Result 0 for shared MP request.
14:31:31.911 [39][asvolmnt.c][1298][AsWaitMP]:Obtained output mpHandle of 000000000C1B3190.
14:31:31.911 [39][asvolmnt.c][1299][AsWaitMP]:Exit (waited = 0), rc = 0.
14:31:31.911 [39][assd.c][2518][GetOutputVol]:Acquiring scratch sequential data volume.
14:31:31.911 [39][assd.c][2521][GetOutputVol]:Acquiring next scratch sequential data volume.
14:31:31.911 [39][asvolacq.c][3951][AsAcquireSdVol]:Session 664 acquiring sequential data scratch volume (1), intendedUse=2.
14:31:31.925 [39][asvolmnt.c][4831][OpenSdVol]:Mounting sequential data volume "", side 0, sequence number 1.
14:31:31.925 [39][asvolmnt.c][4855][OpenSdVol]:Setting open in progress for (2179).
14:31:36.649 [39][output.c][7531][PutConsoleMsg]:ANR0408I Session 1976 started for server DRTSM01 (Windows) (Tcp/Ip) for library sharing. ~
14:32:50.107 [38][output.c][7531][PutConsoleMsg]:ANR2017I Administrator DRADMIN issued command: QUERY MOUNT ~
14:32:50.107 [38][output.c][7531][PutConsoleMsg]:ANR8379I Mount point in device class DRLTO is waiting for the volume mount to complete, status: WAITING FOR VOLUME.~
14:32:50.107 [38][output.c][7531][PutConsoleMsg]:ANR8334I         1 matches found.~
14:32:52.666 [38][output.c][7531][PutConsoleMsg]:ANR2017I Administrator DRADMIN issued command: QUERY PROCESS ~
14:33:00.246 [39][output.c][7531][PutConsoleMsg]:ANR0409I Session 1976 ended for server DRTSM01 (Windows).~
14:33:00.247 [39][output.c][7531][PutConsoleMsg]:ANR1404W Scratch volume mount request denied - mount failed.~
14:33:00.247 [39][asvolmnt.c][3334][AsOpenVol]:Signalling volOpenDone for (2179).
14:33:00.247 [39][asvolacq.c][4321][AsAcquireSdVol]:Mount failed, rc=3028, volP=00000000096F9410
14:33:00.247 [39][asvolacq.c][9663][FreeVolDesc]:Freeing volume descriptor 00000000096F9410()
14:33:00.247 [39][asvolacq.c][4386][AsAcquireSdVol]:Exit: rc=3011, *volPP=0000000000000000
14:33:04.950 [39][output.c][7531][PutConsoleMsg]:ANR0408I Session 1977 started for server DRTSM01 (Windows) (Tcp/Ip) for library sharing. ~
14:33:04.966 [39][output.c][7531][PutConsoleMsg]:ANR0409I Session 1977 ended for server DRTSM01 (Windows).~
14:33:04.966 [39][output.c][7531][PutConsoleMsg]:ANR4578E Database backup/restore terminated - required volume was not mounted.~
14:33:04.967 [16][asvolmnt.c][2228][AsMPAgent]:Mount point agent active.
14:33:04.967 [39][output.c][7531][PutConsoleMsg]:ANR0985I Process 212 for Database Backup running in the BACKGROUND completed with completion state FAILURE at 15:33:07.~
14:33:04.967 [39][output.c][7531][PutConsoleMsg]:ANR1893E Process 212 for Database Backup completed with a completion state of FAILURE.~
14:33:04.968 [16][asvolmnt.c][2309][AsMPAgent]:Mount point agent waiting.
14:33:28.969 [38][output.c][7531][PutConsoleMsg]:ANR2017I Administrator DRADMIN issued command: TRACE END ~
14:33:28.969 [38][trace.c][1853][TrEnd]:========================= ENDOFTRACE =======================

Open in new window


Like I mentioned, the library manager seems to try to use the scratch volume it mounts. updates it to 'private', 'dbbackup' and the owner as 'DRTSM01' but eventually fails and resets the volume back to scratch.
ASKER CERTIFIED SOLUTION
Avatar of John Pope
John Pope
Flag of United Kingdom of Great Britain and Northern Ireland image

Link to home
membership
This solution is only available to members.
To access this solution, you must be a member of Experts Exchange.
Start Free Trial