2 Replies Latest reply: Aug 10, 2012 4:09 PM by 696996 RSS

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

    696996
      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
          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
            696996
            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