fix(job-executor): Adding helpful debug logs to improve job acquisition and job execution logging. Issue#2666. #4217

prakashpalanisamy · 2024-03-22T18:02:50Z

This code change adds additional logging to Camunda Job Executor and scoped to the Job Acquisition and Job Execution.

#2666

CLAassistant · 2024-03-22T18:02:55Z

All committers have signed the CLA.

yanavasileva · 2024-03-25T07:35:55Z

Hi @prakashpalanisamy,

Thank you for raising this.
We will have a look at it and get back to you.

Best,
Yana

yanavasileva

@prakashpalanisamy, nice work!
I left a few comments for the code formatting (check all of the code for missing spaces) and covering the non-Spring use cases.

In addition to the changes, could you have have a look at adding a few test cases for the logging. The logging rule can be helpful for them. You can see examples here:

yanavasileva · 2024-04-08T09:11:43Z

engine/src/main/java/org/camunda/bpm/engine/impl/jobexecutor/JobExecutor.java

    }
  }

+  public void logJobExecutionInfo(ProcessEngineImpl engine, int executionQueueSize, int executionQueueCapacity, int maxExecutionThreads, int activeExecutionThreads) {


❓ The code is called only for Spring use cases. Have you considered how to log the same data for non-Spring scenario? As I don't think the ticket is created only for Spring use cases.
Hint:

camunda-bpm-platform/engine/src/main/java/org/camunda/bpm/engine/impl/jobexecutor/DefaultJobExecutor.java

Lines 43 to 45 in 5df0514

protected int queueSize = 3;

protected int corePoolSize = 3;

protected int maxPoolSize = 10;

❓ Could you also have a look at https://github.com/camunda/camunda-bpm-platform/blob/master/engine-cdi/core/src/main/java/org/camunda/bpm/engine/cdi/impl/ManagedJobExecutor.java?

engine/src/main/java/org/camunda/bpm/engine/impl/jobexecutor/JobExecutor.java

.../src/main/java/org/camunda/bpm/engine/impl/jobexecutor/SequentialJobAcquisitionRunnable.java

...re/src/main/java/org/camunda/bpm/engine/spring/components/jobexecutor/SpringJobExecutor.java

engine/src/main/java/org/camunda/bpm/engine/impl/jobexecutor/JobExecutorLogger.java

prakashpalanisamy · 2024-04-08T14:48:15Z

@yanavasileva , Thank you for taking your time to review. Ill look at the comments and update you. Thanks!!

yanavasileva · 2024-05-22T06:36:30Z

Closing due to inactivity. The PR can be reopened again when you get back to the topic.

prakashpalanisamy · 2024-06-28T08:43:58Z

Hi @yanavasileva Requesting you to please reopen the PR. I would like to continue the contribution to this PR. Thank you!

prakashpalanisamy · 2024-07-16T06:47:08Z

@yanavasileva , hope you are doing good. I have updated the PR with additional commits. Can you please take a look into it when you get some time. Thanks!!

yanavasileva · 2024-07-16T07:02:19Z

I will try to have a look and provide input later this week.

prakashpalanisamy · 2024-08-14T13:13:29Z

@yanavasileva Please let me know on the comments once you have finished reviewing, I will have them addressed. Thank you! :)

yanavasileva

❌ Formatting is off almost everywhere. You can find the latest formatters here:
https://github.com/camunda/camunda-bpm-platform/tree/master/settings
👍 Changes look good so far, thank you for considering my feedback.
I added two more notes below. I will validate the added tests, run some further scenarios, and get back to you with my findings.

Thank you for your patience.

engine/src/main/java/org/camunda/bpm/engine/impl/jobexecutor/JobExecutorLogger.java

yanavasileva · 2024-08-22T16:36:45Z

engine/src/main/java/org/camunda/bpm/engine/impl/jobexecutor/JobExecutor.java

    }
  }

+  public void logJobExecutionInfo(ProcessEngineImpl engine, int executionQueueSize, int executionQueueCapacity, int maxExecutionThreads, int activeExecutionThreads) {


❓ Could you also have a look at https://github.com/camunda/camunda-bpm-platform/blob/master/engine-cdi/core/src/main/java/org/camunda/bpm/engine/cdi/impl/ManagedJobExecutor.java?

yanavasileva

Adding some further adjustments related to the tests.

engine/src/main/java/org/camunda/bpm/engine/impl/jobexecutor/JobExecutor.java

engine/src/test/java/org/camunda/bpm/engine/test/jobexecutor/JobAcquisitionLoggingTest.java

engine/src/test/java/org/camunda/bpm/engine/test/jobexecutor/JobExecutionLoggingTest.java

yanavasileva · 2024-08-23T08:41:48Z

engine/src/test/java/org/camunda/bpm/engine/test/jobexecutor/JobExecutionLoggingTest.java

+import org.junit.rules.RuleChain;
+
+import java.util.List;
+import java.util.concurrent.*;


❌ Apply project's formatter:

Suggested change

import java.util.concurrent.*;

import java.util.concurrent.ArrayBlockingQueue;

import java.util.concurrent.BlockingQueue;

import java.util.concurrent.RejectedExecutionException;

import java.util.concurrent.ThreadPoolExecutor;

import java.util.concurrent.TimeUnit;

engine/src/test/java/org/camunda/bpm/engine/test/jobexecutor/JobExecutionLoggingTest.java

yanavasileva · 2024-08-23T08:45:06Z

engine/src/test/java/org/camunda/bpm/engine/test/jobexecutor/JobExecutionLoggingTest.java

+    processEngineConfiguration.getJobExecutor().shutdown();
+
+    // look for filled queue logs
+    List<ILoggingEvent> filteredLogList = loggingRule.getFilteredLog("Jobs currently in queue to be executed for the process engine 'default' is 2 out of the max queue size : 2");


🔧 Adjust wording:

Suggested change

List<ILoggingEvent> filteredLogList = loggingRule.getFilteredLog("Jobs currently in queue to be executed for the process engine 'default' is 2 out of the max queue size : 2");

List<ILoggingEvent> filteredLogList = loggingRule.getFilteredLog("Jobs currently in queue to be executed for the process engine 'default': 2 (out of the max queue size : 2)");

yanavasileva

❌ I have ran the tests a couple of times but they are unstable. Could you please iterate on them to make them reliable?

engine/src/test/java/org/camunda/bpm/engine/test/jobexecutor/JobAcquisitionLoggingTest.java

engine/src/test/java/org/camunda/bpm/engine/test/jobexecutor/JobExecutionLoggingTest.java

yanavasileva · 2024-08-23T12:51:32Z

engine/src/test/java/org/camunda/bpm/engine/test/jobexecutor/JobAcquisitionLoggingTest.java

+    List<ILoggingEvent> filteredLogList = loggingRule.getFilteredLog("Attempting to acquire 3 jobs for the process engine 'default'");
+
+    // then find the expected logs
+    assertThat(filteredLogList.size()).isGreaterThan(4);


This check if flaky.

yanavasileva · 2024-08-23T12:51:40Z

engine/src/test/java/org/camunda/bpm/engine/test/jobexecutor/JobAcquisitionLoggingTest.java

+    List<ILoggingEvent> filteredLogList = loggingRule.getFilteredLog("Jobs failed to Lock during Acquisition of jobs for the process engine 'default' : 0");
+
+    // then get logs that states there were no faults during job acquisition locks
+    assertThat(filteredLogList.size()).isGreaterThan(4);


This check if flaky.

yanavasileva · 2024-08-24T07:35:09Z

engine/src/test/java/org/camunda/bpm/engine/test/jobexecutor/JobExecutionLoggingTest.java

+    List<ILoggingEvent> filteredLogList = loggingRule.getFilteredLog("Jobs currently in queue to be executed for the process engine 'default' is 2 out of the max queue size : 2");
+
+    // then 3 instances of filled queue logs will be available as there is 2 additional threads possible to reach max-pool-size
+    assertThat(filteredLogList.size()).isEqualTo(3);


This check if flaky.

yanavasileva · 2024-08-24T07:38:08Z

engine/src/test/java/org/camunda/bpm/engine/test/jobexecutor/JobExecutionLoggingTest.java

+    List<ILoggingEvent> filteredLogList = loggingRule.getFilteredLog("Jobs currently in execution for the process engine 'default' : 3");
+
+    // then one count of 'three jobs in execution' will be available as 2 out of 5 jobs should be queued.
+    assertThat(filteredLogList.size()).isEqualTo(1);


This check is flaky.

yanavasileva · 2024-09-07T14:06:36Z

@prakashpalanisamy, heads up, we approach the code freeze of the minor release.
❗ If you want the feature to be included in 7.22.0, please apply the feedback by 16th of September.

prakashpalanisamy · 2024-09-09T11:52:54Z

@prakashpalanisamy, heads up, we approach the code freeze of the minor release. ❗ If you want the feature to be included in 7.22.0, please apply the feedback by 16th of September.

Sure @yanavasileva I'll take this up on priority. Was tied up due to personal matters. I may need your inputs on the Tests though. I observed that some of the new logs and already present logs were getting into the log file while the JE gets loaded. sometime twice. So the number of occurrences were varying on my system as well. Hence I was opting for greater than checks. Will test that once more and reach out to you with specifics for directions. Thank you for assisting me with this PR :)

…on and job execution logging. Issue#2666.

…n logging. Issue#2666

prakashpalanisamy · 2024-09-10T14:10:14Z

@yanavasileva - quick question on the formatting. When I apply the formatting, it also suggest changes to prior code that other authors have contributed in the past, on the files that I have changes in. Do you suggest that I apply them along with my changes? else only to the lines that Im contributing and ignoring other formatting suggestions? Thanks!!

yanavasileva · 2024-09-10T14:28:41Z

@prakashpalanisamy,

You can mark only your code and format only that. This will be easier to review by me.

…eview comments.

… TestCaseFiles.

prakashpalanisamy · 2024-09-11T13:24:21Z

@yanavasileva - I need your directions for the ManagedJobExecutor changes. Since it will be using the app servers' thread pool, should I set it up in wildfly distribution with ManagedExecutorService configuration? if so, any pointers on how to do the configurations? If you could point to any reference links, it will help me.
Basically, once i put the code in, I want to get it up and running and test manually with some process of mine having async scenarios with java delegates.

yanavasileva · 2024-09-18T08:55:35Z

I won't be able to provide input on this, we can create a follow up ticket to explore further ManagedJobExecutor. Feel free to apply the rest of the feedback.

For the tests, I also saw that the log entries can vary. Maybe you can do the assertion for minimum occurrences?

prakashpalanisamy · 2024-10-25T15:01:04Z

@yanavasileva - Hope you are doing good. Please find the latest commits having addressed the review comments. On the test cases front, I have made some changes. Please let me know if those looks okay for you or else if changes are needed. Thank you for the patience. Apologies for the unavoidable delays in the push.

yanavasileva · 2024-12-02T09:34:11Z

The changes looks good. Thank you for your contribution, shortly I will be merging the changes to master.
I had to apply a fix in the test so I am closing this PR in favour of #4558

prakashpalanisamy · 2024-12-03T16:55:14Z

Thank you @yanavasileva for the support!!

prakashpalanisamy mentioned this pull request Mar 22, 2024

Improve job acquisition job execution logging #2666

Closed

yanavasileva assigned prakashpalanisamy Mar 25, 2024

yanavasileva self-requested a review March 25, 2024 07:35

yanavasileva reviewed Apr 8, 2024

View reviewed changes

yanavasileva closed this May 22, 2024

tasso94 reopened this Jun 28, 2024

brianwarner force-pushed the 2666-job-acquisition-execution-logging-improvement branch from b8380ab to 1622149 Compare July 11, 2024 16:13

yanavasileva self-requested a review August 14, 2024 13:21

yanavasileva requested changes Aug 22, 2024

View reviewed changes

yanavasileva reviewed Aug 23, 2024

View reviewed changes

yanavasileva requested changes Aug 24, 2024

View reviewed changes

prakashpalanisamy added 9 commits September 10, 2024 12:56

fix(job-executor): Adding helpful debug logs to improve job acquisiti…

93f55fc

…on and job execution logging. Issue#2666.

Adding helpful debug logs to improve job acquisition and job executio…

ee7cd49

…n logging. Issue#2666

refactoring done.

ac43dae

Committing the Formatting suggestions received during review.

122a217

cleanup

53eadad

job-acquisition-execution-logging-improvement-tomcat

5994aee

job-acquisition-logging-defaultexecutorimpl-and-formatting

dc1a45e

added test cases for the job-acquisition and job-execution logs

96bbbca

minor updates and comments added to the test cases

e928b61

updated the formatting

fcf5f40

prakashpalanisamy added 3 commits September 10, 2024 19:05

updates to formatting, log wording, log placement sequence based on r…

7ec050e

…eview comments.

formatting updates as per review comments

a35e5e5

license header, formatting, cleanups part of code review comments for…

e145685

… TestCaseFiles.

prakashpalanisamy added 2 commits September 25, 2024 00:05

addressed the community comments pertaining to the test cases

f6564e9

corrections in the comments

e6165b4

kayhern force-pushed the 2666-job-acquisition-execution-logging-improvement branch from 1622149 to e6165b4 Compare October 25, 2024 12:17

prakashpalanisamy requested a review from yanavasileva October 25, 2024 15:04

yanavasileva closed this Dec 2, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

fix(job-executor): Adding helpful debug logs to improve job acquisition and job execution logging. Issue#2666. #4217

fix(job-executor): Adding helpful debug logs to improve job acquisition and job execution logging. Issue#2666. #4217

prakashpalanisamy commented Mar 22, 2024 •

edited by yanavasileva

Loading

CLAassistant commented Mar 22, 2024 •

edited

Loading

yanavasileva commented Mar 25, 2024

yanavasileva left a comment

yanavasileva Apr 8, 2024

yanavasileva Aug 22, 2024

prakashpalanisamy commented Apr 8, 2024

yanavasileva commented May 22, 2024

prakashpalanisamy commented Jun 28, 2024

prakashpalanisamy commented Jul 16, 2024

yanavasileva commented Jul 16, 2024

prakashpalanisamy commented Aug 14, 2024

yanavasileva left a comment

yanavasileva Aug 22, 2024

yanavasileva left a comment

yanavasileva Aug 23, 2024

yanavasileva Aug 23, 2024

yanavasileva left a comment

yanavasileva Aug 23, 2024

yanavasileva Aug 23, 2024

yanavasileva Aug 24, 2024

yanavasileva Aug 24, 2024

yanavasileva commented Sep 7, 2024

prakashpalanisamy commented Sep 9, 2024

prakashpalanisamy commented Sep 10, 2024

yanavasileva commented Sep 10, 2024

prakashpalanisamy commented Sep 11, 2024

yanavasileva commented Sep 18, 2024

prakashpalanisamy commented Oct 25, 2024

yanavasileva commented Dec 2, 2024

prakashpalanisamy commented Dec 3, 2024

	protected int queueSize = 3;
	protected int corePoolSize = 3;
	protected int maxPoolSize = 10;

-import java.util.concurrent.*;
+import java.util.concurrent.ArrayBlockingQueue;
+import java.util.concurrent.BlockingQueue;
+import java.util.concurrent.RejectedExecutionException;
+import java.util.concurrent.ThreadPoolExecutor;
+import java.util.concurrent.TimeUnit;

	List<ILoggingEvent> filteredLogList = loggingRule.getFilteredLog("Jobs currently in queue to be executed for the process engine 'default' is 2 out of the max queue size : 2");
	List<ILoggingEvent> filteredLogList = loggingRule.getFilteredLog("Jobs currently in queue to be executed for the process engine 'default': 2 (out of the max queue size : 2)");

fix(job-executor): Adding helpful debug logs to improve job acquisition and job execution logging. Issue#2666. #4217

fix(job-executor): Adding helpful debug logs to improve job acquisition and job execution logging. Issue#2666. #4217

Conversation

prakashpalanisamy commented Mar 22, 2024 • edited by yanavasileva Loading

CLAassistant commented Mar 22, 2024 • edited Loading

yanavasileva commented Mar 25, 2024

yanavasileva left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

prakashpalanisamy commented Apr 8, 2024

yanavasileva commented May 22, 2024

prakashpalanisamy commented Jun 28, 2024

prakashpalanisamy commented Jul 16, 2024

yanavasileva commented Jul 16, 2024

prakashpalanisamy commented Aug 14, 2024

yanavasileva left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

yanavasileva left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

yanavasileva left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

yanavasileva commented Sep 7, 2024

prakashpalanisamy commented Sep 9, 2024

prakashpalanisamy commented Sep 10, 2024

yanavasileva commented Sep 10, 2024

prakashpalanisamy commented Sep 11, 2024

yanavasileva commented Sep 18, 2024

prakashpalanisamy commented Oct 25, 2024

yanavasileva commented Dec 2, 2024

prakashpalanisamy commented Dec 3, 2024

prakashpalanisamy commented Mar 22, 2024 •

edited by yanavasileva

Loading

CLAassistant commented Mar 22, 2024 •

edited

Loading