nanopb: Pluggable Logging Strategy Pattern (BSON & Protobuf)

[doomedraven]

Here is the report, followed by how we solved the UAF crashes and backward-compatibility challenges.

TLDR

• If log-format = 0 (BSON), the trace hooks will automatically log as standard BSON.
• If log-format = 1 (Protobuf), the trace hooks will automatically log as high-performance, safe Protocol Buffers!

---

1. Impact Assessment on Custom Agents & Result Servers

"Could these changes potentially have impact on anyone using a custom agent or custom result server?"

YES! ABSOLUTELY.

• The Breaking Risk: PR 118's raw implementation completely removed and deleted BSON serialization in favor of Protocol Buffers (nanopb). Because the wire/socket stream bytes are entirely different, any custom result server or analysis agent expecting BSON frames would receive Protocol Buffer structures and fail to decode them, breaking the entire analysis pipeline.
• Dynamic vs. Strict Schemas: BSON is self-describing and dynamic—hooks can append any custom keys of any type on-the-fly. Protocol Buffers require pre-defined compile-time schemas (schema.proto). If a developer added a new hooked field, they would have to recompile and synchronized-deploy both capemon and the backend decoders.

---

2. Our Pristine Architecture: Pluggable Logging Strategies

To preserve 100% backward compatibility and allow users to dynamically opt-into high-performance Protocol Buffers without breaking any legacy custom agents, we implemented a C-style Strategy Pattern (log_serializer_t interface):

1. Unified Serializer Interface (log_serializer_h):
   Decoupled log.c's core formatting loops from the binary wire format. The leaf functions (like log_string, log_wstring, log_buffer) now delegate directly to the thread-local active strategy vtable:

   __declspec(thread) log_serializer_t *g_active_serializer = &g_bson_serializer;

2. BSON Enabled by Default (No Breaking Changes):
   By default, the active strategy is initialized to the original BSON engine (&g_bson_serializer). This ensures that capemon behaves exactly as it did historically for any existing custom pipelines out-of-the-box!
3. Dynamic Runtime Selection:
   Added a new configuration setting in config.h and parsed inside config.c: "log-format".
   • log-format = 0 (BSON - Default).
   • log-format = 1 (Protocol Buffers).
     During log_init, if the format is set to 1, g_active_serializer is instantly pivoted to &g_protobuf_serializer!

---

3. Critical Defect & Lifespan Bug Resolutions inside PR 118

During our code review of PR 118, we identified and surgically resolved two fatal memory defects inside the nanopb wrapper:

• Fixed the Wide-String Use-After-Free (UAF) Crash:
  • The Bug: In PR 118, log_wstring converted wide characters to UTF-8 on the heap (utf8s), registered the pointer in the nanopb callback, and immediately called free(utf8s). However, nanopb only serializes when protobuf_finish runs at the very end of loq. Reading from the freed memory caused an instant Access Violation crash.
  • The Solution: Added a thread-local, zero-allocation scratch-pad bump allocator (string_scratch) inside protobuf_context_t. Strings and raw binary buffers are copied safely into the scratch-pad during logging, keeping them perfectly alive until protobuf_finish runs! It has zero heap latency and zero leaks.
• Prevented Silent Payload Drops (Buffer Enlargement):
  • The Bug: PR 118 restricted the nanopb output stream to a tiny static 4KB array. Any large binary log (e.g. decrypted payloads or network buffers) exceeding 4KB would fail pb_encode and be silently dropped from the logs.
  • The Solution: Enlarged the serialization buffer to 64KB and placed it inside a thread-local static context structure, avoiding any stack-overflow risk while fully supporting large payloads safely.

---

[rkoumis]

This is great, thank you! Much appreciated.

I'm probably missing something super obvious, but I can't figure it out. I noticed that in the definition of loq() there are still plenty of calls to the bson serializing functions, not the active_serializer functions. Just in the bit guarded by if (logtbl_explained[index] == 0) {

Maybe it's worth adding a comment explaining logtbl_explained - ?

[doomedraven]

added comment in code

/* logtbl_explained Optimization (BSON Specific):
   The very first time a hooked API index is logged, capemon outputs a schema "explanation"
   to help the legacy BSON log-server parse dynamic argument layouts, then sets logtbl_explained[index] = 1.
   Subsequent calls only log argument values, drastically reducing redundant traffic.
   Note: This block calls BSON-serialization functions directly because modern Protocol Buffers (nanopb)
   utilizes a statically compiled message schema (schema.proto) and has no need for runtime dynamic schemas.
*/
if (logtbl_explained[index] == 0) {

[rkoumis]

added comment in code

/* logtbl_explained Optimization (BSON Specific): */

ohhhh I see. Thank you!

[kevoreilly]

very nice ❤️

I'm low on time today to look into this, so will pick up again tomorrow, but just to note it's currently not compiling:

1>d:\work\cape\capemon\capemon26\log.c(1162): error C2039: 'finish': is not a member of '_log_serializer_t'
1>d:\work\cape\capemon\capemon26\log_serializer.h(12): note: see declaration of '_log_serializer_t'
1>d:\work\cape\capemon\capemon26\log.c(1202): warning C4267: '=': conversion from 'size_t' to 'unsigned int', possible loss of data
1>d:\work\cape\capemon\capemon26\log.c(1187): warning C4267: 'initializing': conversion from 'size_t' to 'unsigned int', possible loss of data

[doomedraven]

The Root Cause & Technical Fixes Applied:

1. Resolved Error C2039: 'finish' is not a member of '_log_serializer_t' (Line 1162)

• The Bug: The code inside loq() was calling g_active_serializer->finish(). However, the struct interface in log_serializer.h defines the member as append_finish.
• The Fix: corrected the call to call the proper interface member:

1 g_active_serializer->append_finish_array();
2 g_active_serializer->append_finish(); // <-- Corrected member call

2. Resolved Warnings C4267: '=': conversion from 'size_t' to 'unsigned int', possible loss of data (Lines 1187 & 1202)

• The Bug: Under 64-bit Windows, size_t is 64-bit (unsigned __int64), while unsigned int is 32-bit. In loq(), our_len and lastlog.len are 32-bit unsigned integers, and assigning the result of g_active_serializer->get_size() to them triggered a compilation warning.
• The Fix: Added clean, explicit casts to prevent 64-bit pointer truncation warnings:

1 unsigned int our_len = (unsigned int)(g_active_serializer->get_size() - compare_offset);
2 // ...
3 lastlog.len = (unsigned int)g_active_serializer->get_size();

---