From 5e4942bcc09de4aa68bd094bb9c3cdf783164382 Mon Sep 17 00:00:00 2001 From: Christian Kreibich Date: Fri, 15 Nov 2024 11:51:44 -0800 Subject: [PATCH 1/3] Sort streams in "-B help" output, and match case-insensitively throughout Matching of plugins' debug streams was still case-sensitive. Also contains some minor output tweaks. It'd be nice to only list plugin debug streams actually _used_ by plugins. I didn't see a quick way to do that so that's for another time. --- src/DebugLogger.cc | 29 ++++++++++++------- src/DebugLogger.h | 2 +- .../plugins.debug-streams/zeek.stderr | 2 +- testing/btest/plugins/debug-streams.zeek | 3 +- 4 files changed, 23 insertions(+), 13 deletions(-) diff --git a/src/DebugLogger.cc b/src/DebugLogger.cc index 8e964aac32..90babe2358 100644 --- a/src/DebugLogger.cc +++ b/src/DebugLogger.cc @@ -53,21 +53,28 @@ void DebugLogger::OpenDebugLog(const char* filename) { } void DebugLogger::ShowStreamsHelp() { - fprintf(stderr, "\n"); fprintf(stderr, "Enable debug output into debug.log with -B .\n"); - fprintf(stderr, " is a comma-separated list of streams to enable.\n"); + fprintf(stderr, " is a case-insensitive, comma-separated list of streams to enable:\n"); fprintf(stderr, "\n"); - fprintf(stderr, "Available streams:\n"); - for ( int i = 0; i < NUM_DBGS; ++i ) - fprintf(stderr, " %s\n", streams[i].prefix); + std::vector prefixes; + for ( const auto& stream : streams ) + prefixes.emplace_back(stream.prefix); + std::sort(prefixes.begin(), prefixes.end()); + + for ( const auto& prefix : prefixes ) + fprintf(stderr, " %s\n", prefix.c_str()); + + fprintf(stderr, "\n"); + fprintf(stderr, "Every plugin (see -N) also has its own debug stream:\n"); fprintf(stderr, "\n"); fprintf(stderr, " plugin- (replace '::' in name with '-'; e.g., '-B " - "plugin-Zeek-Netmap')\n"); + "plugin-Zeek-JavaScript')\n"); + fprintf(stderr, "\n"); + fprintf(stderr, "Pseudo streams:\n"); fprintf(stderr, "\n"); - fprintf(stderr, "Pseudo streams\n"); fprintf(stderr, " verbose Increase verbosity.\n"); fprintf(stderr, " all Enable all streams at maximum verbosity.\n"); fprintf(stderr, "\n"); @@ -79,6 +86,8 @@ void DebugLogger::EnableStreams(const char* s) { char* tok = strtok(tmp, ","); while ( tok ) { + std::string ltok{util::strtolower(tok)}; + if ( strcasecmp("all", tok) == 0 ) { for ( int i = 0; i < NUM_DBGS; ++i ) { streams[i].enabled = true; @@ -99,10 +108,10 @@ void DebugLogger::EnableStreams(const char* s) { exit(0); } - if ( util::starts_with(tok, "plugin-") ) { + if ( util::starts_with(ltok, "plugin-") ) { // Cannot verify this at this time, plugins may not // have been loaded. - enabled_streams.insert(tok); + enabled_streams.insert(ltok); goto next; } @@ -111,7 +120,7 @@ void DebugLogger::EnableStreams(const char* s) { for ( i = 0; i < NUM_DBGS; ++i ) { if ( strcasecmp(streams[i].prefix, tok) == 0 ) { streams[i].enabled = true; - enabled_streams.insert(tok); + enabled_streams.insert(ltok); goto next; } } diff --git a/src/DebugLogger.h b/src/DebugLogger.h index a8df9cd977..bb2c344859 100644 --- a/src/DebugLogger.h +++ b/src/DebugLogger.h @@ -108,7 +108,7 @@ private: static Stream streams[NUM_DBGS]; const std::string PluginStreamName(const std::string& plugin_name) { - return "plugin-" + util::strreplace(plugin_name, "::", "-"); + return "plugin-" + util::strtolower(util::strreplace(plugin_name, "::", "-")); } }; diff --git a/testing/btest/Baseline/plugins.debug-streams/zeek.stderr b/testing/btest/Baseline/plugins.debug-streams/zeek.stderr index 7f6cbf9e04..def86ea9b2 100644 --- a/testing/btest/Baseline/plugins.debug-streams/zeek.stderr +++ b/testing/btest/Baseline/plugins.debug-streams/zeek.stderr @@ -1,2 +1,2 @@ ### BTest baseline data generated by btest-diff. Do not edit. Use "btest -U/-u" to update. Requires BTest >= 0.63. -error in , line 3: No plugin debug stream 'plugin-zeek-http' found +error in , line 3: No plugin debug stream 'plugin-notaplugin' found diff --git a/testing/btest/plugins/debug-streams.zeek b/testing/btest/plugins/debug-streams.zeek index 795f99b909..b2ce3858e6 100644 --- a/testing/btest/plugins/debug-streams.zeek +++ b/testing/btest/plugins/debug-streams.zeek @@ -2,6 +2,7 @@ # @TEST-REQUIRES: test "$($BUILD/zeek-config --build_type)" = "debug" # @TEST-EXEC: zeek -B plugin-Zeek-HTTP -e 'event zeek_init() { print "zeek_init"; }' 2>zeek.stderr -# @TEST-EXEC-FAIL: zeek -B plugin-zeek-http -e 'event zeek_init() { print "zeek_init"; }' 2>zeek.stderr +# @TEST-EXEC: zeek -B PLUGIN-zeek-http -e 'event zeek_init() { print "zeek_init"; }' 2>zeek.stderr +# @TEST-EXEC-FAIL: zeek -B plugin-notaplugin -e 'event zeek_init() { print "zeek_init"; }' 2>zeek.stderr # @TEST-EXEC: btest-diff zeek.stderr From 7563af4906ae45cc2b0e9949744bd80dc233a2cd Mon Sep 17 00:00:00 2001 From: Christian Kreibich Date: Fri, 15 Nov 2024 12:34:10 -0800 Subject: [PATCH 2/3] Make "-B all" apply to plugin streams as well. --- src/DebugLogger.cc | 15 ++++++--------- src/DebugLogger.h | 3 ++- testing/btest/plugins/debug-streams-all.js | 12 ++++++++++++ 3 files changed, 20 insertions(+), 10 deletions(-) create mode 100644 testing/btest/plugins/debug-streams-all.js diff --git a/src/DebugLogger.cc b/src/DebugLogger.cc index 90babe2358..e9bed5817b 100644 --- a/src/DebugLogger.cc +++ b/src/DebugLogger.cc @@ -21,11 +21,6 @@ DebugLogger::Stream DebugLogger::streams[NUM_DBGS] = {"plugins", 0, false}, {"zeekygen", 0, false}, {"pktio", 0, false}, {"broker", 0, false}, {"scripts", 0, false}, {"supervisor", 0, false}, {"hashkey", 0, false}, {"spicy", 0, false}}; -DebugLogger::DebugLogger() { - verbose = false; - file = nullptr; -} - DebugLogger::~DebugLogger() { if ( file && file != stderr ) fclose(file); @@ -94,6 +89,7 @@ void DebugLogger::EnableStreams(const char* s) { enabled_streams.insert(streams[i].prefix); } + all = true; verbose = true; goto next; } @@ -175,10 +171,11 @@ void DebugLogger::Log(DebugStream stream, const char* fmt, ...) { } void DebugLogger::Log(const plugin::Plugin& plugin, const char* fmt, ...) { - std::string tok = PluginStreamName(plugin.Name()); - - if ( enabled_streams.find(tok) == enabled_streams.end() ) - return; + if ( ! all ) { + std::string tok = PluginStreamName(plugin.Name()); + if ( enabled_streams.find(tok) == enabled_streams.end() ) + return; + } fprintf(file, "%17.06f/%17.06f [plugin %s] ", run_state::network_time, util::current_time(true), plugin.Name().c_str()); diff --git a/src/DebugLogger.h b/src/DebugLogger.h index bb2c344859..b331019f45 100644 --- a/src/DebugLogger.h +++ b/src/DebugLogger.h @@ -63,7 +63,7 @@ namespace detail { class DebugLogger { public: // Output goes to stderr per default. - DebugLogger(); + DebugLogger() : file(nullptr), all(false), verbose(false) {}; ~DebugLogger(); void OpenDebugLog(const char* filename = 0); @@ -95,6 +95,7 @@ public: private: FILE* file; + bool all; bool verbose; struct Stream { diff --git a/testing/btest/plugins/debug-streams-all.js b/testing/btest/plugins/debug-streams-all.js new file mode 100644 index 0000000000..0fde271911 --- /dev/null +++ b/testing/btest/plugins/debug-streams-all.js @@ -0,0 +1,12 @@ +/* + * Verify that `-B all` leads to plugin debug stream content in debug.log. + * This requires JavaScript and a debug build. + * @TEST-REQUIRES: test "$($BUILD/zeek-config --build_type)" = "debug" + * @TEST-REQUIRES: $SCRIPTS/have-javascript + * @TEST-EXEC: zeek -b -B all %INPUT + * @TEST-EXEC: grep -q '[plugin Zeek::JavaScript]' debug.log + */ + +zeek.on('zeek_init', () => { + console.log('Hello Zeek!'); +}); From b1e0e2648445fed47182db7716eed008d5605ed8 Mon Sep 17 00:00:00 2001 From: Christian Kreibich Date: Fri, 15 Nov 2024 17:53:29 -0800 Subject: [PATCH 3/3] Make debug stream names use "-", and handle "_" transparently This looks consistent, and doesn't break any existing uses with underscores. --- src/DebugLogger.cc | 15 ++++++++++++--- src/DebugLogger.h | 6 +++--- testing/btest/plugins/debug-streams.zeek | 6 ++++++ 3 files changed, 21 insertions(+), 6 deletions(-) diff --git a/src/DebugLogger.cc b/src/DebugLogger.cc index e9bed5817b..5e97d1e629 100644 --- a/src/DebugLogger.cc +++ b/src/DebugLogger.cc @@ -16,7 +16,7 @@ namespace zeek::detail { // Same order here as in DebugStream. DebugLogger::Stream DebugLogger::streams[NUM_DBGS] = {{"serial", 0, false}, {"rules", 0, false}, {"string", 0, false}, {"notifiers", 0, false}, - {"main-loop", 0, false}, {"dpd", 0, false}, {"packet_analysis", 0, false}, {"file_analysis", 0, false}, + {"main-loop", 0, false}, {"dpd", 0, false}, {"packet-analysis", 0, false}, {"file-analysis", 0, false}, {"tm", 0, false}, {"logging", 0, false}, {"input", 0, false}, {"threading", 0, false}, {"plugins", 0, false}, {"zeekygen", 0, false}, {"pktio", 0, false}, {"broker", 0, false}, {"scripts", 0, false}, {"supervisor", 0, false}, {"hashkey", 0, false}, {"spicy", 0, false}}; @@ -81,7 +81,10 @@ void DebugLogger::EnableStreams(const char* s) { char* tok = strtok(tmp, ","); while ( tok ) { - std::string ltok{util::strtolower(tok)}; + // This maps "_" to "-" for backward compatibility and ease of use: we + // used to have underscores in some stream names, and several plugins + // do as well. + std::string ltok{util::strreplace(util::strtolower(tok), "_", "-")}; if ( strcasecmp("all", tok) == 0 ) { for ( int i = 0; i < NUM_DBGS; ++i ) { @@ -114,7 +117,7 @@ void DebugLogger::EnableStreams(const char* s) { int i; for ( i = 0; i < NUM_DBGS; ++i ) { - if ( strcasecmp(streams[i].prefix, tok) == 0 ) { + if ( ltok == streams[i].prefix ) { streams[i].enabled = true; enabled_streams.insert(ltok); goto next; @@ -189,6 +192,12 @@ void DebugLogger::Log(const plugin::Plugin& plugin, const char* fmt, ...) { fflush(file); } +const std::string DebugLogger::PluginStreamName(const std::string& plugin_name) const { + std::string res{util::strreplace(plugin_name, "::", "-")}; + res = util::strreplace(res, "_", "-"); + return "plugin-" + util::strtolower(res); +} + } // namespace zeek::detail #endif diff --git a/src/DebugLogger.h b/src/DebugLogger.h index b331019f45..7e3a4c0b6b 100644 --- a/src/DebugLogger.h +++ b/src/DebugLogger.h @@ -108,9 +108,9 @@ private: static Stream streams[NUM_DBGS]; - const std::string PluginStreamName(const std::string& plugin_name) { - return "plugin-" + util::strtolower(util::strreplace(plugin_name, "::", "-")); - } + // Canonical rendering of a plugin's name. This is lower-cased, + // with "::" and "_" both becoming "-". + const std::string PluginStreamName(const std::string& plugin_name) const; }; extern DebugLogger debug_logger; diff --git a/testing/btest/plugins/debug-streams.zeek b/testing/btest/plugins/debug-streams.zeek index b2ce3858e6..f8054b7c09 100644 --- a/testing/btest/plugins/debug-streams.zeek +++ b/testing/btest/plugins/debug-streams.zeek @@ -2,7 +2,13 @@ # @TEST-REQUIRES: test "$($BUILD/zeek-config --build_type)" = "debug" # @TEST-EXEC: zeek -B plugin-Zeek-HTTP -e 'event zeek_init() { print "zeek_init"; }' 2>zeek.stderr + +# Variations on case that should all work: # @TEST-EXEC: zeek -B PLUGIN-zeek-http -e 'event zeek_init() { print "zeek_init"; }' 2>zeek.stderr +# @TEST-EXEC: zeek -B plugin-zeek-TCP_PKT -e 'event zeek_init() { print "zeek_init"; }' 2>zeek.stderr +# @TEST-EXEC: zeek -B plugin-zeek-tcp-pkt -e 'event zeek_init() { print "zeek_init"; }' 2>zeek.stderr + +# A plugin that really does not exist: # @TEST-EXEC-FAIL: zeek -B plugin-notaplugin -e 'event zeek_init() { print "zeek_init"; }' 2>zeek.stderr # @TEST-EXEC: btest-diff zeek.stderr