Report what the API actually produced (changes behaviour-log output)

[doomedraven]

What this is

Fourth PR in the review series.

Warning

This one changes what the behaviour log contains. The previous three were memory safety with no intended effect on output. This PR corrects records that report values no API ever produced, which means existing CAPEv2 signatures that match on those values will see different data. The full list of observable differences is at the bottom. Please read it before merging — this is the PR that needs a decision from you, not just a review.

Are these related?

Independent of each other, same as #206–#208. Batched because they share one theme and one validation question: does the monitor report what the API actually did?

Still contrasting with the NDEBUG PR later in the series, which cannot be split: defining NDEBUG deletes the VirtualProtect call inside assert() at alloc.c:85 and the only pre_tramp overflow check at hooking_32.c:267,378 / hooking_64.c:542,826. Those must land in the same commit as the define.

The fixes

1. Output lengths consumed regardless of whether the call succeeded

Seven handlers log an output buffer using a length that is valid only on success:

Handler	File	What was logged
NtQueryVolumeInformationFile	hook_file.c	IoStatusBlock->Information
DeviceIoControl	hook_misc.c	*lpBytesReturned
RtlDecompressBuffer	hook_misc.c	*FinalUncompressedSize
NtQueryInformationToken	hook_process.c	TokenInformationLength
NtWow64ReadVirtualMemory64	hook_process.c	NumberOfBytesRead->LowPart
NtQueryKey	hook_reg_native.c	info->KeyNameLength

On failure the output buffer is untouched, so what ends up in the log is whatever was in the caller's memory. NtQueryInformationToken is the worst of these: TokenInformationLength is the caller's capacity, not the written size, so even successful calls logged trailing uninitialised bytes. It now prefers ReturnLength.

2. NCrypt* store a SECURITY_STATUS in a BOOL

BOOL ret = Old_NCryptDecrypt(...);      // SECURITY_STATUS; success is 0
if (ret && g_config.dump_crypto) { ... }
if (ret && g_config.unpacker && ...) { ... }
LOQ_bool("crypto", ...);                 // is_success = (ret != FALSE)

Three handlers do this: NCryptImportKey, NCryptDecrypt, NCryptEncrypt.

Two consequences. is_success is inverted on every one of these records. And for NCryptDecrypt, dump_crypto and unpacker only fired when the decryption had failed — so the feature that exists to dump decrypted payloads was dumping ciphertext, and only on error paths.

BCryptDecrypt has the same inverted test on an NTSTATUS.

3. BCryptDecrypt / NCryptDecrypt log the caller's capacity as the plaintext length

cbOutput is how big the buffer is. pcbResult is how much was written. The gap is logged as if it were decrypted data.

4. Format specifiers that do not match their argument

loq()'s format letters are typed. Four sites disagree with what they pass:

• SystemFunction040/041 (hook_crypto.c) — "pbII". I does va_arg(args, int *) and dereferences it under SEH. MemorySize and OptionFlags are values, so the value is reinterpreted as a pointer. Logs 0 or garbage. → i.
• EnableTraceEx (hook_trace.c) — "ssxixxxi". x does va_arg(args, LARGE_INTEGER); Level is a UCHAR promoted to int. On x86 varargs that is a 4-byte slot read as 8, which desynchronises every remaining argument in the record. → "ssxiixxi".
• lstrcpynA (hook_misc.c) — u is the wide-string specifier; lpString1 is ANSI.
• FindResourceExW (hook_misc.c) — swprintf_s(type_id, sizeof(type_id), ...) where type_id is wchar_t[8]. swprintf_s counts characters. → _countof.

5. UNICODE_STRING.Length is a byte count, wcsncmp counts characters

!wcsncmp(module_name->Buffer, L"ntdll.dll", module_name->Length)

Three sites: NtProtectVirtualMemory, VirtualProtectEx, RtlDispatchException.

wcsncmp short-circuits on the first difference, so this does not reliably over-read — but that also means the comparison only succeeds if Buffer[9] happens to be L'\0'. UNICODE_STRING is not required to be NUL-terminated. So whether ntdll-protect works at all today depends on what get_module_name leaves after the name.

Note

Two of these three sites are three lines away from the parenthesisation fix in #206 (if (module_name && a || b)). Whichever of the two merges second will need a trivial rebase.

6. Pointer/handle confusion

• CreateThread — GetExportNameByAddress((PVOID)*lpStartAddress) dereferences the thread entry point's first bytes and uses them as an address. The line directly above correctly uses (ULONG_PTR)lpStartAddress.
• RtlCreateUserThread — tid_from_thread_handle(ThreadHandle) is handed the PHANDLE out-parameter, not the handle.
• DbgUiWaitStateChange — CLIENT_ID.UniqueProcess / .UniqueThread are ids stored in HANDLE-typed fields. Passing them to pid_from_process_handle / tid_from_thread_handle returns 0 for every record, in all three branches of the switch.

7. NtQuerySystemTime returned a literal 0

Every failure was reported to the caller as success.

8. char is signed on MSVC

int utf8_length(unsigned short x);
...
ret += utf8_length(*s++);                                  // utf8.c, s is const char *
pos += utf8_do_encode(*p++, (unsigned char *)&utf8s[pos]); // log.c, p is const char *

Byte 0xE9 sign-extends to -23, converts to unsigned short as 0xFFE9, and is encoded as U+FFE9 — 3 bytes instead of 2. Every high-bit byte in an ANSI string is corrupted in the BSON log. pipe.c:44 already casts correctly.

Both the sizing pass (utf8_strlen_ascii) and the encoding pass are changed together — they must agree or the buffer arithmetic breaks.

Observable differences in the behaviour log

This is the list to check against the CAPEv2 side.

1. is_success flips for NCryptImportKey, NCryptDecrypt, NCryptEncrypt.
2. Buffer arguments previously logged after a failed call are now empty.
3. BCryptDecrypt / NCryptDecrypt Output and Length shrink from the caller's capacity to the bytes actually written.
4. DbgUiWaitStateChange ProcessId / ThreadId become non-zero.
5. EnableTraceEx arguments after Level become correct on x86.
6. lstrcpynA String changes from a mis-decoded wide string to the ANSI string.
7. Non-ASCII bytes in ANSI strings decode correctly instead of becoming U+FFxx.
8. dump_crypto and unpacker dumps now happen on successful BCryptDecrypt / NCryptDecrypt instead of failed ones. This is the change most likely to alter what gets extracted from a sample.

If any of these would break an existing signature, say which and I will split it out or gate it.

Not verified by build

No MSVC here. CI has not run on #206, #207 or #208 — gh pr checks reports no checks on any of the branches. Either fork PRs need your approval before workflows run, or .github/workflows/msbuild.yml's runs-on: windows-2019 no longer schedules since GitHub retired that image. Tell me which and I will send a prerequisite PR bumping the runner and the actions/checkout@v3 / upload-artifact@v3 steps.

Series

• Fix logic defects that silently disable checks or corrupt output #206 — logic defects
• Fix memory-safety defects in the API hook handlers #207 — memory safety, hook handlers
• Bound the fixed-size buffers in the core #208 — memory safety, core
• this — log-record correctness (the one that changes output)
• next — leaks and unchecked allocations
• then — hot-path allocations (TLS scratch buffers)
• then — hot-path algorithms (inside_hook ranges, lookup buckets, single backtrace walk)
• then — build configuration (NDEBUG + assert conversion + /O2 /Oy-, the coupled one)
• then — thread safety (hook_api lock, arena free list, breakpoint lists)

[doomedraven]

Correction to the CI note in the description above: the diagnosis there was wrong.

The MSBuild workflow is disabled_manually at the repository level, so it cannot run regardless of what the PR contains:

$ gh api repos/kevoreilly/capemon/actions/workflows
28093452  MSBuild  .github/workflows/msbuild.yml  disabled_manually

On top of that it targets the retired windows-2019 image (jobs queue for 24h and get cancelled by the timeout — visible in every PR Build Test run), and all three projects declare PlatformToolset=v141, which is not installed on windows-2022 or windows-2025.

#212 fixes the workflow file for all three. Re-enabling the workflow in Settings → Actions is the part that has to be done by hand.