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 can add your own additional trace information to the rules to help in the development and troubleshooting processes.
This weeks tip describes how you can dynamically switch on and off tracing of your rulebase without having to perform a restart.
Dynamically Changing the Trace Mode
Within your rules it is possible to check and change the current trace mode of the rulebase. To do this first you need to create your own tracing templates. The ones I use are:-
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. Next we need provide a mechanism where we can actually call this new trace_mode template. First I define a new set of BAROC classes: (actually I usually tag them on the end of tec.baroc).
TEC_CLASS:
TEC_Trace ISA EVENT
DEFINES {
source: default = "TEC";
severity: default = HARMLESS;
};
END
TEC_CLASS:
TEC_Trace_ON ISA TEC_Trace;
END
TEC_CLASS:
TEC_Trace_OFF ISA TEC_Trace;
END?>
|
Now for the rule that actually cause the mode switch to take place
rule: switch_trace_mode:
(
event: _event of_class 'TEC_Trace'
where [ ],
reception_action: switch_trace_on:
(
bo_get_class_of(_event, _class),
_class == 'TEC_Trace_ON',
trace_mode('on')
),
reception_action: switch_trace_off:
(
bo_get_class_of(_event, _class),
_class == 'TEC_Trace_OFF',
trace_mode('off')
),
reception_action: drop_event:
(
drop_received_event,
commit_set
)
).?>
|
Now I can send in a new event whenever I want to turn tracing on or off eg to turn tracing on:
wpostemsg TEC_Trace_ON EVENT
and off
wpostemsg TEC_Trace_OFF EVENT
The following trace extract shows this in action
[46] => rule set troubleshooting
[47] -> rule dump_cache
event : 0x1632660 of_class TEC_Notice
[48] call condition
[49] call msg : _621
[50] exit msg : test
[51] call msg : test equals 'Dump Cache Events'
[52] fail msg : test equals 'Dump Cache Events'
[53] fail condition
[54] => rule set initialise
[55] => rule set troubleshooting
[56] -> rule switch_trace_mode
event : 0x1632878 of_class TEC_Trace_OFF
[57] call reception_action switch_trace_on
[58] call bo_get_class_of(0x1632878, _570 )
[59] exit bo_get_class_of(0x1632878,TEC_Trace_OFF)
[60] call TEC_Trace_OFF == TEC_Trace_ON
[61] fail TEC_Trace_OFF == TEC_Trace_ON
[62] fail reception_action switch_trace_on
[63] call reception_action switch_trace_off
[64] call bo_get_class_of(0x1632878, _570 )
[65] exit bo_get_class_of(0x1632878,TEC_Trace_OFF)
[66] call TEC_Trace_OFF == TEC_Trace_OFF
[67] exit TEC_Trace_OFF == TEC_Trace_OFF
[68] call trace_mode(off)
---->> Rule tracing switched: off
---->> Rule tracing switched: on
[69] exit trace_mode(on)
[70] exit trace_mode(on)
[71] call reception_action switch_trace_off
[72] call bo_get_class_of(0x1632878, _283 )
[73] exit bo_get_class_of(0x1632878,TEC_Trace_ON)
[74] call TEC_Trace_ON == TEC_Trace_OFF
[75] fail TEC_Trace_ON == TEC_Trace_OFF
[76] fail reception_action switch_trace_off
[77] call reception_action drop_event
[78] call drop_received_event
[79] exit drop_received_event
[80] call commit_set
[81] exit commit_set
[82] exit reception_action drop_event?>
|
As you can see the rules were being traced up until the point trace_mode(off) was called, then everything else was ignored. This included the successful trace_mode(off) exit, the test events and the reception of the TEC_Trace_ON event) until the trace_mode(on) exitted (again the call to trace_mode(on) was missed. All off this happening between lines 68 and 69.
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