IBM Support

IC95899: API OBJECT RESTORE/RETRIEVE CORRUPTED REPORTING ANS1245E (RC150)ANS0238E (RC2041)

Subscribe

You can track all active APARs for this component.

APAR status

  • Closed as program error.

Error description

  • To meet this APAR condition, it is required that an API
    application, during backup or archive, estimates an object size
    greater than zero but then does not send data for the object.
    The symptom has been reported for objects managed by IBM
    Commonstore and IBM Content Collector for SAP (ICCSAP), but
    might be seen for other environments, too.
    
    When later using the Tivoli Storage Manager API to restore or
    retrieve objects managed by the server, in some situations the
    following messages might be observed upon restore/retrieve on
    the client side:
    ANS1245E (RC150)  The file has an unknown format.
    ANS0238E (RC2041) The sequence of calls is invalid.
    
    At the same time, the Tivoli Storage Manager server reports a
    message like the following:
    ANR9999D_3486536331 SmSendData(smtrans.c:1875) Thread<798>:
    Object header size mismatch, replacing ### with ###.
    
    In some situations, for example when the data has been imported,
    the messages above will not be reported.
    
    In all situations when the problem occurs the restored/retrieved
    file is corrupted by data being incorrectly inserted or deleted
    at the beginning of the object during the restore/retrieve. The
    file stored on the server remains fully intact.
    
      Customer/L2 Diagnostics (If Applicable) A server trace with
    traceflags "bf ss session sessiond" can be used to verify the
    APAR. The symptom is seen after processing a 0 byte length
    object. The following is the trace for the object that triggers
    the error condition:
    
    18:20:47.785
    [798][smnqr.c][2095][SmRetrieveBitfile]:Session(343) node(CSX)
    retrieving data for object(0.323805) length(0.0)
    18:20:47.785 [798][bfrtrv.c][465][bfRtrv]:bfRtrv: bfId: 323805
    .
    18:20:47.786 [798][sstrans.c][2005][ssRtrv]:Retrieving bitfile
    0.323805, offset=0.0, length=0.0, poolId=2, numSegs=1,
    format=22, mountWaitMode=1, estSize=0.542.
    .
    18:20:47.800 [798][sstrans.c][5336][SsIsValidFrame]:Validating
    frame header: Magic=0x53454652, Version=2, Hdrlen=32, SeqNum=1,
    Length=478, SrvId=0, SegGroupId=323805, CrcValue=0x00000000.
    18:20:47.800 [799][sstrans.c][10587][DoCloseSeg]:DoCloseSeg:
    Segment closed for srcStrategy 10.
    18:20:47.800 [798][sstrans.c][5712][RtrvFramed]:Rtrv new frame
    left = 478.
    18:20:47.800 [799][sstrans.c][8901][AuxAsSource]:Source waiting
    for final rd buf empty.
    18:20:47.800 [798][sstrans.c][5858][RtrvFramed]:Rtrv sending 478
    bytes to sinkFunc.
    18:20:47.801 [798][smtrans.c][1603][SmSendData]: (343)sending
    rc(0) dataPtr(4218a050) dataLen(478) rtrvLen(0.0)
     newRetrieve(1) sendPartialData(0) noQueryRestore(0)
    sendClientHdr(0)
     objectHeaderSize(478) verbHdrPushLen(0) objectHdrSkipped(0)
     -- lines removed for readability --
    18:20:47.803 [798][smtrans.c][1767][SmSendData]:(343)1a:
    hdrSegLen(4) verbHdrPushLen(4) skipped(0)
    18:20:47.803 [798][smtrans.c][1783][SmSendData]:(343)1:
    verbType(92) verbLen(478) verbSize(4)
    18:20:47.803 [798][smtrans.c][1844][SmSendData]:(343)1ca:
    objectHeaderSize(478) verbLen(478) verbType(92)
    18:20:47.803 [798][smtrans.c][1892][SmSendData]:(343)1cb: entire
    verb? dataLen(478) verbLen(478) objectHdrSkipped(0)
    verbBufSize(512)
    
    Notice the 478 header size for the object above, retrieving the
    next file that gets corrupted:
    
    18:20:47.857
    [798][smnqr.c][2095][SmRetrieveBitfile]:Session(343) node(CSX)
    retrieving data for object(0.323806) length(0.0)
    18:20:47.857 [798][bfrtrv.c][465][bfRtrv]:bfRtrv: bfId: 323806
    ..
    18:20:47.874 [798][sstrans.c][5581][RtrvFramed]:Rtrv thread
    received 926 bytes of data, offset 48.
    18:20:47.874 [799][sstrans.c][8792][AuxAsSource]:Source read 0
    bytes from segment.
    18:20:47.875 [798][sstrans.c][5590][RtrvFramed]:Amount left in
    buffer now 878.
    18:20:47.875 [799][sstrans.c][8886][AuxAsSource]:Source closing
    segment 1 of 1.
    18:20:47.875 [798][sstrans.c][5336][SsIsValidFrame]:Validating
    frame header: Magic=0x53454652, Version=2, Hdrlen=32, SeqNum=1,
    Length=814, SrvId=0, SegGroupId=323806, CrcValue=0x00000000.
    18:20:47.875 [799][sstrans.c][10587][DoCloseSeg]:DoCloseSeg:
    Segment closed for srcStrategy 10.
    18:20:47.875 [798][sstrans.c][5712][RtrvFramed]:Rtrv new frame
    left = 814.
    18:20:47.875 [799][sstrans.c][8901][AuxAsSource]:Source waiting
    for final rd buf empty.
    18:20:47.875 [798][sstrans.c][5858][RtrvFramed]:Rtrv sending 814
    bytes to sinkFunc.
    18:20:47.875 [798][smtrans.c][1603][SmSendData]: (343)sending
    rc(0) dataPtr(4218a050) dataLen(814) rtrvLen(0.0)
     newRetrieve(1) sendPartialData(0) noQueryRestore(0)
    sendClientHdr(0)
     objectHeaderSize(466) verbHdrPushLen(4) objectHdrSkipped(478)
     -- lines removed for readability --
     18:20:47.878 [798][smtrans.c][1767][SmSendData]:(343)1a:
    hdrSegLen(0) verbHdrPushLen(4) skipped(478)
    18:20:47.878 [798][smtrans.c][1783][SmSendData]:(343)1:
    verbType(92) verbLen(478) verbSize(4)
    18:20:47.878 [798][smtrans.c][1844][SmSendData]:(343)1ca:
    objectHeaderSize(466) verbLen(478) verbType(92)
    18:20:47.878
    [798][output.c][6404][PutConsoleMsg]:ANR9999D_3486536331
    SmSendData(smtrans.c:1875) Thread<798>: Object header size
    mismatch, replacing 466 with 478.
    18:20:47.878 [792][smtrans.c][846][SmSendVerb]:SmSendVerb: Verb
    AdmCmdResp - passing verbPtr 421842ec and encPtr 41a9c000.
    18:20:47.878 [798][output.c][6404][PutConsoleMsg]:ANR9999D
    Thread<798> issued message 9999 from:
    18:20:47.878
    [792][smtrans.c][6742][EncryptDecryptVerb]:EncryptDecryptVerb:
    Entry with verbPtr 421842ec, verbType f1, verbLen 130, hdrLen 4,
    op 0, encRetBuf 41a9c000, and sendPtr 42183f78.
    18:20:47.879 [798][output.c][6404][PutConsoleMsg]:ANR9999D
    Thread<798>  000000010000c888 StdPutText
    18:20:47.879
    [792][smtrans.c][6871][EncryptDecryptVerb]:EncryptDecryptVerb:
    Setting sendPtr to 421842ec.
    18:20:47.879 [798][output.c][6404][PutConsoleMsg]:ANR9999D
    Thread<798>  000000010000fc40 OutDiagToCons
    18:20:47.879 [798][output.c][6404][PutConsoleMsg]:ANR9999D
    Thread<798>  000000010000a370 outDiagfExt
    18:20:47.879 [792][smtrans.c][874][SmSendVerb]:SmSendVerb: Verb
    AdmCmdResp - sendPtr 421842ec after encrypt with original len
    130 and size 4 - newLen 0.
    18:20:47.879 [798][output.c][6404][PutConsoleMsg]:ANR9999D
    Thread<798>  00000001000ab848 SmSendData
    18:20:47.879 [798][output.c][6404][PutConsoleMsg]:ANR9999D
    Thread<798>  00000001003fff44 RtrvFramed
    18:20:47.879 [798][output.c][6404][PutConsoleMsg]:ANR9999D
    Thread<798>  00000001004065f8 ssRtrv
    18:20:47.880 [798][output.c][6404][PutConsoleMsg]:ANR9999D
    Thread<798>  00000001003219c4 DfRtrv
    18:20:47.880 [798][output.c][6404][PutConsoleMsg]:ANR9999D
    Thread<798>  00000001003ab3fc bfRtrv
    18:20:47.880 [798][output.c][6404][PutConsoleMsg]:ANR9999D
    Thread<798>  0000000100724dbc SmRetrieveBitfile
    18:20:47.880 [798][output.c][6404][PutConsoleMsg]:ANR9999D
    Thread<798>  00000001001f8b14 SmDoObjRtrv
    18:20:47.880 [798][output.c][6404][PutConsoleMsg]:ANR9999D
    Thread<798>  00000001001ff2dc SmNodeSession
    18:20:47.880 [798][output.c][6404][PutConsoleMsg]:ANR9999D
    Thread<798>  000000010069b010 HandleNodeSession
    18:20:47.880 [798][output.c][6404][PutConsoleMsg]:ANR9999D
    Thread<798>  000000010069ee40 DoNodeGeneral
    18:20:47.881 [798][output.c][6404][PutConsoleMsg]:ANR9999D
    Thread<798>  00000001006a0bb4 smExecuteSession
    18:20:47.881 [798][output.c][6404][PutConsoleMsg]:ANR9999D
    Thread<798>  000000010005ee40 psSessionThread
    18:20:47.881 [798][output.c][6404][PutConsoleMsg]:ANR9999D
    Thread<798>  000000010001515c StartThread
    18:20:47.881 [798][smtrans.c][1892][SmSendData]:(343)1cb: entire
    verb? dataLen(814) verbLen(478) objectHdrSkipped(478)
    verbBufSize(512)
    18:20:47.881 [798][smtrans.c][2183][SmSendData]:(343)1ci: recalc
    verbSegLen(0) verbLen(478) skipped(478) dataLen(814)
    dataPtr(4218a050)
    18:20:47.881 [798][smtrans.c][2311][SmSendData]:(343)header
    sent:  dataPtr(4218a050) dataLen(814) noQueryState(0)
    partialRtrv(0) partialData(0)
    ..
    18:20:47.882 [798][smtrans.c][2481][SmSendData]:Send Verb:
    Session 343, Length=818, Code=0007, Type=Data.
    
    Notice above that the verb object header sizes are left over
    from the previous object:
    verbLen(478) objectHdrSkipped(478), however objectHdrSkipped
    should be 0 initially and verbLen should be 466 here.
    
    Tivoli Storage Manager Versions Affected: V5.5 V6.1 V6.2
    
      Initial Impact: Medium
      Additional Keywords: TSM 69774
    

Local fix

  • restore/retrieve objects individually
    

Problem summary

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

Problem conclusion

  • This problem was fixed.
    
    Affected platforms:  AIX, HP-UX, Solaris, Linux, and Windows.
    

Temporary fix

Comments

APAR Information

  • APAR number

    IC95899

  • Reported component name

    TSM SERVER

  • Reported component ID

    5698ISMSV

  • Reported release

    55A

  • Status

    CLOSED PER

  • PE

    NoPE

  • HIPER

    NoHIPER

  • Special Attention

    NoSpecatt / Xsystem

  • Submitted date

    2013-09-12

  • Closed date

    2013-09-26

  • Last modified date

    2016-07-26

  • 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

  • R55A PSY

       UP

  • R55H PSY

       UP

  • R55L PSY

       UP

  • R55S PSY

       UP

  • R55W PSY

       UP

  • R61A PSY

       UP

  • R61H PSY

       UP

  • R61L PSY

       UP

  • R61S PSY

       UP

  • R61W PSY

       UP

  • R62A PSY

       UP

  • R62H PSY

       UP

  • R62L PSY

       UP

  • R62S PSY

       UP

  • R62W PSY

       UP



Document information

More support for: Tivoli Storage Manager

Software version: 55A

Reference #: IC95899

Modified date: 26 July 2016