[Fix] switch to ROS_LOGGER from CONSOLE_BRIDGE #874

jeasinema · 2018-04-30T17:40:25Z

Description

This pull request is an extended version of #859 and inspired by #860. As suggested by @davetcoleman and @v4hn, I switched to use ROS_LOGGER from CONSOLE_BRIDGE and removed the dependency from some cmake files.

Checklist

Required: Code is auto formatted using clang-format
Extended the tutorials / documentation, if necessary reference
Include a screenshot if changing a GUI
Optional: Created tests, which fail without this PR reference
Optional: Decide if this should be cherry-picked to other current ROS branches (Indigo, Jade, Kinetic)

[Fix] clang format

rhaschke · 2018-04-30T18:22:08Z

moveit_core/background_processing/src/background_processing.cpp

@@ -73,13 +73,14 @@ void moveit::tools::BackgroundProcessing::processingThread()
      action_lock_.unlock();
      try
      {
-        CONSOLE_BRIDGE_logDebug("moveit.background: Begin executing '%s'", action_name.c_str());
+        ROS_DEBUG_NAMED("background_processing", "moveit.background: Begin executing '%s'", action_name.c_str());


I like the namespace introduced. However, then you can remove moveit.background: from the message.

rhaschke · 2018-04-30T18:23:27Z

moveit_core/collision_detection/CMakeLists.txt

@@ -13,16 +13,16 @@ add_library(${MOVEIT_LIB_NAME}
 )
 set_target_properties(${MOVEIT_LIB_NAME} PROPERTIES VERSION ${${PROJECT_NAME}_VERSION})

-target_link_libraries(${MOVEIT_LIB_NAME} moveit_robot_state ${catkin_LIBRARIES} ${console_bridge_LIBRARIES} ${urdfdom_LIBRARIES} ${urdfdom_headers_LIBRARIES} ${Boost_LIBRARIES})
+target_link_libraries(${MOVEIT_LIB_NAME} moveit_robot_state ${catkin_LIBRARIES} ${urdfdom_LIBRARIES} ${urdfdom_headers_LIBRARIES} ${Boost_LIBRARIES})


remember to add ${ros_console_LIBRARIES} instead everywhere.

rhaschke

Thanks a lot for your effort. I have a few comments to the naming of the loggers.
In general I like the idea of using a static const variable, e.g. logger_name, to define the logger name only once per cpp file.

rhaschke · 2018-04-30T18:24:19Z

moveit_core/CMakeLists.txt

@@ -12,8 +12,6 @@ endif()

 find_package(Boost REQUIRED system filesystem date_time thread iostreams)

-find_package(console_bridge REQUIRED)


Instead of console_bride, you need to require ros_console now...

rhaschke · 2018-04-30T18:27:23Z

moveit_core/collision_detection_fcl/src/collision_common.cpp

      }
      else if (type == AllowedCollision::CONDITIONAL)
      {
        cdata->acm_->getAllowedCollision(cd1->getID(), cd2->getID(), dcf);
        if (cdata->req_->verbose)
-          CONSOLE_BRIDGE_logDebug("Collision between '%s' and '%s' is conditionally allowed", cd1->getID().c_str(),
-                                  cd2->getID().c_str());
+          ROS_DEBUG_NAMED("collision_detection_fcl", "Collision between '%s' and '%s' is conditionally allowed",


I suggest to use the hierarchical logger scope collision_detection.fcl here.

rhaschke · 2018-04-30T18:32:11Z

moveit_kinematics/cached_ik_kinematics_plugin/src/measure_ik_call_cost.cpp

@@ -139,13 +139,13 @@ int main(int argc, char* argv[])
        num_failed_calls++;
      ++i;
      if (i % 100 == 0)
-        ROS_INFO_NAMED("measure_ik_call_cost",
+        ROS_INFO_NAMED("cached_ik_kinematics_plugin",


Why did you changed the logger name here? In order to include cached_ik, I would suggest cached_ik.measure_ik_call_cost. Remember that the package name (moveit_kinematics) is always part of the logger name.

rhaschke · 2018-04-30T18:32:59Z

moveit_kinematics/ikfast_kinematics_plugin/templates/ikfast61_moveit_plugin_template.cpp

@@ -161,7 +161,7 @@ class IKFastKinematicsPlugin : public kinematics::KinematicsBase
  const size_t num_joints_;
  std::vector<int> free_params_;
  bool active_;  // Internal variable that indicates whether solvers are configured and ready
-  const std::string name_{ "ikfast" };
+  const std::string name_{ "ikfast_kinematics_plugin" };


I suggest to keep the short name ikfast. moveit_kinematics is part of the logger name anyway.

rhaschke · 2018-04-30T18:35:01Z

moveit_kinematics/kdl_kinematics_plugin/src/chainiksolver_pos_nr_jl_mimic.cpp

@@ -52,19 +52,19 @@ ChainIkSolverPos_NR_JL_Mimic::ChainIkSolverPos_NR_JL_Mimic(const Chain& _chain,
  {
    mimic_joints[i].reset(i);
  }
-  ROS_DEBUG_NAMED("kdl", "Limits");
+  ROS_DEBUG_NAMED("kdl_kinematics_plugin", "Limits");


Same as for ikfast.

rhaschke · 2018-04-30T18:35:48Z

moveit_kinematics/srv_kinematics_plugin/src/srv_kinematics_plugin.cpp

@@ -63,7 +63,7 @@ bool SrvKinematicsPlugin::initialize(const std::string& robot_description, const
 {
  bool debug = false;

-  ROS_INFO_STREAM_NAMED("srv", "SrvKinematicsPlugin initializing");
+  ROS_INFO_STREAM_NAMED("srv_kinematics_plugin", "SrvKinematicsPlugin initializing");


Same again. Keep short name.

rhaschke · 2018-04-30T18:36:18Z

moveit_ros/planning_interface/move_group_interface/src/move_group_interface.cpp

@@ -481,8 +481,8 @@ class MoveGroupInterface::MoveGroupInterfaceImpl
        }
        else
        {
-          logError("Unable to transform from frame '%s' to frame '%s'", frame.c_str(),
-                   getRobotModel()->getModelFrame().c_str());
+          ROS_ERROR_NAMED("Unable to transform from frame '%s' to frame '%s'", frame.c_str(),


Here the logger name is missing!

rhaschke · 2018-04-30T18:54:48Z

moveit_plugins/moveit_simple_controller_manager/src/moveit_simple_controller_manager.cpp

@@ -52,7 +52,7 @@ class MoveItSimpleControllerManager : public moveit_controller_manager::MoveItCo
  {
    if (!node_handle_.hasParam("controller_list"))
    {
-      ROS_ERROR_STREAM_NAMED("manager", "No controller_list specified.");
+      ROS_ERROR_STREAM_NAMED("moveit_simple_controller_manager", "No controller_list specified.");


Here we don't need an additional name at all. moveit_simple_controller_manager is already the package name.

davetcoleman

Did a quick run-through and I'm excited about this PR! I can re-review after @rhaschke's comments are addressed

jeasinema · 2018-05-01T05:56:27Z

Thanks @rhaschke @davetcoleman for the reviews. I've made some fixes on my patch following your suggestions.

v4hn · 2018-05-01T06:13:54Z

I encouraged @jeasinema to work on this patch and supervised it in person.
He addresses my last verbal feedback right now. After this is pushed, I approve this request.

Still, @davetcoleman, please look over it once more before you merge because it's just too big to verify everything in detail.

This should be merged soon, because it probably conflicts with many other patches.

rhaschke

@jeasinema Thanks a lot for your effort so far. May I ask for the following changes

Use file-local variables static const char* LOGGER to specify the logger name once per cpp file.
I have suggested different logger names at various locations (see inline comments).
Manually fix badly clang-formatted string literals.

rhaschke · 2018-05-01T07:37:30Z

moveit_core/collision_detection_fcl/src/collision_common.cpp

-          "Collision checking is considered complete due to external callback. %s was found. %u contacts are "
-          "stored.",
-          cdata->res_->collision ? "Collision" : "No collision", (unsigned int)cdata->res_->contact_count);
+      ROS_INFO_NAMED("collision_detection.fcl", "Collision checking is considered complete due to external callback. "


Please can you fix such weird line breaks in string literals. clang-format doesn't remove line breaks in string literals, but only adds new ones...
When I did that manually the last time, I tried to keep sentences (or phrases) on a single line.

rhaschke · 2018-05-01T07:44:07Z

moveit_core/constraint_samplers/test/pr2_arm_kinematics_plugin.cpp

@@ -106,7 +106,7 @@ int PR2ArmIKSolver::CartToJnt(const KDL::JntArray& q_init, const KDL::Frame& p_i
  if (free_angle_ == 0)
  {
    if (verbose)
-      ROS_DEBUG_NAMED("pr2_arm_kinematics_plugin", "Solving with %f", q_init(0));
+      ROS_DEBUG_NAMED("constraint_samplers", "pr2_arm_kinematics_plugin", "Solving with %f", q_init(0));


You cannot use two logger names. This applies to all the following logging calls.
Why doesn't this raise a warning?

It would raise an error with ROS_DEBUG_STREAM_NAMED, but printf-style formatting is syntactically fine with three strings in the parameter list...

However, this should finally end up in an printf-like command and gcc provides some extra checks for these...

rhaschke · 2018-05-01T07:51:34Z

moveit_core/exceptions/src/exceptions.cpp


 moveit::ConstructException::ConstructException(const std::string& what_arg) : std::runtime_error(what_arg)
 {
-  CONSOLE_BRIDGE_logError("Error during construction of object: %s\nException thrown.", what_arg.c_str());
+  ROS_ERROR_NAMED("exceptions", "Error during construction of object: %s\nException thrown.", what_arg.c_str());


Here, I suggest to drop the extra logger name and use ROS_ERROR() only. Applies to next as well.

I disagree.
It is not unlikely that we might want to silence errors from these classes only.

OK. Agreed.

rhaschke · 2018-05-01T07:57:03Z

moveit_core/robot_model/src/joint_model_group.cpp

@@ -295,7 +294,7 @@ const LinkModel* JointModelGroup::getLinkModel(const std::string& name) const
  LinkModelMapConst::const_iterator it = link_model_map_.find(name);
  if (it == link_model_map_.end())
  {
-    CONSOLE_BRIDGE_logError("Link '%s' not found in group '%s'", name.c_str(), name_.c_str());
+    ROS_ERROR_NAMED("robot_model", "Link '%s' not found in group '%s'", name.c_str(), name_.c_str());


Here, I suggest to use robot_model.jmg as the logger name (in whole file).

rhaschke · 2018-05-01T08:00:06Z

moveit_core/trajectory_processing/src/iterative_spline_parameterization.cpp

@@ -93,7 +92,8 @@ bool IterativeSplineParameterization::computeTimeStamps(robot_trajectory::RobotT
  const robot_model::JointModelGroup* group = trajectory.getGroup();
  if (!group)
  {
-    CONSOLE_BRIDGE_logError("It looks like the planner did not set the group the plan was computed for");
+    ROS_ERROR_NAMED("trajectory_processing", "It looks like the planner did not set the group the plan was computed "


Logger name: trajectory_processing.iterative_spline_parameterization?

rhaschke · 2018-05-01T08:05:41Z

moveit_planners/ompl/ompl_interface/src/constraints_library.cpp

@@ -270,11 +270,12 @@ void ompl_interface::ConstraintsLibrary::loadConstraintApproximations(const std:
  std::ifstream fin((path + "/manifest").c_str());
  if (!fin.good())
  {
-    logWarn("Manifest not found in folder '%s'. Not loading constraint approximations.", path.c_str());
+    ROS_WARN_NAMED("constraints_library", "Manifest not found in folder '%s'. Not loading constraint approximations.",


~~This should be ompl.constraints_library.~~

The package name already is ompl_interface. Adding ompl.xyz would be redundant.

rhaschke · 2018-05-01T08:06:53Z

moveit_planners/ompl/ompl_interface/src/detail/constrained_goal_sampler.cpp

@@ -54,7 +54,7 @@ ompl_interface::ConstrainedGoalSampler::ConstrainedGoalSampler(
 {
  if (!constraint_sampler_)
    default_sampler_ = si_->allocStateSampler();
-  logDebug("Constructed a ConstrainedGoalSampler instance at address %p", this);
+  ROS_DEBUG_NAMED("constrained_goal_sampler", "Constructed a ConstrainedGoalSampler instance at address %p", this);


Again, logger name should be prefixed with ompl: ompl.constrained_goal_sampler.

rhaschke · 2018-05-01T08:07:18Z

moveit_planners/ompl/ompl_interface/src/detail/state_validity_checker.cpp

@@ -116,7 +116,7 @@ bool ompl_interface::StateValidityChecker::isValidWithoutCache(const ompl::base:
  if (!si_->satisfiesBounds(state))
  {
    if (verbose)
-      logInform("State outside bounds");
+      ROS_INFO_NAMED("state_validity_checker", "State outside bounds");


ompl.state_validity_checker

rhaschke · 2018-05-01T08:08:08Z

moveit_planners/ompl/ompl_interface/src/model_based_planning_context.cpp

@@ -89,7 +89,7 @@ void ompl_interface::ModelBasedPlanningContext::setProjectionEvaluator(const std
 {
  if (!spec_.state_space_)
  {
-    logError("No state space is configured yet");
+    ROS_ERROR_NAMED("model_based_planning_context", "No state space is configured yet");


Only ompl?

No, the ompl package is too big and confusing to use the top-level namespace here.

And as you stated above, the package name is something like ompl already...

rhaschke · 2018-05-01T08:10:24Z

moveit_plugins/moveit_simple_controller_manager/src/moveit_simple_controller_manager.cpp

@@ -69,7 +69,8 @@ class MoveItSimpleControllerManager : public moveit_controller_manager::MoveItCo
    {
      if (!controller_list[i].hasMember("name") || !controller_list[i].hasMember("joints"))
      {
-        ROS_ERROR_STREAM_NAMED("manager", "Name and joints must be specifed for each controller");
+        ROS_ERROR_STREAM_NAMED("manager", "Name and joints must be specifed for each "
+                                          "controller");


Typical example of bad clang-formatting that should be fixed manually.

v4hn · 2018-05-01T08:43:32Z

Use file-local variables static const char* LOGGER to specify the logger name once per cpp file.

I know this redundancy annoys you to no end, but I would like to keep this as is.

search&replace is simple enough if we ever need to change
nobody says that we need to have only one ns per file (I'm not sure whether this is the case atm)
it requires yet another convention in the code base that new contributors will fail to adhere to
It should be obvious from the local context of the log what exactly will be logged where.

rhaschke · 2018-05-01T09:02:54Z

I know this redundancy annoys you to no end, but I would like to keep this as is.

Yes, it does.

search&replace is simple enough if we ever need to change
nobody says that we need to have only one ns per file (I'm not sure whether this is the case atm)

But you could have different LOGGER variables then.

It requires yet another convention in the code base that new contributors will fail to adhere to

Valid point. But failures can be fixed later too...

It should be obvious from the local context of the log what exactly will be logged where.

That's the one convincing me to some extend. However not sure, this balances out the redundancy drawback. Using modern IDEs, it's rather easy to click on the variable and see its definition.
@davetcoleman also introduced variable for logger names: 2d943ea.

v4hn · 2018-05-01T10:30:38Z

But failures can be fixed later too...

As long as you're the one who does that (for the next 10+ years).
We have way too much code that needs fixes already.

Using modern IDEs, it's rather easy to click on the variable and see its definition.

I know a number of people who browse MoveIt source code on GitHub instead of cloning the repository and starting up their ema... eclipse. I still don't like your IDE-arguments, but we discussed this before.

@davetcoleman also introduced variable for logger names: 2d943ea.

And I'm not convinced the way he did it is very good...

Lastly, I believe @jeasinema did a very good job already and I would not make this request depend on him going over all the changes yet another time.

If you think this really blocks the request, then we should wait for a third opinion.

rhaschke · 2018-05-01T10:37:36Z

I agree that @jeasinema did a great job on this. However, if we already touch most of the logging stuff anyway, we should try to commit the final solution and not start touching everything yet another time.
I agree to accept as is if you insist, but I definitely prefer to have another opinion. If this doesn't arrive soon however, I suggest to merge to avoid conflicts with further PRs.

davetcoleman · 2018-05-01T13:59:21Z

Use file-local variables static const char* LOGGER to specify the logger name once per cpp file.

While I agree this wasn't needed in this PR (already large enough, need to move fast) I certainly agree with @rhaschke this is a cleaner approach to do in the future. I've been using that standard in my personal projects for years and I've added it in several places in the MoveIt! codebase already (Robert pointed out one)

@jeasinema thanks so much for this contribution!

rhaschke · 2018-05-01T15:47:30Z

@jeasinema @v4hn Your changes introduced 10 new warnings on the ROS build farm:
Please fix them asap. They are all related to wrong usage of logging arguments - see #874 (comment).

rhaschke · 2018-05-01T15:50:28Z

@davetcoleman @v4hn Should we consider compiler warnings as errors on Travis to avoid such issues in future?

davetcoleman · 2018-05-01T20:49:02Z

yes I am a strong fan of making our built more strict with warnings and (long term) clang-tidy checks

v4hn · 2018-05-02T12:22:31Z

I agree, Warnings should ideally trigger CI failure eventually, but CI should still run through for everything else. Also, this is a big burden if warnings occur outside "our domain" and we can't fix them in the repository here. Many ROS packages/headers do not compile with `-Wall -Wextra -pedantic` in my experience.

* [Fix] switch to ROS_LOGGER from CONSOLE_BRIDGE * [Fix] clang format * [Fix] manually fix bad clang-formatting in strings

* Limiting the scope of variables moveit#874 Limited the scope of variables in moveit_core/collision_detection * Update moveit_core/collision_detection/src/collision_octomap_filter.cpp Co-authored-by: AndyZe <andyz@utexas.edu> * Update moveit_core/collision_detection/src/collision_octomap_filter.cpp Co-authored-by: AndyZe <andyz@utexas.edu> * Update moveit_core/collision_detection/src/collision_octomap_filter.cpp Co-authored-by: AndyZe <andyz@utexas.edu> * convert float to double * change double to float * Feedback fixes * Introduced variables removed from previous merge commit * Updated GL_Renderer function definitions with double instead of float * Changed update() function arguments to float since it is a derived virtual function and needs to be overriden * Fixed all override errors in visualization * *Fixed override errors in perception *Changed reinterpret_cast to double* from float* * change variable types to fit function definition * Fixed clang-tidy warnings * Fixed scope of reusable variables --------- Co-authored-by: Salah Soliman <salahsoliman96@gmail.com> Co-authored-by: AndyZe <andyz@utexas.edu> Co-authored-by: Henning Kayser <henningkayser@picknik.ai>

[Fix] switch to ROS_LOGGER from CONSOLE_BRIDGE

185c62d

[Fix] clang format

jeasinema force-pushed the kinetic-devel branch from bc3175d to 185c62d Compare April 30, 2018 17:45

rhaschke reviewed Apr 30, 2018

View reviewed changes

rhaschke requested changes Apr 30, 2018

View reviewed changes

davetcoleman reviewed Apr 30, 2018

View reviewed changes

v4hn mentioned this pull request May 1, 2018

[Fix] missed naming problems #859

Closed

[Fix] add missed dependencies and remove redundant names

fce28cb

jeasinema force-pushed the kinetic-devel branch from 8b65ab5 to fce28cb Compare May 1, 2018 05:10

[Fix] use the same logging style, remove more redundant names

955d36b

jeasinema force-pushed the kinetic-devel branch from 63ec30f to 955d36b Compare May 1, 2018 05:55

[Fix] use file name instead of redundant package name

5059293

rhaschke requested changes May 1, 2018

View reviewed changes

[Fix] use proper logging style

47fd437

[Fix] manually fix bad clang-formating

2863377

rhaschke approved these changes May 1, 2018

View reviewed changes

v4hn merged commit 6bf3d04 into moveit:kinetic-devel May 1, 2018

jeasinema mentioned this pull request May 1, 2018

[Fix] fix wrong logging arguments #875

Closed

5 tasks

rhaschke mentioned this pull request May 1, 2018

fix printf conversion specifiers for logging #876

Merged

dg-shadow pushed a commit to shadow-robot/moveit that referenced this pull request Jul 30, 2018

[Fix] switch to ROS_LOGGER from CONSOLE_BRIDGE (moveit#874)

2ee4240

* [Fix] switch to ROS_LOGGER from CONSOLE_BRIDGE * [Fix] clang format * [Fix] manually fix bad clang-formatting in strings

		@@ -12,8 +12,6 @@ endif()

		find_package(Boost REQUIRED system filesystem date_time thread iostreams)

		find_package(console_bridge REQUIRED)

[Fix] switch to ROS_LOGGER from CONSOLE_BRIDGE #874

[Fix] switch to ROS_LOGGER from CONSOLE_BRIDGE #874

Conversation

jeasinema commented Apr 30, 2018 • edited Loading

Description

Checklist

rhaschke Apr 30, 2018 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

rhaschke left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

davetcoleman left a comment

Choose a reason for hiding this comment

jeasinema commented May 1, 2018

v4hn commented May 1, 2018

rhaschke left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

rhaschke May 1, 2018 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

v4hn commented May 1, 2018

rhaschke commented May 1, 2018

v4hn commented May 1, 2018

rhaschke commented May 1, 2018

davetcoleman commented May 1, 2018

rhaschke commented May 1, 2018

rhaschke commented May 1, 2018

davetcoleman commented May 1, 2018

v4hn commented May 2, 2018 via email

jeasinema commented Apr 30, 2018 •

edited

Loading

rhaschke Apr 30, 2018 •

edited

Loading

rhaschke May 1, 2018 •

edited

Loading