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.

Logging grammar

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.

Modeling events and signals

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 Announcement subclass: #BeaconSignal instanceVariableNames: 'timestamp processId properties' classVariableNames: '' package: 'Beacon-Core-Signals' and event classes can subclass GtBeaconLogEvent GtBeaconLogBasicEvent subclass: #GtBeaconLogEvent instanceVariableNames: 'signals' classVariableNames: '' package: 'GToolkit-Utility-Logging-Core' . Start signal should implement an eventType method indicating the type of the actual event.

Generic events: They subclass GtBeaconGenericLogEvent GtBeaconLogEvent subclass: #GtBeaconGenericLogEvent instanceVariableNames: '' classVariableNames: '' package: 'GToolkit-Utility-Logging-Core' 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 GtBeaconGenericLogSignal subclass: #GtBeaconTypedLogSignal instanceVariableNames: 'eventTypeName' classVariableNames: '' package: 'GToolkit-Utility-Logging-Core' . A typed generic signal knows the class of the corresponding event that will be instantiated from that signal.

Generic labeled signal: They subclass GtBeaconLabelledLogSignal GtBeaconGenericLogSignal subclass: #GtBeaconLabelledLogSignal instanceVariableNames: 'eventTypeLabel' classVariableNames: '' package: 'GToolkit-Utility-Logging-Core' . A labelled generic signal creates a GtBeaconGenericLogEvent GtBeaconLogEvent subclass: #GtBeaconGenericLogEvent instanceVariableNames: '' classVariableNames: '' package: 'GToolkit-Utility-Logging-Core' .

To facilitate the creation of events, BeaconSignal Announcement subclass: #BeaconSignal instanceVariableNames: 'timestamp processId properties' classVariableNames: '' package: 'Beacon-Core-Signals' instances are automatically grouped into GtBeaconLogEvent GtBeaconLogBasicEvent subclass: #GtBeaconLogEvent instanceVariableNames: 'signals' classVariableNames: '' package: 'GToolkit-Utility-Logging-Core' instances using a GtBeaconEventsGrouper Object subclass: #GtBeaconEventsGrouper instanceVariableNames: 'rootEvents eventsStack shouldNotifyUpdates announcer straySignals' classVariableNames: '' package: 'GToolkit-Utility-Logging-Core' .

A useful aspect is that GtBeaconEventsCollector Object subclass: #GtBeaconEventsCollector instanceVariableNames: 'mutex logger eventsGrouper' classVariableNames: '' package: 'GToolkit-Utility-Logging-Core' 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.

Moldable logging using concrete signal and event classes

Here we build an full example by creating concrete classes for signals and events

Basic signals

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 Trait named: #TGtBeaconSignalStartEndType instanceVariableNames: 'eventType' package: 'GToolkit-Utility-Logging-Core' , or with two different classes. For this demo we use two signal classes, namely GtMyExampleBeaconStartSignal GtMyExampleBeaconSignal subclass: #GtMyExampleBeaconStartSignal instanceVariableNames: '' classVariableNames: '' package: 'GToolkit-Utility-Logging-Examples' and GtMyExampleBeaconStopSignal GtMyExampleBeaconSignal subclass: #GtMyExampleBeaconStopSignal instanceVariableNames: '' classVariableNames: '' package: 'GToolkit-Utility-Logging-Examples' .

Starting loggers

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
  

Emitting signals

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.
  

Grouping signals

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
  

Stopping loggers

Here we stop all previously started loggers

memoryLogger ifNotNil: [ aLogger | aLogger stop ].
consoleLogger ifNotNil: [ aLogger | aLogger stop ].
  

GtMyExampleBeaconEventsCollector stop
  

Moldable logging using generic signal classes and concrete event classes

Instead of creating a class for each signal that should start/stop an event, we can use GtBeaconTypedLogSignal GtBeaconGenericLogSignal subclass: #GtBeaconTypedLogSignal instanceVariableNames: 'eventTypeName' classVariableNames: '' package: 'GToolkit-Utility-Logging-Core' 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 GtBeaconGenericLogSignal subclass: #GtBeaconTypedLogSignal instanceVariableNames: 'eventTypeName' classVariableNames: '' package: 'GToolkit-Utility-Logging-Core' .

eventsCollector := GtBeaconGenericEventsCollector
	forSignalType: GtBeaconTypedLogSignal
	groupedUsing: GtBeaconEventsGrouper new.
  

eventsCollector start
  

eventsCollector stop
  

Moldable logging using generic signal and event classes

We can also avoid creating classes for signals and events by using GtBeaconLabelledLogSignal GtBeaconGenericLogSignal subclass: #GtBeaconLabelledLogSignal instanceVariableNames: 'eventTypeLabel' classVariableNames: '' package: 'GToolkit-Utility-Logging-Core' that result in events of type GtBeaconGenericLogEvent GtBeaconLogEvent subclass: #GtBeaconGenericLogEvent instanceVariableNames: '' classVariableNames: '' package: 'GToolkit-Utility-Logging-Core' . 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 GtBeaconGenericLogSignal subclass: #GtBeaconLabelledLogSignal instanceVariableNames: 'eventTypeLabel' classVariableNames: '' package: 'GToolkit-Utility-Logging-Core' .

eventsCollector := GtBeaconGenericEventsCollector
	forSignalType: GtBeaconLabelledLogSignal
	groupedUsing: GtBeaconEventsGrouper new.
  

eventsCollector start
  

eventsCollector stop