Merge remote-tracking branch 'origin/topic/christian/debug-stream-twe…

…aks'

* origin/topic/christian/debug-stream-tweaks:
  Make debug stream names use "-", and handle "_" transparently
  Make "-B all" apply to plugin streams as well.
  Sort streams in "-B help" output, and match case-insensitively throughout

CHANGES

@@ -1,3 +1,19 @@
+7.1.0-dev.572 | 2024-11-16 09:34:27 -0700
+
+  * Make debug stream names use "-", and handle "_" transparently (Christian Kreibich, Corelight)
+
+    This looks consistent, and doesn't break any existing uses with underscores.
+
+  * Make "-B all" apply to plugin streams as well. (Christian Kreibich, Corelight)
+
+  * Sort streams in "-B help" output, and match case-insensitively throughout (Christian Kreibich, Corelight)
+
+    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.
+
 7.1.0-dev.568 | 2024-11-15 19:08:02 -0800
 
   * Don't forward out of the unknown IP transport analyzer (Tim Wojtulewicz, Corelight)

VERSION

@@ -1 +1 @@
-7.1.0-dev.568
+7.1.0-dev.572

src/DebugLogger.cc

@@ -16,16 +16,11 @@ 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}};
 
-DebugLogger::DebugLogger() {
-    verbose = false;
-    file = nullptr;
-}
-
 DebugLogger::~DebugLogger() {
     if ( file && file != stderr )
         fclose(file);
@@ -53,21 +48,28 @@ void DebugLogger::OpenDebugLog(const char* filename) {
 }
 
 void DebugLogger::ShowStreamsHelp() {
-    fprintf(stderr, "\n");
     fprintf(stderr, "Enable debug output into debug.log with -B <streams>.\n");
-    fprintf(stderr, "<streams> is a comma-separated list of streams to enable.\n");
+    fprintf(stderr, "<streams> 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<std::string> 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-<plugin-name>   (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,12 +81,18 @@ void DebugLogger::EnableStreams(const char* s) {
     char* tok = strtok(tmp, ",");
 
     while ( 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 ) {
                 streams[i].enabled = true;
                 enabled_streams.insert(streams[i].prefix);
             }
 
+            all = true;
             verbose = true;
             goto next;
         }
@@ -99,19 +107,19 @@ 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;
         }
 
         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(tok);
+                enabled_streams.insert(ltok);
                 goto next;
             }
         }
@@ -166,10 +174,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());
@@ -183,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

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 @@ class DebugLogger {
 
 private:
     FILE* file;
+    bool all;
     bool verbose;
 
     struct Stream {
@@ -107,9 +108,9 @@ class DebugLogger {
 
     static Stream streams[NUM_DBGS];
 
-    const std::string PluginStreamName(const std::string& plugin_name) {
-        return "plugin-" + 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;

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 <command line>, line 3: No plugin debug stream 'plugin-zeek-http' found
+error in <command line>, line 3: No plugin debug stream 'plugin-notaplugin' found

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!');
+});

testing/btest/plugins/debug-streams.zeek

@@ -2,6 +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
-# @TEST-EXEC-FAIL: 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