Clarity PPM

Expand all | Collapse all

How do you read a bg log error

  • 1.  How do you read a bg log error

    Posted 07-30-2015 10:41 AM

    The bg log has errors which are of this type

     

    ERROR 2015-07-06 00:02:03,175

    [Action Execution Pipeline 1 (tenant=clarity)]

    bpm.engine (clarity:process_admin:1366276979__F4236F3E-7F7A-4A13-976E-739F62AD7440:none)

    Error (will retry) caused by Step Instance: com.niku.bpm.engine.objects.StepInstance@1ac5479

    [Id: 15685454 Process Instance Id: 10782341 Step Id: 5009799 State: BPM_SIS_EXEC_ACTION

    Step Name: null

    Start Date: 2015-07-02 19:20:02.0

    Expected End Date: null

    Percent Complete: 0.0

    Warned: false

    Retry Count: 916

    No of Pre Conditions: -1

    No of Post Conditions: -1

    Last Condition Eval Time: 0

    Pre Condition Wait Events: null

    Post Condition Wait Events: null

    Pass Conditions: null Error Id: -1

     

    Process Thread: com.niku.bpm.engine.objects.ProcessThread@58ddd4ca [Id: 11232341 Parent Step Instance Id: -1 Join Step Instance Id: -1]

     

    Split Threads: null

     

    Join Threads:null]

     

    How do you read that?

    To me it looks like the process did not get to a process engine and did not get into any step yet, not even getting the pre conditions done.

    It certainly did try almost a a thousand times though.

     

    Does the error entry give an indication where to to look for the cause?



  • 2.  Re: How do you read a bg log error

    Posted 07-30-2015 11:08 AM

    Ugh ; no idea really!

     

    I guess I would pick up the various ids from this line;

     

    Id: 15685454 Process Instance Id: 10782341 Step Id: 5009799

     

    and try to track these through the process run tables for the ids starting with 1 (since they look like instance ids) and maybe the process definition tables for the 500 id (the Step Id) since that looks like part of the process definition. That might help me find the process/step that is failing, but no clue as to why it is failing seems to be apparent.



  • 3.  Re: How do you read a bg log error

    Posted 07-30-2015 01:40 PM

    Thanks

    I did trace the process instance ID's to a number of processes. No user reports on those.

    Could then look at the data on their instances to see what were the statuses and if they were eventually run, but have not done so yet



  • 4.  Re: How do you read a bg log error

    Posted 08-03-2015 06:19 AM

    Can you check what samos has suggested in the below thread ?

    https://communities.ca.com/message/2300161#2300161

     

    "My first simple suggestion, is to take this part of the error message:   Process Instance Id: 5519038   and use that id to replace in this URL (if you are using v12 or v8 clarity)  https:// >/niku/app?action=bpm.stepHistory&process_instance_id= 5519038 &object_type=admin&ui.page.space=bpm.processDefinitions&ui.page.template=union.adminPage&bpm.returnModuleAction=bpm.processInstancesReturn  and see what process it is.  This would be the first step in your investigation I'd say.  Otherwise, navigate to Clarity > Admin > Processes > Initiated > [filter by Error status]"

     

    NJ



  • 5.  Re: How do you read a bg log error

    Posted 08-03-2015 12:33 PM

    Thanks, I've filtered the process instance ID*s and queried the database for the related processes and that to the process runs, not any good a match. Looked at the initiated process instances which gives a better match to the process runs. No match to the processes executed with a job. I am starting to conclude that those process were never started which also the step ID and number of retries suggest. That would result the processes not appearing in the initiated processes. That though gives no glue for the cause of the errors.

     

    No, doing what samos suggest give less information than what I got through the above so I have not yet done that.



  • 6.  Re: How do you read a bg log error

    Posted 08-04-2015 05:10 PM

    Everything between [Id: ... Join Threads:null] is just reporting the step instance data where an error occurred.

     

    What appears after that ought to yield more about the specific cause (an exception was 'thrown' by some code when an anticipated or unanticipated problem occurred, and the logger should report the details of that exception once that block of text completes).

     

    The inner contents of the block itself will likely not say much, except that in this case it looks like the step instance has been having issues on a recurring basis and that even after several (hundred) retries it still has not been successful.

     

    But without the extra information about the exception that was thrown, it isn't possible to say why.



  • 7.  Re: How do you read a bg log error

    Posted 08-05-2015 04:27 PM

    ERROR 2015-07-06 00:02:03,175 [Action Execution Pipeline 0 (tenant=clarity)] bpm.engine (clarity:process_admin:1366276979__F4236F3E-7F7A-4A13-976E-739F62AD7440:none) Error (will retry) caused by Step Instance: com.niku.bpm.engine.objects.StepInstance@600d9dfb [Id: 15683164 Process Instance Id: 10782086 Step Id: 5012973 State: BPM_SIS_EXEC_ACTION Step Name: null Start Date: 2015-07-01 21:30:04.0 Expected End Date: null Percent Complete: 0.0 Warned: false Retry Count: 1182 No of Pre Conditions: 1 No of Post Conditions: -1 Last Condition Eval Time: 1435779004555 Pre Condition Wait Events: null Post Condition Wait Events: null Pass Conditions: null Error Id: -1

    Process Thread: com.niku.bpm.engine.objects.ProcessThread@1dfefb01 [Id: 11232086 Parent Step Instance Id: -1 Join Step Instance Id: -1]

    Split Threads: null

    Join Threads:null]

    com.niku.bpm.BpmException: java.lang.NullPointerException

        at com.niku.bpm.engine.rules.ActionExecutionPipeline.execute(ActionExecutionPipeline.java:107)

        at com.niku.bpm.engine.rules.Pipeline.run(Pipeline.java:280)

    Caused by: java.lang.NullPointerException

        at com.niku.bpm.engine.objects.StepInstance.processSynchronousStepAction(StepInstance.java:839)

        at com.niku.bpm.engine.rules.ActionExecutionPipeline.execute(ActionExecutionPipeline.java:64)

        ... 1 more

    ERROR 2015-07-06 00:02:03,175 [Action Execution Pipeline 1 (tenant=clarity)] bpm.engine (clarity:process_admin:1366276979__F4236F3E-7F7A-4A13-976E-739F62AD7440:none) Error (will retry) caused by Step Instance: com.niku.bpm.engine.objects.StepInstance@1ac5479 [Id: 15685454 Process Instance Id: 10782341 Step Id: 5009799 State: BPM_SIS_EXEC_ACTION Step Name: null Start Date: 2015-07-02 19:20:02.0 Expected End Date: null Percent Complete: 0.0 Warned: false Retry Count: 916 No of Pre Conditions: -1 No of Post Conditions: -1 Last Condition Eval Time: 0 Pre Condition Wait Events: null Post Condition Wait Events: null Pass Conditions: null Error Id: -1

    Process Thread: com.niku.bpm.engine.objects.ProcessThread@58ddd4ca [Id: 11232341 Parent Step Instance Id: -1 Join Step Instance Id: -1]

    Split Threads: null

    Join Threads:null]

    com.niku.bpm.BpmException: java.lang.NullPointerException

        at com.niku.bpm.engine.rules.ActionExecutionPipeline.execute(ActionExecutionPipeline.java:107)

        at com.niku.bpm.engine.rules.Pipeline.run(Pipeline.java:280)

    Caused by: java.lang.NullPointerException

        at com.niku.bpm.engine.objects.StepInstance.processSynchronousStepAction(StepInstance.java:839)

        at com.niku.bpm.engine.rules.ActionExecutionPipeline.execute(ActionExecutionPipeline.java:64)

        ... 1 more

    ERROR 2015-07-06 00:02:03,176 [Action Execution Pipeline 2 (tenant=clarity)] bpm.engine (clarity:process_admin:1366276979__F4236F3E-7F7A-4A13-976E-739F62AD7440:none) Error (will retry) caused by Step Instance: com.niku.bpm.engine.objects.StepInstance@5f8d7b1b [Id: 15683742 Process Instance Id: 10782385 Step Id: 5013958 State: BPM_SIS_EXEC_ACTION Step Name: null Start Date: 2015-07-02 23:17:01.0 Expected End Date: null Percent Complete: 0.0 Warned: false Retry Count: 873 No of Pre Conditions: 1 No of Post Conditions: -1 Last Condition Eval Time: 1435871821054 Pre Condition Wait Events: null Post Condition Wait Events: null Pass Conditions: null Error Id: -1

    Process Thread: com.niku.bpm.engine.objects.ProcessThread@418d5a9f [Id: 11232385 Parent Step Instance Id: -1 Join Step Instance Id: -1]

    Split Threads: null

    Join Threads:null]

    com.niku.bpm.BpmException: java.lang.NullPointerException

        at com.niku.bpm.engine.rules.ActionExecutionPipeline.execute(ActionExecutionPipeline.java:107)

        at com.niku.bpm.engine.rules.Pipeline.run(Pipeline.java:280)

    Caused by: java.lang.NullPointerException

        at com.niku.bpm.engine.objects.StepInstance.processSynchronousStepAction(StepInstance.java:839)

        at com.niku.bpm.engine.rules.ActionExecutionPipeline.execute(ActionExecutionPipeline.java:64)

        ... 1 more

    ERROR 2015-07-06 00:02:03,182 [Action Execution Pipeline 1 (tenant=clarity)] bpm.engine (clarity:process_admin:1366276979__F4236F3E-7F7A-4A13-976E-739F62AD7440:none) Error (will retry) caused by Step Instance: com.niku.bpm.engine.objects.StepInstance@605e24a8 [Id: 15683944 Process Instance Id: 10778806 Step Id: 5009799 State: BPM_SIS_EXEC_ACTION Step Name: null Start Date: 2015-07-03 10:35:02.0 Expected End Date: null Percent Complete: 0.0 Warned: false Retry Count: 738 No of Pre Conditions: 1 No of Post Conditions: -1 Last Condition Eval Time: 1435912502060 Pre Condition Wait Events: null Post Condition Wait Events: null Pass Conditions: null Error Id: -1

    Process Thread: com.niku.bpm.engine.objects.ProcessThread@44b8c305 [Id: 11228806 Parent Step Instance Id: -1 Join Step Instance Id: -1]

    Split Threads: null

    Join Threads:null]

    com.niku.bpm.BpmException: java.lang.NullPointerException

        at com.niku.bpm.engine.rules.ActionExecutionPipeline.execute(ActionExecutionPipeline.java:107)

        at com.niku.bpm.engine.rules.Pipeline.run(Pipeline.java:280)

    Caused by: java.lang.NullPointerException

        at com.niku.bpm.engine.objects.StepInstance.processSynchronousStepAction(StepInstance.java:839)

        at com.niku.bpm.engine.rules.ActionExecutionPipeline.execute(ActionExecutionPipeline.java:64)

        ... 1 more

     

    It goes on and on and on



  • 8.  Re: How do you read a bg log error

    Posted 08-05-2015 06:07 PM

    Thanks - so in this case the originating cause of your log messages are from this:

     

    Caused by: java.lang.NullPointerException

        at com.niku.bpm.engine.objects.StepInstance.processSynchronousStepAction(StepInstance.java:839)

     

    And that can have (one of) two logical causes:

     

    1) Clarity wasn't able to obtain a reference to a running Process Definition Controller.

    2) The class to hold the results of the step action that ran wasn't populated with anything once it completed executing the action.

     

    I would rule out #1 on the basis that if a PDC isn't running, a new one will be created anyway, so the reference is almost certainly to be valid.

     

    The absence of other error messages between the instances reported suggests that for #2 the query named 'bpm.pe.getSynchronouslyRunningAction' that ran using the step instance id value as a parameter to get the action results didn't return any rows.

     

    The query in question doesn't really have any joins or other complexities that would cause it to not show records that exist in the tables:

     

    SELECT id, step_action_id, status_code FROM BPM_RUN_STEP_ACTION_RESULTS WHERE step_instance_id = ? AND status_code = 'BPM_AIS_RUNNING'

     

    So I could only suspect that the record was not inserted or had other values (different status_code or similar, perhaps due to being cancelled/deleted or something else) which would prevent it from returning something.

     

    The end result of that query not returning values would be the exception you see in the logs.



  • 9.  Re: How do you read a bg log error

    Posted 08-06-2015 04:12 PM

    Thanks for looking into this.

    Now that we know how to read the error message, is there a way get to the root cause of the problem which seems come at random, but then runs wild until the bg is restarted?

    With the current logging level is there a place to look for more information after the problem has occurred?

     

    You rule #1 out on the basis that if a PDC isn't running, a new one will be created anyway. How soon would that happen. If you look at the time the errors are repeated after  0,01 seconds or less

    What is PDC?



  • 10.  Re: How do you read a bg log error

    Posted 08-06-2015 04:23 PM

    urmas wrote:

     

    What is PDC?

     

     

    Sorry, PDC = Process Definition Controller.  The time shouldn't matter, if it needed to created one of these, it would do so along the way and before it reached the next few lines of code where you are getting the error - so out of the possible causes on the line erroring, this one shouldn't be a factor.

     

    Getting to the root cause would almost certainly need to be conducted through a support ticket, whilst an occurrence of the problem is live, and checking/confirming it is an issue of the contents written / being written to the BPM_RUN_STEP_ACTION_RESULTS table for that step instance resulting in the query not returning any rows (based on review alone, that is all the conclusion I can make).



  • 11.  Re: How do you read a bg log error

    Posted 08-06-2015 04:50 PM

    Thanks nick_darlington, will look to that table.

    The problem occurs at random and when it does the bg has to be restarted, so it might be hard to have the problem live which a case with support is open.



  • 12.  Re: How do you read a bg log error

    Posted 08-10-2015 03:39 AM

    So took one of the logs, filtered for the error and got those 5500 lines which all had hundreds of retries.

    They had 63 unique step instances. Queried those with

    Select    

    id   

    ,STEP_INSTANCE_ID   

    ,STEP_ACTION_ID   

    ,ACTION_RESULT   

    ,ENGINE_RUN_ID   

    ,JOB_ID   

    ,STATUS_CODE   

    ,CUSTOM_SCRIPT_SESSION_ID   

    from BPM_RUN_STEP_ACTION_RESULTS   

    WHERE rownum < 200   

    AND STEP_INSTANCE_ID in   

    (   

        14409862

    ,    15431053

    and so on

     

    Got 43 records

    ID    STEP_INSTANCE_ID    STEP_ACTION_ID    ACTION_RESULT    ENGINE_RUN_ID    JOB_ID    STATUS_CODE    CUSTOM_SCRIPT_SESSION_ID

    12177480    14409862    5190262        -1        BPM_AIS_ACTIVE   

    13115535    15431053    5208566        -1        BPM_AIS_ACTIVE   

    13245080    15683164    5172447        -1        BPM_AIS_DONE    9844080

    13245134    15683285    5194513        -1        BPM_AIS_DONE    9844136

    13245145    15683310    5194513        -1        BPM_AIS_DONE    9844148

    13245289    15683637    5160126        -1        BPM_AIS_DONE    9844294

    13245324    15683723    5172447        -1        BPM_AIS_DONE    9844330

    13245332    15683742    5194513        -1        BPM_AIS_DONE    9844339

    13245376    15683842    5165324        -1        BPM_AIS_DONE    9844386

     

    Sorry to say can't figure what that is telling me.



  • 13.  Re: How do you read a bg log error

    Posted 08-12-2015 03:59 AM

    Any update on this, urmas ?

     

    NJ



  • 14.  Re: How do you read a bg log error

    Posted 08-12-2015 04:55 AM

    Sorry to say can't figure what that is telling me.



  • 15.  Re: How do you read a bg log error

    Posted 08-12-2015 10:00 AM

    It shows that the query ran by Clarity is returning no results when it was hoping to receive 1 record at least in order to avoid the null pointer error, as the query Clarity runs includes the criteria "AND status_code = 'BPM_AIS_RUNNING'".

     

    It's going to take more than a discussion here to dig further than that though; some problems just require detailed debugging with a combination of tools (that can't be shared) and a reproducible system.



  • 16.  Re: How do you read a bg log error

    Posted 08-12-2015 10:45 AM

    Thanks

    nick_darlington

    will pass that on and hopefully the pain will grow so that we'll get to the bottom of it.



  • 17.  Re: How do you read a bg log error

    Posted 11-12-2018 09:50 AM

    Sorry for pinging an old issue but we are facing the same problem in 15.3. Did you resolve this issue? If yes, could you please share the resolution with us.

     

    Best Regards



  • 18.  Re: How do you read a bg log error

    Posted 11-12-2018 10:36 AM

    We did not pursue that any further than what is above. Apparently the processes eventually completed.

    The system has since then been taken down.