An example of moldable logging using Beacon
This page gives a quick introduction to using Beacon for moldable logging.
The main idea is to define signals for capturing the start and stop of relevant actions, and create based on those log signals, nested high level events.
In generic terms in this terminology we define signals and events as:
signal : an object that has a timestamp plus relevant data
event : an object that has a duration given by a start and and end signal.
An event can contain more than two signals, as long as it has a start and stop signal. Also an event can have child events to group together multiple related steps of a larger operation.
Moldable logging can viewed as parsing where a signal is a token and an event is an AST node . A "parser" takes a "logging grammar" and uses it to create events from signals.
In the current implementation of moldable logging, as a parser we use a grouper that uses information from signals to create the structure of events.
For that a signal instance needs to knows three basic information:
- is the signal a start signal for an event
- start signals should know the type of event that should be created
- is the signal an end signal for an event
The above model is enough to create a model of nested events from a set of operations executed in sequential order.
For grouping signals from parallel operations, each signal should contain the required information for mapping the start and end signal to the right operation.
There are several ways to model events and signals, either by defining concrete classes or by using generic instances.
Concrete classes: Signal classes can directly subclass BeaconSignal
and event classes can subclass GtBeaconLogEvent
. Start signal should implement an eventType method indicating the type of the actual event.
Generic events: They subclass GtBeaconGenericLogEvent
and have a label that describes the operation.
Generic signals: We use two types depending on weather or not we need a concrete or generic signal.
Generic typed signals: They subclass GtBeaconTypedLogSignal
. A typed generic signal knows the class of the corresponding event that will be instantiated from that signal.
Generic labeled signal: They subclass GtBeaconLabelledLogSignal
. A labelled generic signal creates a GtBeaconGenericLogEvent
.
To facilitate the creation of events, BeaconSignal
instances are automatically grouped into GtBeaconLogEvent
instances using a GtBeaconEventsGrouper
.
A useful aspect is that GtBeaconEventsCollector
can do that grouping live inside the image as signals are emitted, or we can parse the console log for Beacon signals and get exactly the same result.
For this to work it is important that Beacon signals can be fully serialisable.
Here we build an full example by creating concrete classes for signals and events
We first need signals for modeling the start and stop of an event. We can do that with a single signal class that uses the trait TGtBeaconSignalStartEndType
, or with two different classes. For this demo we use two signal classes, namely GtMyExampleBeaconStartSignal
and GtMyExampleBeaconStopSignal
.
We can manually start two loggers , one in memory and one that prints to the console.
memoryLogger := MemoryLogger startFor: GtMyExampleBeaconStartSignal, GtMyExampleBeaconStopSignal.
consoleLogger := NonInteractiveTranscriptLogger startFor: GtMyExampleBeaconStartSignal, GtMyExampleBeaconStopSignal.
We can also start a collector
GtMyExampleBeaconEventsCollector start
Next we emit example Beacon signals. Here we also simulate nesting of signals.
1 to: 10 do: [ :anIndex | GtMyExampleBeaconStartSignal emit: 'Start at index ', anIndex asString. 100 atRandom milliSeconds wait. (anIndex//4)isZero ifTrue: [ GtMyExampleBeaconStartSignal emit: 'Start subcommand at index ' , anIndex asString. 100 atRandom milliSeconds wait. GtMyExampleBeaconStopSignal emit: 'Stop subcommand at index ' , anIndex asString ]. GtMyExampleBeaconStopSignal emit: 'Stop at index ', anIndex asString ].
MemoryLogger reset
MemoryLogger instance.
We can now manually group signals into events.
grouper := GtBeaconEventsGrouper new. grouper processEventSignalsFor: MemoryLogger instance recordings. grouper
We can also look at the example collector that does the grouping automatically.
GtMyExampleBeaconEventsCollector defaultInstance.
If we copy the log from the console to the clipboard we can also read the signals and create the grouping
GtMyExampleBeaconSignalsReader readFrom: Clipboard clipboardText asString
There is also an example log in case you do not have access to the console.
GtMyExampleBeaconSignalsReader readFromExample
Here we stop all previously started loggers
memoryLogger ifNotNil: [ aLogger | aLogger stop ]. consoleLogger ifNotNil: [ aLogger | aLogger stop ].
GtMyExampleBeaconEventsCollector stop
Instead of creating a class for each signal that should start/stop an event, we can use GtBeaconTypedLogSignal
and indicate in the signal the name of the event class
1 to: 10 do: [ :anIndex | (GtBeaconTypedLogSignal new markAsStartSignal; eventTypeName: #GtMyExampleBeaconLogEvent; signalLabel: 'Start at index ', anIndex asString) emit. 100 atRandom milliSeconds wait. (anIndex//4)isZero ifTrue: [ (GtBeaconTypedLogSignal new markAsStartSignal; eventTypeName: #GtMyExampleBeaconLogEvent; signalLabel:'Start subcommand at index ' , anIndex asString) emit. 100 atRandom milliSeconds wait. (GtBeaconTypedLogSignal new markAsEndSignal; eventTypeName: #GtMyExampleBeaconLogEvent; signalLabel: 'Stop subcommand at index ' , anIndex asString) emit ]. (GtBeaconTypedLogSignal new markAsEndSignal; eventTypeName: #GtMyExampleBeaconLogEvent; signalLabel: 'Stop at index ', anIndex asString) emit ].
We can use a generic collector that collect events of type GtBeaconTypedLogSignal
.
eventsCollector := GtBeaconGenericEventsCollector forSignalType: GtBeaconTypedLogSignal groupedUsing: GtBeaconEventsGrouper new.
eventsCollector start
eventsCollector stop
We can also avoid creating classes for signals and events by using GtBeaconLabelledLogSignal
that result in events of type GtBeaconGenericLogEvent
. An event type label can be added to signals to signals to differentiate them.
1 to: 10 do: [ :anIndex | (GtBeaconLabelledLogSignal new markAsStartSignal; eventTypeLabel: #MyExampleEvent; signalLabel: 'Start at index ', anIndex asString) emit. 100 atRandom milliSeconds wait. (anIndex//4)isZero ifTrue: [ (GtBeaconLabelledLogSignal new markAsStartSignal; eventTypeLabel: #MyExampleEvent; signalLabel:'Start subcommand at index ' , anIndex asString) emit. 100 atRandom milliSeconds wait. (GtBeaconLabelledLogSignal new markAsEndSignal; eventTypeLabel: #MyExampleEvent; signalLabel: 'Stop subcommand at index ' , anIndex asString) emit ]. (GtBeaconLabelledLogSignal new markAsEndSignal; eventTypeLabel: #MyExampleEvent; signalLabel: 'Stop at index ', anIndex asString) emit ].
When using a collector we are interested in signals of type GtBeaconLabelledLogSignal
.
eventsCollector := GtBeaconGenericEventsCollector forSignalType: GtBeaconLabelledLogSignal groupedUsing: GtBeaconEventsGrouper new.
eventsCollector start
eventsCollector stop