Use RCUTILS_SET_ERROR_MSG in logging config #65

dhood · 2017-11-09T18:58:25Z

requires #63

currently contains commits from #57 but they'll go away once it's merged

dhood · 2017-11-09T21:37:39Z

Ready for review.

Follow up from the suggestion in https://github.com/ros2/rcutils/pull/57 to use RCUTILS_SET_ERROR_MSG:

0088166 adds setting of error messages where error codes are being returned
I saw a quote of @wjwwood's comment in Accumulate DDS errors during cleanup and return error code from wait() function rmw_connext#265, so c996eab logs when the error message is being overwritten (when it is detected) and a81295a returns an RCUTILS_RET_MULTIPLE_ERRORS rc in the event multiple issues occur.
- In the case that the string_map has issues at a81295a#diff-f909d0b1a298531f76132943dc55f86aR110, the overwriting will be logged by rcutils underneath us; the return code will still reflect multiple errors.

Linux
Linux-aarch64
macOS
Windows

wjwwood

Sorry, I know some of these comments apply to existing code, but I guess I missed them when they were added.

wjwwood · 2017-11-09T21:43:40Z

include/rcutils/logging.h

@@ -58,6 +58,8 @@ extern bool g_rcutils_logging_initialized;
 * \return `RCUTILS_RET_LOGGING_SEVERITY_MAP_INVALID` if the internal logger
 *   severity map cannot be initialized, in which case logger severity
 *   thresholds will not be configurable.
+ * \return `RCUTILS_RET_MULTIPLE_ERRORS` if multiple errors occur, in which
+ *   case the error message will contain that of the last error to occur.


Mmm, I don't think this makes sense. Consider a case where an invalid argument error also produces a bad alloc while formatting the error message for instance... It would be better to receive either ret code than this one imo. With this error code you only know that something went wrong, but not what went wrong without parsing the error string (which is slow and might change over time). Part of the point of the ret codes is so the calling code can react to the issue within the called function, but this return code doesn't give you any useful information in that respect. I'd rather have one of the errors printed to stderr, or added to the error message, and the other one returned normally (with error message set and the proper return code).

ok, I see now that "return an error return code if there are any accumulated" in ros2/rmw_connext#265 doesn't necessarily mean it is a "special" error code. I follow your reasoning and will change it to be one of the existing codes

13cebe7 + b9d749b

I was thinking, for that other comment, that it would return multiple return codes, maybe a list of them or something.

ah ok, thanks for clarifying (I can't find the full context of that quote of yours so I'm inventing a lot of context! )

wjwwood · 2017-11-09T21:52:16Z

src/logging.c

+    if (!rcutils_allocator_is_valid(&allocator)) {
+      allocator = rcutils_get_default_allocator();
+      RCUTILS_SET_ERROR_MSG(
+        "Provided allocator is invalid. Using the default allocator.", allocator);


I actually feel like this should just case the function to fail, not fallback to the default allocator. If the allocator object itself is invalid, then that is a logic error in the program.

Yeah, the "fallback" behaviour in general was put there because I was worried that the logging macros repeatedly calling RCUTILS_LOGGING_AUTOINIT and ignoring the return code would cause hard failures to go unnoticed. However, that argument doesn't apply here since the autoinit macro won't pass a custom allocator anyway, so I will remove this fallback to the default allocator and it is the caller's responsibility to check the return code.

ac66ece removes the fallback

wjwwood · 2017-11-09T21:52:20Z

src/logging.c

-          ret_str);
-        ret = RCUTILS_RET_INVALID_ARGUMENT;
+        if (rcutils_error_is_set()) {
+          fprintf(stderr, "Overwriting error message: %s\n", rcutils_get_error_string_safe());


The RCUTILS_SET_ERROR_MSG does this already when you override an error state without clearing it.

Yeah but it gives a help-like output suggesting you should reset the error message, so to me it seems more user friendly to do it manually where possible.

I'm not sure I understood this bit, do you mean that places invoking RCUTILS_SET_ERROR_MSG should add this print when they need to reset the error message because the one printed by RCUTILS_SET_ERROR_MSG is not clear ?
Would making RCUTILS_SET_ERROR_MSG overwrite message clearer solve this without having to add printfs manually wherever we reset the error message?

Would making RCUTILS_SET_ERROR_MSG overwrite message clearer solve this without having to add printfs manually wherever we reset the error message?

we could change it, yeah, but to me the issue is that it's a little too helpful at the moment, so it would actually have to be made what can be considered less clear:

rcutils/src/error_handling.c

Line 157 in f9a0537

"rcutils_reset_error() should be called after error handling to avoid this.\n"

To me it looks like a bug if that gets output, so I avoided it since in this case overwriting the error message is intentional.

since the previous error now causes a return (ac66ece), this code has gone away naturally 😄

wjwwood · 2017-11-09T21:55:15Z

src/logging.c

    g_rcutils_logging_severities_map = rcutils_get_zero_initialized_string_map();
    rcutils_ret_t string_map_ret = rcutils_string_map_init(
      &g_rcutils_logging_severities_map, 0, g_rcutils_logging_allocator);
    if (string_map_ret != RCUTILS_RET_OK) {
      fprintf(
        stderr,
-        "Failed to initialize map for logger severities. Severities will not be configurable.\n");
+        "Failed to initialize logging severities map: %s\n", rcutils_get_error_string_safe());
+      rcutils_reset_error();


I would incorporate this into your new error state but not print anything here. Consider it being something like this:

try: init_map(...) except SomeMapError as exc: raise MyError("could not setup logging, because: %s" % str(exc))

Basically you're catching the string map error, and "re throwing" you're own more applicable error.

10373ef does this 👍

wjwwood · 2017-11-09T21:56:21Z

src/logging.c

+      fprintf(
+        stderr,
+        "Failed to finalize logging severities map: %s\n", rcutils_get_error_string_safe());
+      rcutils_reset_error();


Same thing here, I'd prefer to integrate this error into the new error message and not print anything to stderr.

wjwwood · 2017-11-09T21:57:01Z

src/logging.c

+      "Error setting severity for logger named '%s': %s\n", name, rcutils_get_error_string_safe());
+    rcutils_reset_error();
+    RCUTILS_SET_ERROR_MSG(
+      "Error setting severity for logger", g_rcutils_logging_allocator);


This reverts commit a81295a.

wjwwood

This new macro for setting the error state with a format string might be of interest: https://github.com/ros2/rcutils/pull/63/files#diff-1b06d4a1ccca0f0dff66d961923143a1R119

It's not yet merged.

wjwwood · 2017-11-10T19:04:13Z

src/logging.c

-          "Failed to get output format from env. variable: %s. Using default output format.\n",
-          ret_str);
+        RCUTILS_SET_ERROR_MSG(
+          "Failed to get output format from env. variable. Using default output format.",


It would be good if this error message could include the ret_str in some way.

done in 2d5f39b

wjwwood · 2017-11-10T19:04:54Z

src/logging.c

+        "Failed to initialize map for logger severities [%s]. Severities will not be configurable.",
+        rcutils_get_error_string_safe());
+      rcutils_reset_error();
+      RCUTILS_SET_ERROR_MSG(msg, g_rcutils_logging_allocator)


What if msg is NULL?

Looks like this line could also set the error state: https://github.com/ros2/rcutils/blob/master/src/format_string.c#L41

I've marked this PR as requiring #63 and swapped to use RCUTILS_SET_ERROR_MSG_WITH_FORMAT_STRING in a088188 which will take care of the NULL case.

I think I've missed your point regarding the format_string allocator check: I don't think that RCUTILS_CHECK_ALLOCATOR sets the error state or error message (RCUTILS_CHECK_ALLOCATOR_WITH_MSG would though)

You're right, w.r.t. the check allocator call 👍

wjwwood · 2017-11-10T19:06:59Z

src/logging.c

+        "Failed to finalize map for logger severities: %s",
+        rcutils_get_error_string_safe());
+      rcutils_reset_error();
+      RCUTILS_SET_ERROR_MSG(msg, g_rcutils_logging_allocator)


Again, what if msg is NULL?

wjwwood · 2017-11-10T19:07:22Z

src/logging.c

+      g_rcutils_logging_allocator,
+      "Error setting severity for logger named '%s': %s", name, rcutils_get_error_string_safe());
+    rcutils_reset_error();
+    RCUTILS_SET_ERROR_MSG(msg, g_rcutils_logging_allocator)


wjwwood

lgtm, thanks for iterating

I'll try to get #63 merged asap

dhood · 2017-11-10T22:37:17Z

no worries, moving back into "in progress" in the meantime (but no work planned)

dhood · 2017-11-16T18:38:37Z

CI now that #63 been merged:

Linux
Linux-aarch64
macOS
Windows

rcutils logging sets error messages on failure as of ros2/rcutils#65

* Clear rcutils error on failure rcutils logging sets error messages on failure as of ros2/rcutils#65 * logging_macros.h isn't needed anymore RCUTILS_LOGGING_AUTOINIT was moved to rcutils/logging.h

dhood added the in progress Actively being worked on (Kanban column) label Nov 9, 2017

dhood self-assigned this Nov 9, 2017

dhood mentioned this pull request Nov 9, 2017

Programmatic logger severity thresholds #57

Merged

dhood added 5 commits November 9, 2017 11:28

Move allocator assignment up so can be used in error msgs

ce97bcf

Use RCUTILS_SET_ERROR_MSG

0088166

Log when overwriting error message

c996eab

Return RCUTILS_RET_MULTIPLE_ERRORS accumulating errors

a81295a

More specific variable for string_map rc

c51a37c

dhood force-pushed the logging_config_error_msg branch from e080db6 to c51a37c Compare November 9, 2017 19:35

dhood added in review Waiting for review (Kanban column) and removed in progress Actively being worked on (Kanban column) labels Nov 9, 2017

wjwwood reviewed Nov 9, 2017

View reviewed changes

Revert "Return RCUTILS_RET_MULTIPLE_ERRORS accumulating errors"

13cebe7

This reverts commit a81295a.

dhood added in progress Actively being worked on (Kanban column) and removed in review Waiting for review (Kanban column) labels Nov 9, 2017

dhood added 4 commits November 9, 2017 15:24

Fail if allocator invalid

ac66ece

Absorb string_map errors into our error message

10373ef

Add comment when error msg gets overwritten

104ef28

Document last error code is returned

b9d749b

dhood added in review Waiting for review (Kanban column) and removed in progress Actively being worked on (Kanban column) labels Nov 10, 2017

wjwwood reviewed Nov 10, 2017

View reviewed changes

dhood added 2 commits November 10, 2017 12:04

Use RCUTILS_SET_ERROR_MSG_WITH_FORMAT_STRING

a088188

Show ret_str if getting env var fails

2d5f39b

wjwwood approved these changes Nov 10, 2017

View reviewed changes

dhood added in progress Actively being worked on (Kanban column) and removed in review Waiting for review (Kanban column) labels Nov 10, 2017

dhood merged commit 21b78ff into master Nov 16, 2017

dhood deleted the logging_config_error_msg branch November 16, 2017 18:38

dhood removed the in progress Actively being worked on (Kanban column) label Nov 16, 2017

dhood added a commit to ros2/rclpy that referenced this pull request Dec 1, 2017

Clear rcutils error on failure

7bbecc8

rcutils logging sets error messages on failure as of ros2/rcutils#65

dhood added a commit to ros2/rclpy that referenced this pull request Dec 1, 2017

Clear rcutils error on failure

f073247

rcutils logging sets error messages on failure as of ros2/rcutils#65

dhood mentioned this pull request Dec 1, 2017

Clear rcutils error on failure ros2/rclpy#163

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Use RCUTILS_SET_ERROR_MSG in logging config #65

Use RCUTILS_SET_ERROR_MSG in logging config #65

dhood commented Nov 9, 2017 •

edited

Loading

dhood commented Nov 9, 2017

wjwwood left a comment

wjwwood Nov 9, 2017

dhood Nov 9, 2017

dhood Nov 9, 2017

wjwwood Nov 10, 2017

dhood Nov 10, 2017

wjwwood Nov 9, 2017

dhood Nov 9, 2017

dhood Nov 9, 2017

wjwwood Nov 9, 2017

dhood Nov 9, 2017

mikaelarguedas Nov 9, 2017

dhood Nov 9, 2017

dhood Nov 9, 2017

wjwwood Nov 9, 2017

dhood Nov 10, 2017

wjwwood Nov 9, 2017

wjwwood Nov 9, 2017

wjwwood left a comment

wjwwood Nov 10, 2017

dhood Nov 10, 2017

wjwwood Nov 10, 2017

wjwwood Nov 10, 2017

dhood Nov 10, 2017

wjwwood Nov 10, 2017

wjwwood Nov 10, 2017

wjwwood Nov 10, 2017

wjwwood left a comment

dhood commented Nov 10, 2017

dhood commented Nov 16, 2017

Use RCUTILS_SET_ERROR_MSG in logging config #65

Use RCUTILS_SET_ERROR_MSG in logging config #65

Conversation

dhood commented Nov 9, 2017 • edited Loading

dhood commented Nov 9, 2017

wjwwood 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

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

wjwwood 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

wjwwood left a comment

Choose a reason for hiding this comment

dhood commented Nov 10, 2017

dhood commented Nov 16, 2017

dhood commented Nov 9, 2017 •

edited

Loading