Logging

This guides describes how to add log statements in a custom C/C++ processing block and read out the log via a motion controller.

Introduction

Logging can be a powerful feature for debugging, and is available on simulator and hardware for C/C++ processing blocks. The log statements of all processing blocks of a controller are added FIFO to the ProcessingBlockLog updatable of that controller. This updatable contains a ring buffer. Oldest entries are overwritten when the buffer is full. When reading the ProcessingBlockLog updatable via the PMP API the entries are read in chronological order, starting with the oldest entry.

The performance of writing logs to the ProcessingBlockLog is limited, when there are too many new log statements they are dropped and an warning is printed to the buffer.

In this guide we first create a C/C++ processing block that logs messages when a signal is written. In the second part of this guide we deploy this processing block, trigger the log statements and read out the ProcessingBlockLog updatable.

Prerequisites

Before continuing with the guide, please make sure that the following prerequisites are met:

  • The PMP installer should be installed. The Complete setup can be used to install all required features, including simulator, tooling and C++ toolchain. Alternatively, the Custom setup can be used to save disk space. In this case make sure the sub-feature Simulator, Tooling and C++ toolchain (under Control loop customization) is selected.

  • The Processing block logging quick start project files should be available. These files can be downloaded from Downloads.

Create processingblock

We create a processing block in which we can trigger different log statements by setting a parameter named ActivateLogging. The log configurations are as followed:

  • 0: Disabled - no logging

  • 1: SingleMessage - write a fixed message

  • 2: SingleFormattedMessage - write a message with variables included

  • 3: Continuous - write a message every sample with the Epoch time

  • 4: Burst - write multiple messages in a single sample, writing a lot logs can trigger a log overload and dropped messages

Additionally, we define a parameter BurstSize to set the amount of messages logged during a a burst.

  1. Create a processing block project named LogExample via the steps explained in the Start project guide.

  2. Define the parameters in the interface description:

    ---
Description: "LogExample description"
ModelVersion: "1.0.0.0"

Parameters:
  - Name: "ActivateLogging"
    DataType: "Uint8"
    Description: "Activate logging type. 0: Disabled, 1: SingleMessage, 2: SingleFormattedMessage, 3: Continuous, 4: Burst."
  - Name: "BurstSize"
    DataType: "Uint16"
    ResetValue: "100"
    Description: "The size of the loggging burst."

...

  3. Open processingblock_logexample.h and declare the persistent variable activateLogging and the LogConfiguration enum:

      uint8_t activateLogging;
  enum LogConfiguration
  {
    Disabled = 0,
    SingleMessage = 1,
    SingleFormattedMessage = 2,
    Continuous = 3,
    Burst = 4
  };

  4. Open processingblock_logexample.cpp to add the implementation. Because logging is handled asynchronously it is not necessary to add it in the Output() method. Therefore, the logging is added in the Update() method to reduce overhead in the IO-critical task.

  5. In the Update() first we read the value of activateLogging, and create a switch case to select the logging type based on the value of activateLogging:

    void CProcessingBlockLogExample::Update()
{
  auto activateLogging_prev = activateLogging;
  activateLogging = ActivateLogging.Value();

  switch (activateLogging)
  {

  6. For a simple message the LOG() macro is called with a plain string:

      case LogConfiguration::SingleMessage:
  {
    if (activateLogging_prev != activateLogging)
    {
      LOG("Log message without any arguments");
    }
    break;
  }

  7. For a message that includes variables the LOG() macro is called via the same format specifiers as printf():

      case LogConfiguration::SingleFormattedMessage:
  {
    if (activateLogging_prev != activateLogging)
    {
      LOG("Double: %f, float: %f, unsigned integer: %d, integer: %d", 3.14159265358979311599796346854, 13.37f, 1234u, -1);
    }
    break;
  }

  8. Logging continuously has a significant impact on the controller sample load. All log statements are written asynchronously to the ProcessingBlockLog in the background. For the continuous case we log the Epoch time every sample:

      case LogConfiguration::Continuous:
  {
    LOG("Epoch time: %f", GetTimeInSeconds());
    break;
  }

  9. Via a burst it is easily possible to cause a processing block log queue overflow on hardware. When messages cannot be written fast enough, messages are dropped and the following message is added to the log: log messages missed. Create a for loop to generate a number of log messages equal to BurstSize in a single sample to trigger an overflow:

      case LogConfiguration::Burst:
  {
    if (activateLogging_prev != activateLogging)
    {
      uint16_t burstSize = BurstSize.Value();
      uint16_t burstCounter = 0;
      for (uint16_t i = 0; i < burstSize; i++)
        LOG("Burst: %hu", burstCounter++);
    }
    break;
  }

    Note

    When an overflow occurs depends on the hardware and load of motion controller or EtherCAT SubDevice. On simulator it is not possible to cause an overflow.

  10. By default, or when the logging is disabled, nothing is done:

      case LogConfiguration::Disabled:
  default:
  {
    // Do nothing
  }

  11. Build the processing block via the steps explained in the Custom C/C++ code guide.

Deploy the processing block and read the log

  1. Deploy the processing block via a configuration file on simulator, as described in processing block deployment motion controllers.

    1
2
3
4
5
6
7
8
9
    <Controller Name="Arcas 5EG-1">
  <Template Name="LogExampleTemplate" TemplateType="ProcessingBlock">
    <Updatable Name="Updatable">
      <FilePath RelativeTo="File">LogExample-windows-x86_64.bin</FilePath>
    </Updatable>
  </Template>

  <ProcessingBlock Name="LogExample" Template="LogExampleTemplate"/>
</Controller>

  2. Trigger the log statements by setting the ActivateLogging signal to the supported enum values, with a 1 second interval in between.

    1
2
3
4
5
6
    var activateLogging = topController.ProcessingBlocks["LogExample"].Signals["ActivateLogging"];
for (uint i = 1; i < 5; i++)
{
    activateLogging.ValueUint32 = i;
    Thread.Sleep(1000);
}

    1
2
3
4
5
6
    auto activateLogging = topController->GetProcessingBlock("LogExample")->GetSignal("ActivateLogging");
for (int i = 1; i < 5; i++)
{
    activateLogging->WriteUint32(i);
    std::this_thread::sleep_for(std::chrono::milliseconds(1000));
}

    1
2
3
4
    activateLogging = topController.ProcessingBlocks["LogExample"].Signals["ActivateLogging"]
for i in range(1,5):
    activateLogging.ValueUint32 = i
    time.sleep(1)

    1
2
3
4
5
    activateLogging = topController.ProcessingBlocks.Item('LogExample').Signals.Item('ActivateLogging');
for i = 1:4
  activateLogging.ValueUint32 = i;
  pause(1);
end

  3. Download the log via the ProcessingBlockLog updatable:

    1
2
3
    var processingBlockLog = topController.Updatables["ProcessingBlockLog"];
processingBlockLog.SaveContentsToFile("ProcessingBlockLog.txt");
processingBlockLog.WaitComplete(10.0);

    1
2
3
    auto processingBlockLog = topController->GetUpdatable("ProcessingBlockLog");
processingBlockLog->SaveContentsToFile("ProcessingBlockLog.txt");
processingBlockLog->WaitComplete(10.0);

    1
2
3
    processingBlockLog = topController.Updatables["ProcessingBlockLog"]
processingBlockLog.SaveContentsToFile("ProcessingBlockLog.txt")
processingBlockLog.WaitComplete(10.0)

    1
2
3
    processingBlockLog = topController.Updatables.Item('ProcessingBlockLog');
processingBlockLog.SaveContentsToFile('ProcessingBlockLog.txt');
processingBlockLog.WaitComplete(10.0);

The downloaded file contains the logging of all processing blocks of that controller in chronological order, started with the oldest entry. The log can be opened in a text editor to read the messages:

processingblock_logexample.cpp:32: Log message without any arguments
processingblock_logexample.cpp:40: Double: 3.141593, Float: 13.370000, unsigned integer: 1234, integer: -1
processingblock_logexample.cpp:46: Epoch time: 1727175746.212470
...
processingblock_logexample.cpp:46: Epoch time: 1727175747.213024
processingblock_logexample.cpp:56: Burst: 0
...
processingblock_logexample.cpp:56: Burst: 99