Thread ID seems strange when running examles_rclcpp_multithreaded_executor #413
Comments
|
I looked a bit more into this and I think this might be the expected output, as the multithreaded executor will likely have more than 2 threads in the thread pool, I was just misled by the name of the classes. In my case, since I have 11 cores, there will be 11 unique thread IDs shown when using this executor I have double-checked this by running the node again, exporting the output and using a python script to count amount of unique thread IDs (was faster than recompiling the node to change the thread pool size anyway 😄) Log output of a longer run, in case you want to double-checkroot@20e2ee865c73:/workspaces/vscode_ros2_workspace# echo $(uname -i), $(lsb_release -sdc), $RMW_IMPLEMENTATION, cpu=$(nproc)
aarch64, Ubuntu 24.04.2 LTS noble, rmw_zenoh_cpp, cpu=11
root@20e2ee865c73:/workspaces/vscode_ros2_workspace# ros2 run examples_rclcpp_multithreaded_executor multithreaded_executor
[INFO] [1746824986.886395168] [PublisherNode]:
<<THREAD 10243968038334070907>> Publishing 'Hello World! 0'
[INFO] [1746824986.887212501] [DualThreadedNode]: THREAD 15371728384292254096 => Heard 'Hello World! 0' at 1746824986887208960
[INFO] [1746824986.887245168] [DualThreadedNode]: THREAD 5843171798383495142 => Heard 'Hello World! 0' at 1746824986887244001
[INFO] [1746824987.390034252] [PublisherNode]:
<<THREAD 3133061543146088179>> Publishing 'Hello World! 1'
[INFO] [1746824987.390514710] [DualThreadedNode]: THREAD 2194284379356956541 => Heard 'Hello World! 1' at 1746824987390510293
[INFO] [1746824987.390563127] [DualThreadedNode]: THREAD 12041647283110581427 => Heard 'Hello World! 1' at 1746824987390560502
[INFO] [1746824987.891514169] [PublisherNode]:
<<THREAD 7222728036633590277>> Publishing 'Hello World! 2'
[INFO] [1746824987.892062919] [DualThreadedNode]: THREAD 10243968038334070907 => Heard 'Hello World! 2' at 1746824987892056960
[INFO] [1746824987.892242335] [DualThreadedNode]: THREAD 15371728384292254096 => Heard 'Hello World! 2' at 1746824987892238460
[INFO] [1746824988.387672835] [PublisherNode]:
<<THREAD 5956384892818245949>> Publishing 'Hello World! 3'
[INFO] [1746824988.388013960] [DualThreadedNode]: THREAD 3133061543146088179 => Heard 'Hello World! 3' at 1746824988388011002
[INFO] [1746824988.388027794] [DualThreadedNode]: THREAD 18060372114508608531 => Heard 'Hello World! 3' at 1746824988388026419
[INFO] [1746824988.887077836] [PublisherNode]:
<<THREAD 17079279921688770370>> Publishing 'Hello World! 4'
[INFO] [1746824988.887401752] [DualThreadedNode]: THREAD 7222728036633590277 => Heard 'Hello World! 4' at 1746824988887399127
[INFO] [1746824988.887464711] [DualThreadedNode]: THREAD 7735472698100343987 => Heard 'Hello World! 4' at 1746824988887463586
[INFO] [1746824989.387207669] [PublisherNode]:
<<THREAD 10243968038334070907>> Publishing 'Hello World! 5'
[INFO] [1746824989.387426003] [DualThreadedNode]: THREAD 5956384892818245949 => Heard 'Hello World! 5' at 1746824989387423544
[INFO] [1746824989.387455169] [DualThreadedNode]: THREAD 3133061543146088179 => Heard 'Hello World! 5' at 1746824989387453919
[INFO] [1746824989.891459628] [PublisherNode]:
<<THREAD 18060372114508608531>> Publishing 'Hello World! 6'
[INFO] [1746824989.891783461] [DualThreadedNode]: THREAD 12041647283110581427 => Heard 'Hello World! 6' at 1746824989891779503
[INFO] [1746824989.891836586] [DualThreadedNode]: THREAD 17079279921688770370 => Heard 'Hello World! 6' at 1746824989891835045
[INFO] [1746824990.390573336] [PublisherNode]:
<<THREAD 7735472698100343987>> Publishing 'Hello World! 7'
[INFO] [1746824990.390865961] [DualThreadedNode]: THREAD 15371728384292254096 => Heard 'Hello World! 7' at 1746824990390862420
[INFO] [1746824990.390892753] [DualThreadedNode]: THREAD 10243968038334070907 => Heard 'Hello World! 7' at 1746824990390891295
[INFO] [1746824990.888569628] [PublisherNode]:
<<THREAD 5956384892818245949>> Publishing 'Hello World! 8'
[INFO] [1746824990.889216212] [DualThreadedNode]: THREAD 2194284379356956541 => Heard 'Hello World! 8' at 1746824990889208378
[INFO] [1746824990.889278795] [DualThreadedNode]: THREAD 18060372114508608531 => Heard 'Hello World! 8' at 1746824990889266253
[INFO] [1746824991.391369420] [PublisherNode]:
<<THREAD 12041647283110581427>> Publishing 'Hello World! 9'
[INFO] [1746824991.391678295] [DualThreadedNode]: THREAD 5843171798383495142 => Heard 'Hello World! 9' at 1746824991391675170
[INFO] [1746824991.391736670] [DualThreadedNode]: THREAD 7735472698100343987 => Heard 'Hello World! 9' at 1746824991391734879
[INFO] [1746824991.887688129] [PublisherNode]:
<<THREAD 15371728384292254096>> Publishing 'Hello World! 10'
[INFO] [1746824991.887954879] [DualThreadedNode]: THREAD 5956384892818245949 => Heard 'Hello World! 10' at 1746824991887951670
[INFO] [1746824991.888010545] [DualThreadedNode]: THREAD 2194284379356956541 => Heard 'Hello World! 10' at 1746824991888008045
[INFO] [1746824992.386654962] [PublisherNode]:
<<THREAD 5956384892818245949>> Publishing 'Hello World! 11'
[INFO] [1746824992.387229504] [DualThreadedNode]: THREAD 12041647283110581427 => Heard 'Hello World! 11' at 1746824992387222796
[INFO] [1746824992.387292046] [DualThreadedNode]: THREAD 5843171798383495142 => Heard 'Hello World! 11' at 1746824992387287796
[INFO] [1746824992.891630754] [PublisherNode]:
<<THREAD 10243968038334070907>> Publishing 'Hello World! 12'
[INFO] [1746824992.892040004] [DualThreadedNode]: THREAD 15371728384292254096 => Heard 'Hello World! 12' at 1746824992892035171
[INFO] [1746824992.892134338] [DualThreadedNode]: THREAD 17079279921688770370 => Heard 'Hello World! 12' at 1746824992892131421
[INFO] [1746824993.390695005] [PublisherNode]:
<<THREAD 15371728384292254096>> Publishing 'Hello World! 13'
[INFO] [1746824993.390861380] [DualThreadedNode]: THREAD 7222728036633590277 => Heard 'Hello World! 13' at 1746824993390859671
[INFO] [1746824993.390897921] [DualThreadedNode]: THREAD 7222728036633590277 => Heard 'Hello World! 13' at 1746824993390897421
[INFO] [1746824993.888310046] [PublisherNode]:
<<THREAD 5956384892818245949>> Publishing 'Hello World! 14'
[INFO] [1746824993.888682588] [DualThreadedNode]: THREAD 7735472698100343987 => Heard 'Hello World! 14' at 1746824993888677921
[INFO] [1746824993.888769921] [DualThreadedNode]: THREAD 5843171798383495142 => Heard 'Hello World! 14' at 1746824993888767005
[INFO] [1746824994.387495338] [PublisherNode]:
<<THREAD 7735472698100343987>> Publishing 'Hello World! 15'
[INFO] [1746824994.387957505] [DualThreadedNode]: THREAD 2194284379356956541 => Heard 'Hello World! 15' at 1746824994387953088
[INFO] [1746824994.388050922] [DualThreadedNode]: THREAD 17079279921688770370 => Heard 'Hello World! 15' at 1746824994388047422
[INFO] [1746824994.891466089] [PublisherNode]:
<<THREAD 17079279921688770370>> Publishing 'Hello World! 16'
[INFO] [1746824994.892073089] [DualThreadedNode]: THREAD 12041647283110581427 => Heard 'Hello World! 16' at 1746824994892067505
[INFO] [1746824994.892242880] [DualThreadedNode]: THREAD 5956384892818245949 => Heard 'Hello World! 16' at 1746824994892238505
[INFO] [1746824995.386376672] [PublisherNode]:
<<THREAD 5843171798383495142>> Publishing 'Hello World! 17'
[INFO] [1746824995.386503880] [DualThreadedNode]: THREAD 7735472698100343987 => Heard 'Hello World! 17' at 1746824995386502297
[INFO] [1746824995.386527089] [DualThreadedNode]: THREAD 18060372114508608531 => Heard 'Hello World! 17' at 1746824995386526255
[INFO] [1746824995.890741589] [PublisherNode]:
<<THREAD 7735472698100343987>> Publishing 'Hello World! 18'
[INFO] [1746824995.891245756] [DualThreadedNode]: THREAD 7222728036633590277 => Heard 'Hello World! 18' at 1746824995891239339
[INFO] [1746824995.891295464] [DualThreadedNode]: THREAD 17079279921688770370 => Heard 'Hello World! 18' at 1746824995891292006
[INFO] [1746824996.386510464] [PublisherNode]:
<<THREAD 17079279921688770370>> Publishing 'Hello World! 19'
[INFO] [1746824996.386818381] [DualThreadedNode]: THREAD 10243968038334070907 => Heard 'Hello World! 19' at 1746824996386815423
[INFO] [1746824996.386893381] [DualThreadedNode]: THREAD 5843171798383495142 => Heard 'Hello World! 19' at 1746824996386891339
[INFO] [1746824996.886643256] [PublisherNode]:
<<THREAD 10243968038334070907>> Publishing 'Hello World! 20'
[INFO] [1746824996.887032715] [DualThreadedNode]: THREAD 15371728384292254096 => Heard 'Hello World! 20' at 1746824996887027881
[INFO] [1746824996.887130548] [DualThreadedNode]: THREAD 7735472698100343987 => Heard 'Hello World! 20' at 1746824996887126965
[INFO] [1746824997.387070548] [PublisherNode]:
<<THREAD 12041647283110581427>> Publishing 'Hello World! 21'
[INFO] [1746824997.387171881] [DualThreadedNode]: THREAD 5956384892818245949 => Heard 'Hello World! 21' at 1746824997387170673
[INFO] [1746824997.387188798] [DualThreadedNode]: THREAD 17079279921688770370 => Heard 'Hello World! 21' at 1746824997387188131
[INFO] [1746824997.888765423] [PublisherNode]:
<<THREAD 5956384892818245949>> Publishing 'Hello World! 22'
[INFO] [1746824997.889266965] [DualThreadedNode]: THREAD 18060372114508608531 => Heard 'Hello World! 22' at 1746824997889262382
[INFO] [1746824997.889369423] [DualThreadedNode]: THREAD 10243968038334070907 => Heard 'Hello World! 22' at 1746824997889365423
[INFO] [1746824998.387081465] [PublisherNode]:
<<THREAD 18060372114508608531>> Publishing 'Hello World! 23'
[INFO] [1746824998.387470215] [DualThreadedNode]: THREAD 3133061543146088179 => Heard 'Hello World! 23' at 1746824998387467882
[INFO] [1746824998.387489674] [DualThreadedNode]: THREAD 12041647283110581427 => Heard 'Hello World! 23' at 1746824998387488382
[INFO] [1746824998.886602840] [PublisherNode]:
<<THREAD 2194284379356956541>> Publishing 'Hello World! 24'
[INFO] [1746824998.886944549] [DualThreadedNode]: THREAD 5843171798383495142 => Heard 'Hello World! 24' at 1746824998886939715
[INFO] [1746824998.887010424] [DualThreadedNode]: THREAD 5843171798383495142 => Heard 'Hello World! 24' at 1746824998887009507
[INFO] [1746824999.386812049] [PublisherNode]:
<<THREAD 5956384892818245949>> Publishing 'Hello World! 25'
[INFO] [1746824999.387141382] [DualThreadedNode]: THREAD 10243968038334070907 => Heard 'Hello World! 25' at 1746824999387138841
[INFO] [1746824999.387180966] [DualThreadedNode]: THREAD 7735472698100343987 => Heard 'Hello World! 25' at 1746824999387179591
[INFO] [1746824999.891409258] [PublisherNode]:
<<THREAD 15371728384292254096>> Publishing 'Hello World! 26'
[INFO] [1746824999.893110258] [DualThreadedNode]: THREAD 15371728384292254096 => Heard 'Hello World! 26' at 1746824999893106633
[INFO] [1746824999.893224466] [DualThreadedNode]: THREAD 15371728384292254096 => Heard 'Hello World! 26' at 1746824999893222674 |
|
at best I would maybe suggest having more "human friendly IDs", for example, keeping track of IDs in a vector/list and just return the index of the ID in that vector (or if it hasn't been seen before, append it and return the index), would make it much easier to interpret the log in my opinion |
|
it is totally doable, but i think the thread ID is just a identification. diff --git a/rclcpp/executors/multithreaded_executor/multithreaded_executor.cpp b/rclcpp/executors/multithreaded_executor/multithreaded_executor.cpp
index 2414dc3..b7e5e2e 100644
--- a/rclcpp/executors/multithreaded_executor/multithreaded_executor.cpp
+++ b/rclcpp/executors/multithreaded_executor/multithreaded_executor.cpp
@@ -14,6 +14,7 @@
#include <chrono>
#include <functional>
#include <memory>
+#include <sstream>
#include <string>
#include <thread>
@@ -27,8 +28,9 @@ using namespace std::chrono_literals;
**/
std::string string_thread_id()
{
- auto hashed = std::hash<std::thread::id>()(std::this_thread::get_id());
- return std::to_string(hashed);
+ std::ostringstream oss;
+ oss << std::this_thread::get_id();
+ return oss.str();
}
/* For this example, we will be creating a publishing node like the one in minimal_publisher. |
|
@mjcarroll @jncfa do you think my patch could be better? if that is so, i can create the PR. |
|
the hashing definitely does not feel necessary, so removing that seems good! but personally, I still think if we could label the threads somehow it would make it easier to digest the output of the node when we have a large amount of threads for example, if we just assign an arbitrary index, we get something like this for an 11-core PC: I used this patch to run the node: diff --git a/rclcpp/executors/multithreaded_executor/multithreaded_executor.cpp b/rclcpp/executors/multithreaded_executor/multithreaded_executor.cpp
index 2414dc3..5fd05ee 100644
--- a/rclcpp/executors/multithreaded_executor/multithreaded_executor.cpp
+++ b/rclcpp/executors/multithreaded_executor/multithreaded_executor.cpp
@@ -16,6 +16,8 @@
#include <memory>
#include <string>
#include <thread>
+#include <algorithm>
+#include <vector>
#include "rclcpp/rclcpp.hpp"
#include "std_msgs/msg/string.hpp"
@@ -27,8 +29,13 @@ using namespace std::chrono_literals;
**/
std::string string_thread_id()
{
- auto hashed = std::hash<std::thread::id>()(std::this_thread::get_id());
- return std::to_string(hashed);
+ static std::vector<std::thread::id> known_thread_ids {};
+ const auto thread_it = std::find(known_thread_ids.cbegin(), known_thread_ids.cend(), std::this_thread::get_id());
+ if (thread_it != known_thread_ids.end()){
+ return std::to_string(std::distance(known_thread_ids.cbegin(), thread_it));
+ }
+ known_thread_ids.push_back(std::this_thread::get_id());
+ return std::to_string(known_thread_ids.size() - 1);
}
/* For this example, we will be creating a publishing node like the one in minimal_publisher.@fujitatomoya what do you think? 😄 |
|
sgtm, please go ahead to create PR! i am happy to review that! |
done, thanks 😄 |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
ros2/kilted_tutorial_party#185
The text was updated successfully, but these errors were encountered: