Skip to content

Commit dbd1d54

Browse files
samuelmalesamuelmale
committed
Add comprehensive session execution logging
1 parent 11021ce commit dbd1d54

File tree

3 files changed

+98
-14
lines changed

3 files changed

+98
-14
lines changed

‎api/src/main/java/org/openmrs/module/drools/api/impl/DroolsEngineServiceImpl.java‎

Lines changed: 44 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -16,6 +16,8 @@
1616
import org.openmrs.module.drools.event.DroolsEventsManager;
1717
import org.openmrs.module.drools.session.*;
1818
import org.openmrs.module.drools.utils.CommonUtils;
19+
import org.slf4j.Logger;
20+
import org.slf4j.LoggerFactory;
1921
import org.springframework.beans.factory.annotation.Autowired;
2022

2123
import java.util.*;
@@ -24,6 +26,8 @@
2426

2527
public class DroolsEngineServiceImpl extends BaseOpenmrsService implements DroolsEngineService {
2628

29+
private static final Logger log = LoggerFactory.getLogger(DroolsEngineServiceImpl.class);
30+
2731
private KieContainer kieContainer;
2832

2933
@Autowired
@@ -40,47 +44,83 @@ public class DroolsEngineServiceImpl extends BaseOpenmrsService implements Drool
4044

4145
@Override
4246
public KieSession requestSession(String sessionId) {
47+
log.info("Requesting Drools session: {}", sessionId);
4348
KieSession session;
4449
if (ruleConfigs == null) {
50+
log.debug("Initializing session configurations");
4551
ruleConfigs = initializeSessionConfigs();
4652
}
4753
if (kieContainer == null) {
54+
log.debug("Building KieContainer");
4855
kieContainer = kieContainerBuilder.build();
4956
}
5057
if (ruleConfigs.get(sessionId) != null) {
58+
log.debug("Creating KieSession for sessionId: {}", sessionId);
5159
session = CommonUtils.createKieSession(kieContainer, ruleConfigs.get(sessionId), droolsConfig.getExternalEvaluatorManager(), globalBindings);
5260
eventsManager.subscribeSessionEventListenersIfNecessary(sessionId, session, ruleConfigs);
53-
61+
log.info("Successfully created session: {}", sessionId);
5462
return session;
5563
} else {
64+
log.error("Session configuration not found for: {}", sessionId);
5665
throw new DroolsSessionException("Can't find session configuration for: " + sessionId);
5766
}
5867
}
5968

6069
@Override
6170
public KieSession evaluate(String sessionId, Collection<? extends OpenmrsObject> facts) {
71+
log.info("Evaluating session: {} with {} facts", sessionId, facts.size());
72+
long startTime = System.currentTimeMillis();
73+
6274
KieSession currentSession = requestSession(sessionId);
6375
if (currentSession != null) {
64-
facts.forEach(currentSession::insert);
65-
currentSession.fireAllRules(getSessionAgendaFilter(currentSession, ruleConfigs.get(sessionId)));
76+
log.debug("Inserting {} facts into session: {}", facts.size(), sessionId);
77+
facts.forEach(fact -> {
78+
log.trace("Inserting fact: {} ({})", fact.getClass().getSimpleName(), fact);
79+
currentSession.insert(fact);
80+
});
81+
82+
log.debug("Firing all rules for session: {}", sessionId);
83+
int rulesFired = currentSession.fireAllRules(getSessionAgendaFilter(currentSession, ruleConfigs.get(sessionId)));
84+
long duration = System.currentTimeMillis() - startTime;
85+
86+
log.info("Session {} evaluation completed: {} rules fired in {}ms", sessionId, rulesFired, duration);
6687
} else {
88+
log.error("Could not establish KIE session: {}", sessionId);
6789
throw new DroolsSessionException("Could not establish a KIE session of ID: " + sessionId);
6890
}
6991
return currentSession;
7092
}
7193

7294
@Override
7395
public DroolsExecutionResult evaluate(String sessionId, Collection<Object> facts, String resultClassName) {
96+
log.info("Evaluating session: {} with {} facts, expecting results of type: {}", sessionId, facts.size(), resultClassName);
97+
long startTime = System.currentTimeMillis();
98+
7499
KieSession currentSession = requestSession(sessionId);
75100
DroolsExecutionResult result;
76101
if (currentSession != null) {
77-
facts.forEach(currentSession::insert);
102+
log.debug("Inserting {} facts into session: {}", facts.size(), sessionId);
103+
facts.forEach(fact -> {
104+
log.trace("Inserting fact: {} ({})", fact.getClass().getSimpleName(), fact);
105+
currentSession.insert(fact);
106+
});
107+
108+
log.debug("Firing all rules for session: {}", sessionId);
78109
int fired = currentSession.fireAllRules(getSessionAgendaFilter(currentSession, ruleConfigs.get(sessionId)));
110+
111+
log.debug("Retrieving session objects of type: {}", resultClassName);
79112
List<?> results = getSessionObjects(currentSession, resolveClass(resultClassName, currentSession.getKieBase()));
80113
result = new DroolsExecutionResult(sessionId, fired, (List<Object>) results);
114+
115+
long duration = System.currentTimeMillis() - startTime;
116+
log.info("Session {} evaluation completed: {} rules fired, {} results returned in {}ms",
117+
sessionId, fired, results.size(), duration);
118+
81119
currentSession.dispose();
120+
log.debug("Session {} disposed", sessionId);
82121

83122
} else {
123+
log.error("Could not establish KIE session: {}", sessionId);
84124
throw new DroolsSessionException("Could not establish a KIE session of ID: " + sessionId);
85125
}
86126

‎omod/src/main/java/org/openmrs/module/drools/DroolsEngineRunner.java‎

Lines changed: 35 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -24,28 +24,56 @@ public DroolsEngineRunner() {
2424

2525
@Override
2626
public void run() {
27+
log.info("Starting Drools Engine auto-start process");
2728
DroolsEngineService droolsEngineService = Context.getService(DroolsEngineService.class);
2829

30+
log.debug("Loading rule providers");
2931
Context.getRegisteredComponents(RuleProviderLoader.class).forEach(ruleProviderLoader -> {
3032
try {
31-
ruleProviderLoader.loadRuleProviders().forEach(droolsEngineService::registerRuleProvider);
33+
log.debug("Processing rule provider loader: {}", ruleProviderLoader.getClass().getSimpleName());
34+
ruleProviderLoader.loadRuleProviders().forEach(ruleProvider -> {
35+
log.debug("Registering rule provider: {}", ruleProvider.getClass().getSimpleName());
36+
droolsEngineService.registerRuleProvider(ruleProvider);
37+
});
3238
} catch (Exception e) {
33-
log.error("Error loading rule providers", e);
39+
log.error("Error loading rule providers from loader: {}", ruleProviderLoader.getClass().getSimpleName(), e);
3440
}
3541
});
36-
droolsEngineService.getSessionsForAutoStart().forEach(sessionConfig -> {
37-
KieSession session = droolsEngineService.requestSession(sessionConfig.getSessionId());
38-
session.fireAllRules();
39-
openSessions.add(session);
42+
43+
var autoStartSessions = droolsEngineService.getSessionsForAutoStart();
44+
log.info("Found {} session(s) configured for auto-start", autoStartSessions.size());
45+
46+
autoStartSessions.forEach(sessionConfig -> {
47+
try {
48+
String sessionId = sessionConfig.getSessionId();
49+
log.info("Auto-starting session: {}", sessionId);
50+
long startTime = System.currentTimeMillis();
51+
52+
KieSession session = droolsEngineService.requestSession(sessionId);
53+
int rulesFired = session.fireAllRules();
54+
openSessions.add(session);
55+
56+
long duration = System.currentTimeMillis() - startTime;
57+
log.info("Auto-start session {} completed: {} rules fired in {}ms", sessionId, rulesFired, duration);
58+
} catch (Exception e) {
59+
log.error("Error auto-starting session: {}", sessionConfig.getSessionId(), e);
60+
}
4061
});
62+
63+
log.info("Drools Engine auto-start process completed. {} session(s) active", openSessions.size());
4164
}
4265

4366
public void startDroolsEngine() {
4467
Daemon.runInDaemonThreadWithoutResult(this, daemonToken);
4568
}
4669

4770
public void shutdown() {
48-
this.openSessions.forEach(KieSession::dispose);
71+
log.info("Shutting down Drools Engine, disposing {} open session(s)", openSessions.size());
72+
this.openSessions.forEach(session -> {
73+
log.debug("Disposing session");
74+
session.dispose();
75+
});
76+
log.info("Drools Engine shutdown complete");
4977
}
5078

5179
public static void setDaemonToken(DaemonToken token) {

‎omod/src/main/java/org/openmrs/module/drools/web/DroolsSessionExecutor.java‎

Lines changed: 19 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -4,6 +4,8 @@
44
import org.openmrs.module.drools.api.DroolsEngineService;
55
import org.openmrs.module.drools.session.DroolsExecutionResult;
66
import org.openmrs.module.drools.session.DroolsSessionConfig;
7+
import org.slf4j.Logger;
8+
import org.slf4j.LoggerFactory;
79
import org.springframework.beans.factory.annotation.Autowired;
810
import org.springframework.stereotype.Component;
911

@@ -18,6 +20,8 @@
1820
@Component
1921
public class DroolsSessionExecutor {
2022

23+
private static final Logger log = LoggerFactory.getLogger(DroolsSessionExecutor.class);
24+
2125
@Autowired
2226
private DroolsEngineService droolsService;
2327

@@ -42,29 +46,41 @@ public void destroy() {
4246
* Synchronous execution
4347
*/
4448
public DroolsExecutionResult executeSession(String sessionId, Map<String, String> params) {
49+
log.info("Executing session synchronously: {} with parameters: {}", sessionId, params.keySet());
4550
return performExecution(sessionId, params);
4651
}
4752

4853
/**
4954
* Asynchronous execution
5055
*/
5156
public CompletableFuture<DroolsExecutionResult> executeSessionAsync(String sessionId, Map<String, String> params) {
57+
log.info("Executing session asynchronously: {} with parameters: {}", sessionId, params.keySet());
5258
return CompletableFuture.supplyAsync(() -> performExecution(sessionId, params), executorService);
5359
}
5460

5561
private DroolsExecutionResult performExecution(String sessionId, Map<String, String> params) {
62+
log.debug("Performing execution for session: {}", sessionId);
63+
long startTime = System.currentTimeMillis();
64+
5665
DroolsSessionConfig config = droolsService.getSessionConfig(sessionId);
5766
String clazzName = config.getReturnObjectsTypeClassName();
5867
if (StringUtils.isBlank(clazzName)) {
5968
throw new IllegalArgumentException(
6069
"Missing return object type class configuration for session '" + sessionId + "'. " +
6170
"The session configuration must specify a valid fully-qualified class name " +
62-
"in the 'returnObjectsTypeClassName' property."
63-
);
71+
"in the 'returnObjectsTypeClassName' property.");
6472
}
6573

74+
log.debug("Resolving facts from parameters for session: {}", sessionId);
6675
List<Object> facts = parameterFactResolver.resolveFacts(config, params);
76+
log.debug("Resolved {} facts from parameters", facts.size());
77+
78+
DroolsExecutionResult result = droolsService.evaluate(sessionId, facts, clazzName);
79+
80+
long duration = System.currentTimeMillis() - startTime;
81+
log.info("Session {} execution completed in {}ms: {} rules fired, {} results",
82+
sessionId, duration, result.getFiredRulesCount(), result.getResults().size());
6783

68-
return droolsService.evaluate(sessionId, facts, clazzName);
84+
return result;
6985
}
7086
}

0 commit comments

Comments
 (0)