High CPU Usage with ROS Action BT Nodes

[wafts95]

Bug Report

Required Info

• Docker version:
  24.0.6
• Installation:
  • ROS2 docker container from base image: osrf/ros:humble-desktop
  • Ubuntu 20.04
• Version or commit hash:
  b8ee381
• DDS Implementation:
  FastDDS (default)
• ROS2 Distribution:
  Humble
• Processor info
  • Processor: Intel® Core™ i7-9700T CPU @ 2.00GHZ
  • CPU(s): 8
  • Socket(s): 1
  • Core(s) per socket: 1

Steps to reproduce issue

Run sleep_client node from the btcpp_ros2_samples/ package. Also, sleep_server node must be running in parallel.
We identified three scenarios of BT diagrams for our tests, which we document below. In these scenarios, we must differentiate between

1. the SleepAction BT node, which is a ROS Action Client node as written in the sleep_action.cpp module, communicating with the ROS Action Server running in the sleep_server node.

and

2. the SleepNormal BT node, which is one of the default BT nodes in the BT.CPP library, written in pure cpp, with source code found in sleep_node.cpp.

Scenario 1: SleepAction + SleepNormal

Tree.xml:

<root BTCPP_format="4">
    <BehaviorTree>
        <Sequence>
            <PrintValue message="start sleepAction"/>
            <SleepAction name="sleepA" msec="5000"/>
            <PrintValue message="sleepAction completed"/>
            <PrintValue message="start sleepNormal"/>
            <Sleep msec="6000"/>
            <PrintValue message="sleepNormal completed"/>
        </Sequence>
    </BehaviorTree>
</root>

Expected Behavior: While the tree executes the sleepAction node, the CPU should spike a little, as communication between nodes (action client and server nodes) will be happening, but afterwards when the sleepAction node succeeds, the sleepNormal node should execute and the CPU usage should be back to low values, as there is no ROS communication happening.

Actual Behavior: When the tree is executing the sleepAction node, the CPU consumption rises up to 44%. When the sleepNormal node is being executed, the CPU consumption reaches 101%, and remains high until the sleepNormal succeeds causing the tree to succeed and the client.cpp script to exit.

Scenario 2: SleepAction

Tree.xml:

<root BTCPP_format="4">
    <BehaviorTree>
        <Sequence>
            <PrintValue message="start sleepAction"/>
            <SleepAction name="sleepA" msec="5000"/>
            <PrintValue message="sleepAction completed"/>
        </Sequence>
    </BehaviorTree>
</root>

Expected Behavior: While the tree executes the sleepAction node, the CPU should spike a little, as communication between nodes (action client and server nodes) will be happening, but afterwards when the sleepAction node succeeds, the sleepNormal node should execute and the CPU usage should be back to low values.

Actual Behavior: When the tree is executing the sleepAction node, the CPU consumption rises up to 39% until the node succeeds causing the tree to succeed and the client.cpp script to exit.

Scenario 3: SleepNormal

Tree.xml:

<root BTCPP_format="4">
    <BehaviorTree>
        <Sequence>
            <PrintValue message="start sleepNormal"/>
            <Sleep msec="6000"/>
            <PrintValue message="sleepNormal completed"/>
        </Sequence>
    </BehaviorTree>
</root>

Expected Behavior: While the tree executes the sleepNormal node, the CPU should remain small, as there is no communication through ROS.

Actual Behavior: When the sleepNormal node is being executed, the CPU consumption reaches 5%.

Additional Feedback

Scenario 1 reveals that there is an issue with BT Nodes acting as ROS Action Clients, especially when we note that we tested the same tree, but replaced the sleepAction with an addTwoIntsService BT Node acting as a ROS Service Client (not featured here or in the original source code of BT.ROS2) , and the CPU usage was very low during the execution of the subsequent sleepNormal node.

Scenario 3 compared to Scenario 1 shows what the baseline CPU usage should be while a sleepNormal BT node is executed, namely it should be around 5% as in Scenario 3, but instead in Scenario 1, following (not before) the execution of a sleepAction node (or any ROS Action based BT Node for that matter), the CPU hits 100%, and stays there, until another ROS Action BT Node is executed, at which point CPU consumption drops to around 40%, before shooting back up to 100% when not executing a ROS Action BT Node.

[facontidavide]

thanks for reporting, I will look at this

[facontidavide]

Hi,

I am unfortunately unable to reproduce the issue:

Trying scenario 1 my CPU is arounf 2.5% when executin SleepAction and aroung 0.7% when executing Sleep

[facontidavide]

I am thinking that maybe the issue is in the way the tree is ticked.

Are you suing tree.tickWhileRunning(); or something else ?

If you use tickExactlyOnce or tickOnce continuously, you will create a busy look