:question: How to enable rclc debug logging?

• Hardware description: Custom board with STM32F765BIT
• RTOS: N/A
• Installation type: micro-ROS for PlatformIO with Arduino Framework.
• Version or commit hash: Humble

I'm trying to debug why I occasionally see RCL_RET_ERR sometimes return from rclc_executor_spin_some() in my main project. To do so I'm trying to print out additional debug information from the executor to narrow down what the root cause of the RCL_RET_ERR. I've tried to create a simple project to print out the debug information from rclc_executor_spin_some() but I can't get it to output anything!

Steps to reproduce the issue

• Program the board using main.cpp and colcon.meta linked below.
• See "test log debug print" printed to Serial.
• No messages from rclc_executor_spin_some() are printed.

Expected behavior

• Logging messages (e.g. RCUTILS_LOG_x() from https://github.com/ros2/rclc/blob/rolling/rclc/src/rclc/executor.c) are printed to stderr/stdout and /rosout

Actual behavior

• Only "test log debug print" printed to Serial

Additional information

Code snips

Let me know if more context is needed!

main.cpp:

#include <Arduino.h>

#include <micro_ros_platformio.h>
#include <micro_ros_utilities/type_utilities.h>
#include <rclc/executor.h>
#include <rclc/rclc.h>
#include <rosidl_runtime_c/string_functions.h>

#include <rcl_interfaces/msg/log.h>

#include "drivers/gpio.h"


rcl_node_t node;
rclc_support_t support;
rcl_allocator_t allocator;
rclc_executor_t executor_main;

rcl_timer_t low_freq_timer;

rcl_publisher_t rosout_publisher;


#define ARRAY_LEN(x) (sizeof(x) / sizeof((x)[0]))
#define RCCHECK(fn) {rcl_ret_t temp_rc = fn; if ((temp_rc != RCL_RET_OK)) {error_loop();}}
#define RCSOFTCHECK(fn) {rcl_ret_t temp_rc = fn; if ((temp_rc != RCL_RET_OK)) {Serial.println( \
        "Soft check fail")}}

/**
 * @brief loop to indicate error
 * @todo Add explicit error codes
 */
void error_loop(void)
{
  while (true) {
    delay(100);
    gpio_state_toggle(GPIO_LED_ONBOARD);
    Serial.println("Hard check fail");
  }
}


void low_freq_timer_callback(rcl_timer_t * timer, int64_t last_call_time)
{
  gpio_state_toggle(GPIO_LED_ONBOARD);

  RCUTILS_LOG_DEBUG_NAMED("", "test log debug print");
}

// cppcheck-suppress unusedFunction
void setup()
{
  Serial.begin(115200);
  // Trap until USB VCOM port attached to microROS prior to proceeding
  SerialUSB.dtr(true);
  while (!SerialUSB.dtr()) {
    delay(100);
  }
  SerialUSB.begin();
  set_microros_serial_transports(SerialUSB);
  delay(1000);

  const uint64_t low_freq_timer_timeout = 400;
  gpio_init();
  allocator = rcl_get_default_allocator();
  rcl_init_options_t init_options = rcl_get_zero_initialized_init_options();
  RCCHECK(rcl_init_options_init(&init_options, allocator));
  #ifdef ROS_DOMAIN_OVERRIDE
  RCCHECK(rcl_init_options_set_domain_id(&init_options, ROS_DOMAIN_OVERRIDE));
  #endif
  RCCHECK(rclc_support_init_with_options(&support, 0, NULL, &init_options, &allocator));
  RCCHECK(rcutils_logging_set_logger_level("", RCUTILS_LOG_SEVERITY_DEBUG));
  RCCHECK(rclc_node_init_default(&node, "micro_ros_node", "hardware", &support));

  RCCHECK(
    rclc_publisher_init_default(
      &rosout_publisher,
      &node,
      ROSIDL_GET_MSG_TYPE_SUPPORT(rcl_interfaces, msg, Log),
      "/rosout"
    )
  );

  RCCHECK(
    rclc_timer_init_default(
      &low_freq_timer,
      &support,
      RCL_MS_TO_NS(low_freq_timer_timeout),
      low_freq_timer_callback
    )
  );

  // handles_num is the total num of subscriptions, timers, services, clients and guard conditions
  const size_t handles_num = 1;
  RCCHECK(rclc_executor_init(&executor_main, &support.context, handles_num, &allocator));
  RCCHECK(rclc_executor_add_timer(&executor_main, &low_freq_timer));
}

void loop()
{
  RCCHECK(rclc_executor_spin_some(&executor_main, RCL_MS_TO_NS(1)));
}

colcon.meta:

{
    "names": {
        "rmw_microxrcedds": {
            "cmake-args": [
                "-DRMW_UXRCE_MAX_NODES=1",
                "-DRMW_UXRCE_MAX_PUBLISHERS=15",
                "-DRMW_UXRCE_MAX_SUBSCRIPTIONS=3",
                "-DRMW_UXRCE_MAX_SERVICES=7",
                "-DRMW_UXRCE_MAX_CLIENTS=0"
            ]
        }
        "rclc": {
            "cmake-args": [
                "-DRCUTILS_LOG_MIN_SEVERITY=RCUTILS_LOG_MIN_SEVERITY_DEBUG"
            ]
        }
    }
}

[platformio]
src_dir = mcu
workspace_dir = ../../build/mcu_pio

[env]
board_microros_distro = humble

check_flags =
  cppcheck: --inconclusive --inline-suppr --suppress=*:*/libdeps/*
check_skip_packages = yes

lib_deps =
  https://github.com/micro-ROS/micro_ros_platformio#48096f8


[env:ststm32]
; pin platform version to 17.4, as 17.5 has build
; issues with undefined reference to `SerialUSB`
platform = ststm32@17.4.0
framework = arduino
board = rev_b
extra_scripts = pre:boards/config_board.py
monitor_dtr = 1

build_src_filter =
  +<stm32/*>

build_flags =
  ${env.build_flags}
  ; enable SerialUSB
  -I mcu/stm32/
  -DPIO_FRAMEWORK_ARDUINO_ENABLE_CDC_WITHOUT_SERIAL
  -DUSBCON
  ; Increase USB buffer sizes. Each TX and RX buffer is calculated based
  ; on the teensy 4.0 default USB buffer sizes (TX: 8192, RX: 4096)
  ; (see https://github.com/PaulStoffregen/cores/blob/master/teensy4/usb_serial.c)). Note the TX/RX buffer
  ; sizes are calculated by multiplying the packet number by 64.
  ; Default buffer sizes:
  ;   CDC_TRANSMIT_QUEUE_BUFFER_PACKET_NUMBER 2
  ;   CDC_RECEIVE_QUEUE_BUFFER_PACKET_NUMBER 3
  ; Minimum buffer sizes:
  ;   CDC_TRANSMIT_QUEUE_BUFFER_PACKET_NUMBER 1
  ;   CDC_RECEIVE_QUEUE_BUFFER_PACKET_NUMBER 2
  -DCDC_TRANSMIT_QUEUE_BUFFER_PACKET_NUMBER=128
  -DCDC_RECEIVE_QUEUE_BUFFER_PACKET_NUMBER=64

  -DSERIAL_TX_BUFFER_SIZE=256
  -DSERIAL_RX_BUFFER_SIZE=256

  ; Reduce timeout of I2C from 100 to 10. This should still allow
  ; 1000 bytes of data to be sent via I2C at 100 kHz, more than enough for
  ; the BME environemntal and pressure sensor comms.
  -DI2C_TIMEOUT_TICK=10

  -DRCUTILS_LOG_MIN_SEVERITY=RCUTILS_LOG_MIN_SEVERITY_DEBUG

board_microros_user_meta = ststm32_custom.meta

lib_deps =
  ${env.lib_deps}

Bắt đầu với các lệnh gọi logging trong rclc/src/rclc/executor.c và phần thiết lập được thể hiện trong main.cpp, sau đó so sánh các cài đặt RCUTILS_LOG_MIN_SEVERITY trong colcon.meta và cấu hình PlatformIO. Tái tạo bản build STM32F765BIT và xác minh rằng logging của executor xuất hiện qua đường dẫn đầu ra dự kiến khi severity debug được bật.