Skip to content

Improve failure info in MessageFilter and TransformListener#130

Closed
rotu wants to merge 5 commits intoros2:ros2from
RoverRobotics-forks:missing_failure_info
Closed

Improve failure info in MessageFilter and TransformListener#130
rotu wants to merge 5 commits intoros2:ros2from
RoverRobotics-forks:missing_failure_info

Conversation

@rotu
Copy link
Copy Markdown
Contributor

@rotu rotu commented Jul 19, 2019

fix #118

Copy link
Copy Markdown
Contributor

@tfoote tfoote left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks for adding these improvements to the debugging. I found one bug and two places where I'd rather have small well scoped helper functions rather than just increasing the complexity of the processing methods.

@@ -861,7 +868,7 @@ bool BufferCore::canTransform(const std::string& target_frame, const TimePoint&
if (warnFrameId("canTransform argument fixed_frame", fixed_frame))
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

There appear to be more instances of warnFrameId that could pass through the error message instead of just printing to console.

CompactFrameID source_id = lookupFrameNumber(source_frame);
CompactFrameID target_id, source_id;

try {
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This logic could be worked inside of warnFrameId instead of replacing it. Then it could be reused elsewhere. The prototype would need to be extended with the error_msg pointer.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

That sounds like a great idea for a followup PR by someone who is more comfortable than I with this code

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This logic is creating the warnings, throwing an exception then immediately catching the exception and then pulling the string out of it. This is in one of the potentially highest throughput and consequently desired to be lowest latency sections of code. We don't want to be doing that.

If we add the third check of non-existant frame to warnFrameId it will have full coverage of the cases for validateFrameId's cases. And right now warnFrameId only outputs to console. In some cases like can_transform where we have an error string that we can populate if it's set. We should add that same capability to warnFrameId by adding the error_msg argument and then it can simply be added as an additional argument. And the behavior can be to either populate that error_msg if it's present, otherwise do the current behavior and send a warning to the console.

This will be an overloaded function and the current prototype can be updated to simply call the new version with the error_msg set to null to get the same behavior.

RCLCPP_INFO(node_logging_->get_logger(), "[%s] Drop message: frame '%s' at time %.3f for reason(%d)",
__func__, frame_id.c_str(), stamp.seconds(), reason);

std::string reason_string;
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This logic would be great for a helper function that converts the enum to string to keep the complexity of the functions lower. It then could also have a small unit test to ensure coverage too.

Copy link
Copy Markdown
Contributor Author

@rotu rotu Aug 9, 2019

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This function exists just for logging. It's appropriate to convert the enum here. Also, I have no idea what the enums actually mean beyond what their names say.

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Just because it's used for logging doesn't mean it shouldn't have coverage and follow best practices.

The code would be much more readable if the whole case block was just a function std::string get_failure_reason_string(const FilterFailureReason& reason)

That then is invoked in the RCLCPP_INFO element instead of reason_string.c_str() it would be get_failure_reason_string(reason).c_str() And this method stays 5 lines long with no branchpoints.

And a unit test can be written for the static function that exercises all 3 cases and provides full coverage of that function.

This is just cleaning up the structure of the code to avoid building up technical debt.

@rotu
Copy link
Copy Markdown
Contributor Author

rotu commented Aug 9, 2019

I'm sorry. I can't really iterate on this. I don't understand the code well at all, and it's been 3 weeks since I had a tenuous grasp on how it works :-(

@nuclearsandwich nuclearsandwich added backlog and removed in review Waiting for review (Kanban column) labels Aug 15, 2019
@rotu
Copy link
Copy Markdown
Contributor Author

rotu commented Oct 2, 2019

@tfoote could you please either accept or reject this PR as-is? It’s clear this code needs lots of love, and I don’t intend to increase the scope of this PR

Copy link
Copy Markdown
Contributor

@tfoote tfoote left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

As it stands this is valuable but needs a little bit of refactoring to be a cleaner implementation. If you or anyone has time to update it that would be appreciated, right now I don't have time to clean this up myself.

RCLCPP_INFO(node_logging_->get_logger(), "[%s] Drop message: frame '%s' at time %.3f for reason(%d)",
__func__, frame_id.c_str(), stamp.seconds(), reason);

std::string reason_string;
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Just because it's used for logging doesn't mean it shouldn't have coverage and follow best practices.

The code would be much more readable if the whole case block was just a function std::string get_failure_reason_string(const FilterFailureReason& reason)

That then is invoked in the RCLCPP_INFO element instead of reason_string.c_str() it would be get_failure_reason_string(reason).c_str() And this method stays 5 lines long with no branchpoints.

And a unit test can be written for the static function that exercises all 3 cases and provides full coverage of that function.

This is just cleaning up the structure of the code to avoid building up technical debt.

CompactFrameID source_id = lookupFrameNumber(source_frame);
CompactFrameID target_id, source_id;

try {
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This logic is creating the warnings, throwing an exception then immediately catching the exception and then pulling the string out of it. This is in one of the potentially highest throughput and consequently desired to be lowest latency sections of code. We don't want to be doing that.

If we add the third check of non-existant frame to warnFrameId it will have full coverage of the cases for validateFrameId's cases. And right now warnFrameId only outputs to console. In some cases like can_transform where we have an error string that we can populate if it's set. We should add that same capability to warnFrameId by adding the error_msg argument and then it can simply be added as an additional argument. And the behavior can be to either populate that error_msg if it's present, otherwise do the current behavior and send a warning to the console.

This will be an overloaded function and the current prototype can be updated to simply call the new version with the error_msg set to null to get the same behavior.

@emersonknapp
Copy link
Copy Markdown
Contributor

@tfoote I am planning to continue out this PR over the next week, thanks for the above feedback, that informs the direction.

@rotu
Copy link
Copy Markdown
Contributor Author

rotu commented Oct 18, 2019

Thank you so much for taking this over, @emersonknapp!!!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

Projects

None yet

Development

Successfully merging this pull request may close these issues.

Uninformative error messages from MessageFilter

4 participants