This discussion is archived
2 Replies Latest reply: Aug 10, 2012 2:09 PM by user3693508 RSS

SAF Agent forwards the message but the message never reaches the detination

user3693508 Newbie
Currently Being Moderated
We have a SAF Agent configured on WLS 9.2(MP3). Oracle's Order Service Mananment(OSM 6.3.1) application is running on this server. The SAF Agent dispatches JMS messages to a remote destination on another WLS 9.2(MP3) which is received by Oracle's Unified Inventory Management Application(UIM 7.1.2).

When OSM send a SOAP request over JMS to UIM destination, the SAF Agent seems to have forwarded the messages but the messages never reached their destination and the sending application keeps waiting for te response message indefinitely.

Below is the excerpt from the SAF logs:

####<Oct 9, 2012 9:06:09 AM CDT> <BEA1-02A2C50491E0E3977E19-574C53746F72655F64657630355F6F736D5F75696D5F7361665F66696C6573746F7265> <> <1349791569774> <619141> <ID:<392780.1349791569737.0>> <15024:1.0.0:Send_UIM_To_Query_MDN:3057986> <SAF_UIM_Module!SAF_UIM_Imported_Destinations!inventoryWSQueue@UIM_SAF_AGENT@osmdev05> <*Stored*> <oms-automation> <> <&lt;?xml version="1.0" encoding="UTF-8"?&gt;
&lt;mes:WLJMSMessage xmlns:mes="http://www.bea.com/WLS/JMS/Message"&gt;&lt;mes:Header&gt;&lt;mes:JMSCorrelationID&gt;15024:1.0.0:Send_UIM_To_Query_MDN:3057986&lt;/mes:JMSCorrelationID&gt;&lt;mes:JMSDeliveryMode&gt;PERSISTENT&lt;/mes:JMSDeliveryMode&gt;&lt;mes:JMSExpiration&gt;0&lt;/mes:JMSExpiration&gt;&lt;mes:JMSPriority&gt;5&lt;/mes:JMSPriority&gt;&lt;mes:JMSReplyTo&gt;&lt;mes:Destination name="SAF_UIM_Module!uim_response_queue" serverName="osm_uim_saf_jms_server" applicationName="SAF_UIM_Module" moduleName=""/&gt;&lt;/mes:JMSReplyTo&gt;&lt;mes:Properties/&gt;&lt;/mes:Header&gt;&lt;mes:Body&gt;&lt;mes:Text&gt;&lt;?xml version=&quot;1.0&quot; encoding=&quot;UTF-8&quot;?&gt;&lt;soapenv:Envelope xmlns:soapenv=&quot;http://schemas.xmlsoap.org/soap/envelope/&quot; xmlns:com=&quot;http://xmlns.oracle.com/communications/inventory/webservice/common&quot;&gt;&lt;soapenv:Header&gt;&lt;wsse:Security xmlns:wsse=&quot;http://docs.oasis-open.org/wss/2004/01/oasis-200401-wss-wssecurity-secext-1.0.xsd&quot; soapenv:mustUnderstand=&quot;1&quot;&gt;&lt;wsse:UsernameToken&gt;&lt;wsse:Username&gt;OSM_Integration&lt;/wsse:Username&gt;&lt;wsse:Password&gt;ApexOsmAdmin&lt;/wsse:Password&gt;&lt;/wsse:UsernameToken&gt;&lt;/wsse:Security&gt;&lt;/soapenv:Header&gt;&lt;soapenv:Body&gt;&lt;telephoneNumberRequest xmlns=&quot;http://xmlns.oracle.com/communications/inventory/webservice/telephone&quot;&gt;&lt;com:header&gt;string&lt;/com:header&gt;&lt;com:requestContext&gt;&lt;com:businessInteractionId&gt;string&lt;/com:businessInteractionId&gt;&lt;com:messageConfirmation&gt;ignore&lt;/com:messageConfirmation&gt;&lt;/com:requestContext&gt;&lt;telephoneNumber xmlns=&quot;&quot;&gt;1982440015&lt;/telephoneNumber&gt;&lt;/telephoneNumberRequest&gt;&lt;/soapenv:Body&gt;&lt;/soapenv:Envelope&gt;&lt;/mes:Text&gt;&lt;/mes:Body&gt;&lt;/mes:WLJMSMessage&gt;> <>

####<Oct 9, 2012 9:06:09 AM CDT> <> <> <1349791569785> <282842> <ID:<392780.1349791569737.0>> <15024:1.0.0:Send_UIM_To_Query_MDN:3057986> <SAF_UIM_Module!SAF_UIM_Imported_Destinations!inventoryWSQueue@UIM_SAF_AGENT@osmdev05> <Forwarded> <<WLS Kernel>> <> <&lt;?xml version="1.0" encoding="UTF-8"?&gt;
&lt;mes:WLJMSMessage xmlns:mes="http://www.bea.com/WLS/JMS/Message"&gt;&lt;mes:Header&gt;&lt;mes:JMSCorrelationID&gt;15024:1.0.0:Send_UIM_To_Query_MDN:3057986&lt;/mes:JMSCorrelationID&gt;&lt;mes:JMSDeliveryMode&gt;PERSISTENT&lt;/mes:JMSDeliveryMode&gt;&lt;mes:JMSExpiration&gt;0&lt;/mes:JMSExpiration&gt;&lt;mes:JMSPriority&gt;5&lt;/mes:JMSPriority&gt;&lt;mes:JMSReplyTo&gt;&lt;mes:Destination name="SAF_UIM_Module!uim_response_queue" serverName="osm_uim_saf_jms_server" applicationName="SAF_UIM_Module" moduleName=""/&gt;&lt;/mes:JMSReplyTo&gt;&lt;mes:Properties/&gt;&lt;/mes:Header&gt;&lt;mes:Body&gt;&lt;mes:Text&gt;&lt;?xml version=&quot;1.0&quot; encoding=&quot;UTF-8&quot;?&gt;&lt;soapenv:Envelope xmlns:soapenv=&quot;http://schemas.xmlsoap.org/soap/envelope/&quot; xmlns:com=&quot;http://xmlns.oracle.com/communications/inventory/webservice/common&quot;&gt;&lt;soapenv:Header&gt;&lt;wsse:Security xmlns:wsse=&quot;http://docs.oasis-open.org/wss/2004/01/oasis-200401-wss-wssecurity-secext-1.0.xsd&quot; soapenv:mustUnderstand=&quot;1&quot;&gt;&lt;wsse:UsernameToken&gt;&lt;wsse:Username&gt;OSM_Integration&lt;/wsse:Username&gt;&lt;wsse:Password&gt;ApexOsmAdmin&lt;/wsse:Password&gt;&lt;/wsse:UsernameToken&gt;&lt;/wsse:Security&gt;&lt;/soapenv:Header&gt;&lt;soapenv:Body&gt;&lt;telephoneNumberRequest xmlns=&quot;http://xmlns.oracle.com/communications/inventory/webservice/telephone&quot;&gt;&lt;com:header&gt;string&lt;/com:header&gt;&lt;com:requestContext&gt;&lt;com:businessInteractionId&gt;string&lt;/com:businessInteractionId&gt;&lt;com:messageConfirmation&gt;ignore&lt;/com:messageConfirmation&gt;&lt;/com:requestContext&gt;&lt;telephoneNumber xmlns=&quot;&quot;&gt;1982440015&lt;/telephoneNumber&gt;&lt;/telephoneNumberRequest&gt;&lt;/soapenv:Body&gt;&lt;/soapenv:Envelope&gt;&lt;/mes:Text&gt;&lt;/mes:Body&gt;&lt;/mes:WLJMSMessage&gt;> <>


Below is the except from the server log:

####<Oct 9, 2012 9:06:09 AM CDT> <Info> <oms> <con02bl28.mtsallstream.com> <osmdev05> <ExecuteThread: '48' for queue: 'oms.automation'> <oms-automation> <BEA1-02A2C50491E0E3977E19> <> <1349791569728> <000000> <plugin.XSLTSender: telephoneNumberRequest : ********** Starting... **********>
####<Oct 9, 2012 9:06:09 AM CDT> <Info> <oms> <con02bl28.mtsallstream.com> <osmdev05> <ExecuteThread: '48' for queue: 'oms.automation'> <oms-automation> <BEA1-02A2C50491E0E3977E19> <> <1349791569729> <000000> <plugin.XSLTSender: telephoneNumberRequest - OrderId: 15024 - Adding OSM Correlator: 15024:1.0.0:Send_UIM_To_Query_MDN:3057986>
####<Oct 9, 2012 9:06:09 AM CDT> <Info> <oms> <con02bl28.mtsallstream.com> <osmdev05> <ExecuteThread: '48' for queue: 'oms.automation'> <oms-automation> <BEA1-02A2C50491E0E3977E19> <> <1349791569730> <000000> <plugin.XSLTSender: telephoneNumberRequest : Completed.>
####<Oct 9, 2012 9:06:09 AM CDT> <Info> <JMS> <con02bl28.mtsallstream.com> <osmdev05> <[STANDBY] ExecuteThread: '4' for queue: 'weblogic.kernel.Default (self-tuning)'> <<WLS Kernel>> <> <> <1349791569785> <BEA-040507> <The JMS SAF forwarder failed to connect to the remote destination "t3://convm2002:7001/inventoryWSQueue", because of java.lang.Exception: SAF refresh interval elapsed
     at weblogic.jms.forwarder.Forwarder$Subforwarder.pushMessages(Forwarder.java:804)
     at weblogic.messaging.util.DeliveryList.run(DeliveryList.java:256)
     at weblogic.work.ServerWorkManagerImpl$WorkAdapterImpl.run(ServerWorkManagerImpl.java:518)
     at weblogic.work.ExecuteThread.execute(ExecuteThread.java:209)
     at weblogic.work.ExecuteThread.run(ExecuteThread.java:181)
.>
####<Oct 9, 2012 9:06:09 AM CDT> <Info> <JMS> <con02bl28.mtsallstream.com> <osmdev05> <[ACTIVE] ExecuteThread: '2' for queue: 'weblogic.kernel.Default (self-tuning)'> <<WLS Kernel>> <> <> <1349791569804> <BEA-040506> <The JMS SAF forwarder has successfully connected to the remote destination "t3://convm2002:7001/inventoryWSQueue".>


Now as per an SR we had raised earlier with Oracle regarding this SAF issue, we already applied a patch "VCIS" to both OSM and UIM WLSs. We checked for network connectivity between the 2 boxes and they look good too. Also if we change the RemotContext to point to another UIM environment, the SAF messages seem to reach the remote destination of the that server. The WL patches have been applied in all environments OSM as well as UIM. Here is the list of applied patches:

OSM:
/home/weblogic/bea/utils/bsu>./bsu.sh -prod_dir=/home/weblogic/bea/weblogic92 -verbose -view -status=applied

ProductName: WebLogic Platform
ProductVersion: 9.2 MP3
Components: WebLogic Platform/WebLogic Server,WebLogic Platform/Workshop
for WebLogic Platform
BEAHome: /home/weblogic/bea
ProductHome: /home/weblogic/bea/weblogic92
PatchSystemDir: /home/weblogic/bea/utils/bsu
PatchDir: /home/weblogic/bea/patch_weblogic923
Profile: Default
DownloadDir: /home/weblogic/bea/utils/bsu/cache_dir


Patch ID: HBP3
PatchContainer: HBP3.jar
Checksum: -2044063729
Severity: optional
Category: J2EE
CR/BUG:
Restart: true
Description: Add supported descriptor to specify user identity for applif
ecyclelisteners

Patch ID: VCIS
PatchContainer: VCIS.jar
Checksum: -1381357176
Severity: optional
Category: JMS
CR/BUG: 8193293,8328101,8872943,8465123,8178640,8170982,8175621,8174786
Restart: true
Description: Merge Request - MLR Bug11925885

====================================================================================
UIM:
[weblogic@convm2002 UIM bsu]$ ./bsu.sh -prod_dir=/home/weblogic/appServer/uimfb/bea/weblogic92 -verbose -view -status=applied
ProductName: WebLogic Platform
ProductVersion: 9.2 MP3
Components: WebLogic Platform/WebLogic Server,WebLogic Platform/Workshop
for WebLogic Platform
BEAHome: /home/weblogic/appServer/uimfb/bea
ProductHome: /home/weblogic/appServer/uimfb/bea/weblogic92
PatchSystemDir: /home/weblogic/appServer/uimfb/bea/utils/bsu
PatchDir: /home/weblogic/appServer/uimfb/bea/patch_weblogic923
Profile: Default
DownloadDir: /home/weblogic/appServer/uimfb/bea/utils/bsu/cache_dir


Patch ID: 2LYV
PatchContainer: 2LYV.jar
Checksum: -2134691467
Severity: optional
Category: Web App
CR:
Restart: true
Description: CPUJuly2009 Advisory Fix

Patch ID: KVI2
PatchContainer: KVI2.jar
Checksum: -2127922697
Severity: optional
Category: Web App
CR:
Restart: true
Description: Advisory: Source code disclosure in WebLogic Server web page
s

Patch ID: RDKF
PatchContainer: RDKF.jar
Checksum: -1172180244
Severity: optional
Category: Web App
CR:
Restart: true
Description: Advisory: Elevation of privilege vulnerability in WebLogic S
erver

Patch ID: TRY5
PatchContainer: TRY5.jar
Checksum: 138660860
Severity: optional
Category: Web Services
CR:
Restart: true
Description: CPUJuly2009 Advisory fix

Patch ID: VCIS
PatchContainer: VCIS.jar
Checksum: -1381357176
Severity: optional
Category: JMS
CR: 8193293,8328101,8872943,8465123,8178640,8170982,8175621,8174786
Restart: true
Description: Merge Request - MLR Bug11925885

Also we have followed the steps mentioned in this Support Document 1337247.1 (OSM-UIM Integration. SAF Forwarder Fails to Reconnect When One of End Points Goes Down.) which can be found at: https://support.oracle.com/epmos/faces/ui/km/DocumentDisplay.jspx?id=1337247.1

Appreciate if someone can explain the weird behaviour of the WL Servers. Why is it that SAF Agent able to forward the same message to another WLS but not the one with which we intend it to communicate with?

Regards,
Avinash
  • 1. Re: SAF Agent forwards the message but the message never reaches the detination
    653697 Journeyer
    Currently Being Moderated
    One possibility is that the history records between the sending side and the remote side do not match. Say for some reason the sending side store is cleaned up while the remote side store stays. When this happens, the sending side will send messages with sequence numbers that are smaller than the history record on the remote side. As a result the messages are considered duplicate and dropped when they reach the remote side. I believe patch VCIS should help for a scenario like this. You can verify this by enabling JMSSAF debugging (-Dweblogic.debug.DebugJMSSAF=true). You need to check:
    1. if the sequence name has a timestamp appended at the end
    2. if any messages are dropped because that they are determined to be duplicate.

    Hope this helps.
  • 2. Re: SAF Agent forwards the message but the message never reaches the detination
    user3693508 Newbie
    Currently Being Moderated
    Hi,

    Thank You for your reply. As suggested, I enabled JMSSAF debugging. The log below is from the instance when SAF Agent tries to forward JMS message generated by OSM application to WLS running the UIM application.

    *####<Oct 10, 2012 3:42:29 PM CDT> <Debug> <JMSSAF> <con02bl28.mtsallstream.com> <osmdev05> <[STANDBY] ExecuteThread: '6' for queue: 'weblogic.kernel.Default (self-tuning)'> <<WLS Kernel>> <> <> <1349901749620> <000000> <Forwarder is trying to forward the message <786163.1349901749574.0>ddExactlyOnceForwardHelper= null>*
    *####<Oct 10, 2012 3:42:29 PM CDT> <Debug> <JMSSAF> <con02bl28.mtsallstream.com> <osmdev05> <[STANDBY] ExecuteThread: '6' for queue: 'weblogic.kernel.Default (self-tuning)'> <<WLS Kernel>> <> <> <1349901749621> <000000> <Forwarder is trying to forward the message with id <786163.1349901749574.0> to MSLV WS!inventoryWSQueue>*
    *####<Oct 10, 2012 3:42:29 PM CDT> <Debug> <JMSSAF> <con02bl28.mtsallstream.com> <osmdev05> <[STANDBY] ExecuteThread: '6' for queue: 'weblogic.kernel.Default (self-tuning)'> <<WLS Kernel>> <> <> <1349901749629> <000000> <needsSchedule= false isExactlyOnceDDForwarding false>*####<Oct 10, 2012 3:42:29 PM CDT> <Info> <JMS> <con02bl28.mtsallstream.com> <osmdev05> <[STANDBY] ExecuteThread: '6' for queue: 'weblogic.kernel.Default (self-tuning)'> <<WLS Kernel>> <> <> <1349901749641> <BEA-040507> <The JMS SAF forwarder failed to connect to the remote destination "t3://convm2002:7001/inventoryWSQueue", because of java.lang.Exception: SAF refresh interval elapsed
    at weblogic.jms.forwarder.Forwarder$Subforwarder.pushMessages(Forwarder.java:804)
    at weblogic.messaging.util.DeliveryList.run(DeliveryList.java:256)
    at weblogic.work.ServerWorkManagerImpl$WorkAdapterImpl.run(ServerWorkManagerImpl.java:518)
    at weblogic.work.ExecuteThread.execute(ExecuteThread.java:209)
    at weblogic.work.ExecuteThread.run(ExecuteThread.java:181)
    .>
    *####<Oct 10, 2012 3:42:29 PM CDT> <Debug> <JMSSAF> <con02bl28.mtsallstream.com> <osmdev05> <[ACTIVE] ExecuteThread: '2' for queue: 'weblogic.kernel.Default (self-tuning)'> <<WLS Kernel>> <> <> <1349901749651> <000000> <Forwarder reconnect(): remoteInitialCtx= null>*
    *####<Oct 10, 2012 3:42:29 PM CDT> <Debug> <JMSSAF> <con02bl28.mtsallstream.com> <osmdev05> <[ACTIVE] ExecuteThread: '2' for queue: 'weblogic.kernel.Default (self-tuning)'> <<WLS Kernel>> <> <> <1349901749651> <000000> <Forwarder connectTarget()>*
    *####<Oct 10, 2012 3:42:29 PM CDT> <Debug> <JMSSAF> <con02bl28.mtsallstream.com> <osmdev05> <[ACTIVE] ExecuteThread: '2' for queue: 'weblogic.kernel.Default (self-tuning)'> <<WLS Kernel>> <> <> <1349901749651> <000000> <Retry for 't3://convm2002:7001' on behalf of 'ID:<786163.1349901749574.0>' to 't3://convm2002:7001'>*
    *####<Oct 10, 2012 3:42:29 PM CDT> <Debug> <JMSSAF> <con02bl28.mtsallstream.com> <osmdev05> <[ACTIVE] ExecuteThread: '2' for queue: 'weblogic.kernel.Default (self-tuning)'> <<WLS Kernel>> <> <> <1349901749652> <000000> <Forwarder::getInitialContext()::Password=XXXX,username=OSM_Integration forceResolveDNS true>*
    *####<Oct 10, 2012 3:42:29 PM CDT> <Debug> <JMSSAF> <con02bl28.mtsallstream.com> <osmdev05> <[ACTIVE] ExecuteThread: '2' for queue: 'weblogic.kernel.Default (self-tuning)'> <OSM_Integration> <> <> <1349901749669> <000000> <ddExactlyOnceForwardHelper= null target MSLV WS!inventoryWSQueue targetJNDI inventoryWSQueue>*####<Oct 10, 2012 3:42:29 PM CDT> <Info> <JMS> <con02bl28.mtsallstream.com> <osmdev05> <[ACTIVE] ExecuteThread: '2' for queue: 'weblogic.kernel.Default (self-tuning)'> <<WLS Kernel>> <> <> <1349901749669> <BEA-040506> <The JMS SAF forwarder has successfully connected to the remote destination "t3://convm2002:7001/inventoryWSQueue".>

    Does this make any sense? The messages still did not reach the destination( I had already paused the consumption on the remote queue inventoryWSQueue to see if messages come into the queue). I then rebuilt the queue under SAF Imported desinations, bounced the server and tried again. This time the message could each the remote destinatation. The problem is that the its noteasy to replicate this SAF Issue. But was is sure it happend when SAF Remote Contect URL is changed to point to another UIM environment. Sometimes just bouncing the server after URL change is enough and it would work. Then there are times like these when the SAF message is simply lost even though the log says that the message was forwarded.

    Regards,
    Avinash

    Edited by: user3693508 on Aug 10, 2012 2:08 PM

Legend

  • Correct Answers - 10 points
  • Helpful Answers - 5 points