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

Fixes are available

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

[{"Business Unit":{"code":"BU059","label":"IBM Software w\/o TPS"},"Product":{"code":"SSEQTP","label":"WebSphere Application Server"},"Platform":[{"code":"PF025","label":"Platform Independent"}],"Version":"8.5","Line of Business":{"code":"LOB45","label":"Automation"}}]

Document Information

Modified date:
28 April 2022

Tips

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

Fixes are available

Subscribe

APAR status

Closed as program error.

Error description

Local fix

Problem summary

Problem conclusion

Temporary fix

Comments

APAR Information

APAR number

Reported component name

Reported component ID

Reported release

Status

PE

HIPER

Special Attention

Submitted date

Closed date

Last modified date

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

Fixed component ID

Applicable component levels

R850 PSY

Document Information

Share your feedback

Need support?