[Date Prev] [Date Next] [Prev in Thread] [Next in Thread] [Date Index] [Thread Index]

Re: Run API from filter deadlocks



**
Glad I was able to help.

On Wed, Mar 15, 2017 at 2:25 PM, Charlie Lotridge <lotridge@mcs-sf.com> wrote:
**
Nice...good catch. I'd never seen evidence of ARS level locking before...interesting.

It was simple enough refactor to avoid this and get it working as needed. Without boring you with details, I'd originally coded it that way to avoid an extra round trip from client to server. But it's not really important in this situation.

Thanks for the help.



On Wed, Mar 15, 2017 at 10:51 AM, LJ LongWing <lj.longwing@gmail.com> wrote:
**
Ok, I see your issue.

You are working with a 'Physician, operate on thyself' type of issue.

So, you finish doing phase 1 operations on form MD_KronosTest, request MDKT-0000000001....you then start phase 2 which includes the run-processes...

you run process is then coming in and trying to do a set on the same form, same record....

Because your original operation is currently locking that record, the second operation cannot modify it until phase 3 is completed, and the record is released....so, because operation 2 is sitting inside of operation 1, operation 1 won't be able to complete BEFORE operation 2 finishes...and operation 2 can't complete till operation 1 finishes....thus deadlock....

simply....you can't have the doctor operate on himself....

On Wed, Mar 15, 2017 at 12:01 PM, Charlie Lotridge <lotridge@mcs-sf.com> wrote:
**
LJ,

Thanks for the suggestion.

Unfortunately filterAPI isn't really an option. I have a large infrastructure (C++ & C# libraries) that I build on that allow me to rapidly develop API programs, but don't lend themselves to being used for filterAPI. I'd have to get the .NET runtime to work in the plugin framework and haven't taken (don't have) the time to figure that out, especially for this short project. Also, (getting way off topic) my typical API paradigm doesn't require synchronous access...this is a very unusual use case for me...which further decreases the motivation to do that research.

Not sure if I can better describe the deadlock beyond the filter log description I gave, but I'll try...

The $PROCESS$ times out and causes the ARS transaction to error. Here's the relevant filter log section with the $PROCESS$ Set Fields, and the subsequent failure message, highlighted:

<FLTR> <TID: 0000001804> <RPC ID: 0000031115> <Queue: Fast > <Client-RPC: 390620   > <USER: Admin > <Overlay-Group: 1 > /* Wed Mar 15 2017 08:40:53.3190 */     End of filter processing (phase 1) -- Operation - SET on MD_KronosTest - MDKT-0000000001
<FLTR> <TID: 0000001804> <RPC ID: 0000031115> <Queue: Fast > <Client-RPC: 390620   > <USER: Admin > <Overlay-Group: 1 >         1: Process
<FLTR> <TID: 0000001804> <RPC ID: 0000031115> <Queue: Fast > <Client-RPC: 390620   > <USER: Admin > <Overlay-Group: 1 >               Application-Release-Pending
<FLTR> <TID: 0000001804> <RPC ID: 0000031115> <Queue: Fast > <Client-RPC: 390620   > <USER: Admin > <Overlay-Group: 1 >         2: Set Fields
<FLTR> <TID: 0000001804> <RPC ID: 0000031115> <Queue: Fast > <Client-RPC: 390620   > <USER: Admin > <Overlay-Group: 1 >                   c:\bin\KronosPost.exe -X=localhost -U=ARSystem -P=xxxxx --arRPC=390680 MDKT-0000000001
<FLTR> <TID: 0000001804> <RPC ID: 0000031115> <Queue: Fast > <Client-RPC: 390620   > <USER: Admin > <Overlay-Group: 1 >                   Exit code: 0  Value: 
<FLTR> <TID: 0000001804> <RPC ID: 0000031115> <Queue: Fast > <Client-RPC: 390620   > <USER: Admin > <Overlay-Group: 1 >               Filter/escalation 'set field' process timed out before completion
<FLTR> <TID: 0000001804> <RPC ID: 0000031115> <Queue: Fast > <Client-RPC: 390620   > <USER: Admin > <Overlay-Group: 1 > **** Error while performing filter action: Error 39
<FLTR> <TID: 0000001804> <RPC ID: 0000031115> <Queue: Fast > <Client-RPC: 390620   > <USER: Admin > <Overlay-Group: 1 > **** Filter "MDKT:GUIDEHandleEvents200Post:IfServicePushToUpdateEntry&Setup&RunKronosPost`!": No enabled error handler
<FLTR> <TID: 0000001804> <RPC ID: 0000031115> <Queue: Fast > <Client-RPC: 390620   > <USER: Admin > <Overlay-Group: 1 > /* Wed Mar 15 2017 08:40:58.3540 */     Call Guide "MDKT:F:HandleEvents:GENERATED" (return)
<FLTR> <TID: 0000001804> <RPC ID: 0000031115> <Queue: Fast > <Client-RPC: 390620   > <USER: Admin > <Overlay-Group: 1 > **** Error while performing filter action: Error 39
<FLTR> <TID: 0000001804> <RPC ID: 0000031115> <Queue: Fast > <Client-RPC: 390620   > <USER: Admin > <Overlay-Group: 1 > **** Filter "MDKT:050OnSubmitModifyService:IfEventCallHandleEvents:GENERATED": No enabled error handler
<FLTR> <TID: 0000001804> <RPC ID: 0000031115> <Queue: Fast > <Client-RPC: 390620   > <USER: Admin > <Overlay-Group: 1 > /* Wed Mar 15 2017 08:40:58.3540 */     End of filter processing (phase 1) -- Operation - SERVICE on MD_KronosTest - MDKT-0000000001

Once the transaction completes, I then see workflow associated with the API program operation, indicating it DID get started (this logging immediately follows the above):

<FLTR> <TID: 0000003856> <RPC ID: 0000031120> <Queue: Prv:390680> <Client-RPC: 390680 > <USER: ARSystem > <Overlay-Group: 1 > /* Wed Mar 15 2017 08:40:58.3550 */     Start filter processing (phase 1) -- Operation - GET on MD_KronosTest - MDKT-0000000001
<FLTR> <TID: 0000003856> <RPC ID: 0000031120> <Queue: Prv:390680> <Client-RPC: 390680 > <USER: ARSystem > <Overlay-Group: 1 > /* Wed Mar 15 2017 08:40:58.3550 */     <Filter Level:0 Number Of Filters:0> Checking "MDKT:500OnGetEntry:CallOnGetEntry:GENERATED" (500)
<FLTR> <TID: 0000003856> <RPC ID: 0000031120> <Queue: Prv:390680> <Client-RPC: 390680 > <USER: ARSystem > <Overlay-Group: 1 >    --> Passed -- perform actions
<FLTR> <TID: 0000003856> <RPC ID: 0000031120> <Queue: Prv:390680> <Client-RPC: 390680 > <USER: ARSystem > <Overlay-Group: 1 >         0: Call Guide "MDKT:F:OnGetEntry:GENERATED"
<FLTR> <TID: 0000003856> <RPC ID: 0000031120> <Queue: Prv:390680> <Client-RPC: 390680 > <USER: ARSystem > <Overlay-Group: 1 > /* Wed Mar 15 2017 08:40:58.3570 */     <Filter Level:0 Number Of Filters:1> Checking "MDKT:GUIDEOnGetEntry010CallGetEntryDescription:GENERATED" (0)
<FLTR> <TID: 0000003856> <RPC ID: 0000031120> <Queue: Prv:390680> <Client-RPC: 390680 > <USER: ARSystem > <Overlay-Group: 1 >    --> Passed -- perform actions
<FLTR> <TID: 0000003856> <RPC ID: 0000031120> <Queue: Prv:390680> <Client-RPC: 390680 > <USER: ARSystem > <Overlay-Group: 1 >         0: Call Guide "MDKT:F:GetEntryDescription:GENERATED"
...

Until the timeout on the $PROCESS$ occurs, both the ARS thread and my API process are stuck (deadlocked).

When run standalone, the program completes in less than 1 second. Still, just to test, I did try setting the "Process Timeout" to 25 seconds.

Regardless, the documentation, and my vague recollection from the last time I tried this, suggest that it can be made to work and my question is: why isn't it working?

I *am* running this in a SERVICE operation...maybe Remedy doesn't like that for some reason? I will try refactoring to run it in a SET operation instead to test.

Thanks,
Charlie


On Wed, Mar 15, 2017 at 9:22 AM, LJ LongWing <lj.longwing@gmail.com> wrote:
**
Charlie,
Being you are writing it.....have you considered making it a filterAPI Plugin instead of a command line?....this has many advantages over a run-process....anyway

You say it's a deadlock....can you identify what you mean by that?

On Wed, Mar 15, 2017 at 11:11 AM, Charlie Lotridge <lotridge@mcs-sf.com> wrote:
**
Hi,

I'm trying to run an API program I wrote in a filter Set Fields using $PROCESS$, but it's deadlocking and I can't see why.

The first thing I tried, described in the documentation here, is to increase the Max Thread counts of the relevant queues but no joy. I even tried directing the API to use a private queue (RPC 390680), but still it deadlocks.

I can see the deadlocking occur in a filter log: I first see my workflow (running in a fast queue) perform the $PROCESS$. It hangs for the configured 5 second timeout, then issues its error and completes its transaction. But it DID spin up my program, which (after my initial transaction fails and completes) then makes its connection (to private queue 390680) and correctly does its thing.

I haven't bothered to instrument the API program to test this, but I'm quite sure that it's hanging at the point that it tries to make the ARS connection.

FYI I need to use $PROCESS$ because I need the results of the API to be available to subsequent filter workflow. Run Process, which will run the API asynchronously, is not suitable.

Also FYI, it's a fully licensed development system with absolutely nothing else going on (no other person or processes are using it).

I've done this kind of thing before, but it's been a long time and my best recollection is that increasing the thread count solved the problem.

Any suggestions?

Thanks,
Charlie
_ARSlist: "Where the Answers Are" and have been for 20 years_

_ARSlist: "Where the Answers Are" and have been for 20 years_

_ARSlist: "Where the Answers Are" and have been for 20 years_

_ARSlist: "Where the Answers Are" and have been for 20 years_

_ARSlist: "Where the Answers Are" and have been for 20 years_

_ARSlist: "Where the Answers Are" and have been for 20 years_