IBM Support

PI45227: SESSION DATA IS RETURNED AFTER A FULL 5 SECOND DRS TIMEOUT

Subscribe

You can track all active APARs for this component.

APAR status

  • Closed as program error.

Error description

  • The issue is a request for a session timed out but the session
    was returned.  The thread that received the get response
    notified the DRS object that the response was received but the
    thread that waits on the response had not yet started waiting.
    
    This thread sends the request and does a wait for 5 secs:
    
    [6/24/15 18:47:45:813 CEST] 000000a9 DRSGroup      <
    send(destination[]): Exit.  Exit
    .
    .
    [6/24/15 18:47:45:819 CEST] 000000a9 DRSActionStat >
    updateMessageStats Entry. Entry
    [6/24/15 18:47:45:822 CEST] 000000a9 DRSActionStat 3
    updateMessageStats stats logging not enabled
    [6/24/15 18:47:45:822 CEST] 000000a9 DRSActionStat <
    updateMessageStats Exit. Exit
    [6/24/15 18:47:45:822 CEST] 000000a9 DRSSyncGet    3
    processSendMessage: Waiting for a response. timeout=5000
    ****
    The wait happens between these 2 trace statements.
    ****
    [6/24/15 18:47:50:822 CEST] 000000a9 DRSSyncGet    3
    processSendMessage: Awakened after waiting for a response for
    DRSCacheMsgImpl=
    
    This thread receives the response, deserializes and calls
    notify on the waiting object:
    
    [6/24/15 18:47:45:820 CEST] 000000a5 DRSThreadTask >
    Domain/messageReceived/run:  Processing received dcm through
    domain. task=-1405407181 Entry
    [6/24/15 18:47:45:820 CEST] 000000a5 DRSMessageHel >
    extractDCM: Entry. message.length=740 Entry
    [6/24/15 18:47:45:820 CEST] 000000a5 DRSMessageHel 3
    extractDCM: Converting.
    [6/24/15 18:47:45:820 CEST] 000000a5 WASSession    1
    BackedSession setCreationTime creationTime= 1435164254434
    [6/24/15 18:47:45:820 CEST] 000000a5 WASSessionCor 1
    MemorySession updateLastAccessTime 1435164454703
    [6/24/15 18:47:45:820 CEST] 000000a5 WASSessionCor 1
    MemorySession setIsValid New Value=true; Old Value=true
    [6/24/15 18:47:45:820 CEST] 000000a5 WASSessionCor 1
    MemorySession setIsNew New Value=false; Old Value=true
    [6/24/15 18:47:45:820 CEST] 000000a5 WASSessionCor 1
    MemorySession setVersion New Value=1; Old Value=1
    [6/24/15 18:47:45:820 CEST] 000000a5 DRSMessageHel <
    extractDCM: Exit.
    dcm=DRSCacheMsgImpl=
    .
    .
    [6/24/15 18:47:45:821 CEST] 0000002d DRSSyncGet    3
    processRcvMessage: Calling notify. Got a response object.
    waitingDCM=DRSCacheMsgImpl=
    
    The problem is the notify happens before (18:47:45:821) the
    other thread
    invokes wait (18:47:45:822) and therefore ends up waiting for
    the entire
    response timeout.
    
    This thread receives the response, deserializes and calls
    notify on the waiting object:
    [6/24/15 18:47:45:820 CEST] 000000a5 DRSThreadTask >
    Domain/messageReceived/run:  Processing received dcm through
    domain.
    task=-1405407181 Entry
    [6/24/15 18:47:45:820 CEST] 000000a5 DRSMessageHel >
    extractDCM: Entry.
    message.length=740 Entry
    [6/24/15 18:47:45:820 CEST] 000000a5 DRSMessageHel 3
    extractDCM:
    Converting.
    [6/24/15 18:47:45:820 CEST] 000000a5 WASSession    1
    BackedSession
    setCreationTime creationTime= 1435164254434
    [6/24/15 18:47:45:820 CEST] 000000a5 WASSessionCor 1
    MemorySession
    updateLastAccessTime 1435164454703
    [6/24/15 18:47:45:820 CEST] 000000a5 WASSessionCor 1
    MemorySession
    setIsValid New Value=true; Old Value=true
    [6/24/15 18:47:45:820 CEST] 000000a5 WASSessionCor 1
    MemorySession
    setIsNew New Value=false; Old Value=true
    [6/24/15 18:47:45:820 CEST] 000000a5 WASSessionCor 1
    MemorySession
    setVersion New Value=1; Old Value=1
    [6/24/15 18:47:45:820 CEST] 000000a5 DRSMessageHel <
    extractDCM: Exit.
    dcm=DRSCacheMsgImpl=
    .
    .
    [6/24/15 18:47:45:821 CEST] 0000002d DRSSyncGet    3
    processRcvMessage: Calling notify. Got a response object.
    waitingDCM=DRSCacheMsgImpl=
    
    The problem is the notify happens before (18:47:45:821) the
    other thread invokes wait (18:47:45:822) and therefore ends up
    waiting for the entire response timeout.
    

Local fix

Problem summary

  • ****************************************************************
    * USERS AFFECTED:  All users of IBM WebSphere Application      *
    *                  Server Data Replication Services (DRS).     *
    ****************************************************************
    * PROBLEM DESCRIPTION: Synchronous gets from replication may   *
    *                      timeout but still return the            *
    *                      requested data.                         *
    ****************************************************************
    * RECOMMENDATION:                                              *
    ****************************************************************
    The requesting thread sets the timeout after the response is
    received by another thread.
    

Problem conclusion

  • The requesting thread will only set a timeout if a response is
    not already received.
    
    The fix for this APAR is currently targeted for inclusion in
    fix pack 7.0.0.39, 8.0.0.12 and 8.5.5.8.  Please refer to the
    Recommended Updates page for delivery information:
    
    http://www.ibm.com/support/docview.wss?rs=180&uid=swg27004980
    

Temporary fix

Comments

APAR Information

  • APAR number

    PI45227

  • Reported component name

    WEBSPHERE APP S

  • Reported component ID

    5724J0800

  • Reported release

    850

  • Status

    CLOSED PER

  • PE

    NoPE

  • HIPER

    NoHIPER

  • Special Attention

    NoSpecatt / Xsystem

  • Submitted date

    2015-07-17

  • Closed date

    2015-07-28

  • Last modified date

    2015-07-30

  • 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

    WEBSPHERE APP S

  • Fixed component ID

    5724J0800

Applicable component levels

  • R850 PSY

       UP



Document information

More support for: WebSphere Application Server
General

Software version: 850

Reference #: PI45227

Modified date: 30 July 2015