oracle-samples/clara-rules

Exceptions thrown in the rules engine during propagate-items-to-nodes need better debugging information

Closed this issue · 4 comments

k13gomez commented

When an exception is thrown inside the method propagate-items-to-nodes the stack trace provides very little details about which rule was it that threw the exception and where to handle. For this reason I think it would be much useful if an exception was thrown with cause and better debugging information such as the condition and rule (by fully qualified namespace name) where it was thrown.

Example new message:

Condition exception raised.
condition:
[?fact-binding <- TemperatureControlBlah]
rules:
my-rules.namespace.core/my-rule

java.lang.NullPointerException: null
at clojure.lang.Numbers.ops (Numbers.java:1068)
clojure.lang.Numbers.gte (Numbers.java:263)
clojure.core$eval4653$TN_2647_TE__5713.invoke (NO_SOURCE_FILE:0)
clojure.core$filter$fn__5911.invoke (core.clj:2821)
clojure.lang.LazySeq.sval (LazySeq.java:42)
clojure.lang.LazySeq.seq (LazySeq.java:51)
clojure.lang.RT.seq (RT.java:535)
clojure.core$seq__5419.invokeStatic (core.clj:139)
clojure.core/seq (core.clj:139)
clara.rules.engine$propagate_items_to_nodes.invokeStatic (engine.cljc:164)
clara.rules.engine$propagate_items_to_nodes.invoke (engine.cljc:147)
clara.rules.engine.LocalTransport.send_tokens (engine.cljc:179)
clara.rules.engine.TestNode.left_activate (engine.cljc:940)
clara.rules.engine$fn__12690$G__12637__12697.invoke (engine.cljc:99)
clara.rules.engine$fn__12690$G__12636__12705.invoke (engine.cljc:99)
clara.rules.engine$propagate_items_to_nodes.invokeStatic (engine.cljc:165)
clara.rules.engine$propagate_items_to_nodes.invoke (engine.cljc:147)
clara.rules.engine.LocalTransport.send_tokens (engine.cljc:179)
clara.rules.engine$send_accumulated.invokeStatic (engine.cljc:990)
clara.rules.engine$send_accumulated.invoke (engine.cljc:970)
clara.rules.engine.AccumulateNode.left_activate (engine.cljc:1058)
clara.rules.engine$fn__12690$G__12637__12697.invoke (engine.cljc:99)
clara.rules.engine$fn__12690$G__12636__12705.invoke (engine.cljc:99)
clara.rules.engine$propagate_items_to_nodes.invokeStatic (engine.cljc:155)
clara.rules.engine$propagate_items_to_nodes.invoke (engine.cljc:147)
clara.rules.engine.LocalTransport.send_tokens (engine.cljc:179)
clara.rules.engine$send_accumulated.invokeStatic (engine.cljc:990)
clara.rules.engine$send_accumulated.invoke (engine.cljc:970)
clara.rules.engine.AccumulateNode.left_activate (engine.cljc:1036)
clara.rules.engine$fn__12690$G__12637__12697.invoke (engine.cljc:99)
clara.rules.engine$fn__12690$G__12636__12705.invoke (engine.cljc:99)
clara.rules.engine$propagate_items_to_nodes.invokeStatic (engine.cljc:165)
clara.rules.engine$propagate_items_to_nodes.invoke (engine.cljc:147)
clara.rules.engine.LocalTransport.send_tokens (engine.cljc:179)
clara.rules.engine$send_accumulated.invokeStatic (engine.cljc:990)
clara.rules.engine$send_accumulated.invoke (engine.cljc:970)
clara.rules.engine.AccumulateNode.left_activate (engine.cljc:1058)
clara.rules.engine$fn__12690$G__12637__12697.invoke (engine.cljc:99)
clara.rules.engine$fn__12690$G__12636__12705.invoke (engine.cljc:99)
clara.rules.engine$propagate_items_to_nodes.invokeStatic (engine.cljc:155)
clara.rules.engine$propagate_items_to_nodes.invoke (engine.cljc:147)
clara.rules.engine.LocalTransport.send_tokens (engine.cljc:179)
clara.rules.engine$send_accumulated.invokeStatic (engine.cljc:990)
clara.rules.engine$send_accumulated.invoke (engine.cljc:970)
clara.rules.engine.AccumulateWithJoinFilterNode.left_activate (engine.cljc:1404)
clara.rules.engine$fn__12690$G__12637__12697.invoke (engine.cljc:99)
clara.rules.engine$fn__12690$G__12636__12705.invoke (engine.cljc:99)
clara.rules.engine$propagate_items_to_nodes.invokeStatic (engine.cljc:155)
clara.rules.engine$propagate_items_to_nodes.invoke (engine.cljc:147)
clara.rules.engine.LocalTransport.send_tokens (engine.cljc:179)
clara.rules.engine.RootJoinNode.right_activate (engine.cljc:582)
clara.rules.engine$fn__12718$G__12712__12725.invoke (engine.cljc:107)
clara.rules.engine$fn__12718$G__12711__12733.invoke (engine.cljc:107)
clara.rules.engine$propagate_items_to_nodes.invokeStatic (engine.cljc:165)
clara.rules.engine$propagate_items_to_nodes.invoke (engine.cljc:147)
clara.rules.engine.LocalTransport.send_elements (engine.cljc:176)
clara.rules.engine.AlphaNode.alpha_activate (engine.cljc:538)
clara.rules.engine$flush_updates$flush_all__13057.invoke (engine.cljc:269)
clara.rules.engine$flush_updates.invokeStatic (engine.cljc:277)
clara.rules.engine$flush_updates.invoke (engine.cljc:252)
clara.rules.engine$fire_rules_STAR_.invokeStatic (engine.cljc:1839)
clara.rules.engine$fire_rules_STAR_.invoke (engine.cljc:1732)
clara.rules.engine.LocalSession.fire_rules (engine.cljc:1925)
clara.rules$fire_rules.invokeStatic (rules.cljc:44)
clara.rules$fire_rules.invoke (rules.cljc:29)
rules.engine$run_rules_BANG_.invokeStatic (engine.clj:72)
rules.engine$run_rules_BANG_.doInvoke (engine.clj:54)
clojure.lang.RestFn.applyTo (RestFn.java:139)
clojure.core$apply.invokeStatic (core.clj:669)
clojure.core$apply.invoke (core.clj:662)
rules.engine$run_rules_async_BANG_$fn__17913.invoke (engine.clj:139)
async_util.pool$future_supplier$reify__16298.get (pool.clj:31)
java.util.concurrent.CompletableFuture$AsyncSupply.run (:-1)
java.util.concurrent.ThreadPoolExecutor.runWorker (:-1)
java.util.concurrent.ThreadPoolExecutor$Worker.run (:-1)
java.lang.Thread.run (:-1)

EthanEChristian commented

based on the stacktrace, i would assume the rule that produced it was something along the lines of:

(defrule a-rule
  [SomeFact (= ?maybe-numeric-field maybe-numeric-field)]
  [:test (>= ?maybe-numeric-field 42)]
  =>
  (<do something>))

where the maybe-numeric-field happened to be null.

@k13gomez,
Would it also make sense to add the item that was being propagated to the error as well?

k13gomez commented

@EthanEChristian yes the rule was something similar to that, except the maybe-numeric-field was inside an accumulated/merged map, either way it would be useful to have the item being propagated but I might need some help doing that. I'm writing some test cases right now to help me with that but if you have some suggestions that'd be great.

k13gomez commented

@EthanEChristian this is what the new stack trace would look like:

clojure.lang.ExceptionInfo: Condition exception raised.
when processing fact
  #clara.rules.testfacts.WindSpeed{:windspeed 10, :location "MCI"}
  #clara.rules.testfacts.Temperature{:temperature nil, :location "MCI"}
with bindings
  {:?w 10, :?t nil}
Conditions:

1. [:test (> ?t ?w)]
   queries:
     my-test-query

 at clojure.core$ex_info.invoke (core.clj:4593)
    clara.rules.engine$throw_condition_exception.invoke (engine.cljc:507)
    clara.rules.engine$test_node_matches$fn__6131.invoke (engine.cljc:934)
    clara.rules.engine$test_node_matches.invoke (engine.cljc:931)
    clojure.core$partial$fn__4531.invoke (core.clj:2507)
    clojure.core$filter$fn__4580.invoke (core.clj:2690)
    clojure.lang.LazySeq.sval (LazySeq.java:40)
    clojure.lang.LazySeq.seq (LazySeq.java:49)
    clojure.lang.RT.seq (RT.java:507)
    clojure.core/seq (core.clj:137)
    clara.rules.engine$propagate_items_to_nodes.invoke (engine.cljc:164)
    clara.rules.engine.LocalTransport.send_tokens (engine.cljc:179)
    clara.rules.engine.TestNode.left_activate (engine.cljc:953)
    clara.rules.engine$eval4927$fn__4971$G__4913__4978.invoke (engine.cljc:99)
    clara.rules.engine$eval4927$fn__4971$G__4912__4986.invoke (engine.cljc:99)
    clara.rules.engine$propagate_items_to_nodes.invoke (engine.cljc:165)
    clara.rules.engine.LocalTransport.send_tokens (engine.cljc:179)
    clara.rules.engine.HashJoinNode.right_activate (engine.cljc:651)
    clara.rules.engine$eval5008$fn__5009$G__4998__5016.invoke (engine.cljc:107)
    clara.rules.engine$eval5008$fn__5009$G__4997__5024.invoke (engine.cljc:107)
    clara.rules.engine$propagate_items_to_nodes.invoke (engine.cljc:165)
    clara.rules.engine.LocalTransport.send_elements (engine.cljc:176)
    clara.rules.engine.AlphaNode.alpha_activate (engine.cljc:540)
    clara.rules.engine.LocalSession/fn (engine.cljc:1932)
    clara.rules.engine.LocalSession.fire_rules (engine.cljc:1925)
    clara.rules$fire_rules.invoke (rules.cljc:44)
    clara.test_rules$eval16115$fn__16116.invoke (form-init3212989977979054669.clj:2376)
    clara.test_rules$eval16115.invoke (form-init3212989977979054669.clj:2373)
    clojure.lang.Compiler.eval (Compiler.java:6782)
    clojure.lang.Compiler.eval (Compiler.java:6745)
    clojure.core$eval.invoke (core.clj:3081)
    nrepl.middleware.interruptible_eval$evaluate$fn__744.invoke (interruptible_eval.clj:91)
    clojure.main$repl$read_eval_print__7099$fn__7102.invoke (main.clj:240)
    clojure.main$repl$read_eval_print__7099.invoke (main.clj:240)
    clojure.main$repl$fn__7108.invoke (main.clj:258)
    clojure.main$repl.doInvoke (main.clj:258)
    clojure.lang.RestFn.invoke (RestFn.java:1523)
    nrepl.middleware.interruptible_eval$evaluate.invoke (interruptible_eval.clj:84)
    nrepl.middleware.interruptible_eval$interruptible_eval$fn__770$fn__774.invoke (interruptible_eval.clj:155)
    clojure.lang.AFn.run (AFn.java:22)
    nrepl.middleware.session$session_exec$main_loop__867$fn__869.invoke (session.clj:190)
    nrepl.middleware.session$session_exec$main_loop__867.invoke (session.clj:189)
    clojure.lang.AFn.run (AFn.java:22)
    java.lang.Thread.run (Thread.java:748)
Caused by: java.lang.NullPointerException: null
 at clojure.lang.Numbers.ops (Numbers.java:1013)
    clojure.lang.Numbers.gt (Numbers.java:229)
    clara.test_rules$eval13532$TN_3_TE__13539.invoke (form-init3212989977979054669.clj:2368)
    clara.test_rules$eval13532$fn__13541.invoke (form-init3212989977979054669.clj:2368)
    clojure.lang.AFn.applyToHelper (AFn.java:154)
   ...
k13gomez commented

I've updated the PR to specifically handle TestNode which seems to be the one missing throw-condition-exception functionality.