]> git.ipfire.org Git - thirdparty/snort3.git/commitdiff
Merge pull request #3039 in SNORT/snort3 from ~OSHUMEIK/snort3:js_trace to master
authorMike Stepanek (mstepane) <mstepane@cisco.com>
Tue, 7 Sep 2021 15:52:14 +0000 (15:52 +0000)
committerMike Stepanek (mstepane) <mstepane@cisco.com>
Tue, 7 Sep 2021 15:52:14 +0000 (15:52 +0000)
Squashed commit of the following:

commit e3a3e9bdb3fe9939334474775fc323bf38280fad
Author: Oleksii Shumeiko <oshumeik@cisco.com>
Date:   Fri Aug 20 18:07:16 2021 +0300

    http_inspect: enable traces for JS Normalizer

    This presents Trace framework to NHI.
    Dev/User documentation updated with config option description and
    trace verbosity levels.

12 files changed:
doc/user/http_inspect.txt
src/service_inspectors/http_inspect/dev_notes.txt
src/service_inspectors/http_inspect/http_enum.h
src/service_inspectors/http_inspect/http_flow_data.cc
src/service_inspectors/http_inspect/http_js_norm.cc
src/service_inspectors/http_inspect/http_module.cc
src/service_inspectors/http_inspect/http_module.h
src/utils/js_normalizer.cc
src/utils/js_normalizer.h
src/utils/js_tokenizer.h
src/utils/js_tokenizer.l
src/utils/test/js_normalizer_test.cc

index 3f08584de756663bad52ac17312016f37af227b2..53a913b8aa983586ee064bdbf0bab8d3bac32e06 100755 (executable)
@@ -335,6 +335,35 @@ server. Due to this potential evasion tactic, the HTTP inspector will not cut ov
 it sees any early client-to-server traffic, but will continue normal HTTP processing of the flow
 regardless of the eventual server response.
 
+==== Trace messages
+
+When a user needs help to sort out things going on inside HTTP inspector, Trace module becomes handy.
+
+    $ snort --help-module trace | grep http_inspect
+
+Messages for the enhanced JavaScript Normalizer follow
+(more verbosity available in debug build):
+
+===== trace.module.http_inspect.js_proc
+
+Messages from script processing flow and their verbosity levels:
+
+1. Script opening tag location.
+
+2. Attributes of the detected script.
+
+3. Return codes from Normalizer.
+
+===== trace.module.http_inspect.js_dump
+
+Script data dump and verbosity levels:
+
+1. script_data buffer as it is passed to detection.
+
+2. Current script in normalized form.
+
+3. Current script as it is passed to Normalizer.
+
 ==== Detection rules
 
 http_inspect parses HTTP messages into their components and makes them
index 305ab6dd60958b8387566dce0e958a67e3fdcb71..f19f0a0d414a9c3c419ebb5da7bbb7e3812f619f 100755 (executable)
@@ -251,9 +251,6 @@ though the already-processed data remains in the output buffer.
 Enhanced Normalizer supports scripts over multiple PDUs.
 So, if the script is not ended, Normalizer's context is saved in HttpFlowData.
 The script continuation will be processed with the saved context.
-This has some limitations, like:
- * split in the middle of the identifier will result in two identifiers in the output
- * "<script" or "</script>" sequences split over two PDU will not be detected
 
 In order to support Script Detection feature for inline scripts, Normalizer ensures
 that after reaching the script end (legitimate closing tag or bad token),
@@ -416,3 +413,27 @@ developer to get it right.
 The test tool is designed for single-threaded operation only.
 
 The test tool is only available when compiled with REG_TEST.
+
+NHI has some trace messages available. Trace options follow:
+
+* trace.module.http_inspect.js_proc turns on messages from script processing flow.
++
+Verbosity levels:
++
+1. Script opening tag detected (available in release build)
+2. Attributes of detected script (available in release build)
+3. Normalizer return code (available in release build)
+4. Contexts management (debug build only)
+5. Parser states (debug build only)
+6. Input stream states (debug build only)
+
+* trace.module.http_inspect.js_dump dumps script data from processing layers.
++
+Verbosity levels:
++
+1. script_data buffer as it is being passed to detection (available in release build)
+2. Current normalized script (available in release build)
+3. Payload passed to Normalizer (available in release build)
+4. Temporary buffer (debug build only)
+5. Matched token (debug build only)
+6. Identifier substitution (debug build only)
index 5dd0af5c6ca10cc160b4d434de50a0444300de36..043cc23e25ce7544864cb5a4e75706edf773eafa 100755 (executable)
 
 #include <cstdint>
 
+enum
+{
+    TRACE_JS_PROC = 0,
+    TRACE_JS_DUMP
+};
+
 namespace HttpEnums
 {
 static const int MAX_OCTETS = 63780;
index 7778a0155a567bb612c953d6138eb83ee0e76134..977d7967500c3afa1f46a24fc6a27051659224ef 100644 (file)
@@ -24,6 +24,7 @@
 #include "http_flow_data.h"
 
 #include "decompress/file_decomp.h"
+#include "main/snort_debug.h"
 #include "service_inspectors/http2_inspect/http2_flow_data.h"
 #include "utils/js_identifier_ctx.h"
 #include "utils/js_normalizer.h"
@@ -96,11 +97,17 @@ HttpFlowData::~HttpFlowData()
     {
         update_deallocations(js_ident_ctx->size());
         delete js_ident_ctx;
+
+        debug_log(4, http_trace, TRACE_JS_PROC, nullptr,
+            "js_ident_ctx deleted\n");
     }
     if (js_normalizer)
     {
         update_deallocations(JSNormalizer::size());
         delete js_normalizer;
+
+        debug_log(4, http_trace, TRACE_JS_PROC, nullptr,
+            "js_normalizer deleted\n");
     }
 #endif
 
@@ -240,7 +247,11 @@ void HttpFlowData::garbage_collect()
 void HttpFlowData::reset_js_ident_ctx()
 {
     if (js_ident_ctx)
+    {
         js_ident_ctx->reset();
+        debug_log(4, http_trace, TRACE_JS_PROC, nullptr,
+            "js_ident_ctx reset\n");
+    }
 }
 
 snort::JSNormalizer& HttpFlowData::acquire_js_ctx(int32_t ident_depth, size_t norm_depth,
@@ -253,11 +264,18 @@ snort::JSNormalizer& HttpFlowData::acquire_js_ctx(int32_t ident_depth, size_t no
     {
         js_ident_ctx = new JSIdentifierCtx(ident_depth);
         update_allocations(js_ident_ctx->size());
+
+        debug_logf(4, http_trace, TRACE_JS_PROC, nullptr,
+            "js_ident_ctx created (ident_depth %d)\n", ident_depth);
     }
 
     js_normalizer = new JSNormalizer(*js_ident_ctx, norm_depth, max_template_nesting);
     update_allocations(JSNormalizer::size());
 
+    debug_logf(4, http_trace, TRACE_JS_PROC, nullptr,
+        "js_normalizer created (norm_depth %zd, max_template_nesting %d)\n",
+        norm_depth, max_template_nesting);
+
     return *js_normalizer;
 }
 
@@ -269,6 +287,9 @@ void HttpFlowData::release_js_ctx()
     update_deallocations(JSNormalizer::size());
     delete js_normalizer;
     js_normalizer = nullptr;
+
+    debug_log(4, http_trace, TRACE_JS_PROC, nullptr,
+        "js_normalizer deleted\n");
 }
 #else
 void HttpFlowData::reset_js_ident_ctx() {}
index e371d5f413a3ff5a7b1131879d88c9e4bb96feaf..3b110bdfaa154421f1a2d1f99393bb9ef8067c00 100644 (file)
@@ -23,6 +23,7 @@
 
 #include "http_js_norm.h"
 
+#include "main/snort_debug.h"
 #include "utils/js_normalizer.h"
 #include "utils/safec.h"
 #include "utils/util_jsnorm.h"
 using namespace HttpEnums;
 using namespace snort;
 
+static const char* jsret_codes[] =
+{
+    "end of stream",
+    "script ended",
+    "script continues",
+    "opening tag",
+    "closing tag",
+    "bad token",
+    "identifier overflow",
+    "template nesting overflow",
+    "unknown"
+};
+
+static const char* ret2str(JSTokenizer::JSRet ret)
+{
+    ret = ret < JSTokenizer::JSRet::MAX ? ret : JSTokenizer::JSRet::MAX;
+    return jsret_codes[ret];
+}
+
 static inline JSTokenizer::JSRet js_normalize(JSNormalizer& ctx, const char* const end,
     const char* dst_end, const char*& ptr, char*& dst)
 {
+    trace_logf(3, http_trace, TRACE_JS_DUMP, nullptr,
+        "original[%zu]: %.*s\n", end - ptr, static_cast<int>(end - ptr), ptr);
+
     auto ret = ctx.normalize(ptr, end - ptr, dst, dst_end - dst);
-    auto next = ctx.get_src_next();
+    auto src_next = ctx.get_src_next();
+    auto dst_next = ctx.get_dst_next();
 
-    if (next > ptr)
-        HttpModule::increment_peg_counts(PEG_JS_BYTES, next - ptr);
+    trace_logf(3, http_trace, TRACE_JS_PROC, nullptr,
+        "normalizer returned with %d '%s'\n", ret, ret2str(ret));
+
+    trace_logf(2, http_trace, TRACE_JS_DUMP, nullptr,
+        "normalized[%zu]: %.*s\n", dst_next - dst, static_cast<int>(dst_next - dst), dst);
+
+    if (src_next > ptr)
+        HttpModule::increment_peg_counts(PEG_JS_BYTES, src_next - ptr);
     else
-        next = end; // Normalizer has failed, thus aborting the remaining input
+        src_next = end; // Normalizer has failed, thus aborting the remaining input
 
-    ptr = next;
-    dst = ctx.get_dst_next();
+    ptr = src_next;
+    dst = dst_next;
 
     return ret;
 }
@@ -123,6 +153,12 @@ void HttpJsNorm::enhanced_external_normalize(const Field& input, Field& output,
 
     while (ptr < end)
     {
+        trace_logf(1, http_trace, TRACE_JS_PROC, nullptr,
+            "external script at %zd offset\n", ptr - (const char*)input.start());
+
+        trace_logf(2, http_trace, TRACE_JS_PROC, nullptr,
+            "script %s\n", alive_ctx(ssn) ? "continues" : "starts");
+
         if (!buffer)
         {
             auto len = end - ptr; // not more than the remaining raw data
@@ -176,7 +212,12 @@ void HttpJsNorm::enhanced_external_normalize(const Field& input, Field& output,
     }
 
     if (buffer)
+    {
         output.set(dst - buffer, (const uint8_t*)buffer, true);
+
+        trace_logf(1, http_trace, TRACE_JS_DUMP, nullptr,
+            "script_data[%zu]: %.*s\n", dst - buffer, static_cast<int>(dst - buffer), buffer);
+    }
 }
 
 void HttpJsNorm::enhanced_inline_normalize(const Field& input, Field& output,
@@ -214,6 +255,15 @@ void HttpJsNorm::enhanced_inline_normalize(const Field& input, Field& output,
                 ptr = sctx.next;
             }
 
+            trace_logf(1, http_trace, TRACE_JS_PROC, nullptr,
+                "opening tag at %zd offset\n", ptr - (const char*)input.start());
+
+            trace_logf(2, http_trace, TRACE_JS_PROC, nullptr,
+                "script attributes [%s, %s, %s]\n",
+                sctx.is_shortened ? "shortened form" : "full form",
+                sctx.is_javascript ? "JavaScript type" : "unknown type",
+                sctx.is_external ? "external source" : "inline");
+
             if (sctx.is_shortened)
             {
                 *infractions += INF_JS_SHORTENED_TAG;
@@ -303,7 +353,12 @@ void HttpJsNorm::enhanced_inline_normalize(const Field& input, Field& output,
         ssn->release_js_ctx();
 
     if (buffer)
+    {
         output.set(dst - buffer, (const uint8_t*)buffer, true);
+
+        trace_logf(1, http_trace, TRACE_JS_DUMP, nullptr,
+            "script_data[%zu]: %.*s\n", dst - buffer, static_cast<int>(dst - buffer), buffer);
+    }
 }
 
 void HttpJsNorm::legacy_normalize(const Field& input, Field& output, HttpInfractions* infractions,
index 69ec5f1faadd1df4b316d82360ae712dca031642..b090fbf64a8978696cf627b289410616a5f8b634 100755 (executable)
@@ -24,6 +24,7 @@
 #include "http_module.h"
 
 #include "log/messages.h"
+#include "trace/trace.h"
 
 #include "http_enum.h"
 #include "http_js_norm.h"
@@ -173,6 +174,25 @@ ProfileStats* HttpModule::get_profile() const
 
 THREAD_LOCAL PegCount HttpModule::peg_counts[PEG_COUNT_MAX] = { };
 
+THREAD_LOCAL const Trace* http_trace = nullptr;
+
+static const TraceOption http_trace_options[] =
+{
+    { "js_proc",  TRACE_JS_PROC,  "enable JavaScript processing logging" },
+    { "js_dump",  TRACE_JS_DUMP,  "enable JavaScript data logging" },
+    { nullptr, 0, nullptr }
+};
+
+void HttpModule::set_trace(const Trace* trace) const
+{
+    http_trace = trace;
+}
+
+const TraceOption* HttpModule::get_trace_options() const
+{
+    return http_trace_options;
+}
+
 bool HttpModule::begin(const char*, int, SnortConfig*)
 {
     delete params;
index 3ec9dd4b1912277fcec981bcfc5a622f8c10d45a..ac27843dc6fa79511f799d06a17f6f3408d6e9ee 100755 (executable)
 #define HTTP_NAME "http_inspect"
 #define HTTP_HELP "HTTP inspector"
 
+namespace snort
+{
+class Trace;
+struct SnortConfig;
+}
+
+extern THREAD_LOCAL const snort::Trace* http_trace;
+
 struct HttpParaList
 {
 public:
@@ -172,6 +180,9 @@ public:
     bool is_bindable() const override
     { return true; }
 
+    void set_trace(const snort::Trace*) const override;
+    const snort::TraceOption* get_trace_options() const override;
+
 #ifdef REG_TEST
     static const PegInfo* get_peg_names() { return peg_names; }
     static const PegCount* get_peg_counts() { return peg_counts; }
index 9e6067782f1a5e31f12b03732053efdd364e6814..38ccf0ef53299afb2be53ad135c99ff7447be3d6 100644 (file)
@@ -52,6 +52,9 @@ JSTokenizer::JSRet JSNormalizer::normalize(const char* src, size_t src_len, char
 {
     if (rem_bytes == 0 && !unlim)
     {
+        debug_log(5, http_trace, TRACE_JS_PROC, nullptr,
+            "depth limit reached\n");
+
         src_next = src + src_len;
         dst_next = dst;
         return JSTokenizer::EOS;
@@ -60,6 +63,9 @@ JSTokenizer::JSRet JSNormalizer::normalize(const char* src, size_t src_len, char
     size_t len = unlim ? src_len :
         src_len < rem_bytes ? src_len : rem_bytes;
 
+    debug_logf(4, http_trace, TRACE_JS_DUMP, nullptr,
+        "tmp buffer[%zu]: %.*s\n", tmp_buf_size, static_cast<int>(tmp_buf_size), tmp_buf);
+
     in_buf.pubsetbuf(tmp_buf, tmp_buf_size, const_cast<char*>(src), len);
     out_buf.pubsetbuf(dst, dst_len);
 
index f0dd5896959ac6c605ff554f2eab0097cc14c41a..9bbbeb8a507b9ee768438f32836609a08572bc93 100644 (file)
@@ -73,6 +73,10 @@ protected:
 
         if (current_src_len + off < 0 and once)
         {
+            debug_logf(6, http_trace, TRACE_JS_PROC, nullptr,
+                "seek offset %ld, %p:%zu => %p:%zu\n",
+                off, src2, len2, src1, len1);
+
             off += current_src_len;
             once = false;
             setbuf(src1, len1);
@@ -85,7 +89,15 @@ protected:
     virtual int underflow() override
     {
         if (once)
+        {
+            debug_log(6, http_trace, TRACE_JS_PROC, nullptr,
+                "underflow, no buffer to switch to\n");
             return EOF;
+        }
+
+        debug_logf(6, http_trace, TRACE_JS_PROC, nullptr,
+            "underflow, %p:%zu => %p:%zu\n",
+            src1, len1, src2, len2);
 
         once = true;
         setbuf(src2, len2);
index c6c3bc1f0aea069e403bd78484acffe8ce51eae5..d7f73d054e9088263a4470369900e9d8da7abb2e 100644 (file)
 #include <vector>
 
 #include "log/messages.h"
+#include "main/snort_debug.h"
+#include "service_inspectors/http_inspect/http_enum.h"
+
+extern THREAD_LOCAL const snort::Trace* http_trace;
 
 // The longest pattern has 9 characters " < / s c r i p t > ",
 // 8 of them can reside in 1st chunk
@@ -61,7 +65,8 @@ public:
         CLOSING_TAG,
         BAD_TOKEN,
         IDENTIFIER_OVERFLOW,
-        TEMPLATE_NESTING_OVERFLOW
+        TEMPLATE_NESTING_OVERFLOW,
+        MAX
     };
 
     JSTokenizer(std::istream& in, std::ostream& out, JSIdentifierCtxBase& ident_ctx,
index d2cb3e04c294ce4b293dbdb44a9f0534047ccc05..ea8a350d53c4bbad944f7f850fc3a00fbec563b4 100644 (file)
 #include "utils/js_identifier_ctx.h"
 #include "utils/util_cstring.h"
 
-#define YY_USER_ACTION { states_push(); }
+#define YY_USER_ACTION                                      \
+    {                                                       \
+        debug_logf(5, http_trace, TRACE_JS_PROC, nullptr,   \
+            "pattern #%d, sc %d\n", yy_act, YY_START);      \
+                                                            \
+        debug_logf(5, http_trace, TRACE_JS_DUMP, nullptr,   \
+            "text '%s'\n", YYText());                       \
+                                                            \
+        states_push();                                      \
+    }
+
 #define EXEC(f) { auto r = (f); if (r) { BEGIN(regst); return r; } }
 #define EEOF(f) { auto r = (f); if (r) { if (r != SCRIPT_CONTINUE) BEGIN(regst); return r; } }
 %}
@@ -1208,10 +1218,16 @@ JSTokenizer::JSRet JSTokenizer::do_identifier_substitution(const char* lexeme)
 
     if (ident)
     {
+        debug_logf(6, http_trace, TRACE_JS_DUMP, nullptr,
+            "'%s' => '%s'\n", lexeme, ident);
+
         yyout << ident;
         return EOS;
     }
 
+    debug_logf(6, http_trace, TRACE_JS_DUMP, nullptr,
+        "'%s' => IDENTIFIER_OVERFLOW\n", lexeme);
+
     return IDENTIFIER_OVERFLOW;
 }
 
index 00cfa6b16be9e087d3900af06f42db657ae2de28..65322a88fcbb54d947a2ee8c4c2c67f82339514a 100644 (file)
 #include "utils/js_identifier_ctx.h"
 #include "utils/js_normalizer.h"
 
+// Mock functions
+
 namespace snort
 {
-// Mock for JSTokenizer
 [[noreturn]] void FatalError(const char*, ...)
 { exit(EXIT_FAILURE); }
+void trace_vprintf(const char*, TraceLevel, const char*, const Packet*, const char*, va_list) {}
+uint8_t TraceApi::get_constraints_generation() { return 0; }
+void TraceApi::filter(const Packet&) {}
 }
 
+THREAD_LOCAL const snort::Trace* http_trace = nullptr;
+
 class JSIdentifierCtxTest : public JSIdentifierCtxBase
 {
 public:
@@ -46,6 +52,8 @@ public:
     size_t size() const override { return 0; }
 };
 
+// Test cases
+
 using namespace snort;
 
 #define DEPTH 65535