From: russ <rucombs@cisco.com>
Date: Thu, 4 Jul 2019 18:26:52 +0000 (-0400)
Subject: Squashed commit of the following:
X-Git-Tag: 3.0.0-258~10
X-Git-Url: http://git.ipfire.org/cgi-bin/gitweb.cgi?a=commitdiff_plain;h=88d4b6272b84425d83c0e532fd4119216f108e57;p=thirdparty%2Fsnort3.git

Squashed commit of the following:

commit 90bacc16fa036bd678c47a51898a0e247a4659cf
Author: russ <rucombs@cisco.com>
Date:   Thu Jul 4 10:32:46 2019 -0400

    profiler: include onload/offload efforts in mpse

commit 280854ff2229555fb893a409a62725d31ed403ed
Author: russ <rucombs@cisco.com>
Date:   Wed Jul 3 21:52:09 2019 -0400

    detection: reduce hard number of contexts to work with pcap default

commit 8eb020e4470c568039b89e12ae29f5b8a625cec3
Author: russ <rucombs@cisco.com>
Date:   Wed Jul 3 12:25:53 2019 -0400

    profiler: refactor

commit 656e280fc09d1d06c379dfc94fe2b905b79ba03c
Author: russ <rucombs@cisco.com>
Date:   Sun Jun 30 13:54:38 2019 -0400

    profiler: implement general exclusion

    The profiler module has been reworked for performance and accuracy.
    There is now a single level (default build) and no need to specify
    exclusions.  When a new scope is entered, the existing scope if any
    is paused and then resumed when the new scope exits.  The "total"
    root is now implemented internally and fixed at total packets and
    total runtime.  The difference from that and the sum of all root
    children is given in other.
---

diff --git a/src/detection/detect.h b/src/detection/detect.h
index 241d2d6eb..79042e0e2 100644
--- a/src/detection/detect.h
+++ b/src/detection/detect.h
@@ -30,9 +30,6 @@ namespace snort
 struct Packet;
 struct ProfileStats;
 }
-struct Event;
-struct RuleFpList;
-struct RuleTreeNode;
 
 extern THREAD_LOCAL snort::ProfileStats eventqPerfStats;
 
@@ -41,7 +38,7 @@ bool snort_ignore(snort::Packet*);
 bool snort_log(snort::Packet*);
 
 // alerts
-void CallLogFuncs(snort::Packet*, ListHead*, Event*, const char*);
+void CallLogFuncs(snort::Packet*, ListHead*, struct Event*, const char*);
 void CallLogFuncs(snort::Packet*, const OptTreeNode*, ListHead*);
 void CallAlertFuncs(snort::Packet*, const OptTreeNode*, ListHead*);
 
diff --git a/src/detection/detection_engine.cc b/src/detection/detection_engine.cc
index 8bf8d9966..d3afe492e 100644
--- a/src/detection/detection_engine.cc
+++ b/src/detection/detection_engine.cc
@@ -403,6 +403,7 @@ bool DetectionEngine::offload(Packet* p)
 
     if ( p->flow ? p->flow->context_chain.front() : sw->non_flow_chain.front() )
     {
+        Profile profile(mpsePerfStats);
         p->context->searches.search_sync();
         sw->suspend();
         pc.offload_suspends++;
@@ -450,15 +451,19 @@ void DetectionEngine::onload(Flow* flow)
 
 void DetectionEngine::onload()
 {
+    Profile profile(mpsePerfStats);
     Packet* p;
+
     while (offloader->count() and offloader->get(p))
     {
-        trace_logf(detection, TRACE_DETECTION_ENGINE, "%" PRIu64 " de::onload %" PRIu64 " (r=%d)\n",
+        trace_logf(detection, TRACE_DETECTION_ENGINE,
+            "%" PRIu64 " de::onload %" PRIu64 " (r=%d)\n",
             p->context->packet_number, p->context->context_num, offloader->count());
         
         p->clear_offloaded();
         
-        IpsContextChain& chain = p->flow ? p->flow->context_chain : Analyzer::get_switcher()->non_flow_chain;
+        IpsContextChain& chain = p->flow ? p->flow->context_chain :
+            Analyzer::get_switcher()->non_flow_chain;
         
         resume_ready_suspends(chain);
     }
diff --git a/src/detection/fp_detect.cc b/src/detection/fp_detect.cc
index b0a25321f..e2c8a716c 100644
--- a/src/detection/fp_detect.cc
+++ b/src/detection/fp_detect.cc
@@ -328,10 +328,6 @@ int fpEvalRTN(RuleTreeNode* rtn, Packet* p, int check_ports)
 int fp_eval_option(void* v, Cursor& c, Packet* p)
 {
     IpsOption* opt = (IpsOption*)v;
-    // FIXIT-L use this with RuleProfile enabled in profiler_defs.h
-    // all ips options should be double counted w/o this exclude but
-    // this causes rule_eval to underflow.
-    //ProfileExclude exclude(rulePerfStats);
     return opt->eval(c, p);
 }
 
diff --git a/src/detection/regex_offload.cc b/src/detection/regex_offload.cc
index 7dcea543f..45376a464 100644
--- a/src/detection/regex_offload.cc
+++ b/src/detection/regex_offload.cc
@@ -117,6 +117,8 @@ MpseRegexOffload::MpseRegexOffload(unsigned max) : RegexOffload(max) { }
 
 void MpseRegexOffload::put(snort::Packet* p)
 {
+    Profile profile(mpsePerfStats);
+
     assert(p);
     assert(!idle.empty());
     assert(p->context->searches.items.size() > 0);
@@ -135,6 +137,7 @@ void MpseRegexOffload::put(snort::Packet* p)
 
 bool MpseRegexOffload::get(snort::Packet*& p)
 {
+    Profile profile(mpsePerfStats);
     assert(!busy.empty());
 
     snort::Mpse::MpseRespType resp_ret;
@@ -207,6 +210,8 @@ void ThreadRegexOffload::stop()
 
 void ThreadRegexOffload::put(snort::Packet* p)
 {
+    Profile profile(mpsePerfStats);
+
     assert(p);
     assert(!idle.empty());
     assert(p->context->searches.items.size() > 0);
@@ -236,6 +241,7 @@ void ThreadRegexOffload::put(snort::Packet* p)
 
 bool ThreadRegexOffload::get(snort::Packet*& p)
 {
+    Profile profile(mpsePerfStats);
     assert(!busy.empty());
 
     for ( auto i = busy.begin(); i != busy.end(); i++ )
diff --git a/src/main/analyzer.cc b/src/main/analyzer.cc
index 1788d9fc2..2891df194 100644
--- a/src/main/analyzer.cc
+++ b/src/main/analyzer.cc
@@ -74,7 +74,6 @@ using namespace std;
 
 static MainHook_f main_hook = snort_ignore;
 
-THREAD_LOCAL ProfileStats totalPerfStats;
 THREAD_LOCAL ProfileStats daqPerfStats;
 
 static THREAD_LOCAL Analyzer* local_analyzer = nullptr;
@@ -317,7 +316,6 @@ void Analyzer::post_process_daq_pkt_msg(Packet* p)
 
 void Analyzer::process_daq_pkt_msg(DAQ_Msg_h msg, bool retry)
 {
-    Profile profile(totalPerfStats);
     const DAQ_PktHdr_t* pkthdr = daq_msg_get_pkthdr(msg);
     set_default_policy();
 
@@ -413,12 +411,7 @@ void Analyzer::post_process_packet(Packet* p)
 
 void Analyzer::finalize_daq_message(DAQ_Msg_h msg, DAQ_Verdict verdict)
 {
-    // FIXIT-L excluding daqPerfStats profile here because it needs to
-    // be excluded by stream_tcp which requires some refactoring.
-    // Instead the profiler could automatically exclude from current
-    // context if new scope has no parent but that requires additional
-    // plumbing.
-    // Profile profile(daqPerfStats);
+    Profile profile(daqPerfStats);
     daq_instance->finalize_message(msg, verdict);
 }
 
@@ -487,10 +480,12 @@ void Analyzer::idle()
 void Analyzer::init_unprivileged()
 {
     // using dummy values until further integration
+    // FIXIT-H max_contexts must be <= DAQ msg pool to avoid permanent stall
+    // condition (polling for packets that won't come to resume ready suspends)
 #ifdef REG_TEST
     const unsigned max_contexts = 20;
 #else
-    const unsigned max_contexts = 1024;
+    const unsigned max_contexts = 255;
 #endif
 
     switcher = new ContextSwitcher;
diff --git a/src/main/analyzer.h b/src/main/analyzer.h
index 0aff93722..0d4bfc826 100644
--- a/src/main/analyzer.h
+++ b/src/main/analyzer.h
@@ -136,7 +136,6 @@ private:
 };
 
 extern THREAD_LOCAL snort::ProfileStats daqPerfStats;
-extern THREAD_LOCAL snort::ProfileStats totalPerfStats;
 
 #endif
 
diff --git a/src/main/modules.cc b/src/main/modules.cc
index 796df16da..f4a339427 100644
--- a/src/main/modules.cc
+++ b/src/main/modules.cc
@@ -49,7 +49,7 @@
 #include "parser/parse_conf.h"
 #include "parser/parse_ip.h"
 #include "parser/parser.h"
-#include "profiler/profiler_defs.h"
+#include "profiler/profiler.h"
 #include "search_engines/pat_stats.h"
 #include "side_channel/side_channel_module.h"
 #include "sfip/sf_ipvar.h"
@@ -512,6 +512,8 @@ public:
     bool set(const char*, Value&, SnortConfig*) override;
     bool end(const char*, int, SnortConfig*) override;
 
+    ProfileStats* get_profile(unsigned, const char*&, const char*&) const override;
+
     Usage get_usage() const override
     { return GLOBAL; }
 };
@@ -541,6 +543,24 @@ bool ProfilerModule::end(const char*, int, SnortConfig* sc)
     return true;
 }
 
+ProfileStats* ProfilerModule::get_profile(
+    unsigned index, const char*& name, const char*& parent) const
+{
+    switch ( index )
+    {
+    case 0:
+        name = "total";
+        parent = nullptr;
+        return &totalPerfStats;
+
+    case 1:
+        name = "other";
+        parent = nullptr;
+        return &otherPerfStats;
+    }
+    return nullptr;
+}
+
 //-------------------------------------------------------------------------
 // classification module
 //-------------------------------------------------------------------------
diff --git a/src/main/snort.cc b/src/main/snort.cc
index 3e9b23135..e04bd590d 100644
--- a/src/main/snort.cc
+++ b/src/main/snort.cc
@@ -30,9 +30,7 @@
 #include "actions/ips_actions.h"
 #include "codecs/codec_api.h"
 #include "connectors/connectors.h"
-#include "detection/detect.h"
 #include "detection/fp_config.h"
-#include "detection/fp_detect.h"
 #include "file_api/file_service.h"
 #include "filters/rate_filter.h"
 #include "filters/sfrf.h"
@@ -82,7 +80,6 @@
 #include "control_mgmt.h"
 #endif
 
-#include "analyzer.h"
 #include "build.h"
 #include "snort_config.h"
 #include "thread_config.h"
@@ -93,44 +90,6 @@ using namespace std;
 static SnortConfig* snort_cmd_line_conf = nullptr;
 static pid_t snort_main_thread_pid = 0;
 
-//-------------------------------------------------------------------------
-// perf stats
-// FIXIT-M move these to appropriate modules
-//-------------------------------------------------------------------------
-
-static ProfileStats* get_profile(const char* key)
-{
-    if ( !strcmp(key, "daq") )
-        return &daqPerfStats;
-
-    if ( !strcmp(key, "decode") )
-        return &decodePerfStats;
-
-    if ( !strcmp(key, "mpse") )
-        return &mpsePerfStats;
-
-    if ( !strcmp(key, "rule_eval") )
-        return &rulePerfStats;
-
-    if ( !strcmp(key, "eventq") )
-        return &eventqPerfStats;
-
-    if ( !strcmp(key, "total") )
-        return &totalPerfStats;
-
-    return nullptr;
-}
-
-static void register_profiles()
-{
-    Profiler::register_module("daq", nullptr, get_profile);
-    Profiler::register_module("decode", nullptr, get_profile);
-    Profiler::register_module("mpse", nullptr, get_profile);
-    Profiler::register_module("rule_eval", nullptr, get_profile);
-    Profiler::register_module("eventq", nullptr, get_profile);
-    Profiler::register_module("total", nullptr, get_profile);
-}
-
 //-------------------------------------------------------------------------
 // initialization
 //-------------------------------------------------------------------------
@@ -186,7 +145,6 @@ void Snort::init(int argc, char** argv)
     }
 
     FileService::init();
-    register_profiles();
 
     parser_init();
     SnortConfig* sc = ParseSnortConf(snort_cmd_line_conf);
diff --git a/src/main/snort_module.cc b/src/main/snort_module.cc
index 3d994140e..be103cf51 100644
--- a/src/main/snort_module.cc
+++ b/src/main/snort_module.cc
@@ -24,11 +24,14 @@
 
 #include "snort_module.h"
 
+#include "detection/detect.h"
+#include "detection/fp_detect.h"
 #include "framework/module.h"
 #include "framework/parameter.h"
 #include "log/messages.h"
 #include "main.h"
 #include "main/snort_debug.h"
+#include "managers/codec_manager.h"
 #include "packet_io/sfdaq_config.h"
 #include "packet_io/trough.h"
 #include "parser/config_file.h"
@@ -40,6 +43,7 @@
 #include "catch/unit_test.h"
 #endif
 
+#include "analyzer.h"
 #include "help.h"
 #include "shell.h"
 #include "snort_config.h"
@@ -611,11 +615,13 @@ public:
     void sum_stats(bool) override
     { }  // accumulate externally
 
+    ProfileStats* get_profile(unsigned, const char*&, const char*&) const override;
+
     Usage get_usage() const override
     { return GLOBAL; }
 
 private:
-    SFDAQModuleConfig *module_config;
+    SFDAQModuleConfig* module_config;
 };
 
 bool SnortModule::begin(const char* fqn, int, SnortConfig*)
@@ -1052,6 +1058,39 @@ bool SnortModule::end(const char*, int, SnortConfig* sc)
     return true;
 }
 
+ProfileStats* SnortModule::get_profile(
+    unsigned index, const char*& name, const char*& parent) const
+{
+    switch ( index )
+    {
+    case 0:
+        name = "daq";
+        parent = nullptr;
+        return &daqPerfStats;
+
+    case 1:
+        name = "decode";
+        parent = nullptr;
+        return &decodePerfStats;
+
+    case 2:
+        name = "mpse";
+        parent = nullptr;
+        return &mpsePerfStats;
+
+    case 3:
+        name = "rule_eval";
+        parent = nullptr;
+        return &rulePerfStats;
+
+    case 4:
+        name = "eventq";
+        parent = nullptr;
+        return &eventqPerfStats;
+    }
+    return nullptr;
+}
+
 //-------------------------------------------------------------------------
 // singleton
 //-------------------------------------------------------------------------
diff --git a/src/network_inspectors/appid/test/appid_http_session_test.cc b/src/network_inspectors/appid/test/appid_http_session_test.cc
index cf6b31ae2..9bbf26fa9 100644
--- a/src/network_inspectors/appid/test/appid_http_session_test.cc
+++ b/src/network_inspectors/appid/test/appid_http_session_test.cc
@@ -163,11 +163,7 @@ void Profiler::register_module(const char*, const char*, Module*)
 {
 }
 
-void Profiler::register_module(const char*, const char*, get_profile_stats_fn)
-{
-}
-
-void Profiler::consolidate_stats()
+void Profiler::consolidate_stats(uint64_t, uint64_t)
 {
 }
 
diff --git a/src/profiler/profiler.cc b/src/profiler/profiler.cc
index 7ef1bb485..1fc664654 100644
--- a/src/profiler/profiler.cc
+++ b/src/profiler/profiler.cc
@@ -41,6 +41,11 @@
 
 using namespace snort;
 
+THREAD_LOCAL ProfileStats totalPerfStats;
+THREAD_LOCAL ProfileStats otherPerfStats;
+
+THREAD_LOCAL TimeContext* ProfileContext::curr_time = nullptr;
+
 static ProfilerNodeMap s_profiler_nodes;
 
 void Profiler::register_module(Module* m)
@@ -52,8 +57,8 @@ void Profiler::register_module(Module* m)
     {
         unsigned i = 0;
         const char* n, * pn;
-        // const ProfilerStats* ps = nullptr;
         const ProfileStats* ps = nullptr;
+
         while ( (ps = m->get_profile(i++, n, pn)) )
             register_module(n, pn, m);
     }
@@ -65,14 +70,23 @@ void Profiler::register_module(const char* n, const char* pn, Module* m)
     s_profiler_nodes.register_node(n, pn, m);
 }
 
-void Profiler::register_module(const char* n, const char* pn, get_profile_stats_fn fn)
+void Profiler::consolidate_stats(uint64_t num_pkts, uint64_t usecs)
 {
-    assert(n);
-    s_profiler_nodes.register_node(n, pn, fn);
-}
+    totalPerfStats.time.checks = otherPerfStats.time.checks = num_pkts;
+
+#ifdef USE_TSC_CLOCK
+    totalPerfStats.time.elapsed = otherPerfStats.time.elapsed = clock_ticks(usecs);
+#else
+    hr_duration dt = TO_DURATION(dt, usecs);
+    totalPerfStats.time.elapsed = otherPerfStats.time.elapsed = dt;
+#endif
+
+    const ProfilerNode& root = s_profiler_nodes.get_root();
+    auto children = root.get_children();
+
+    for ( auto pn : children )
+        otherPerfStats.time.elapsed -= pn->get_stats().time.elapsed;
 
-void Profiler::consolidate_stats()
-{
     s_profiler_nodes.accumulate_nodes();
     MemoryProfiler::consolidate_fallthrough_stats();
 }
diff --git a/src/profiler/profiler.h b/src/profiler/profiler.h
index b5d0e526b..c9e049628 100644
--- a/src/profiler/profiler.h
+++ b/src/profiler/profiler.h
@@ -21,6 +21,7 @@
 #ifndef PROFILER_H
 #define PROFILER_H
 
+#include "main/thread.h"
 #include "profiler_defs.h"
 
 namespace snort
@@ -33,14 +34,14 @@ class Profiler
 public:
     static void register_module(snort::Module*);
     static void register_module(const char*, const char*, snort::Module*);
-    static void register_module(const char*, const char*, snort::get_profile_stats_fn);
 
-    // FIXIT-RC do we need to call on main thread?  we should know the answer by now.
-    // call from packet threads, just before thread termination
-    static void consolidate_stats();
+    static void consolidate_stats(uint64_t pkts = 0, uint64_t usecs = 0);
+
     static void reset_stats();
     static void show_stats();
 };
 
+extern THREAD_LOCAL snort::ProfileStats totalPerfStats;
+extern THREAD_LOCAL snort::ProfileStats otherPerfStats;
 
 #endif
diff --git a/src/profiler/profiler_defs.h b/src/profiler/profiler_defs.h
index 6e1530105..60cde46da 100644
--- a/src/profiler/profiler_defs.h
+++ b/src/profiler/profiler_defs.h
@@ -22,6 +22,7 @@
 #define PROFILER_DEFS_H
 
 #include "main/snort_types.h"
+#include "main/thread.h"
 #include "memory_defs.h"
 #include "memory_profiler_defs.h"
 #include "rule_profiler_defs.h"
@@ -71,26 +72,29 @@ inline ProfileStats& ProfileStats::operator+=(const ProfileStats& rhs)
     return *this;
 }
 
-class ProfileContext
+class SO_PUBLIC ProfileContext
 {
 public:
-    ProfileContext(ProfileStats& stats) :
-        time(stats.time), memory(stats.memory) { }
+    ProfileContext(ProfileStats& stats) : time(stats.time), memory(stats.memory)
+    {
+        prev_time = curr_time;
+        if ( prev_time )
+            prev_time->pause();
+        curr_time = &time;
+    }
+
+    ~ProfileContext()
+    {
+        if ( prev_time )
+            prev_time->resume();
+        curr_time = prev_time;
+    }
 
 private:
     TimeContext time;
     MemoryContext memory;
-};
-
-class ProfileExclude
-{
-public:
-    ProfileExclude(ProfileStats& stats) : ProfileExclude(stats.time, stats.memory) { }
-    ProfileExclude(TimeProfilerStats& time, MemoryTracker&) : time(time) { }
-
-private:
-    TimeExclude time;
-    MemoryExclude memory;
+    TimeContext* prev_time;
+    static THREAD_LOCAL TimeContext* curr_time;
 };
 
 using get_profile_stats_fn = ProfileStats* (*)(const char*);
@@ -105,16 +109,6 @@ private:
     TimeContext time;
 };
 
-class NoMemExclude
-{
-public:
-    NoMemExclude(ProfileStats& stats) : NoMemExclude(stats.time, stats.memory) { }
-    NoMemExclude(TimeProfilerStats& time, MemoryTracker&) : time(time) { }
-
-private:
-    TimeExclude time;
-};
-
 class ProfileDisabled
 {
 public:
@@ -124,19 +118,15 @@ public:
 
 #ifdef NO_PROFILER
 using Profile = ProfileDisabled;
-using NoProfile = ProfileDisabled;
 #else
 #ifdef NO_MEM_MGR
 using Profile = NoMemContext;
-using NoProfile = NoMemExclude;
 #else
 using Profile = ProfileContext;
-using NoProfile = ProfileExclude;
 #endif
 #endif
 
 // developer enable for profiling rule options
-// see also fp_eval_option
 //using RuleProfile = ProfileContext;
 using RuleProfile = ProfileDisabled;
 
diff --git a/src/profiler/profiler_nodes.cc b/src/profiler/profiler_nodes.cc
index 02a276987..07bdfbb13 100644
--- a/src/profiler/profiler_nodes.cc
+++ b/src/profiler/profiler_nodes.cc
@@ -125,9 +125,6 @@ void ProfilerNode::accumulate()
 void ProfilerNodeMap::register_node(const std::string &n, const char* pn, Module* m)
 { setup_node(get_node(n), get_node(pn ? pn : ROOT_NODE), m); }
 
-void ProfilerNodeMap::register_node(const std::string& n, const char* pn, get_profile_stats_fn fn)
-{ setup_node(get_node(n), get_node(pn ? pn : ROOT_NODE), fn); }
-
 void ProfilerNodeMap::accumulate_nodes()
 {
     static std::mutex stats_mutex;
@@ -154,17 +151,6 @@ ProfilerNode& ProfilerNodeMap::get_node(const std::string& key)
 
 #ifdef UNIT_TEST
 
-static ProfileStats* s_profiler_stats = nullptr;
-static const char* s_profiler_name = nullptr;
-
-static ProfileStats* s_profiler_stats_getter(const char* name)
-{
-    if ( s_profiler_name && std::string(name) == s_profiler_name )
-        return s_profiler_stats;
-
-    return nullptr;
-}
-
 static ProfilerNode find_node(const ProfilerNodeMap& tree, const std::string& name)
 {
     for ( const auto& it : tree )
@@ -239,18 +225,6 @@ TEST_CASE( "get profile functor for module", "[profiler]" )
     }
 }
 
-TEST_CASE( "get profile functor for function", "[profiler]" )
-{
-    ProfileStats the_stats;
-    s_profiler_stats = &the_stats;
-    s_profiler_name = "foo";
-
-    GetProfileFromFunction functor("foo", s_profiler_stats_getter);
-    CHECK( functor() == &the_stats );
-
-    s_profiler_stats = nullptr;
-}
-
 TEST_CASE( "profiler node", "[profiler]" )
 {
     ProfileStats the_stats;
@@ -274,17 +248,6 @@ TEST_CASE( "profiler node", "[profiler]" )
             node.accumulate();
             CHECK( node.get_stats() == the_stats );
         }
-
-        SECTION( "function" )
-        {
-            ProfilerNode f_node("foo");
-            s_profiler_stats = &the_stats;
-            s_profiler_name = "foo";
-            f_node.set(s_profiler_stats_getter);
-            f_node.accumulate();
-            CHECK( f_node.get_stats() == the_stats );
-            s_profiler_stats = nullptr;
-        }
     }
 
     SECTION( "accumulate" )
@@ -330,12 +293,6 @@ TEST_CASE( "profiler node map", "[profiler]" )
             CHECK( !find_node(tree, "foo").name.empty() );
         }
 
-        SECTION( "register function")
-        {
-            tree.register_node("foo", nullptr, s_profiler_stats_getter);
-            CHECK( !find_node(tree, "foo").name.empty() );
-        }
-
         SECTION( "register child -> parent" )
         {
             tree.register_node("foo", "bar", &m);
diff --git a/src/profiler/profiler_nodes.h b/src/profiler/profiler_nodes.h
index 1d1255804..727b74484 100644
--- a/src/profiler/profiler_nodes.h
+++ b/src/profiler/profiler_nodes.h
@@ -90,7 +90,6 @@ public:
     { return nodes.end(); }
 
     void register_node(const std::string&, const char*, snort::Module*);
-    void register_node(const std::string&, const char*, snort::get_profile_stats_fn);
 
     void accumulate_nodes();
     void reset_nodes();
diff --git a/src/profiler/profiler_printer.h b/src/profiler/profiler_printer.h
index c0f0e8fa0..8250bfbb2 100644
--- a/src/profiler/profiler_printer.h
+++ b/src/profiler/profiler_printer.h
@@ -151,12 +151,18 @@ public:
             // delegate to user function
             print(table, cur.view);
 
-            // don't need to print %/caller or %/total if root
+            // don't need to print %/caller if root
             if ( root == cur )
-                table << "--" << "--";
+                table << "--" << total;
 
             else
-                table << cur.view.pct_caller() << cur.view.pct_of(root.view.get_stats());
+            {
+                float value = cur.view.pct_of(root.view.get_stats());
+                table << cur.view.pct_caller() << value;
+
+                if ( layer == 1 )
+                    total += value;
+            }
         }
 
         snort::LogMessage("%s", ss.str().c_str());
@@ -166,6 +172,7 @@ private:
     const StatsTable::Field* fields;
     const PrintFn print;
     const Sorter& sort;
+    float total = 0;
 };
 
 #endif
diff --git a/src/profiler/time_profiler_defs.h b/src/profiler/time_profiler_defs.h
index 7e810ef13..455938e39 100644
--- a/src/profiler/time_profiler_defs.h
+++ b/src/profiler/time_profiler_defs.h
@@ -120,6 +120,12 @@ public:
             stats.update(sw.get());
     }
 
+    void pause()
+    { sw.stop(); }
+
+    void resume()
+    { sw.start(); }
+
     bool active() const
     { return !stopped_once; }
 
diff --git a/src/service_inspectors/dnp3/dnp3_reassembly.cc b/src/service_inspectors/dnp3/dnp3_reassembly.cc
index a7ac459f7..725e935b8 100644
--- a/src/service_inspectors/dnp3/dnp3_reassembly.cc
+++ b/src/service_inspectors/dnp3/dnp3_reassembly.cc
@@ -411,10 +411,7 @@ bool dnp3_full_reassembly(dnp3ProtoConf& config, dnp3_session_data_t* session, P
            via the get_buf() inspector api */
         if ((ret == true) && (packet->is_udp()))
         {
-            {
-                NoProfile exclude(dnp3_perf_stats);
-                DetectionEngine::detect(packet);
-            }
+            DetectionEngine::detect(packet);
 
             /* Since detection was done, reset reassembly state to avoid double alerts
                on the last PDU */
diff --git a/src/service_inspectors/ftp_telnet/ftp.cc b/src/service_inspectors/ftp_telnet/ftp.cc
index e36cabac0..c90297f1c 100644
--- a/src/service_inspectors/ftp_telnet/ftp.cc
+++ b/src/service_inspectors/ftp_telnet/ftp.cc
@@ -93,8 +93,6 @@ static int SnortFTP(
     ret = check_ftp(FTPsession, p, iInspectMode);
     if ( ret == FTPP_SUCCESS )
     {
-        NoProfile exclude(ftpPerfStats);
-
         // FIXIT-L ideally do_detection will look at the cmd & param buffers
         // or the rsp & msg buffers.  We should call it from inside check_ftp
         // each time we process a pipelined FTP command.
diff --git a/src/service_inspectors/ftp_telnet/telnet.cc b/src/service_inspectors/ftp_telnet/telnet.cc
index 027d2c739..7f49b84ad 100644
--- a/src/service_inspectors/ftp_telnet/telnet.cc
+++ b/src/service_inspectors/ftp_telnet/telnet.cc
@@ -85,15 +85,11 @@ static int SnortTelnet(TELNET_PROTO_CONF* telnet_config, TELNET_SESSION* Telnets
             FTPP_APPLY_TNC_ERASE_CMDS, false);
 
         if ( ret == FTPP_SUCCESS || ret == FTPP_NORMALIZED )
-        {
-            NoProfile exclude(telnetPerfStats);
             do_detection(p);
-        }
     }
 
     else
     {
-        NoProfile exclude(telnetPerfStats);
         do_detection(p);
     }
 
diff --git a/src/stream/tcp/tcp_reassembler.cc b/src/stream/tcp/tcp_reassembler.cc
index 07069bc57..cf156041c 100644
--- a/src/stream/tcp/tcp_reassembler.cc
+++ b/src/stream/tcp/tcp_reassembler.cc
@@ -579,8 +579,6 @@ int TcpReassembler::_flush_to_seq(
             tcpStats.rebuilt_packets++;
             tcpStats.rebuilt_bytes += flushed_bytes;
 
-            NoProfile exclude(s5TcpPerfStats);
-
             if ( !Analyzer::get_local_analyzer()->inspect_rebuilt(pdu) )
                 last_pdu = pdu;
             else
@@ -668,7 +666,6 @@ int TcpReassembler::do_zero_byte_flush(TcpReassemblerState& trs, Packet* p, uint
         trs.flush_count++;
 
         show_rebuilt_packet(trs, pdu);
-        NoProfile exclude(s5TcpPerfStats);
         Analyzer::get_local_analyzer()->inspect_rebuilt(pdu);
 
         if ( trs.tracker->splitter )
@@ -931,13 +928,9 @@ int32_t TcpReassembler::flush_pdu_ips(TcpReassemblerState& trs, uint32_t* flags,
             continue;
         }
 
-        int32_t flush_pt;
-        {
-            NoProfile exclude(s5TcpPerfStats);
-            flush_pt = paf_check(
-                trs.tracker->splitter, &trs.tracker->paf_state, p, tsn->payload(),
-                tsn->c_len, total, tsn->c_seq, flags);
-        }
+        int32_t flush_pt = paf_check(
+            trs.tracker->splitter, &trs.tracker->paf_state, p, tsn->payload(),
+            tsn->c_len, total, tsn->c_seq, flags);
 
         if (flush_pt >= 0)
         {
@@ -1010,13 +1003,10 @@ int32_t TcpReassembler::flush_pdu_ackd(TcpReassemblerState& trs, uint32_t* flags
             size = trs.tracker->r_win_base - tsn->c_seq;
 
         total += size;
-        int32_t flush_pt;
-        {
-            NoProfile exclude(s5TcpPerfStats);
-            flush_pt = paf_check(
-                trs.tracker->splitter, &trs.tracker->paf_state, p, tsn->payload(),
-                size, total, tsn->c_seq, flags);
-        }
+
+        int32_t flush_pt = paf_check(
+            trs.tracker->splitter, &trs.tracker->paf_state, p, tsn->payload(),
+            size, total, tsn->c_seq, flags);
 
         if ( flush_pt >= 0 )
         {
diff --git a/src/stream/tcp/tcp_session.cc b/src/stream/tcp/tcp_session.cc
index be2d4457b..cd7cc283f 100644
--- a/src/stream/tcp/tcp_session.cc
+++ b/src/stream/tcp/tcp_session.cc
@@ -1017,7 +1017,6 @@ bool TcpSession::validate_packet_established_session(TcpSegmentDescriptor& tsd)
 int TcpSession::process(Packet* p)
 {
     Profile profile(s5TcpPerfStats);
-
     assert(flow->ssn_server);
 
     // FIXIT-H need to do something here to handle check for need to swap trackers??
@@ -1035,6 +1034,7 @@ int TcpSession::process(Packet* p)
     if ( ( flow->get_session_flags() & SSNFLAG_RESET ) && tsd.get_tcph()->is_syn()
         && !handle_syn_on_reset_session(tsd) )
         return ACTION_NOTHING;
+
     else
     {
         if ( tsm->eval(tsd, *talker, *listener) )
diff --git a/src/utils/stats.cc b/src/utils/stats.cc
index 0bd4f972b..d4265de1a 100644
--- a/src/utils/stats.cc
+++ b/src/utils/stats.cc
@@ -134,7 +134,7 @@ void TimeStop()
     gettimeofday(&endtime, nullptr);
 }
 
-static void timing_stats()
+static void timing_stats(uint64_t& num_pkts, uint64_t& usecs)
 {
     struct timeval difftime;
     TIMERSUB(&endtime, &starttime, &difftime);
@@ -155,10 +155,12 @@ static void timing_stats()
 
     LogMessage("%25.25s: %02d:%02d:%02d\n", "runtime", hrs, mins, secs);
 
-    LogMessage("%25.25s: %lu.%lu\n", "seconds",
+    LogMessage("%25.25s: %lu.%06lu\n", "seconds",
         (unsigned long)difftime.tv_sec, (unsigned long)difftime.tv_usec);
 
-    PegCount num_pkts = ModuleManager::get_module("daq")->get_global_count("received");
+    usecs = (uint64_t)difftime.tv_sec * 1000000 + difftime.tv_usec;
+    num_pkts = (uint64_t)ModuleManager::get_module("daq")->get_global_count("received");
+
     LogMessage("%25.25s: " STDu64 "\n", "packets", num_pkts);
 
     uint64_t pps = (num_pkts / total_secs);
@@ -238,7 +240,10 @@ void DropStats()
 void PrintStatistics()
 {
     DropStats();
-    timing_stats();
+
+    PegCount pkts;
+    uint64_t usecs;
+    timing_stats(pkts, usecs);
 
     // FIXIT-L can do flag saving with RAII (much cleaner)
     int save_quiet_flag = SnortConfig::get_conf()->logging_flags & LOGGING_FLAG__QUIET;
@@ -246,7 +251,7 @@ void PrintStatistics()
     SnortConfig::get_conf()->logging_flags &= ~LOGGING_FLAG__QUIET;
 
     // once more for the main thread
-    Profiler::consolidate_stats();
+    Profiler::consolidate_stats(pkts, usecs);
     Profiler::show_stats();
 
     SnortConfig::get_conf()->logging_flags |= save_quiet_flag;