1:19 p.m.
Hi,
I am using the latest 5.1.1 (8/2010 release) Drools code to test out
rules. What I see is when I try to retract/insert an object from the
working memory, it doesn't seem to take effect.
The example is as follows. I pump metrics into the rule engine at 4s
interval. Drools is configured to run in STREAM mode to allow facts to
expire and to use the sliding window feature of Fusion. There are 2
rules, the set rule says that if the minimum value is > set threshold
over the sliding window interval, raise an alarm if not raised earlier
(it also inserts an alarm into the working memory). The clear rule says
that if the minimum value is < clear threshold over the sliding window
interval and if alarm exists, then clear the alarm and retract it.
I use the pseudo clock and advance every time I insert an event. Now, if
I use a data set, where all the values are > set threshold, then I see
that an alarm is raised and only once (as expected). But if I use a data
set that should cause a set/clear/set pattern, I see that after setting,
the clear happens twice, followed by set, which happens twice again.
I used the Drools debugger within Eclipse and saw that I was hitting the
RHS side twice in the clear/set rule. As I cannot put a break-point on
the LHS to see why it decided to do fire in the first place, I can't
tell the behavior.
Its as if drools ignores the insert/retract of the alarm action.
Thanks in advance,
sb
Here is the DRL:
package com.x.y.rules;
import java.util.Date;
import com.x.y.z.ruleengine.AlarmActionFactory;
import com.x.y.z.rule.Event.Srd;
import com.x.y.z.NaEvent;
import com.x.y.z.Common.SeverityLevels;
import com.x.y.z.Common.EventsStatus;
import com.x.y.z.rule.Event.Alarm;
global AlarmActionFactory actionFactory;
declare Srd
@role(event)
@expires(5s)
end
rule "Clear Srd threshold of 25.0 for 5s"
dialect "java"
when
$c : Srd(probeName == 'threstest1')
$SrdMin : Number(doubleValue <= 25.0) from accumulate(
Srd(probeName == $c.probeName,$v : value) over window:time(5s),
min($v)
)
$alarm : Alarm(type == 'Srd' && probeName == 'threstest1')
then
if($alarm !=null)
{
System.out.println("Clearing alarm, since Srd went below
25.0 threshold for 5s. Srd: "+$SrdMin);
System.out.println("Removing alarm from system "+$alarm);
retract($alarm);
String desc = "Clearing alarm as SessionRequestDelayMilliSecs went
below threshold 25.0 for probe threstest1";
actionFactory.logEvent(desc);
}
else
actionFactory.logEvent("WARN: clearing again, alarm doesnt
exist for Srd metric with probename threstest1");
end
rule "Set Srd threshold of 50.0 for 5s"
dialect "java"
when
$c : Srd(probeName == 'threstest1')
$minsrd : Number(doubleValue >= 50.0) from accumulate(
Srd(probeName == $c.probeName,$v : value) over window:time(5s),
min($v)
)
not Alarm(type == 'Srd' && probeName == 'threstest1')
then
System.out.println("Srd above 50.0 for 5s, raising alarm. min Srd:
"+$minsrd);
Alarm a = new Alarm("Srd","threstest1");
insert(a);
String desc = "Raised alarm as SessionRequestDelayMilliSecs hit
threshold 50.0 for probe threstest1";
actionFactory.logEvent(desc);
end
Here is the data set that is read by the java class pumping the events.
# the set/clear threshold in thres1_Srd.drl is set to 50/25.O
# the test program reads the values one line at a time
# the sliding window time and fact expiration time it set to 5s.
# the test program advances the pseudo clock by delta value
# which is the difference between the previous and the current token
value
# read from this file.
# the alarm raising pattern for this data should be
# set/clear/set
# NOTE: first value is time, second value is the actual event value.
1358,60
5359,66
9360,62
13361,24
17362,23
21363,24
25364,28
29365,21
33366,27
37367,67
41367,89
45367,92
49367,72
53367,65
57367,99
Snippet of main method of the java class
KnowledgeBuilder kbuilder =
KnowledgeBuilderFactory.newKnowledgeBuilder();
boolean useSrdMetric = true;
kbuilder.add(ResourceFactory.newClassPathResource("threstest1_Srd.drl",
REAlarmFiringTest.class),
ResourceType.DRL);
// Check the builder for errors
if (kbuilder.hasErrors())
{
System.out.println(kbuilder.getErrors().toString());
throw new RuntimeException("Unable to compile "
+ ("Srd".equals(args[0]) ? "thres1_Srd.drl" :
"thres1_Owd.drl"));
}
// get the compiled packages (which are serializable)
Collection<KnowledgePackage> pkgs =
kbuilder.getKnowledgePackages();
// to use sliding windows, have to run the engine in stream mode
// default is cloud mode..where there are no concept of time and
// event ordering
KnowledgeBaseConfiguration kbaseconfig =
KnowledgeBaseFactory.newKnowledgeBaseConfiguration();
kbaseconfig.setOption(EventProcessingOption.STREAM);
// add the packages to a knowledgebase (deploy the knowledge
packages).
KnowledgeBase kbase =
KnowledgeBaseFactory.newKnowledgeBase(kbaseconfig);
kbase.addKnowledgePackages(pkgs);
KnowledgeSessionConfiguration conf =
KnowledgeBaseFactory.newKnowledgeSessionConfiguration();
conf.setOption(ClockTypeOption.get("pseudo"));
StatefulKnowledgeSession ksession =
kbase.newStatefulKnowledgeSession(conf, null);
// get clock to manually advance and test firing..
SessionPseudoClock clock = ksession.getSessionClock();
logger.info("Pseudo clock current time initialized to " +
clock.getCurrentTime());
// we will have one helper class AlarmActionFactory, that will
provide
// static methods for all the possible actions that can be taken
// when an alarm fires, including logging events.
ksession.setGlobal("actionFactory",
AlarmActionFactory.newInstance());
// this will send data to the std err stream
ksession.addEventListener(new DebugAgendaEventListener());
ksession.addEventListener(new DebugWorkingMemoryEventListener());
// setup the audit logging
KnowledgeRuntimeLogger krlogger =
KnowledgeRuntimeLoggerFactory.newFileLogger(ksession, destdir
+ ("Srd".equals(args[0]) ? "srdaudit" :
"owdaudit"));
BufferedReader bf = new BufferedReader(new FileReader(args[1]));
String s;
int time = 0;
int count = 0;
int lastime = 0;
int delta = 0;
// NOTE: the drl are setup with a sliding window of 5s.
// We will insert objects into the RE every 4s, so that the
// previous objects linger long enough to contribute to the calc
while ((s = bf.readLine()) != null)
{
if (s.startsWith("#"))
continue;
String[] vals = s.split(",");
Event event = new Srd();
event.setValue(Integer.parseInt(vals[1]));
// set in ms
// for the first time, initialize time and lastime
// to the value read in from the first line.
time = Integer.parseInt(vals[0]);
if (count == 0)
{
lastime = time;
logger.info("Initialized lastime to " + lastime);
// this is basically time t0 when the first event gets
inserted
clock.advanceTime(time, TimeUnit.MILLISECONDS);
} else
{
// advance based on the read in time in ms
// do it only from the second insert onwards
// note that the time delta should be around 4s
delta = (int) (time - lastime);
clock.advanceTime(delta, TimeUnit.MILLISECONDS);
logger.info("Pseudo clock advanced " + delta + "ms");
}
event.setTimestamp(time);
// the probename has to be threstest1 as the drls are
configured with
// that probe name. so do not change this value.
event.setProbeName("threstest1");
logger.info("Inserted event " + event);
logger.info("Count: " + count + " Pseudo clock current time:
"
+ clock.getCurrentTime());
ksession.insert(event);
logger.info("calling drools fire rules");
ksession.fireAllRules();
count++;
lastime = time;
}
System.out.println("Inserted facts, current time is " + new
Date());
krlogger.close();
ksession.dispose();
bf.close();
System.out.println("Closed audit logger, disposing session,
exiting..");
Here is the log output of the run of the program above: Note the EVENT
MESSAGE green/red output, which gets printed as a consequence of the
rule firing. Red indicates it fired again without any other insertion of
event.
2010-09-24 11:53:17,039-INFO -[main]: Pseudo clock current time
initialized to 0
2010-09-24 11:53:17,053-INFO -[main]: Initialized lastime to 1358
2010-09-24 11:53:17,054-INFO -[main]: Inserted event Srd
[probeName=threstest1,
destIp=10.155.21.81, srcIp=10.155.21.82, timestamp=1358, value=60.0]
2010-09-24 11:53:17,054-INFO -[main]: Count: 0 Pseudo clock current
time: 1358
2010-09-24 11:53:17,074-INFO -[main]: calling drools fire rules
2010-09-24 11:53:17,076-INFO -[main]: EVENT MESSAGE: Raised alarm as
SessionRequ
estDelayMilliSecs hit threshold 50.0 for probe threstest1
2010-09-24 11:53:17,077-INFO -[main]: Pseudo clock advanced 4001ms
2010-09-24 11:53:17,077-INFO -[main]: Inserted event Srd
[probeName=threstest1,
destIp=10.155.21.81, srcIp=10.155.21.82, timestamp=5359, value=66.0]
2010-09-24 11:53:17,077-INFO -[main]: Count: 1 Pseudo clock current
time: 5359
2010-09-24 11:53:17,077-INFO -[main]: calling drools fire rules
2010-09-24 11:53:17,077-INFO -[main]: Pseudo clock advanced 4001ms
2010-09-24 11:53:17,078-INFO -[main]: Inserted event Srd
[probeName=threstest1,
destIp=10.155.21.81, srcIp=10.155.21.82, timestamp=9360, value=62.0]
2010-09-24 11:53:17,078-INFO -[main]: Count: 2 Pseudo clock current
time: 9360
2010-09-24 11:53:17,080-INFO -[main]: calling drools fire rules
2010-09-24 11:53:17,080-INFO -[main]: Pseudo clock advanced 4001ms
2010-09-24 11:53:17,080-INFO -[main]: Inserted event Srd
[probeName=threstest1,
destIp=10.155.21.81, srcIp=10.155.21.82, timestamp=13361, value=24.0]
2010-09-24 11:53:17,080-INFO -[main]: Count: 3 Pseudo clock current
time: 13361
2010-09-24 11:53:17,081-INFO -[main]: calling drools fire rules
2010-09-24 11:53:17,082-INFO -[main]: EVENT MESSAGE: Clearing alarm as
SessionRe
questDelayMilliSecs went below threshold 25.0 for probe threstest1
2010-09-24 11:53:17,082-INFO -[main]: EVENT MESSAGE: WARN: clearing
again, alarm
doesnt exist for Srd metric with probename threstest1
2010-09-24 11:53:17,082-INFO -[main]: Pseudo clock advanced 4001ms
2010-09-24 11:53:17,083-INFO -[main]: Inserted event Srd
[probeName=threstest1,
destIp=10.155.21.81, srcIp=10.155.21.82, timestamp=17362, value=23.0]
2010-09-24 11:53:17,083-INFO -[main]: Count: 4 Pseudo clock current
time: 17362
2010-09-24 11:53:17,083-INFO -[main]: calling drools fire rules
2010-09-24 11:53:17,083-INFO -[main]: Pseudo clock advanced 4001ms
2010-09-24 11:53:17,083-INFO -[main]: Inserted event Srd
[probeName=threstest1,
destIp=10.155.21.81, srcIp=10.155.21.82, timestamp=21363, value=24.0]
2010-09-24 11:53:17,084-INFO -[main]: Count: 5 Pseudo clock current
time: 21363
2010-09-24 11:53:17,084-INFO -[main]: calling drools fire rules
2010-09-24 11:53:17,084-INFO -[main]: Pseudo clock advanced 4001ms
2010-09-24 11:53:17,084-INFO -[main]: Inserted event Srd
[probeName=threstest1,
destIp=10.155.21.81, srcIp=10.155.21.82, timestamp=25364, value=28.0]
2010-09-24 11:53:17,085-INFO -[main]: Count: 6 Pseudo clock current
time: 25364
2010-09-24 11:53:17,085-INFO -[main]: calling drools fire rules
2010-09-24 11:53:17,085-INFO -[main]: Pseudo clock advanced 4001ms
2010-09-24 11:53:17,085-INFO -[main]: Inserted event Srd
[probeName=threstest1,
destIp=10.155.21.81, srcIp=10.155.21.82, timestamp=29365, value=21.0]
2010-09-24 11:53:17,086-INFO -[main]: Count: 7 Pseudo clock current
time: 29365
2010-09-24 11:53:17,086-INFO -[main]: calling drools fire rules
2010-09-24 11:53:17,086-INFO -[main]: Pseudo clock advanced 4001ms
2010-09-24 11:53:17,087-INFO -[main]: Inserted event Srd
[probeName=threstest1,
destIp=10.155.21.81, srcIp=10.155.21.82, timestamp=33366, value=27.0]
2010-09-24 11:53:17,087-INFO -[main]: Count: 8 Pseudo clock current
time: 33366
2010-09-24 11:53:17,087-INFO -[main]: calling drools fire rules
2010-09-24 11:53:17,088-INFO -[main]: Pseudo clock advanced 4001ms
2010-09-24 11:53:17,088-INFO -[main]: Inserted event Srd
[probeName=threstest1,
destIp=10.155.21.81, srcIp=10.155.21.82, timestamp=37367, value=67.0]
2010-09-24 11:53:17,088-INFO -[main]: Count: 9 Pseudo clock current
time: 37367
2010-09-24 11:53:17,088-INFO -[main]: calling drools fire rules
2010-09-24 11:53:17,089-INFO -[main]: Pseudo clock advanced 4000ms
2010-09-24 11:53:17,089-INFO -[main]: Inserted event Srd
[probeName=threstest1,
destIp=10.155.21.81, srcIp=10.155.21.82, timestamp=41367, value=89.0]
2010-09-24 11:53:17,089-INFO -[main]: Count: 10 Pseudo clock current
time: 41367
2010-09-24 11:53:17,090-INFO -[main]: calling drools fire rules
2010-09-24 11:53:17,090-INFO -[main]: EVENT MESSAGE: Raised alarm as
SessionRequ
estDelayMilliSecs hit threshold 50.0 for probe threstest1
2010-09-24 11:53:17,090-INFO -[main]: EVENT MESSAGE: Raised alarm as
SessionRequ
estDelayMilliSecs hit threshold 50.0 for probe threstest1
2010-09-24 11:53:17,091-INFO -[main]: Pseudo clock advanced 4000ms
2010-09-24 11:53:17,091-INFO -[main]: Inserted event Srd
[probeName=threstest1,
destIp=10.155.21.81, srcIp=10.155.21.82, timestamp=45367, value=92.0]
2010-09-24 11:53:17,091-INFO -[main]: Count: 11 Pseudo clock current
time: 45367
2010-09-24 11:53:17,092-INFO -[main]: calling drools fire rules
2010-09-24 11:53:17,092-INFO -[main]: Pseudo clock advanced 4000ms
2010-09-24 11:53:17,092-INFO -[main]: Inserted event Srd
[probeName=threstest1,
destIp=10.155.21.81, srcIp=10.155.21.82, timestamp=49367, value=72.0]
2010-09-24 11:53:17,092-INFO -[main]: Count: 12 Pseudo clock current
time: 49367
2010-09-24 11:53:17,093-INFO -[main]: calling drools fire rules
2010-09-24 11:53:17,093-INFO -[main]: Pseudo clock advanced 4000ms
2010-09-24 11:53:17,093-INFO -[main]: Inserted event Srd
[probeName=threstest1,
destIp=10.155.21.81, srcIp=10.155.21.82, timestamp=53367, value=65.0]
2010-09-24 11:53:17,093-INFO -[main]: Count: 13 Pseudo clock current
time: 53367
2010-09-24 11:53:17,094-INFO -[main]: calling drools fire rules
2010-09-24 11:53:17,094-INFO -[main]: Pseudo clock advanced 4000ms
2010-09-24 11:53:17,094-INFO -[main]: Inserted event Srd
[probeName=threstest1,
destIp=10.155.21.81, srcIp=10.155.21.82, timestamp=57367, value=99.0]
2010-09-24 11:53:17,094-INFO -[main]: Count: 14 Pseudo clock current
time: 57367
2010-09-24 11:53:17,095-INFO -[main]: calling drools fire rules