IC92745: A RE-OPEN OF A DRIVE MAY FAIL WITH ANR9999D MESSAGES AFTER A SUCCESSFUL RESERVATION CHECK

IBM Tivoli Storage Manager V6.3 Fix Pack 5 (6.3.5.000) Server Downloads

APAR status

• Closed as program error.

Error description

• A re-open of a tape drive may fail with ANR9999D messages after
  a successful reservation check. This reservation check is
  failing to detect that the drive is reserved.
  
  Customer/L2 Diagnostics :
  Here is an example of a MOVE DATA after a restart of the
  library manager and library client.
  
  Actlog from the library client:
  
   ANR4743W An insufficient number of mount points are available
            in device class DC_JAG. (SESSION: 7, PROCESS: 2)
   ANR1145W Move data process terminated for volume VOL001 -
            insufficient number of mount points available for
            removable media. (SESSION: 7, PROCESS: 2)
   ANR0985I Process 2 for MOVE DATA running in the BACKGROUND
            completed with completion state FAILURE at 15:19:45.
            (SESSION: 7, PROCESS: 2)
   ANR1893E Process 2 for MOVE DATA completed with a completion
            state of FAILURE. (SESSION: 7, PROCESS: 2)
  
  
  Actlog on the library manager:
  
   ANR8311E An I/O error occurred while accessing drive JAG01
            (\\.\Tape1001) for RESERVE operation, errno = 0,
            rc = 2845. (SESSION: 3)
   ANR1626I The previous message (message number 8311) was
            repeated 1 times.
   ANR8779E Unable to open drive \\.\Tape1001, error
            number= 68912. (SESSION: 3)
   ANR8311E An I/O error occurred while accessing drive JAG01
            (\\.\Tape1001) for SETMODE operation, errno = 6,
            rc = 1. (SESSION: 3)
   ANR9999D_3254895215 ErrorHandler(pvrntp.c:8381) Thread<37>:
            Unexpected RC=1, VOL=NULL, DRIVE=JAG01 (\\.\Tape1001)
            (SESSION: 3)
   ANR9999D Thread<37> issued message 9999 from: (SESSION: 3)
   ANR9999D Thread<37>  000007FEF3FEBC89 OutDiagToCons()+159
   ANR9999D Thread<37>  000007FEF3FE580A outDiagfExt()+11a
   ANR9999D Thread<37>  000007FEF411E9EA NtpBuildTapePos()+124a
   ANR9999D Thread<37>  000007FEF411D2A1 NtpReadLabel()+151
   ANR9999D Thread<37>  000007FEF3C8CA88
  PvrCompatibleDevclass()+26c8
   ANR9999D Thread<37>  000007FEF3C904F3 PvrQueryMpDetailed()+d63
   ANR9999D Thread<37>  000007FEF3C90796 PvrQueryMpDetailed()+1006
   ANR9999D Thread<37>  000007FEF3C92459
  PvrSyncDismountVolume()+669
   ANR9999D Thread<37>  000007FEF37D6384 startThread()+124
   ANR9999D Thread<37>  00000000745E1D9F endthreadex()+43
   ANR9999D Thread<37>  00000000745E1E3B endthreadex()+df
   ANR9999D Thread<37>  00000000779E652D BaseThreadInitThunk()+d
   ANR9999D Thread<37>  0000000077C1C521 RtlUserThreadStart()+21
   ANR8355E I/O error reading label for volume VOL001 in drive
            JAG01 (\\.\Tape1001). (SESSION: 3)
   ANR8311E An I/O error occurred while accessing drive JAG01
            (\\.\Tape1001) for RESERVE operation, errno = 0,
            rc = 2845.
   ANR1626I The previous message (message number 8311) was
            repeated 2 times.
   ANR8779E Unable to open drive \\.\Tape1001,
            error number= 68424.
  
  later:
  
   ANR8331I 3592 volume VOL001 is mounted R/O in drive
    JAG01 (\\.\Tape1001), status: DISMOUNTING. (SESSION: 20)
  
   ANR8331I 3592 volume VOL001 is mounted R/O in drive
   JAG01 (\\.\Tape1001), status: DISMOUNTING. (SESSION: 19)
  
   ANR8468I 3592 volume VOL001 dismounted from drive
    JAG01 (\\.\Tape1001) in library LIB001.
   ANR8311E An I/O error occurred while accessing drive
    JAG2_RZ01-02 (\\.\Tape4801104) for RESERVE operation,
    errno = 0, rc = 2845. (SESSION: 3)
  
  again the error ANR9999D_3254895215 ...
  
   ANR9790W Request to mount volume VOL001 for library
    client LC3 failed. (SESSION: 98)
  
  
  This is an example from a server trace with the traceflag PVR
  
   [46][pvr.c][6319][PvrOpenTapeDrive]:Drive JAG01, handle 68912,
       checktapeId returned rc = 2845.
   [46][output.c][7271][PutConsoleMsg]:ANR8779E Unable to open
       drive \\.\Tape1001, error number= 68912.~
   [46][pvrmp.c][8846][MgrGetIdleVol]:Open failed for JA01 devName
       \\.\Tape1001 will check reservation
  
  -> Checking the Reservation
  
   [46][pspvr.c][3275][PvrPsOpenDevice]:Opening device
       \\.\Tape1001 with nonDelay = 1, accessMode = 0
   [46][pspvr.c][3285][PvrPsOpenDevice]:Open with passthru? 0
   [46][pspvr.c][3472][PvrPsOpenDevice]:Device \\.\Tape1001 is
       opened with handle 0000000000010D30
   [46][pvrutil.c][712][PvrOpenDevice]:Attempted to open device
       \\.\Tape1001, 1 time(s), rc = 0.
  
  -> It's not reserved, the server then closes the file handle
     used to check the reservation>
  
   [46][pspvr.c][3594][PvrPsCloseDevice]:Device with handle
       0000000000010D30 is closed
  
  -> Here it returns rc=0 on the reserve check when the drive is
     really reserved
  
   [46][pspvr.c][3606][PvrPsCloseDevice]:Removing device
       \\.\Tape1001 with handle 68912 from devList
  
  -> The server tries to read the label on a closed file handle
  
   [46][pvrntp.c][5223][NtpReadLabel]:Reading label from volume in
       drive JAG01 (\\.\Tape1001).
  
  Additional:
  The ANR8779E error message has at the end the handle number as
  error number like:
  
    ANR8779E Unable to open drive \\.\Tape1001,
             error number= 68912.
  
  This will be also fixed here.
  
  | MDVREGR 6.3.1.000 -TIV_5698MSV |
  
  Tivoli Storage Manager Versions Affected:
  Tivoli Storage Manager Server version  6.3.1. or later on
  Windows
  
  Initial Impact:
  medium
  
  Additional Keywords:
  TSM zz63 LM LC handle IC89826
  

Local fix

• A tape drive reset should clear the condition,
  or resetting the reservation using
  - for IBM devices: ITDT tool.
  - for non-IBM devices: mttest tool.
  

Problem summary

• ****************************************************************
  * USERS AFFECTED: All Tivoli Storage Manager server users of   *
  *                 IBM drives.                                  *
  ****************************************************************
  * PROBLEM DESCRIPTION: All Tivoli Storage Manager server       *
  *                      users of IBM drives.                    *
  ****************************************************************
  * RECOMMENDATION: Apply fixing level when available. This      *
  *                 problem is currently projected to be fixed   *
  *                 in levels 6.3.4.100 and 6.3.5. Note that     *
  *                 this is subject to change at the discretion  *
  *                 of IBM.                                      *
  ****************************************************************
  *
  

Problem conclusion

• This problem was fixed.
  Affected platforms:  Windows.
  

Temporary fix

Comments

APAR Information

• APAR is sysrouted FROM one or more of the following:

• APAR is sysrouted TO one or more of the following:

Fix information

• Fixed component name

  TSM SERVER

• Fixed component ID

  5698ISMSV

Applicable component levels

• R63W PSY

     UP