Currently, calls like ovs_assert() just print out a condition that caused assertion to fail. But it may be not enough to understand what exactly has happened, especially if assertion failed in some generic function like dp_packet_resize() or similar.
Print the stack trace along with the abort message to give more context for the later debugging. This should be especially useful in case the issue happens in an environment with core dumps disabled. Adding the log to vlog_abort() to cover a little more cases where VLOG_ABORT is called and not only assertion failures. It would be nice to also have stack traces in case of reaching the OVS_NOT_REACHED(). But this macro is used in some places as a last resort and should not actually do more than just stopping the process immediately. And it also can be used in contexts without logging initialized. Such a change will need to be done more carefully. Better solution might be to use VLOG_ABORT() where appropriate instead. Signed-off-by: Ilya Maximets <[email protected]> --- lib/vlog.c | 10 ++++++++-- tests/library.at | 4 +++- 2 files changed, 11 insertions(+), 3 deletions(-) diff --git a/lib/vlog.c b/lib/vlog.c index b2653142f..e78c785f7 100644 --- a/lib/vlog.c +++ b/lib/vlog.c @@ -29,6 +29,7 @@ #include <time.h> #include <unistd.h> #include "async-append.h" +#include "backtrace.h" #include "coverage.h" #include "dirs.h" #include "openvswitch/dynamic-string.h" @@ -1274,8 +1275,9 @@ vlog_fatal(const struct vlog_module *module, const char *message, ...) va_end(args); } -/* Logs 'message' to 'module' at maximum verbosity, then calls abort(). Always - * writes the message to stderr, even if the console destination is disabled. +/* Attempts to log a stack trace, logs 'message' to 'module' at maximum + * verbosity, then calls abort(). Always writes the message to stderr, even + * if the console destination is disabled. * * Choose this function instead of vlog_fatal_valist() if the daemon monitoring * facility should automatically restart the current daemon. */ @@ -1289,6 +1291,10 @@ vlog_abort_valist(const struct vlog_module *module_, * message written by the later ovs_abort_valist(). */ module->levels[VLF_CONSOLE] = VLL_OFF; + /* Printing the stack trace before the 'message', because the 'message' + * will flush the async log queue (VLL_EMER). With a different order we + * would need to flush the queue manually again. */ + log_backtrace(); vlog_valist(module, VLL_EMER, message, args); ovs_abort_valist(0, message, args); } diff --git a/tests/library.at b/tests/library.at index 7b4acebb8..d962e1b3f 100644 --- a/tests/library.at +++ b/tests/library.at @@ -230,7 +230,9 @@ AT_CHECK([ovstest test-util -voff -vfile:info '-vPATTERN:file:%c|%p|%m' --log-fi [$exit_status], [], [stderr]) AT_CHECK([sed 's/\(opened log file\) .*/\1/ -s/|[[^|]]*: /|/' test-util.log], [0], [dnl +s/|[[^|]]*: /|/ +/backtrace/d +/|.*|/!d' test-util.log], [0], [dnl vlog|INFO|opened log file util|EMER|assertion false failed in test_assert() ]) -- 2.44.0 _______________________________________________ dev mailing list [email protected] https://mail.openvswitch.org/mailman/listinfo/ovs-dev
