I've done a few small improvements to the Unit::Tracer in the C++ code.
The first one, I've moved the message buffer support from Unit::StringTracer into the base class Unit::Tracer. The buffer is used in pretty much any tracer, so it looks like a good idea. And if some subclass doesn't want to use it, it doesn't have to.
So, now in Unit::Tracer is a protected element for the use of subclasses:
Erref buffer_;
And a couple of methods for manipulating this buffer:
virtual Erref getBuffer();
virtual void clearBuffer();
They are virtual to let the subclasses do whatever they please, but the default implementation is exactly as it was in the StringTracer: return the buffer_ element, and put a new clean Errors object into the buffer_ reference.
The next improvement allows to add a custom row printer. Now not only the Perl code but also C++ code can print the rows in tracing (though you have to provide that C++ code that prints the interesting portion of the row or the whole row). This separation of the general trace logic and of the row printing will eventually make it to Perl too , but not yet.
There are two ways to do it. First, there is a virtual method
virtual void printRow(string &res, const RowType *rt, const Row *row);
You can re-define it in your subclass and do the printing. The job of this method is to append the information from the row row of the type rt to the result string res. Append, not replace.
The second way is by providing a pointer to a simple C-style function of the type:
typedef void RowPrinter(string &res, const RowType *rt, const Row *row);
The arguments are exactly the same as for the method. This pointer can be given to the Tracer constructor:
Tracer(RowPrinter *rp = NULL);
StringTracer(bool verbose = false, RowPrinter *rp = NULL);
StringNameTracer(bool verbose = false, RowPrinter *rp = NULL);
The default implementation of the method printRow() simply calls the function at this pointer if it's not NULL. So if you redefine this method in your subclass, the row printer function pointer will stop working.
Showing posts with label tracing. Show all posts
Showing posts with label tracing. Show all posts
Saturday, March 9, 2013
Monday, December 24, 2012
Unit tracing in C++
By the way, I forgot to mention that Unit lives in sched/Unit.h. Now, to the tracing.
Unlike Perl, in C++ the tracer is defined by inheriting from the class Unit::Tracer. The base class provides the Mtarget, and in the subclass all you need is define your virtual method:
virtual void execute(Unit *unit, const Label *label, const Label *fromLabel, Rowop *rop, TracerWhen when);
It gets called at the exactly same points as the Perl tracer (the C++ part of the UnitTracerPerl forwards the calls to the Perl level). The arguments are also the same as described in the Perl docs. The only difference is that the argument when is a value of enum Unit::TracerWhen.
For example:
class SampleTracer : public Unit::Tracer
{
public:
virtual void execute(Unit *unit, const Label *label, const Label *fromLabel, Rowop *rop, Unit::TracerWhen when)
{
printf("trace %s label '%s' %c\n", Unit::tracerWhenHumanString(when), label->getName().c_str(), Unit::tracerWhenIsBefore(when)? '{' : '}');
}
};
This also shows a few Unit methods used for conversion and testing of the constants:
static const char *tracerWhenString(int when, const char *def = "???");
static int stringTracerWhen(const char *when);
Convert between the when enum value and the appropriate name. def is as usual the default placeholder that will be used for an invalid value. And the conversion from string would return a -1 on an invalid value.
static const char *tracerWhenHumanString(int when, const char *def = "???");
static int humanStringTracerWhen(const char *when);
The same conversion, only using a "human-readable" string format that is nivcer for the messages. Basically, the same thing, only in the lowercase words. For example, TW_BEFORE_CHAINED would become "before-chained".
static bool tracerWhenIsBefore(int when);
static bool tracerWhenIsAfter(int when);
Determines whether a when value is a "before" or "after" kind. This is an addition from 1.1, that was introduced together with the reformed scheduling. As you can see in the example above, it's convenient for printing the braces, or if you prefer indentation, for adjusting the indentation.
The tracer object (not a class but a constructed object!) is set into the Unit:
void setTracer(Onceref<Tracer> tracer);
Onceref<Tracer> getTracer() const;
Theoretically, nothing stops you from using the same tracer object for multiple units, even from multiple threads. But the catch for that is that for the multithreaded calls the tracer must have the internal synchronization. Sharing a tracer between multiple units in the same thread is a more interesting idea. It might be useful in case of the intertwined execution, with the cross-unit calls. But the catch is that the trace will be intertwined all the time.
The SampleTracer above was just printing the trace right away. Usually a better idea is to save the trace in the tracer object and return it on demand. Triceps provides a couple of ready tracers, and they use exactly this approach.
Here is the StringTracer interface:
class StringTracer : public Tracer
{
public:
// @param verbose - if true, record all the events, otherwise only the BEGIN records
StringTracer(bool verbose = false);
// Get back the buffer of messages
// (it can also be used to add messages to the buffer)
Erref getBuffer() const
{
return buffer_;
}
// Replace the message buffer with a clean one.
// The old one gets simply dereferenced, so if you have a reference, you can keep it.
void clearBuffer();
// from Tracer
virtual void execute(Unit *unit, const Label *label, const Label *fromLabel, Rowop *rop, TracerWhen when);
protected:
Erref buffer_;
bool verbose_;
};
An Erref object is used as a buffer, where the data can be added efficiently line-by-line, and later read. On each call StringTracer::execute() builds the string res, and appends it to the buffer:
buffer_->appendMsg(false, res);
The pattern of reading the buffer contents works like this:
string tlog = trace->getBuffer()->print();
trace->clearBuffer();
The log can then be actually printed, or used in any other way. An interesting point is that clearBuffer() doesn't clear the buffer but replaces it with a fresh one. So if you keep a reference to the buffer, you can keep using it:
Erref buf = trace->getBuffer();trace->clearBuffer();
string tlog = buf->print();
The two ready tracers provided with Triceps are:
StringTracer: collects the trace in a buffer, identifying the objects as addresses. This is not exactly easy to read normally but may come useful if you want to analyze a core dump.
StringNameTracer: similar but prints the object identification as names. More convenient but prone to the duplicate names used for different objects.
Unfortunately, at the C++ level there is currently no nice printout of the rowops, like in Perl. But you can always make your own.
The tracing does not have to be used just for tracing. It can also be used for debugging, as a breakpoint: check in your tracer for an arbitrary condition, and stop if it has been met.
There is only one tracer per uint at a time. However if you want, you can implement the chaining in your own tracer (particularly useful if it's a breakpoint tracer): support a reference to another tracer object, and after doing your own part, call that one's execute() method.
Unlike Perl, in C++ the tracer is defined by inheriting from the class Unit::Tracer. The base class provides the Mtarget, and in the subclass all you need is define your virtual method:
virtual void execute(Unit *unit, const Label *label, const Label *fromLabel, Rowop *rop, TracerWhen when);
It gets called at the exactly same points as the Perl tracer (the C++ part of the UnitTracerPerl forwards the calls to the Perl level). The arguments are also the same as described in the Perl docs. The only difference is that the argument when is a value of enum Unit::TracerWhen.
For example:
class SampleTracer : public Unit::Tracer
{
public:
virtual void execute(Unit *unit, const Label *label, const Label *fromLabel, Rowop *rop, Unit::TracerWhen when)
{
printf("trace %s label '%s' %c\n", Unit::tracerWhenHumanString(when), label->getName().c_str(), Unit::tracerWhenIsBefore(when)? '{' : '}');
}
};
This also shows a few Unit methods used for conversion and testing of the constants:
static const char *tracerWhenString(int when, const char *def = "???");
static int stringTracerWhen(const char *when);
Convert between the when enum value and the appropriate name. def is as usual the default placeholder that will be used for an invalid value. And the conversion from string would return a -1 on an invalid value.
static const char *tracerWhenHumanString(int when, const char *def = "???");
static int humanStringTracerWhen(const char *when);
The same conversion, only using a "human-readable" string format that is nivcer for the messages. Basically, the same thing, only in the lowercase words. For example, TW_BEFORE_CHAINED would become "before-chained".
static bool tracerWhenIsBefore(int when);
static bool tracerWhenIsAfter(int when);
Determines whether a when value is a "before" or "after" kind. This is an addition from 1.1, that was introduced together with the reformed scheduling. As you can see in the example above, it's convenient for printing the braces, or if you prefer indentation, for adjusting the indentation.
The tracer object (not a class but a constructed object!) is set into the Unit:
void setTracer(Onceref<Tracer> tracer);
Onceref<Tracer> getTracer() const;
Theoretically, nothing stops you from using the same tracer object for multiple units, even from multiple threads. But the catch for that is that for the multithreaded calls the tracer must have the internal synchronization. Sharing a tracer between multiple units in the same thread is a more interesting idea. It might be useful in case of the intertwined execution, with the cross-unit calls. But the catch is that the trace will be intertwined all the time.
The SampleTracer above was just printing the trace right away. Usually a better idea is to save the trace in the tracer object and return it on demand. Triceps provides a couple of ready tracers, and they use exactly this approach.
Here is the StringTracer interface:
class StringTracer : public Tracer
{
public:
// @param verbose - if true, record all the events, otherwise only the BEGIN records
StringTracer(bool verbose = false);
// Get back the buffer of messages
// (it can also be used to add messages to the buffer)
Erref getBuffer() const
{
return buffer_;
}
// Replace the message buffer with a clean one.
// The old one gets simply dereferenced, so if you have a reference, you can keep it.
void clearBuffer();
// from Tracer
virtual void execute(Unit *unit, const Label *label, const Label *fromLabel, Rowop *rop, TracerWhen when);
protected:
Erref buffer_;
bool verbose_;
};
An Erref object is used as a buffer, where the data can be added efficiently line-by-line, and later read. On each call StringTracer::execute() builds the string res, and appends it to the buffer:
buffer_->appendMsg(false, res);
The pattern of reading the buffer contents works like this:
string tlog = trace->getBuffer()->print();
trace->clearBuffer();
The log can then be actually printed, or used in any other way. An interesting point is that clearBuffer() doesn't clear the buffer but replaces it with a fresh one. So if you keep a reference to the buffer, you can keep using it:
Erref buf = trace->getBuffer();trace->clearBuffer();
string tlog = buf->print();
The two ready tracers provided with Triceps are:
StringTracer: collects the trace in a buffer, identifying the objects as addresses. This is not exactly easy to read normally but may come useful if you want to analyze a core dump.
StringNameTracer: similar but prints the object identification as names. More convenient but prone to the duplicate names used for different objects.
Unfortunately, at the C++ level there is currently no nice printout of the rowops, like in Perl. But you can always make your own.
The tracing does not have to be used just for tracing. It can also be used for debugging, as a breakpoint: check in your tracer for an arbitrary condition, and stop if it has been met.
There is only one tracer per uint at a time. However if you want, you can implement the chaining in your own tracer (particularly useful if it's a breakpoint tracer): support a reference to another tracer object, and after doing your own part, call that one's execute() method.
Monday, October 8, 2012
Fork revisited
I've been working on the streaming functions, and that gave me an idea for a change in scheduling. Sorry that this description is a little dense, you'd need to get the context of the old ways from the manual for the description of the changes to make sense.
If you'd want to look up the section on Basic scheduling http://triceps.sourceforge.net/docs-1.0.1/guide.html#sc_sched_basic, and the section on Loop scheduling http://triceps.sourceforge.net/docs-1.0.1/guide.html#sc_sched_loop, I've been saying that the loop logic could use some simplification, and the forking of the rowops is getting deprecated. Now I've come up with a solution for them both.
The loops required a separate label at the beginning of the loop to put a mark on its queue frame. When the loop's body unwinds and the next iteration starts, it has to avoid pushing more frames with each iteration. So it has to put the rowop for the next iteration into that beginning frame (like fork but farther up the stack), and then unwind the whole body before the beginning label picks the next rowop from its frame and runs the loop body for the next iteration.
But now one little change in the execution of the forked rowops from the frame fixes things: rather than doing a proper call and pushing a new frame for each of them, just execute them using the parent's frame. This muddles up the precise forking sequence a little (where the rowops forked by a label were guaranteed to execute before any other rowops forked by its parent). But this precision doesn't matter much: first, forking is not used much anyway, and second, the forked labels can't have an expectation that the model won't change between them being forked and executed. However this little change is very convenient for the loops.
In a loop the first label of the loop can now put the mark directly on its frame. This mark will stay there until the loop completes, executing every iteration from that point.
If we review the example from the section on Loop scheduling, with the topology
Then the sequence will look like this:
Rowop X1 scheduled on the outer frame:
[X1]
Rowop X1 executes:
[ ] ~X1
[ ]
Label X calls the first label of the loop, A, with rowop A1:
[ ] ~A1
[ ] ~X1
[ ]
The label A calls setMark() and puts the mark M on itself:
[ ] ~A1, mark M
[ ] ~X1
[ ]
The label A then calls the rowop B1 with calls the rowop C1:
[ ] ~C1
[ ] ~B1
[ ] ~A1, mark M
[ ] ~X1
[ ]
The label C loops the rowop A2 (for the second iteration of the loop) at mark M, thus placing A2 into the A1's frame.
[ ] ~C1
[ ] ~B1
[A2] ~A1, mark M
[ ] ~X1
[ ]
Then the label C returns, label B returns, and label A returns. But A1's frame is not empty yet (* shows that A1 has completed and now it's a frame without a rowop as such).
[A2] *, mark M
[ ] ~X1
[ ]
Then A2 gets taken from the frame and executed with the context of the same frame:
[ ] ~A2, mark M
[ ] ~X1
[ ]
The label A again sets the mark M, which marks the same frame, so it's pretty much a no-op (so A doesn't really have to set the mark the second time, it's just easier this way). And then it proceeds to call B and C again:
[ ] ~C2
[ ] ~B2
[ ] ~A2, mark M
[ ] ~X1
[ ]
The label C loops again back to A:
[ ] ~C2
[ ] ~B2
[A3] ~A2, mark M
[ ] ~X1
[ ]
The stack then unrolls, finds the A2's frame not empty, takes A3 from it, and continues in the same way until C decides to not loop to A any more, calling Y instead.
This has pulled with it a few more changes. The first consequence is that the frame draining doesn't happen between executing the label itself and executing its chained labels. Now it has moved to the very end. Now the label runs, then calls whatever labels are chained from it, then the frame draining happens after all the other processing has completed. If the frame is found not empty, the first label from it gets removed from the frame and "semi-called" with the same frame. If the frame is not empty again (because either the original rowop had forked/looped rowops onto it, or because the "semi-called" one did), the next label gets removed and "semi-called", and so on.
The second consequence is that this has changed the traces of the unit tracers, and I've had to add one more TracerWhen constant. Remembering the difficulties with the nesting of the traces, this was a good time to fix that too, so I've added the second TracerWhen constant. Now all of them go nicely in pairs:
TW_BEFORE, // before calling the label's execution as such
TW_AFTER, // after all the execution is done
TW_BEFORE_CHAINED, // after execution, before calling the chained labels (if they are present)
TW_AFTER_CHAINED, // after calling the chained labels (if they were present)
TW_BEFORE_DRAIN, // before draining the label's frame if it's not empty
TW_AFTER_DRAIN, // after draining the label's frame if was not empty
The TW_BEFORE/AFTER_CHAINED trace points now get called only if there actually were any chained labels to call, and TW_BEFORE/AFTER_DRAIN trace points get called only if there were anything to drain. The DRAIN trace points get always called with the original rowop that pushed this frame onto the stack first (so that matching the "before" and "after" is easy).
The full sequence in the correct order now becomes:
TW_BEFORE
TW_BEFORE_CHAINED
TW_AFTER_CHAINED
TW_AFTER
TW_BEFORE_DRAIN
TW_AFTER_DRAIN
But since parts of it are optional, the minimal (and most typical) one is only:
TW_BEFORE
TW_AFTER
There also are new methods to check if a particular constant (in its integer form, not as a string) is a "before" or "after". Their typical usage in a trace function, to print an opening or closing brace, looks like:
if (Triceps::tracerWhenIsBefore($when)) {
$msg .= " {";
} elsif (Triceps::tracerWhenIsAfter($when)) {
$msg .= " }";
}
More trace points that are neither "before" or "after" could get added in the future, so a good practice is to use an elsif with both conditions rather than a simple if/else with one condition.
The third consequence is that the methods Unit::makeLoopHead() and Unit::makeLoopAround() now return only a pair of values, not a triplet. The "begin" label is not needed any more, so it's not created and not returned.
If you'd want to look up the section on Basic scheduling http://triceps.sourceforge.net/docs-1.0.1/guide.html#sc_sched_basic, and the section on Loop scheduling http://triceps.sourceforge.net/docs-1.0.1/guide.html#sc_sched_loop, I've been saying that the loop logic could use some simplification, and the forking of the rowops is getting deprecated. Now I've come up with a solution for them both.
The loops required a separate label at the beginning of the loop to put a mark on its queue frame. When the loop's body unwinds and the next iteration starts, it has to avoid pushing more frames with each iteration. So it has to put the rowop for the next iteration into that beginning frame (like fork but farther up the stack), and then unwind the whole body before the beginning label picks the next rowop from its frame and runs the loop body for the next iteration.
But now one little change in the execution of the forked rowops from the frame fixes things: rather than doing a proper call and pushing a new frame for each of them, just execute them using the parent's frame. This muddles up the precise forking sequence a little (where the rowops forked by a label were guaranteed to execute before any other rowops forked by its parent). But this precision doesn't matter much: first, forking is not used much anyway, and second, the forked labels can't have an expectation that the model won't change between them being forked and executed. However this little change is very convenient for the loops.
In a loop the first label of the loop can now put the mark directly on its frame. This mark will stay there until the loop completes, executing every iteration from that point.
If we review the example from the section on Loop scheduling, with the topology
X -> A -> B -> C -> Y ^ | +---------+
Then the sequence will look like this:
Rowop X1 scheduled on the outer frame:
[X1]
Rowop X1 executes:
[ ] ~X1
[ ]
Label X calls the first label of the loop, A, with rowop A1:
[ ] ~A1
[ ] ~X1
[ ]
The label A calls setMark() and puts the mark M on itself:
[ ] ~A1, mark M
[ ] ~X1
[ ]
The label A then calls the rowop B1 with calls the rowop C1:
[ ] ~C1
[ ] ~B1
[ ] ~A1, mark M
[ ] ~X1
[ ]
The label C loops the rowop A2 (for the second iteration of the loop) at mark M, thus placing A2 into the A1's frame.
[ ] ~C1
[ ] ~B1
[A2] ~A1, mark M
[ ] ~X1
[ ]
Then the label C returns, label B returns, and label A returns. But A1's frame is not empty yet (* shows that A1 has completed and now it's a frame without a rowop as such).
[A2] *, mark M
[ ] ~X1
[ ]
Then A2 gets taken from the frame and executed with the context of the same frame:
[ ] ~A2, mark M
[ ] ~X1
[ ]
The label A again sets the mark M, which marks the same frame, so it's pretty much a no-op (so A doesn't really have to set the mark the second time, it's just easier this way). And then it proceeds to call B and C again:
[ ] ~C2
[ ] ~B2
[ ] ~A2, mark M
[ ] ~X1
[ ]
The label C loops again back to A:
[ ] ~C2
[ ] ~B2
[A3] ~A2, mark M
[ ] ~X1
[ ]
The stack then unrolls, finds the A2's frame not empty, takes A3 from it, and continues in the same way until C decides to not loop to A any more, calling Y instead.
This has pulled with it a few more changes. The first consequence is that the frame draining doesn't happen between executing the label itself and executing its chained labels. Now it has moved to the very end. Now the label runs, then calls whatever labels are chained from it, then the frame draining happens after all the other processing has completed. If the frame is found not empty, the first label from it gets removed from the frame and "semi-called" with the same frame. If the frame is not empty again (because either the original rowop had forked/looped rowops onto it, or because the "semi-called" one did), the next label gets removed and "semi-called", and so on.
The second consequence is that this has changed the traces of the unit tracers, and I've had to add one more TracerWhen constant. Remembering the difficulties with the nesting of the traces, this was a good time to fix that too, so I've added the second TracerWhen constant. Now all of them go nicely in pairs:
TW_BEFORE, // before calling the label's execution as such
TW_AFTER, // after all the execution is done
TW_BEFORE_CHAINED, // after execution, before calling the chained labels (if they are present)
TW_AFTER_CHAINED, // after calling the chained labels (if they were present)
TW_BEFORE_DRAIN, // before draining the label's frame if it's not empty
TW_AFTER_DRAIN, // after draining the label's frame if was not empty
The TW_BEFORE/AFTER_CHAINED trace points now get called only if there actually were any chained labels to call, and TW_BEFORE/AFTER_DRAIN trace points get called only if there were anything to drain. The DRAIN trace points get always called with the original rowop that pushed this frame onto the stack first (so that matching the "before" and "after" is easy).
The full sequence in the correct order now becomes:
TW_BEFORE
TW_BEFORE_CHAINED
TW_AFTER_CHAINED
TW_AFTER
TW_BEFORE_DRAIN
TW_AFTER_DRAIN
But since parts of it are optional, the minimal (and most typical) one is only:
TW_BEFORE
TW_AFTER
There also are new methods to check if a particular constant (in its integer form, not as a string) is a "before" or "after". Their typical usage in a trace function, to print an opening or closing brace, looks like:
if (Triceps::tracerWhenIsBefore($when)) {
$msg .= " {";
} elsif (Triceps::tracerWhenIsAfter($when)) {
$msg .= " }";
}
More trace points that are neither "before" or "after" could get added in the future, so a good practice is to use an elsif with both conditions rather than a simple if/else with one condition.
The third consequence is that the methods Unit::makeLoopHead() and Unit::makeLoopAround() now return only a pair of values, not a triplet. The "begin" label is not needed any more, so it's not created and not returned.
Friday, July 6, 2012
more updates
Some more stuff has been getting cleaned up:
now confesses on errors, so the problem with its error checking is fixed.
The tables now allow to create rowops of rows of all matching types, not only of the equal types. The approach with matching types was not consistent with what the labels did, so I've changed it.
The TableType now has the method
that has the name consistent with the tables and labels. The old method rowType() also still exists.
The Opt::ck_ref() now also accepts the subclasses of the defined classes.
The new helper Fields::isStringType() has been added.
There also have been some major addition of the examples:
I've added a pretty big example of the main loop that includes the full socket handling in the chapter on Scheduling. It's not exactly production-ready but gives some idea.
Another addition in the chapter on Scheduling is an example of a topological loop that computes the Fibonacci numbers.
Many new examples have been added to the chapter on Templates.
$unit->setTracer($tracer);
now confesses on errors, so the problem with its error checking is fixed.
The tables now allow to create rowops of rows of all matching types, not only of the equal types. The approach with matching types was not consistent with what the labels did, so I've changed it.
The TableType now has the method
$tt->getRowType()
that has the name consistent with the tables and labels. The old method rowType() also still exists.
The Opt::ck_ref() now also accepts the subclasses of the defined classes.
The new helper Fields::isStringType() has been added.
There also have been some major addition of the examples:
I've added a pretty big example of the main loop that includes the full socket handling in the chapter on Scheduling. It's not exactly production-ready but gives some idea.
Another addition in the chapter on Scheduling is an example of a topological loop that computes the Fibonacci numbers.
Many new examples have been added to the chapter on Templates.
Friday, June 15, 2012
the Unit update
I've been editing the docs about Units, and there have been a couple of developments.
First, I've noticed that I've already got a decent fix for the more serious scheduling issue. To get the predictable order with the scheduling, just always feed the rowops one by one into the model. I've been doing it in the later examples all over the place.
Second, I think I've found a nice compromise for the tracing that on one hand doesn't create deep indentation, and on the other hand lets to find the nesting boundaries easy: add "{" and "}" at the end of the lines before and after running the label. Then it can be written to a file and an editor like vi or Emacs can be used to jump from one end to the other.
First, I've noticed that I've already got a decent fix for the more serious scheduling issue. To get the predictable order with the scheduling, just always feed the rowops one by one into the model. I've been doing it in the later examples all over the place.
Second, I think I've found a nice compromise for the tracing that on one hand doesn't create deep indentation, and on the other hand lets to find the nesting boundaries easy: add "{" and "}" at the end of the lines before and after running the label. Then it can be written to a file and an editor like vi or Emacs can be used to jump from one end to the other.
Tuesday, January 24, 2012
A Perl tracer example
For an example of what can be done with a Perl tracer, let's make a tracer function that works like UnitTracerStringName but prints the whole rowop contents too. In a "proper" way that would be an object, but to reduce the amount of code let's just make it a standalone function. It can be then used as a method of an object as well.
Note: this code has not been tested, so it might work or not work at the moment. I'll test and fix it later.
The function would take 3 extra arguments:
The code is as follows:
It is then supposed to be used like:
And produce the nicely formatted nested traces. For the previous example the nesting would be:
Each label produces two levels of nesting: one for everything after "before", another one for the nested labels. In reality this nested idea might be not that great because when a label calls another one, that will be nested, and the long call sequences may produce some very deep and unreadable nesting.
Note: this code has not been tested, so it might work or not work at the moment. I'll test and fix it later.
The function would take 3 extra arguments:
- boolean: verbosity
- reference to a variable where to append the text of the trace
- reference to a variable that would be used to keep the chaining level
The code is as follows:
sub traceStringRowop
{
my ($unit, $label, $fromLabel, $rowop, $when, $verbose, $rlog, $rnest) = @_;
return if (!$verbose && $when != &Triceps::TW_BEFORE);
${$rnest}-- if ($when != &Triceps::TW_BEFORE);
my $msg = "unit '" . $unit->getName() . "' "
. Triceps::tracerWhenHumanString($when) . " label '"
. $label->getName() . "' ";
if (defined $fromLabel) {
$msg .= "(chain '" . $fromLabel->getName() . "') ";
}
${$rlog} .= (" " x $rnest) . $msg . "op " . $rowop->printP() . "\n";
if ($verbose) {
if ($when != &Triceps::TW_AFTER) {
${$rnest}++;
} else {
${$rnest}--;
}
}
}
It is then supposed to be used like:
my ($traceLog, $traceNest); $tracer = Ticeps::UnitTracerPerl->new( 1, \&tracerStringRowop, \$traceLog, \$traceNest);
And produce the nicely formatted nested traces. For the previous example the nesting would be:
unit 'u' before label 'lab1' op ... unit 'u' drain label 'lab1' op ... unit 'u' before-chained label 'lab1' op ... unit 'u' before label 'lab2' (chain 'lab1') op ... unit 'u' drain label 'lab2' (chain 'lab1') op ... unit 'u' before-chained label 'lab2' (chain 'lab1') op ... unit 'u' before label 'lab3' (chain 'lab2') op ... unit 'u' drain label 'lab3' (chain 'lab2') op ... unit 'u' after label 'lab3' (chain 'lab2') op ... unit 'u' after label 'lab2' (chain 'lab1') op ... unit 'u' before label 'lab3' (chain 'lab1') op ... unit 'u' drain label 'lab3' (chain 'lab1') op ... unit 'u' after label 'lab3' (chain 'lab1') op ... unit 'u' after label 'lab1' op ... unit 'u' before label 'lab1' op ... unit 'u' drain label 'lab1' op ... unit 'u' before-chained label 'lab1' op ... unit 'u' before label 'lab2' (chain 'lab1') op ... unit 'u' drain label 'lab2' (chain 'lab1') op ... unit 'u' before-chained label 'lab2' (chain 'lab1') op ... unit 'u' before label 'lab3' (chain 'lab2') op ... unit 'u' drain label 'lab3' (chain 'lab2') op ... unit 'u' after label 'lab3' (chain 'lab2') op ... unit 'u' after label 'lab2' (chain 'lab1') op ... unit 'u' before label 'lab3' (chain 'lab1') op ... unit 'u' drain label 'lab3' (chain 'lab1') op ... unit 'u' after label 'lab3' (chain 'lab1') op ... unit 'u' after label 'lab1' op ...
Each label produces two levels of nesting: one for everything after "before", another one for the nested labels. In reality this nested idea might be not that great because when a label calls another one, that will be nested, and the long call sequences may produce some very deep and unreadable nesting.
Monday, January 23, 2012
Tracing the unit execution
When developing the CEP models, there always comes the question: WTF has just happened? How did it manage get this result? Followed by subscribing to many intermediate results and trying to piece together the execution order.
Triceps provides two solutions for this situation: First, the procedural approach should make the logic much easier to follow. Second, it has a ready way to trace the execution and then read the trace in one piece. It can also be used to analyze any variables on the fly, and possibly stop the execution and enter some manual mode.
The idea here is simple: provide the Unit with a method that will be called:
For the simple tracing, there is a small simple tracer provided. It actually executes directly as compiled in C++, so it's fairly efficient:
The only option supported is "verbose", which may be 0 (default) or non-0. If it's 0 (false), the tracer will record a message only before executing each label. If true, it will record a message after each stage. The class is named UnitTracerStringName because it records the execution trace in the string format, including the names of the labels. The tracer is set into the unit:
If no tracer was previously set, getTracer() will return undef. And undef can also be used as an argument of setTracer(), to cancel any previously set tracing. setTracer() is actually not done very cleanly now, because it may return an error, yet it always returns an undef. So the only way to check for an error is to check whether the string value of "$!" is empty. This will be fixed in the future.
As the unit runs, the tracing information gets collected in the tracer object. It can be extracted back with:
This does not reset the trace. To reset it, use:
Here is an example of a fairly involved verbose trace:
In non-verbose mode the same trace would be:
The actual contents of the records is not printed in either case. This is basically because the tracer is implemented in C++, and I've been trying to keep the knowledge of the meaning of the simple data types out of the C++ code as much as possible for now. But it can be implemented with a Perl tracer.
A Perl tracer is created with:
The arguments are a reference to a function, and optionally arguments for it. The resulting tracer can be used in the unit's setTracer() as usual.
Also the tracer references support the call same():
They can be caller safely for either kind of tracer, including mixing them together. Of course, the tracers of different kinds definitely would not be the same tracer object.
The function of the Perl tracer gets called as:
The arguments are:
There also are the conversion functions with strings more suitable for the human-readable messages: "before", "drain", "before-chained", "drain". These are actually the conversions used in the UnitTracerStringName. The functions for them are:
The Perl tracers allow to execute any arbitrary actions when tracing.
Triceps provides two solutions for this situation: First, the procedural approach should make the logic much easier to follow. Second, it has a ready way to trace the execution and then read the trace in one piece. It can also be used to analyze any variables on the fly, and possibly stop the execution and enter some manual mode.
The idea here is simple: provide the Unit with a method that will be called:
- before a label executes
- after the label executes but before draining its frame
- after the frame is drained but before the chained labels execute
- after all the execution caused by a label is completed
For the simple tracing, there is a small simple tracer provided. It actually executes directly as compiled in C++, so it's fairly efficient:
$tracer = Triceps::UnitTracerStringName(option => value) or die "$!";
The only option supported is "verbose", which may be 0 (default) or non-0. If it's 0 (false), the tracer will record a message only before executing each label. If true, it will record a message after each stage. The class is named UnitTracerStringName because it records the execution trace in the string format, including the names of the labels. The tracer is set into the unit:
$unit->setTracer($tracer); die "$!" if ($! ne ""); $oldTracer = $unit->getTracer();
If no tracer was previously set, getTracer() will return undef. And undef can also be used as an argument of setTracer(), to cancel any previously set tracing. setTracer() is actually not done very cleanly now, because it may return an error, yet it always returns an undef. So the only way to check for an error is to check whether the string value of "$!" is empty. This will be fixed in the future.
As the unit runs, the tracing information gets collected in the tracer object. It can be extracted back with:
$data = $tracer->print();
This does not reset the trace. To reset it, use:
$tracer->clearBuffer();
Here is an example of a fairly involved verbose trace:
unit 'u' before label 'lab1' op OP_INSERT unit 'u' drain label 'lab1' op OP_INSERT unit 'u' before-chained label 'lab1' op OP_INSERT unit 'u' before label 'lab2' (chain 'lab1') op OP_INSERT unit 'u' drain label 'lab2' (chain 'lab1') op OP_INSERT unit 'u' before-chained label 'lab2' (chain 'lab1') op OP_INSERT unit 'u' before label 'lab3' (chain 'lab2') op OP_INSERT unit 'u' drain label 'lab3' (chain 'lab2') op OP_INSERT unit 'u' after label 'lab3' (chain 'lab2') op OP_INSERT unit 'u' after label 'lab2' (chain 'lab1') op OP_INSERT unit 'u' before label 'lab3' (chain 'lab1') op OP_INSERT unit 'u' drain label 'lab3' (chain 'lab1') op OP_INSERT unit 'u' after label 'lab3' (chain 'lab1') op OP_INSERT unit 'u' after label 'lab1' op OP_INSERT unit 'u' before label 'lab1' op OP_DELETE unit 'u' drain label 'lab1' op OP_DELETE unit 'u' before-chained label 'lab1' op OP_DELETE unit 'u' before label 'lab2' (chain 'lab1') op OP_DELETE unit 'u' drain label 'lab2' (chain 'lab1') op OP_DELETE unit 'u' before-chained label 'lab2' (chain 'lab1') op OP_DELETE unit 'u' before label 'lab3' (chain 'lab2') op OP_DELETE unit 'u' drain label 'lab3' (chain 'lab2') op OP_DELETE unit 'u' after label 'lab3' (chain 'lab2') op OP_DELETE unit 'u' after label 'lab2' (chain 'lab1') op OP_DELETE unit 'u' before label 'lab3' (chain 'lab1') op OP_DELETE unit 'u' drain label 'lab3' (chain 'lab1') op OP_DELETE unit 'u' after label 'lab3' (chain 'lab1') op OP_DELETE
In non-verbose mode the same trace would be:
unit 'u' before label 'lab1' op OP_INSERT unit 'u' before label 'lab2' (chain 'lab1') op OP_INSERT unit 'u' before label 'lab3' (chain 'lab2') op OP_INSERT unit 'u' before label 'lab3' (chain 'lab1') op OP_INSERT unit 'u' before label 'lab1' op OP_DELETE unit 'u' before label 'lab2' (chain 'lab1') op OP_DELETE unit 'u' before label 'lab3' (chain 'lab2') op OP_DELETE unit 'u' before label 'lab3' (chain 'lab1') op OP_DELETE
The actual contents of the records is not printed in either case. This is basically because the tracer is implemented in C++, and I've been trying to keep the knowledge of the meaning of the simple data types out of the C++ code as much as possible for now. But it can be implemented with a Perl tracer.
A Perl tracer is created with:
$tracer = Triceps::UnitTracerPerl->new($sub, args...) or die "$!";
The arguments are a reference to a function, and optionally arguments for it. The resulting tracer can be used in the unit's setTracer() as usual.
Also the tracer references support the call same():
$result = $tracer1->same($tracer2);
They can be caller safely for either kind of tracer, including mixing them together. Of course, the tracers of different kinds definitely would not be the same tracer object.
The function of the Perl tracer gets called as:
sub($unit, $label, $fromLabel, $rowop, $when, args...)
The arguments are:
- $unit is the usual unit reference
- $label is the current label being traced
- $fromLabel is the parent label in the chaining (would be undef if the current label is called directly, without chaining from anything)
- $rowop is the current row operation
- TW_BEFORE, Triceps::TW_BEFORE_DRAIN, Triceps::TW_BEFORE_CHAINED, Triceps::TW_AFTER), the prefix TW stands for "tracer when"
- args are the extra arguments passed from the tracer creation
$string = &Triceps::tracerWhenString($value); $value = &Triceps::stringTracerWhen($string);
There also are the conversion functions with strings more suitable for the human-readable messages: "before", "drain", "before-chained", "drain". These are actually the conversions used in the UnitTracerStringName. The functions for them are:
$string = &Triceps::tracerWhenHumanString($value); $value = &Triceps::humanStringTracerWhen($string);
The Perl tracers allow to execute any arbitrary actions when tracing.
Subscribe to:
Posts (Atom)