TEC Rule Tracing
Tracing is an invaluable aid when developing or troubleshooting rulebases. Unfortunately in an environment where you're sharing the development load, or you have many background events arriving, searching through the trace log can be a lengthy process and often quite frustrating. In last weeks tip I described how you could turn on and off rule tracing dynamically.
This weeks tip describes how you can trace just those rules or actions you're developing, rather than the whole rulebase.
Tracing Particular Rules
Using the custom rule templates we created last week, we can insert tracing rules and or actions around the rules or actions we actually want to see trace information for. The tracing templates we use are as follows:-
rule: initialise_rulebase:
(
event: _event of_class _
where [ ],
reception_action: is_initialised:
(
/* Have we been initialised yet? This gets round the problem
that TEC_Start may not be the first event to be processed
if we have QUEUED or WAITING events hanging around from
before the last restart */
initialised(_state),
/* If this succeeds then we've already been initialised,
therefore we'll skip the definitions of our custom
templates below */
commit_action
),
reception_action: set_initialised:
(
/* Set initialised flag */
assert(initialised('YES'))
),
reception_action: define_custom_templates:
(
/* First my own trace routine so I can see what's happening
within my own custom templates */
/* This was described in last weeks tip */
assert((trace_msg(_msg) :-
/* Check current status */
recorded(recording, debugger, _status),
/* If it's on, then we'll write a message */
_status == 'on',
/* Get the filehandle for the trace file */
recorded(trace_file, debugger, _F),
fprintf(_F, '---->> %s\n', _msg);
/* Else we won't - but never fail */
true
)),
/* The following will allow tracing to switched on or off as
and when we tell the rulebase to */
assert((trace_mode(_switch) :-
/* Produce trace message - switching off
(NOTE: will only if appear if tracing already
switched on) */
atomconcat(['Rule tracing switched: ', _switch], _msg1),
trace_msg(_msg1),
/* Switch trace modes */
erase(recording, debugger),
record(recording, debugger, _switch),
/* Produce trace message - switching on
(NOTE: will only if was already switched off) */
atomconcat(['Rule tracing switched: ', _switch], _msg2),
trace_msg(_msg2)
))
)
).?>
|
This sets up the custom templates which I usually put in the first ruleset - initialise.rls.
Now we need to define our rules that will switch on and off tracing. I use the following rules to switch on tracing:
rule: trace_on:
(
event: _event of_class _
where [ ],
action: switch_trace_on:
(
trace_mode('on')
)
).?>
|
and after the rule I want to trace, I use the following to turn off tracing:-
rule: trace_off:
(
event: _event of_class _
where [ ],
action: switch_trace_off:
(
trace_mode('off')
)
).?>
|
Sometimes it's just particular actions I want to trace rather than the whole rule, so I just include the action part in the rule before and after.
Note, you need to be careful about commits, if you commit before you switch tracing off then you'll get trace information for all other rules and events.
The following is a simple example where I turn on tracing before and after.
rule: switch_trace_on:
(
event: _event of_class _
where [ ],
action: on:
(
trace_mode('on')
)
).
rule: update_severity:
(
event: _event of_class 'TEC_Notice'
where [
severity: _new_severity
],
reception_action:
(
first_instance(
event: _old_event of_class 'TEC_Notice'
where [
severity: outside [ _new_severity ]
]),
bo_set_slotval(_old_event, severity, _new_severity),
re_mark_as_modified(_old_event, _)
)
).
rule: switch_trace_off:
(
event: _event of_class _
where [ ],
action: off:
(
trace_mode('off')
)
).?>
|
Which creates the following trace information
---->> Rule tracing switched: on
[1] exit trace_mode(on)
[2] exit trace_mode(on)
[3] -> rule update_severity
event : 0x1631dd0 of_class TEC_Notice
[4] call condition
[5] call severity : _500
[6] exit severity : FATAL
[7] exit condition
[8] call reception_action action_1
[9] call first_instance(event : _1394 of_class TEC_Notice
where [severity : outside [FATAL]])
[10] exit first_instance(event : 0x1633940 of_class TEC_Notic
e where [severity : outside [FATAL]])
[11] call bo_set_slotval(0x1633940,severity,FATAL)
[12] exit bo_set_slotval(0x1633940,severity,FATAL)
[13] call re_mark_as_modified(0x1633940, _2530 )
[14] exit re_mark_as_modified(0x1633940, _2792 )
[15] exit reception_action action_1
[16] -> rule switch_trace_off
event : 0x1631dd0 of_class _53
[17] call action off
[18] call trace_mode(off)
---->> Rule tracing switched: off?>
|
NOTE: In order to dynamically switch tracing on and off the rulebase must have originally been compiled in trace mode ie using wcomprules -t
Page last updated by Giles McGarry