Usage

Short snippets on this page show only the LogThat calls. Longer ones are written inside the routine they belong in. Where a snippet shows its rendered output in a comment, the values it prints are declared so the result can be checked; other application variables are left undeclared.

Installation

Install with the Loupe Package Manager:

lpm install logthat

LogThat depends on ArEventLog and AsBrStr, which ship with Automation Studio, and on Loupe’s StringExt library. If StringExt is not already in the project, install it as well:

lpm install stringext

LogThat requires StringExt 1.0.0 or newer.

Setup

Create a logbook

A logbook has to exist before anything can be written to it. Create it once from an _INIT routine with createLogInit.

void _INIT ProgramInit(void)
{
	createLogInit("App", 100000, LOG_PERSISTENCE_PERSIST);
}
  • Name is limited to LOG_STRLEN_LOGGERNAME (8) characters by LogThat’s own input declaration. The name must not be empty and must not start with $, which is reserved for B&R’s system logbooks. See Choosing a name before picking one.
  • Size is the size of the log data area in bytes, 4096 minimum. Passing 0 uses LOG_DEFAULT_LOGGERSIZE (100000).
  • Persistence selects where the entries live, see LOG_PERSISTENCE_enum. LOG_PERSISTENCE_PERSIST is almost always what you want: diagnostics are most useful after the restart that followed the problem, and entries in a volatile logbook are gone by the time anyone looks. Note that persistent and remanent entries are held in a DRAM image copied to the backing memory every 60 seconds and on an orderly shutdown, so up to a minute can still be lost to a power fail or watchdog reset.

The logbook shows up in the Automation Studio Logger under the name it was created with, alongside the system logbooks.

Creating a logbook only if it does not exist

A logbook that outlives the restart which reran _INIT is still there when createLogInit runs again, and the create then reports arEVENTLOG_ERR_LOGBOOK_EXISTS (-1070586095). LOG_PERSISTENCE_PERSIST survives a cold restart, so with a persistent logbook this is the normal case on every boot after the first. LOG_PERSISTENCE_REMANENT survives a warm restart only, so it is the normal case after one of those. It is not a failure: the existing logbook and its entries are left untouched, and logging keeps working. A volatile logbook, or a remanent one after a cold restart, is gone and gets created fresh with status 0.

There is no “create if missing” call. Instead, create unconditionally and treat “already exists” as success, so that a real problem still surfaces. Discarding that status should be a deliberate choice rather than an oversight: nothing else reports a failed create, and every write to the missing logbook then fails silently too. The arEVENTLOG_* constants come from B&R’s ArEventLog library, which LogThat already depends on, so they are in scope wherever LogThat.h is.

// Globals: gLogReady : BOOL, gLogCreateStatus : DINT

void _INIT ProgramInit(void)
{
	DINT status = createLogInit("App", 100000, LOG_PERSISTENCE_PERSIST);

	if (status == 0 || status == arEVENTLOG_ERR_LOGBOOK_EXISTS) {
		// Create was accepted, confirm on the first write
		gLogReady = 1;
	} else {
		// Something is actually wrong, see below for the usual cause
		gLogCreateStatus = status;
	}
}

If you would rather ask first, ArEventLogGetIdent is synchronous and returns arEVENTLOG_ERR_LOGBOOK_NOT_FOUND (-1070586087) when the logbook does not exist. That takes an extra function block instance and gets you to the same place, so checking the create status is usually simpler.

Note: B&R documents ArEventLogCreate as asynchronous, and createLogInit calls it once without polling it to completion. In an _INIT routine it finishes within that call: production code creates its logbooks this way and writes to them later in the same _INIT, which only works if the logbook already exists. The returned status is therefore the final result, not a busy code.

Note: An existing logbook keeps the size and persistence it was created with. Changing the arguments passed to createLogInit does not resize or move a logbook that is already on the target. Delete it with logDelete first, or give the new logbook a different name.

Choosing a name

Logbooks are stored as Automation Runtime modules and share one namespace with every other module on the target, which includes the tasks and programs in the project. Creating a logbook with the same name as an existing task, program, or data object fails with arEVENTLOG_ERR_MODULE_EXISTS (-1070586084), because a module with that name already exists with a different type.

This is a common one to trip over, since the natural name for a subsystem’s logbook is the name of the task that writes to it:

// A task in the project is named "Infeed"

void _INIT ProgramInit(void)
{
	DINT status;

	status = createLogInit("Infeed", 100000, LOG_PERSISTENCE_PERSIST);
	// -> arEVENTLOG_ERR_MODULE_EXISTS, no logbook is created, and every
	//    subsequent logInfo("Infeed", ...) fails with LOGBOOK_NOT_FOUND

	status = createLogInit("InfeedLg", 100000, LOG_PERSISTENCE_PERSIST);
	// -> 0, works
}

Rules of thumb when naming a logbook:

  • Do not reuse a task, program, or module name. Add a suffix, or use one shared logbook for a whole subsystem rather than one per task.
  • Keep it inside LogThat’s 8 character limit. Automation Runtime itself allows 10, the module name limit, and rejects anything longer with arEVENTLOG_ERR_NAME_INVALID. LogThat declares its name inputs as STRING[LOG_STRLEN_LOGGERNAME], so 8 is the length that is guaranteed to behave the same from every caller and on every function.
  • Do not start the name with $. That prefix is reserved for B&R system logbooks such as $arlogsys.

Because createLogInit only runs in _INIT, a failed create is silent unless the return status is checked. A logbook named Application (11 characters) simply never appears, and every later write to it fails. If entries never show up in the Logger, check the create status first.

Write entries

Four severity-specific functions write to a logbook: logError, logWarning, logInfo, and logSuccess. All four take the same arguments and return a status.

logInfo("App", 0, "Machine started", 0);
logWarning("App", 100, "Infeed sensor blocked", 0);
logError("App", 200, "Drive fault, machine stopped", 0);

The second argument is a user-defined code that is written to the event ID, which makes it easy to filter for a specific event in the Logger. The last argument is a pointer to format arguments; pass 0 when the message has no runtime values in it.

A log entry is a one-shot event, so call these on a transition rather than unconditionally in a cyclic body, which would write an entry every scan and churn the logbook. The snippets below that call these four functions are guarded on an edge flag for that reason. The function blocks are different: logStateChange and logDelete are called every scan by design.

Formatted messages

To include runtime values, put format specifiers in the message and pass the address of a StrExtArgs_typ structure as pMsgData. The structure holds five values of each supported type, and each specifier consumes the next value of its type in order.

Specifier Type Source member
%i, %d Signed integer i[0..4]
%r, %f Real r[0..4]
%s String s[0..4] (pointer to string)
%b Boolean b[0..4] 
void _CYCLIC ProgramCyclic(void)
{
	unsigned short errorCount = 3;
	plcbit errorActive = 1;

	StrExtArgs_typ msgData;

	if (faultEdge) {
		memset(&msgData, 0, sizeof(msgData));

		msgData.i[0] = errorCount;
		msgData.b[0] = errorActive;

		logWarning("App", 300, "This task has %i errors, error active: %b", (UDINT)&msgData);
		// -> "This task has 3 errors, error active: TRUE"
	}
}

Strings are passed by address, so s[] members are set to the address of the string:

void _CYCLIC ProgramCyclic(void)
{
	StrExtArgs_typ msgData;

	if (recipeLoadedEdge) {
		memset(&msgData, 0, sizeof(msgData));

		msgData.s[0] = (UDINT)recipeName;
		msgData.r[0] = lineSpeed;

		logInfo("App", 301, "Loaded recipe %s at %r units/min", (UDINT)&msgData);
	}
}

For a plcstring array the array already is that address, so pass it directly; & adds nothing.

Values must be filled in and still in scope at the moment the log function is called, since the string is formatted during the call. A formatted message is truncated to 319 characters plus the terminating null, the size of LogThat’s internal LOG_STRLEN_MESSAGE (320) byte buffer.

Formatting happens only when pMsgData is non-zero. With 0 the message is written to the logger verbatim, percent signs included. When you do pass arguments, use %% for a literal percent sign: an unrecognized % is dropped together with the single character that follows it, so a stray % in operator text eats the next character.

Formatting is done by formatString() from StringExt.

Logging state changes

logStateChange is a function block that watches a state variable and writes an entry every time the value changes. Call it cyclically.

// Declaration
logStateChange_typ stateLogger;

void _CYCLIC ProgramCyclic(void)
{
	strcpy(stateLogger.LoggerName, "App");
	strcpy(stateLogger.ModuleName, "Infeed");
	stateLogger.State = infeed.state;
	strcpy(stateLogger.StateName, infeed.stateName);
	logStateChange(&stateLogger);
}

On its first call it logs a start entry; after that it logs only transitions, for example Infeed change from Idle to Running (0 to 1).

If StateName is left empty, only the numeric state is logged. LoggerName and ModuleName each fall back to the literal string "State" when empty on the first call, but the block does this by writing that string back into the input itself, once. A caller that assigns those inputs cyclically from an empty variable overwrites the fallback on the next cycle, and every later entry then fails on an empty logger name.

Note: The start entry reports the current state number as of LogThat 1.0.1. In 1.0.0 it always reported state 0, whatever the real starting state was. The state name was correct in both versions.

Writing a raw event ID

logEventID takes a complete, pre-built event ID instead of a severity plus a code. This is useful when forwarding an event ID that came from somewhere else, such as another library’s status.

logEventID("App", myEventID, "Forwarded event", 0);

Severity-specific functions build the event ID from LOG_DEFAULT_FACILITY (0) and the code passed in. In both cases LogThat sets the customer bit on the event ID before writing, because ArEventLog rejects system IDs written from user code.

Deleting a logbook

logDelete removes a logbook and its entries. It is an execute/done function block, so it must be called cyclically with execute held true until done or error goes true, and then reset with execute = 0. The input is level triggered: clearing it early stops driving the delete, rather than cancelling work already handed to Automation Runtime. The outputs keep being re-derived from the underlying function blocks after execute is cleared, so done or error can still change.

// Declaration
logDelete_typ deleter;

void _CYCLIC ProgramCyclic(void)
{
	if (deleteRequested) {
		strcpy(deleter.name, "App");
		deleter.execute = 1;
	}

	logDelete(&deleter);

	if (deleter.done || deleter.error) {
		deleter.execute = 0;
		deleteRequested = 0;
	}
}

Error handling

Every log function returns a status. 0 means the entry was written. LOG_ERR_INVALIDINPUT (58300) means a required pointer was null, in practice the logger name. Any other value is passed straight through from ArEventLog, most commonly arEVENTLOG_ERR_LOGBOOK_NOT_FOUND because the logbook does not exist. See Structures for the full list.

void _CYCLIC ProgramCyclic(void)
{
	DINT status;

	if (startEdge) {
		status = logInfo("App", 0, "Machine started", 0);

		if (status != 0) {
			gLogStatus = status;
		}
	}
}

A logbook that fills up is not an error. Logbooks are ring buffers, so the oldest entries are overwritten and writes keep succeeding. If writes are failing with arEVENTLOG_ERR_LOGBOOK_NOT_FOUND, the logbook was never created: either createLogInit was not called, or it failed, most often because of a name collision. See Choosing a name.