nanopb: pluggable logging strategy (BSON default, protobuf opt-in) - #164
doomedraven wants to merge 2 commits into
Conversation
doomedraven
changed the title
|
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 Maybe it's worth adding a comment explaining |
54eedce to
2a735de
Compare
|
added comment in code |
ohhhh I see. Thank you! |
|
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: |
|
The Root Cause & Technical Fixes Applied:
1 g_active_serializer->append_finish_array();
1 unsigned int our_len = (unsigned int)(g_active_serializer->get_size() - compare_offset); |
0181748 to
c3925c6
Compare
Test coverage: - BSON serialization (default mode) - Protobuf serialization (opt-in mode) - Runtime serializer switching - Thread-local serializer isolation (16 threads) - Concurrent mixed serializers (8 threads, BSON + Protobuf) - NULL safety in serializer access Verifies: 1. Strategy pattern implementation 2. Thread-safe serializer switching 3. Independent per-thread serializer contexts 4. Graceful fallback on NULL 5. No interference between BSON and Protobuf modes Run with: cd tests && make test-pluggable-serialization.exe && ./test-pluggable-serialization.exe
doomedraven
left a comment
doomedraven
left a comment
There was a problem hiding this comment.
Thank you! I have successfully submitted a structural refactor to the backend code merging the protobuf state via standard TlsAlloc() memory architecture mapping instead of utilizing unallocated __declspec(thread) structures to fix the structural crash bugs observed in native DLL imports. Please review the updated branch.
…all of loq()
`g_bson` and `g_istr` were process-wide statics, so `loq()` had to hold
`g_mutex` from the moment it was entered until the record was flushed. Every
hooked API call on every thread serialized against every other one, and the
lock covered the expensive part (format parsing, string conversion, BSON
building) as well as the cheap part.
This moves the serialization state into a per-thread context and narrows the
lock to the two regions that actually touch shared state:
* region A - `logtbl_explained`, `last_api_logged`, `lastlog` reset, and the
one-time schema "explanation" record;
* region B - the flush into the output buffer and the `lastlog` dedup slot.
Everything in between (the sizing pass, the emit pass, `log_string`,
`log_wstring`, `log_buffer`, ...) now runs unlocked against thread-local
memory.
How the context is reached, and three things this deliberately does not do:
* Not `__declspec(thread)`. Static TLS is resolved by the loader. It happens
to work when capemon is injected with LoadLibrary, which is the normal
path, but `ReflectiveInjectDllViaThread()` in loader/loader/Loader.c maps
the image by hand and nothing processes the TLS directory there.
* Not the TEB `NtTib.ArbitraryUserPointer` slot. It is not free: ntdll's
loader parks the `FullDllName` pointer there across its
`NtMapViewOfSection` call so the debugger can see the module name.
capemon hooks `NtMapViewOfSection` (hooks.c:127 and three more places), so
a hook firing during a module load would read a `PWSTR` out of that slot
and write BSON state over the loader's string.
* Not a `DLL_THREAD_DETACH` destructor. capemon.c calls
`hide_module_from_peb()` during `DLL_PROCESS_ATTACH`, and
misc.c:1072-1095 unlinks the module from InLoadOrderModuleList,
InInitializationOrderModuleList, InMemoryOrderModuleList and the hash
table. The loader walks those lists to dispatch thread notifications, so
DllMain is never entered again and a TLS callback would never fire.
The context is therefore allocated once per logging thread and never
reclaimed. That is intentional: it is about 40 bytes, the BSON payload itself
is still allocated and released per call by `bson_init`/`bson_destroy`, and
freeing contexts at teardown would race with threads still inside `loq()`.
The accessor macros are plain parenthesised expressions. GNU statement
expressions (`({ ... })`) are not accepted by cl.exe.
The bounded-spin lock acquisition from ada31ca is preserved verbatim, just
factored into `loq_lock()` so both regions use the same shape: one cheap
`TryEnterCriticalSection`, then up to 100 `SwitchToThread` retries, then drop
the record rather than stall a hooked API.
TAG=agy
CONV=b3280e17-abe0-4fed-ad0b-c2e7f65da90f
…mat=1 Rebased onto kevoreilly#215, which owns the thread-local logging context. What is left here is the serializer abstraction and the nanopb backend. `log.c`'s formatting loops no longer talk to BSON directly. They go through a `log_serializer_t` vtable held in the per-thread log context, so the wire format is a runtime choice: log-format = 0 BSON (default, unchanged bytes on the wire) log-format = 1 Protocol Buffers (experimental) Existing result servers and custom agents see exactly what they saw before unless `log-format` is set, so nothing downstream has to change. Relative to the previous revision of this branch: * The context is reached through dynamic TLS instead of the TEB `NtTib.ArbitraryUserPointer` slot. That slot is not free: ntdll's loader parks the `FullDllName` pointer there across its `NtMapViewOfSection` call, and capemon hooks `NtMapViewOfSection`, so a hook firing during a module load read a `PWSTR` out of the slot and wrote serializer state over the loader's string. * `TlsThreadCleanup()` and the `DLL_THREAD_DETACH` hook in capemon.c are gone. `hide_module_from_peb()` unlinks the module from the loader lists during `DLL_PROCESS_ATTACH`, so DllMain is never entered again and that cleanup never ran. * The `lookup_t` keyed by thread id is gone with it; `TlsGetValue` answers the same question without a list walk or a thread-id lookup. * All three `g_mutex` acquisitions go through `loq_lock()`, which keeps the fast-path-then-bounded-spin shape from ada31ca instead of dropping straight into the 100-iteration spin. * Both serializer vtables use positional initializers. C99 designated initializers are not accepted by PlatformToolset v141 in C mode. * The `.github/workflows/` changes are dropped. kevoreilly#212 owns CI, and the `pr-build-test.yml` copy that was carried here targeted `windows-2019`, which no longer exists as a runner image. The protobuf backend is experimental and lossy: `schema.proto` cannot yet represent capemon's full call model, and no host-side parser consumes it. `log_init()` says so over the pipe when it is enabled. TAG=agy CONV=b3280e17-abe0-4fed-ad0b-c2e7f65da90f
d40f720 to
8222e3d
Compare
doomedraven
changed the title
|
Force-pushed. History rewritten, so the earlier review comments no longer line up with the diff — sorry about that. Summary of what moved: Split out. The thread-local logging context is now #215, on its own. This branch is stacked on it and contains only the serializer vtable and the nanopb backend. #162, which was the first two commits here, is closed. Dropped the TEB slot. Dropped Positional initializers for both serializer vtables. Dropped the Restored the delay-load settings. The previous revision's @rkoumis the Still not compiled — the |
3 participants
Stacked on #215, which owns the thread-local logging context. Merge that first; this branch contains it as its parent commit, so the diff GitHub shows here will collapse to just the serializer work once #215 lands.
TLDR
log-format = 0(default) — BSON, byte-for-byte the same output as today.log-format = 1— Protocol Buffers, experimental.log.c's formatting loops no longer call BSON directly. They go through alog_serializer_tvtable held in the per-thread log context, so the wire format becomes a runtime choice instead of a compile-time one. Nothing downstream changes unlesslog-formatis set.1. Impact on custom agents and result servers
Only if you opt in. #118 removed BSON outright in favour of nanopb, which would have broken every result server and analysis agent expecting BSON frames. Here BSON stays the default and the strategy is selected at
log_init().The schema question is real either way: BSON is self-describing, so a hook can append arbitrary keys at runtime. Protocol Buffers need a compile-time
schema.proto, so a new hooked field means recompiling and deploying capemon and the host-side decoder together.2. Defects fixed in #118's nanopb wrapper
Wide-string use-after-free.
log_wstringconverted to UTF-8 on the heap, registered the pointer with the nanopb callback, then freed it immediately. nanopb only serializes atprotobuf_finish, at the end ofloq. Reading the freed block was an access violation. Fixed with a thread-local bump-allocated scratch pad inprotobuf_context_t; strings and binary buffers are copied into it and stay alive untilprotobuf_finish.Silent payload drops. The nanopb output stream was a static 4 KB array, so any log over 4 KB — decrypted payloads, network buffers — failed
pb_encodeand vanished. Buffer is now 64 KB, in the thread-local context rather than on the stack.3. What changed in this revision
Rebased onto #215 and reduced to the serializer work. Previous revision's problems:
The TEB
NtTib.ArbitraryUserPointerslot is not free. ntdll's loader parks theFullDllNamepointer there across itsNtMapViewOfSectioncall so the debugger can see the module being mapped, and capemon hooksNtMapViewOfSection(hooks.c:127,:975,:1065,:1358):That is memory corruption on every module load. The context now comes from dynamic TLS (
TlsAlloc/TlsGetValue), in #215.TlsThreadCleanup()never ran. It was wired toDLL_THREAD_DETACH, butcapemon.c:632callshide_module_from_peb()duringDLL_PROCESS_ATTACHandmisc.c:1072-1095unlinks the module from all three loader lists. The loader walks those to dispatch thread notifications, so DllMain is never entered again. Both the hook and the function are gone; contexts are per-thread and die with the process.The
lookup_tkeyed by thread id is gone with it.TlsGetValueanswers the same question without a list walk.All three
g_mutexacquisitions go throughloq_lock(), which keeps the fast-path-then-bounded-spin shape from ada31ca rather than dropping straight into the 100-iteration spin.Both serializer vtables use positional initializers. C99 designated initializers are not accepted by PlatformToolset v141 in C mode, which is what
capemon.vcxprojtargets. The previous revision would not have compiled on VS2017 even after thefinish/append_finishfix.The
.github/workflows/changes are dropped. #212 owns CI. Thepr-build-test.ymlcopy carried on this branch targetedwindows-2019, which is no longer a runner image — every run on it queued for 24h and was cancelled without being scheduled.capemon.vcxprojnow carries only the fiveClCompileand sevenClIncludeadditions; the delay-load settings from 321a8e0 are preserved.4. Protobuf backend status
Experimental and lossy.
schema.protocannot represent capemon's call model yet — heterogeneous indexed arguments, nested%aarrays, the callerCaddress, the thread id — and no host-side parser consumes the output.log_init()emits aCRITICAL:notice over the pipe whenlog-format=1is set.announce_netlog()still announcesBSON; a real protobuf transport needs its own header and a matching reader.The per-index "explain" frame is BSON-only and is skipped in protobuf mode, so the stream is never a mix of BSON and protobuf frames. The
lastlogdedup is likewise BSON-only — it depends on byte-comparable frames with arepeatedcounter at a fixed offset.5. Testing
Not compiled and not run. No MSVC available, and the
MSBuildworkflow isdisabled_manuallyat the repo level, so nothing in this series has been through a compiler. Re-enabling needs Settings → Actions; #212 fixes the workflow file but cannot flip that switch.tests/test-pluggable-serialization.cis included but has not been built.6. Are these related?
This one genuinely is coupled: it cannot be reviewed or merged without #215, because the serializer pointer lives in the context #215 introduces. That is the opposite of the independent batch (#206–#210, #213, #214), and similar in kind to the
NDEBUGcase in #211 where the assert removals are only correct because the same PR definesNDEBUG.#162 is closed — it was the first two commits of this branch, and it could not compile (GNU statement expressions in
log.c).Known textual conflicts in
log.c, both trivial rebases: #208 (logtbl_explainedbounds — this branch also readslogtbl_explained[index]with an unbounded index) and #209 (log_string/log_wstring).Series
#206, #207, #208, #209, #210, #211, #212, #213, #214, #215, this one.