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

* 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
This commit is contained in:
Tim Wojtulewicz 2024-11-16 09:34:27 -07:00
commit 62bc324fe1
7 changed files with 79 additions and 28 deletions

16
CHANGES
View file

@ -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 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) * Don't forward out of the unknown IP transport analyzer (Tim Wojtulewicz, Corelight)

View file

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

View file

@ -16,16 +16,11 @@ namespace zeek::detail {
// Same order here as in DebugStream. // Same order here as in DebugStream.
DebugLogger::Stream DebugLogger::streams[NUM_DBGS] = DebugLogger::Stream DebugLogger::streams[NUM_DBGS] =
{{"serial", 0, false}, {"rules", 0, false}, {"string", 0, false}, {"notifiers", 0, false}, {{"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}, {"tm", 0, false}, {"logging", 0, false}, {"input", 0, false}, {"threading", 0, false},
{"plugins", 0, false}, {"zeekygen", 0, false}, {"pktio", 0, false}, {"broker", 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}}; {"scripts", 0, false}, {"supervisor", 0, false}, {"hashkey", 0, false}, {"spicy", 0, false}};
DebugLogger::DebugLogger() {
verbose = false;
file = nullptr;
}
DebugLogger::~DebugLogger() { DebugLogger::~DebugLogger() {
if ( file && file != stderr ) if ( file && file != stderr )
fclose(file); fclose(file);
@ -53,21 +48,28 @@ void DebugLogger::OpenDebugLog(const char* filename) {
} }
void DebugLogger::ShowStreamsHelp() { void DebugLogger::ShowStreamsHelp() {
fprintf(stderr, "\n");
fprintf(stderr, "Enable debug output into debug.log with -B <streams>.\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, "\n");
fprintf(stderr, "Available streams:\n");
for ( int i = 0; i < NUM_DBGS; ++i ) std::vector<std::string> prefixes;
fprintf(stderr, " %s\n", streams[i].prefix);
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, "\n");
fprintf(stderr, fprintf(stderr,
" plugin-<plugin-name> (replace '::' in name with '-'; e.g., '-B " " 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, "\n");
fprintf(stderr, "Pseudo streams\n");
fprintf(stderr, " verbose Increase verbosity.\n"); fprintf(stderr, " verbose Increase verbosity.\n");
fprintf(stderr, " all Enable all streams at maximum verbosity.\n"); fprintf(stderr, " all Enable all streams at maximum verbosity.\n");
fprintf(stderr, "\n"); fprintf(stderr, "\n");
@ -79,12 +81,18 @@ void DebugLogger::EnableStreams(const char* s) {
char* tok = strtok(tmp, ","); char* tok = strtok(tmp, ",");
while ( tok ) { 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 ) { if ( strcasecmp("all", tok) == 0 ) {
for ( int i = 0; i < NUM_DBGS; ++i ) { for ( int i = 0; i < NUM_DBGS; ++i ) {
streams[i].enabled = true; streams[i].enabled = true;
enabled_streams.insert(streams[i].prefix); enabled_streams.insert(streams[i].prefix);
} }
all = true;
verbose = true; verbose = true;
goto next; goto next;
} }
@ -99,19 +107,19 @@ void DebugLogger::EnableStreams(const char* s) {
exit(0); exit(0);
} }
if ( util::starts_with(tok, "plugin-") ) { if ( util::starts_with(ltok, "plugin-") ) {
// Cannot verify this at this time, plugins may not // Cannot verify this at this time, plugins may not
// have been loaded. // have been loaded.
enabled_streams.insert(tok); enabled_streams.insert(ltok);
goto next; goto next;
} }
int i; int i;
for ( i = 0; i < NUM_DBGS; ++i ) { for ( i = 0; i < NUM_DBGS; ++i ) {
if ( strcasecmp(streams[i].prefix, tok) == 0 ) { if ( ltok == streams[i].prefix ) {
streams[i].enabled = true; streams[i].enabled = true;
enabled_streams.insert(tok); enabled_streams.insert(ltok);
goto next; goto next;
} }
} }
@ -166,10 +174,11 @@ void DebugLogger::Log(DebugStream stream, const char* fmt, ...) {
} }
void DebugLogger::Log(const plugin::Plugin& plugin, const char* fmt, ...) { void DebugLogger::Log(const plugin::Plugin& plugin, const char* fmt, ...) {
std::string tok = PluginStreamName(plugin.Name()); if ( ! all ) {
std::string tok = PluginStreamName(plugin.Name());
if ( enabled_streams.find(tok) == enabled_streams.end() ) if ( enabled_streams.find(tok) == enabled_streams.end() )
return; return;
}
fprintf(file, "%17.06f/%17.06f [plugin %s] ", run_state::network_time, util::current_time(true), fprintf(file, "%17.06f/%17.06f [plugin %s] ", run_state::network_time, util::current_time(true),
plugin.Name().c_str()); plugin.Name().c_str());
@ -183,6 +192,12 @@ void DebugLogger::Log(const plugin::Plugin& plugin, const char* fmt, ...) {
fflush(file); 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 } // namespace zeek::detail
#endif #endif

View file

@ -63,7 +63,7 @@ namespace detail {
class DebugLogger { class DebugLogger {
public: public:
// Output goes to stderr per default. // Output goes to stderr per default.
DebugLogger(); DebugLogger() : file(nullptr), all(false), verbose(false) {};
~DebugLogger(); ~DebugLogger();
void OpenDebugLog(const char* filename = 0); void OpenDebugLog(const char* filename = 0);
@ -95,6 +95,7 @@ public:
private: private:
FILE* file; FILE* file;
bool all;
bool verbose; bool verbose;
struct Stream { struct Stream {
@ -107,9 +108,9 @@ private:
static Stream streams[NUM_DBGS]; static Stream streams[NUM_DBGS];
const std::string PluginStreamName(const std::string& plugin_name) { // Canonical rendering of a plugin's name. This is lower-cased,
return "plugin-" + util::strreplace(plugin_name, "::", "-"); // with "::" and "_" both becoming "-".
} const std::string PluginStreamName(const std::string& plugin_name) const;
}; };
extern DebugLogger debug_logger; extern DebugLogger debug_logger;

View file

@ -1,2 +1,2 @@
### BTest baseline data generated by btest-diff. Do not edit. Use "btest -U/-u" to update. Requires BTest >= 0.63. ### 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

View file

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

View file

@ -2,6 +2,13 @@
# @TEST-REQUIRES: test "$($BUILD/zeek-config --build_type)" = "debug" # @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: 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 # @TEST-EXEC: btest-diff zeek.stderr