AutoSys Workload Automation

  • Private Community
 View Only
Back to discussions
Expand all | Collapse all

BWPC_JOB Prematurly Completing

  • 1.  BWPC_JOB Prematurly Completing

    Posted Apr 27, 2016 10:24 AM

    Hi,

     

    We are currently experiencing a very intermittent issues where the following two issues occur.

     

    System

    - SAP_BW 740 0009 SAPKW74009 SAP Business Warehouse

    - R11.3 SP2 Agent

    - AIX Server

     

    - BWPC_JOB runs a process chain and the ESP job completes prior to the process chain finishing. As you can see from the job spool, the COMPLETE message was sent before the EXEC status, which seems to be why it completed prematurely.

     

    ESP.png

     

    BWPC_JOB run a process chain and doesn't complete even though the process chain finishes. The log below shows that an exec message was sent back to the mainframe, but then ESP removed the monitor on the process chain causing it to not receive the complete message.

     

    04/26/2016 03:06:59.934 CDT-0500 4 main.Execution:2463683380051305420.CybSAPRequestProcessorBase.notifyCaller[:1201] -    *@*  Caller Notified.

    04/26/2016 03:06:59.934 CDT-0500 4 main.Execution:-3669075852341782411.CybConnectionsPool.push[:158] - NOTIFY POOL : connection = 9

    04/26/2016 03:06:59.934 CDT-0500 4 main.Execution:-4236747906414316582.CybSAPJobManager.processGroupOfResponses[:1465] - &&& response 0 is cybermation.plugins.sap.communicator.CybSAPRequest@4740474

    04/26/2016 03:06:59.934 CDT-0500 4 main.Execution:-3669075852341782411.CybSAPRequestProcessorBase.notifyCaller[:1201] -    *@*  Caller Notified.

    04/26/2016 03:06:59.934 CDT-0500 4 main.Execution:-4236747906414316582.CybSAPJobManager.processResponse[:1556] -     operation = 87(Table Read)

    04/26/2016 03:06:59.934 CDT-0500 1 main.Execution:-4236747906414316582.CybSAPBWGetChainProcessStatus.replyChangedStatusOnly[:210] - Process chain name>>> SASO005_AUMO01  status>> A

    04/26/2016 03:06:59.935 CDT-0500 5 main.Execution:-4236747906414316582.CybSAPTableImageBase.display[:435] - TABLE: DATA

    04/26/2016 03:06:59.935 CDT-0500 5 main.Execution:-4236747906414316582.CybSAPTableImageBase.display[:443] - [Type]  [Variant]  [Instance]  [State]  [Actual_State] 

    04/26/2016 03:06:59.935 CDT-0500 5 main.Execution:-4236747906414316582.CybSAPTableImageBase.display[:454] - [DTP_LOAD]  [DTP_7GJZLT4H93G1FRWP3UOF3SISN]  [Unknown]  [Unknown]  [Running] 

    04/26/2016 03:06:59.935 CDT-0500 5 main.Execution:-4236747906414316582.CybSAPTableImageBase.display[:454] - [DTP_LOAD]  [DTP_7GJZLT4H93G1FRWPA5DVL0LD3]  [Unknown]  [Unknown]  [Running] 

    04/26/2016 03:06:59.935 CDT-0500 5 main.Execution:-4236747906414316582.CybSAPTableImageBase.display[:454] - [TRIGGER]  [SASO005_AUMO01_SP]  [55O6LHRKMQ39IH9R6C520YHBJ]  [Finished]  [Finished] 

    04/26/2016 03:07:01.941 CDT-0500 4 main.Execution:-4236747906414316582.CybSAPResponseQueue.display[:240] -

                                                                                                               ################## REPLY AUMO01_SASO005.CHAIN/SAPAPP.482/MAIN

                                                                                                               * VERB     : STATE

                                                                                                               * SUBVERB  : EXEC

                                                                                                               * RESIDUAL : Status(Active) FormatType(1) ExtTable(Type,Variant,Instance,State,Actual_State/nDTP_LOAD,DTP_7GJZLT4H93G1FRWP3UOF3SISN,Unknown,Unknown,Running,DTP_LOAD,DTP_7GJZLT4H93G1FRWPA5DVL0LD3,Unknown,Unknown,Running,TRIGGER,SASO005_AUMO01_SP,55O6LHRKMQ39IH9R6C520YHBJ,Finished,Finished)

    04/26/2016 03:07:01.941 CDT-0500 4 main.Execution:-4236747906414316582.CybSAPResponseQueue.push[:107] - >>>>> Response added to queue...

    04/26/2016 03:07:01.943 CDT-0500 1 main.Execution:-4236747906414316582.CybSAPJobManager.startPCorIPMonitoringThread[:2892] - operation >>87

    04/26/2016 03:07:01.943 CDT-0500 4 main.Thread-13.CybSAPResponseQueue.popObject[:138] - <<<<< Got response from queue...

    04/26/2016 03:07:03.951 CDT-0500 4 main.Execution:-4236747906414316582.CybSAPJobManager.tryToSetJobRemovalFlag[:3117] - Set Removal Flag: Job <AUMO01_SASO005.CHAIN/SAPAPP.482/MAIN> not found. Retrying ....

    04/26/2016 03:07:03.951 CDT-0500 4 main.Execution:-4236747906414316582.CybSAPJobManager.tryToSetJobRemovalFlag[:3118] - Try alternative action for operation - 87

    04/26/2016 03:07:03.951 CDT-0500 1 main.Execution:-4236747906414316582.CybSAPJobManager.returnConnectionToPool[:1375] -  returnConnectionToPool Thread >>Thread[Execution:-4236747906414316582,5,main]

    04/26/2016 03:07:03.951 CDT-0500 1 main.Execution:-4236747906414316582.CybSAPJobManager.returnConnectionToPool[:1376] - cnc Id>>8 cnc Type>> 1  established >>false

    04/26/2016 03:07:03.951 CDT-0500 4 main.Execution:-4236747906414316582.CybSAPJobManager.tryToCloseConnection[:1416] - Connection #8 is not established. No need to disconnect.

    04/26/2016 03:07:03.952 CDT-0500 5 main.Execution:-4236747906414316582.CybConnectionsPool.push[:149] - ConnectionsPool.push from size = 9

    04/26/2016 03:07:03.952 CDT-0500 4 main.Execution:-4236747906414316582.CybConnectionsPool.push[:158] - NOTIFY POOL : connection = 8

    04/26/2016 03:07:03.952 CDT-0500 4 main.Execution:-4236747906414316582.CybSAPRequestProcessorBase.notifyCaller[:1201] -    *@*  Caller Notified.

    04/26/2016 03:07:05.048 CDT-0500 4 main.Monitor:2764908713870940128.CybSAPProcessChainManager.threadHandler1[:264] - 0-0-0 Process Chains Removal...

    04/26/2016 03:07:05.048 CDT-0500 4 main.Monitor:2764908713870940128.CybSAPProcessChainManager.threadHandler1[:278] - +-- Chain <SASO005_AUMO01@AUMO01_SASO005.CHAIN/SAPAPP.482/MAIN> added to removals.

    04/26/2016 03:07:05.139 CDT-0500 4 main.Monitor:2764908713870940128.CybSAPProcessChainManager.removeChain[:170] - Process Chain <SASO005_AUMO01@AUMO01_SASO005.CHAIN/SAPAPP.482/MAIN> removed from collector.

    04/26/2016 03:07:05.139 CDT-0500 4 main.Monitor:2764908713870940128.CybSAPProcessChainManager.removeMarkedChains[:242] - --- Process Chain <SASO005_AUMO01@AUMO01_SASO005.CHAIN/SAPAPP.482/MAIN> removed by monitor.

    04/26/2016 03:07:05.139 CDT-0500 4 main.Monitor:2764908713870940128.CybSAPProcessChainManager.threadHandler1[:301] - 0-0-0 Monitoring Process Chains



  • 2.  Re: BWPC_JOB Prematurly Completing

    Posted Apr 27, 2016 03:17 PM

    Hello,

    This has been fixed in later versions of the plug-in.   The fix is in Service Pack 4 of the SAP plug-in.  (I am not sure what release this was fixed in.)

    I suggest using the latest fix.  RO82940.

    Note that RO82940 requires the SAP JCO 3.0 package.  This is only available on AIX in 64-bit form so you will need to run under a 64-bit System Agent.

    Brad Erdner



  • 3.  Re: BWPC_JOB Prematurly Completing

    Posted Apr 27, 2016 03:24 PM

    Hi Brad,

     

    Thanks for the fast reply. Unfortunately we are currently running on patch RO82940. We had this same issue a few months ago and after we applied RO82940 the issue went away. It just recently started occurring again, so I'm not sure what is happening.

     

    Regards,

    Chuck



  • 4.  Re: BWPC_JOB Prematurly Completing

    Posted Apr 27, 2016 05:12 PM

    Chuck,

    Sorry that wasn't it.  I suggest opening an issue and we can work through this and figure out what is going on.

    Hopefully another community member may have some insight into what is going on.

    Thanks,

    Brad E



  • 5.  Re: BWPC_JOB Prematurly Completing
    Best Answer

    Posted Apr 28, 2016 09:23 AM

    We actually found an SAP note "2123865 - Process Chain Status is returned green when it is checked immediately after start"

     

    This sounds like it might fix the first problem where the process chain complete message was sent before the exec. We are upgrading our prod environment next week, which will bring in this note. Will reply back in a few weeks on whether the issue happens again.



  • 6.  Re: BWPC_JOB Prematurly Completing

    Posted Apr 28, 2016 09:33 AM

    That might help



  • 7.  Re: BWPC_JOB Prematurly Completing

    Posted Apr 28, 2016 02:29 AM

    I also had a similar problem at my site though I am running my plugin on Windows and my manager is Autosys.

    Anyway, the problem was finally solved when implementing RO82940 and increasing memory on the BW-system and increasing the number of background-processes on the bw-system.

    I also changed the parameter in agentparm.txt sap.request.timeout.min and sap.default.polling.rate.sec.

    At my site we discovered lack of resources on the BW-system, you might have to look into that.

    Good luck!



  • 8.  Re: BWPC_JOB Prematurly Completing

    Posted Apr 28, 2016 09:23 AM

    Hi Lars,

     

    May I ask what values you set the sap.request.timeout.min and sap.default.polling.rate.sec to?

     

    Thanks!

    Chuck



  • 9.  Re: BWPC_JOB Prematurly Completing

    Posted Apr 28, 2016 09:32 AM

    I actually updated sap.default.connection.wait.sec also, so there are three parameters you might want to add/change.

     

    I use these values and they work fine at my site:

     

    sap.default.connection.wait.sec=300

    sap.request.timeout.min=120

    sap.default.polling.rate.sec=20

     

    Hope these will help you!



  • 10.  Re: BWPC_JOB Prematurly Completing

    Posted Apr 28, 2016 09:44 AM

    Thanks! I checked our agentparm and we aren't specifying these parameters, so the defaults are being used. We will try this config out and see if the issue happens again.



  • 11.  Re: BWPC_JOB Prematurly Completing

    Posted Apr 28, 2016 09:53 AM

    Check the memory and backgroudprocesses on the BW-system also... and maybe the sap-note

    Good luck!