From b6a11a69dbd30742a0bc88764a9b5c26083e9ff3 Mon Sep 17 00:00:00 2001 From: Christian Kreibich Date: Thu, 16 Sep 2021 17:18:09 -0700 Subject: [PATCH] Add debug string and ODesc support to HashKey class This allows tracing of hash key buffer reservations, reads, and writes via a new debug stream, and supports printing a summary of a HashKey object via Describe(). The latter comes in handy e.g. in TableVal::Describe() (where including the hash key is now available but commented out). --- src/DebugLogger.cc | 4 ++- src/DebugLogger.h | 1 + src/Hash.cc | 63 ++++++++++++++++++++++++++++++++++++++++++++++ src/Hash.h | 6 +++++ src/Val.cc | 3 +++ 5 files changed, 76 insertions(+), 1 deletion(-) diff --git a/src/DebugLogger.cc b/src/DebugLogger.cc index f30892fd67..bb6a5b5f20 100644 --- a/src/DebugLogger.cc +++ b/src/DebugLogger.cc @@ -21,7 +21,9 @@ DebugLogger::Stream DebugLogger::streams[NUM_DBGS] = { {"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}}; + {"broker", 0, false}, {"scripts", 0, false}, {"supervisor", 0, false}, + {"hashkey", 0, false}, +}; DebugLogger::DebugLogger() { diff --git a/src/DebugLogger.h b/src/DebugLogger.h index 9ba8b8b0e9..ed8f9a7d37 100644 --- a/src/DebugLogger.h +++ b/src/DebugLogger.h @@ -54,6 +54,7 @@ enum DebugStream DBG_BROKER, // Broker communication DBG_SCRIPTS, // Script initialization DBG_SUPERVISOR, // Process supervisor + DBG_HASHKEY, // HashKey buffers NUM_DBGS // Has to be last }; diff --git a/src/Hash.cc b/src/Hash.cc index ac16e4f60f..0e2a298c1c 100644 --- a/src/Hash.cc +++ b/src/Hash.cc @@ -6,6 +6,8 @@ #include #include +#include "zeek/DebugLogger.h" +#include "zeek/Desc.h" #include "zeek/Reporter.h" #include "zeek/Val.h" // needed for const.bif #include "zeek/ZeekString.h" @@ -198,6 +200,11 @@ hash_t HashKey::Hash() const { if ( hash == 0 ) hash = HashBytes(key, size); +#ifdef DEBUG + ODesc d; + Describe(&d); + DBG_LOG(DBG_HASHKEY, "HashKey %p %s", this, d.Description()); +#endif return hash; } @@ -212,6 +219,46 @@ void* HashKey::TakeKey() return CopyKey(key, size); } +void HashKey::Describe(ODesc* d) const + { + char buf[64]; + snprintf(buf, 16, "%0" PRIx64, hash); + d->Add(buf); + d->SP(); + + if ( size > 0 ) + { + d->Add(IsAllocated() ? "(" : "["); + + for ( size_t i = 0; i < size; i++ ) + { + if ( i > 0 ) + { + d->SP(); + // Extra spacing every 8 bytes, for readability. + if ( i % 8 == 0 ) + d->SP(); + } + + // Don't display unwritten content, only say how much there is. + if ( i > write_size ) + { + d->Add("<+"); + d->Add(static_cast(size - write_size - 1)); + d->Add(" of "); + d->Add(static_cast(size)); + d->Add(" available>"); + break; + } + + snprintf(buf, 3, "%02x", key[i]); + d->Add(buf); + } + + d->Add(IsAllocated() ? ")" : "]"); + } + } + char* HashKey::CopyKey(const char* k, size_t s) const { char* k_copy = new char[s]; // s == 0 is okay, returns non-nil @@ -279,6 +326,9 @@ void HashKey::Reserve(const char* tag, size_t addl_size, size_t alignment) size_t s0 = size; size_t s1 = util::memory_size_align(size, alignment); size = s1 + addl_size; + + DBG_LOG(DBG_HASHKEY, "HashKey %p reserving %lu/%lu: %lu -> %lu -> %lu [%s]", this, addl_size, + alignment, s0, s1, size, tag); } void HashKey::Allocate() @@ -358,7 +408,9 @@ void HashKey::Write(const char* tag, double d, bool align) void HashKey::Write(const char* tag, const void* bytes, size_t n, size_t alignment) { + size_t s0 = write_size; AlignWrite(alignment); + size_t s1 = write_size; EnsureWriteSpace(n); memcpy(key + write_size, bytes, n); @@ -370,6 +422,9 @@ void HashKey::Write(const char* tag, const void* bytes, size_t n, size_t alignme void HashKey::SkipWrite(const char* tag, size_t n) { + DBG_LOG(DBG_HASHKEY, "HashKey %p skip-writing %lu: %lu -> %lu [%s]", this, n, write_size, + write_size + n, tag); + EnsureWriteSpace(n); write_size += n; } @@ -443,7 +498,9 @@ void HashKey::Read(const char* tag, double& d, bool align) const void HashKey::Read(const char* tag, void* out, size_t n, size_t alignment) const { + size_t s0 = read_size; AlignRead(alignment); + size_t s1 = read_size; EnsureReadSpace(n); // In case out is nil, make sure nothing is to be read, and only memcpy @@ -456,10 +513,16 @@ void HashKey::Read(const char* tag, void* out, size_t n, size_t alignment) const memcpy(out, key + read_size, n); read_size += n; } + + DBG_LOG(DBG_HASHKEY, "HashKey %p reading %lu/%lu: %lu -> %lu -> %lu [%s]", this, n, alignment, + s0, s1, read_size, tag); } void HashKey::SkipRead(const char* tag, size_t n) const { + DBG_LOG(DBG_HASHKEY, "HashKey %p skip-reading %lu: %lu -> %lu [%s]", this, n, read_size, + read_size + n, tag); + EnsureReadSpace(n); read_size += n; } diff --git a/src/Hash.h b/src/Hash.h index e98d0ef1fb..469cf75219 100644 --- a/src/Hash.h +++ b/src/Hash.h @@ -28,8 +28,12 @@ namespace zeek { + class String; +class ODesc; + } + namespace zeek::detail { @@ -354,6 +358,8 @@ public: const void* KeyAtRead() const { return static_cast(key + read_size); } const void* KeyEnd() const { return static_cast(key + size); } + void Describe(ODesc* d) const; + protected: char* CopyKey(const char* key, size_t size) const; diff --git a/src/Val.cc b/src/Val.cc index a127f8674c..9e9ad5fdbc 100644 --- a/src/Val.cc +++ b/src/Val.cc @@ -2395,6 +2395,9 @@ void TableVal::Describe(ODesc* d) const d_ptr->SP(); } + // The following shows the HashKey state as well: + // k->Describe(d_ptr); + // d_ptr->SP(); vl->Describe(d_ptr); if ( table_type->IsSet() )