diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index ba3bd67..85db807 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -15,6 +15,8 @@ jobs: - name: Add MSBuild to PATH uses: microsoft/setup-msbuild@v2 + with: + msbuild-architecture: x64 - name: Build solution run: | @@ -42,8 +44,13 @@ jobs: Configuration: ${{ matrix.configuration }} Platform: ${{ matrix.platform }} + - name: Get short commit hash + id: commit + run: | + "short_sha=$(git rev-parse --short HEAD)" >> $env:GITHUB_OUTPUT + - name: Upload bundle uses: actions/upload-artifact@v4 with: - name: crosecbus_${{ matrix.configuration }} + name: crosecbus_${{ matrix.configuration }}_${{ steps.commit.outputs.short_sha }} path: bundle diff --git a/README.md b/README.md index 830d526..d1d61b4 100644 --- a/README.md +++ b/README.md @@ -30,3 +30,126 @@ Protocols Implemented: Note: Framework laptop does not implement GOOG0004 ACPI device. Override DSDT/SSDT with testsigning or with OpenCore to add it. (See https://github.com/coreboot/coreboot/blob/master/src/ec/google/chromeec/acpi/cros_ec.asl for an example) Tested on HP Chromebook 14b (Ryzen 3 3250C) + +## EC console log + +The EC keeps its console output in a small ring buffer, so older output gets overwritten. +The driver copies it into the Windows Event Log so it survives reboots. + +* Channel: `Framework-CrosEcBus/Console` (Event Viewer: Applications and Services Logs > Framework-CrosEcBus > Console) +* One event per console line (event ID 1). Every time the driver loads, typically once per boot, it writes a + marker with the EC firmware version (event ID 2), then the whole current EC buffer, which includes output + from before Windows started and from the end of the previous boot. +* The log is capped at 10 MB; the oldest events are overwritten. Change the size with + `wevtutil sl Framework-CrosEcBus/Console /ms:` +* Requires Windows 10 1809 or later + +Read it as text (PowerShell): + +```powershell +# Whole log, oldest first +Get-WinEvent -LogName Framework-CrosEcBus/Console -Oldest | + ForEach-Object { "{0:yyyy-MM-dd HH:mm:ss} {1}" -f $_.TimeCreated, $_.Message } + +# Current boot only +$start = Get-WinEvent -LogName Framework-CrosEcBus/Console -FilterXPath "*[System[EventID=2]]" -MaxEvents 1 +Get-WinEvent -LogName Framework-CrosEcBus/Console -Oldest | + Where-Object TimeCreated -ge $start.TimeCreated | ForEach-Object Message + +# Save to a file +Get-WinEvent -LogName Framework-CrosEcBus/Console -Oldest | ForEach-Object Message | Set-Content ec-console.txt +``` + +Or from cmd: `wevtutil qe Framework-CrosEcBus/Console /f:text` + +Settings (DWORD values under the device's hardware key, `HKLM\SYSTEM\CurrentControlSet\Enum\\Device Parameters\Settings`, +take effect after the device is restarted): + +* `ConsoleLogEnabled`: 1 (default) to log, 0 to disable +* `ConsoleLogPollMs`: how often to read the EC console, in milliseconds (default 15000, minimum 1000) + +Note: the driver and tools such as `framework_tool --console` or `ectool console` share the same EC read +position. If you use them while logging is enabled, each side will miss some of the output. +Set `ConsoleLogEnabled` to 0 if you need those tools to see everything. + +### Troubleshooting the EC console log + +The version number alone doesn't tell builds apart. To check that the installed driver is the one you built, +compare hashes: + +```powershell +$dev = Get-PnpDevice -InstanceId 'ACPI\FRMWC004*' +Get-PnpDeviceProperty -InstanceId $dev.InstanceId -KeyName DEVPKEY_Device_DriverInfPath, DEVPKEY_Device_DriverVersion, DEVPKEY_Device_DriverDate +(Get-CimInstance Win32_SystemDriver -Filter "Name='CrosEcBus'").PathName # the .sys that is running +Get-FileHash , \crosecbus.sys # should match +``` + +Check each link in the chain: + +```powershell +# 1. Provider registered (only exists if the INF's Events section was installed) +wevtutil gp Framework-CrosEcBus + +# 2. Channel exists, is enabled ("enabled: true") and has "isolation: System" +wevtutil gl Framework-CrosEcBus/Console +# If it says false: wevtutil sl Framework-CrosEcBus/Console /e:true +# If it says "isolation: Application" (installed by an older build of this branch), events from +# the driver never reach the log. Fix it without reinstalling: +# Set-ItemProperty 'HKLM:\SOFTWARE\Microsoft\Windows\CurrentVersion\WINEVT\Channels\Framework-CrosEcBus/Console' Isolation 1 +# wevtutil sl Framework-CrosEcBus/Console /e:false; wevtutil sl Framework-CrosEcBus/Console /e:true +# (The registry uses 1 for System; the INF's Isolation directive uses 2.) + +# 3. Number of events in the log ("numberOfLogRecords") +wevtutil gli Framework-CrosEcBus/Console + +# 4. The Event Log service is listening to the driver. The driver only reads the +# EC console while this is true, so the data isn't consumed when nobody records it. +# Expect "Framework-CrosEcBus" with KeywordsAny 0x8000000000000000. +logman query EventLog-System -ets | Select-String -Context 0,4 CrosEcBus + +# 5. The driver has the provider registered (a row with PID 0x00000000 = kernel) +logman query providers Framework-CrosEcBus + +# 6. Settings: ConsoleLogEnabled should be 1 +Get-ItemProperty "HKLM:\SYSTEM\CurrentControlSet\Enum\$((Get-PnpDevice -InstanceId 'ACPI\FRMWC004*').InstanceId)\Device Parameters\Settings" +``` + +The driver writes event ID 2 on the first poll after it starts, even if the EC buffer is empty. If the log +stays empty for more than one poll interval, capture the driver's WPP trace (as admin) while restarting the device: + +```powershell +logman create trace CrosEcBusWpp -p '{73e3b785-f5fb-423e-94a9-56627fea9053}' 0xFFFFFFFF 0xFF -o crosecbus.etl -ets +pnputil /restart-device "ACPI\FRMWC004\1" +# wait at least one poll interval +logman stop CrosEcBusWpp -ets +``` + +Decoding needs the TMF format strings from the matching `crosecbus.pdb` (CI uploads it next to the `.sys`). +With the WDK: `tracepdb -f crosecbus.pdb -p tmf`, then `tracefmt crosecbus.etl -p tmf -o crosecbus.txt`. +Without the WDK, pull them out of the PDB and decode with the built-in `tracerpt`: + +```powershell +New-Item -ItemType Directory -Force tmf | Out-Null +$s = [Text.Encoding]::ASCII.GetString([IO.File]::ReadAllBytes("$PWD\crosecbus.pdb")) +foreach ($r in [regex]::Matches($s, 'TMF:\x00((?:[^\x00]+\x00)+?)\x00')) { + $lines = $r.Groups[1].Value.TrimEnd([char]0).Split([char]0) + Add-Content -Path "tmf\$($lines[0].Split(' ')[0]).tmf" -Value ($lines -join "`r`n") -Encoding ASCII +} +tracerpt crosecbus.etl -o crosecbus.csv -of CSV -tp tmf -y +``` + +To tell whether the driver writes events at all, independent of the Event Log service, record the provider +in a session of your own. Starting it also makes the driver poll right away: + +```powershell +logman create trace CrosEcBusEvents -p Framework-CrosEcBus 0xFFFFFFFFFFFFFFFF 0xFF -o events.etl -ets +# wait a few seconds +logman stop CrosEcBusEvents -ets +Get-WinEvent -Path events.etl -Oldest | Select-Object TimeCreated, Id, Message +``` + +If events show up here but not in the channel, the problem is the channel configuration (see step 2). + +Messages from the console logger to look for: `EC console logging started, polling every N ms`, +`EC console logging disabled`, `Failed to start EC console logging`, `Console snapshot failed` and +`Console read failed`. diff --git a/crosecbus/consolelog.c b/crosecbus/consolelog.c new file mode 100644 index 0000000..8662e95 --- /dev/null +++ b/crosecbus/consolelog.c @@ -0,0 +1,379 @@ +#include "driver.h" +#include "comm-host.h" + +// +// Called by the mc.exe generated ETW enable callback, after the provider's +// enable bits have been updated. Must be declared before the generated header. +// +static VOID CrosEcConsoleLogEnableCallback( + _In_ LPCGUID SourceId, + _In_ ULONG ControlCode, + _In_ UCHAR Level, + _In_ ULONGLONG MatchAnyKeyword, + _In_ ULONGLONG MatchAllKeyword, + _In_opt_ PEVENT_FILTER_DESCRIPTOR FilterData, + _Inout_opt_ PVOID CallbackContext); +#define MCGEN_PRIVATE_ENABLE_CALLBACK_V2 CrosEcConsoleLogEnableCallback + +#include "crosecbusEvents.h" +#include "consolelog.tmh" + +// Declared in ntifs.h, which can't be included alongside wdm.h +NTSYSAPI NTSTATUS NTAPI ZwWaitForSingleObject( + _In_ HANDLE Handle, + _In_ BOOLEAN Alertable, + _In_opt_ PLARGE_INTEGER Timeout); + +#define CROSEC_CONSOLE_POLL_MS_DEFAULT 15000 +#define CROSEC_CONSOLE_POLL_MS_MIN 1000 +// Upper bound on read commands per poll, in case the EC keeps producing output +#define CROSEC_CONSOLE_MAX_CHUNKS 256 + +// Device to kick when a consumer (the event log service) enables the provider +static KSPIN_LOCK g_ConsoleLogDeviceLock; +static PCROSECBUS_CONTEXT g_ConsoleLogDevice; + +static EXT_CALLBACK CrosEcConsoleLogTimerCallback; +static KSTART_ROUTINE CrosEcConsoleLogThread; + +VOID CrosEcConsoleLogRegisterProvider(VOID) +{ + KeInitializeSpinLock(&g_ConsoleLogDeviceLock); + EventRegisterFramework_CrosEcBus(); +} + +VOID CrosEcConsoleLogUnregisterProvider(VOID) +{ + EventUnregisterFramework_CrosEcBus(); +} + +static VOID CrosEcConsoleLogSetDevice(_In_opt_ PCROSECBUS_CONTEXT pDevice) +{ + KIRQL oldIrql; + KeAcquireSpinLock(&g_ConsoleLogDeviceLock, &oldIrql); + g_ConsoleLogDevice = pDevice; + KeReleaseSpinLock(&g_ConsoleLogDeviceLock, oldIrql); +} + +static VOID CrosEcConsoleLogEnableCallback( + _In_ LPCGUID SourceId, + _In_ ULONG ControlCode, + _In_ UCHAR Level, + _In_ ULONGLONG MatchAnyKeyword, + _In_ ULONGLONG MatchAllKeyword, + _In_opt_ PEVENT_FILTER_DESCRIPTOR FilterData, + _Inout_opt_ PVOID CallbackContext) +{ + UNREFERENCED_PARAMETER(SourceId); + UNREFERENCED_PARAMETER(Level); + UNREFERENCED_PARAMETER(MatchAnyKeyword); + UNREFERENCED_PARAMETER(MatchAllKeyword); + UNREFERENCED_PARAMETER(FilterData); + UNREFERENCED_PARAMETER(CallbackContext); + + if (ControlCode != EVENT_CONTROL_CODE_ENABLE_PROVIDER) + return; + + // Poll right away instead of waiting for the next timer tick + KIRQL oldIrql; + KeAcquireSpinLock(&g_ConsoleLogDeviceLock, &oldIrql); + if (g_ConsoleLogDevice) { + KeSetEvent(&g_ConsoleLogDevice->ConsoleLog.PollEvent, IO_NO_INCREMENT, FALSE); + } + KeReleaseSpinLock(&g_ConsoleLogDeviceLock, oldIrql); +} + +static VOID CrosEcConsoleLogTimerCallback( + _In_ PEX_TIMER Timer, + _In_opt_ PVOID Context) +{ + UNREFERENCED_PARAMETER(Timer); + + PCROSECBUS_CONTEXT pDevice = (PCROSECBUS_CONTEXT)Context; + if (pDevice) { + KeSetEvent(&pDevice->ConsoleLog.PollEvent, IO_NO_INCREMENT, FALSE); + } +} + +// +// Like CrosEcCmdXferStatus, but returns the raw result (response size or +// negative error). Doesn't bump KernelAccessesWaiting: console logging is +// low priority and shouldn't make userspace IOCTLs return STATUS_RETRY. +// +_IRQL_requires_(PASSIVE_LEVEL) +static int CrosEcConsoleLogCommand( + _In_ PCROSECBUS_CONTEXT pDevice, + UINT16 command, + UINT8 version, + _In_reads_bytes_opt_(outsize) const void* outdata, + int outsize, + _Out_writes_bytes_opt_(insize) void* indata, + int insize) +{ + if (!ec_command_proto) { + return -EC_RES_UNAVAILABLE; + } + + WdfWaitLockAcquire(pDevice->EcLock, NULL); + int rv = ec_command_proto(command, version, outdata, outsize, indata, insize); + WdfWaitLockRelease(pDevice->EcLock); + + return rv; +} + +static VOID CrosEcConsoleLogEmitLine(_Inout_ PCROSEC_CONSOLE_LOG log) +{ + log->Line[log->LineLen] = '\0'; + EventWriteConsoleLine(NULL, log->Line); + log->LineLen = 0; +} + +// Split console output into lines. A trailing partial line is kept for later. +static VOID CrosEcConsoleLogAppend( + _Inout_ PCROSEC_CONSOLE_LOG log, + _In_reads_(len) const CHAR* data, + int len) +{ + for (int i = 0; i < len; i++) { + CHAR c = data[i]; + if (c == '\0') + break; + if (c == '\r') + continue; + if (c == '\n') { + CrosEcConsoleLogEmitLine(log); + continue; + } + + if (log->LineLen >= CROSEC_CONSOLE_LINE_MAX - 1) + CrosEcConsoleLogEmitLine(log); + log->Line[log->LineLen++] = c; + } +} + +_IRQL_requires_(PASSIVE_LEVEL) +static VOID CrosEcConsoleLogWriteStarted(_In_ PCROSECBUS_CONTEXT pDevice) +{ + struct ec_response_get_version r = { 0 }; + + int rv = CrosEcConsoleLogCommand(pDevice, EC_CMD_GET_VERSION, 0, NULL, 0, &r, sizeof(r)); + if (rv < 0) { + RtlZeroMemory(&r, sizeof(r)); + } + r.version_string_ro[sizeof(r.version_string_ro) - 1] = '\0'; + r.version_string_rw[sizeof(r.version_string_rw) - 1] = '\0'; + + EventWriteConsoleLogStarted(NULL, r.version_string_ro, r.version_string_rw); +} + +_IRQL_requires_(PASSIVE_LEVEL) +static VOID CrosEcConsoleLogPoll(_In_ PCROSECBUS_CONTEXT pDevice, BOOLEAN Final) +{ + PCROSEC_CONSOLE_LOG log = &pDevice->ConsoleLog; + + // Leave the data in the EC until someone is listening + if (!EventEnabledConsoleLine()) + return; + + int rv = CrosEcConsoleLogCommand(pDevice, EC_CMD_CONSOLE_SNAPSHOT, 0, NULL, 0, NULL, 0); + if (rv < 0) { + TraceEvents(TRACE_LEVEL_ERROR, TRACE_CONSOLELOG, "Console snapshot failed: %d\n", rv); + return; + } + + struct ec_params_console_read_v1 params = { 0 }; + if (!log->DumpedInitial) { + // First poll after load: dump the whole EC buffer, including + // output from before the OS (or before the last reboot) + CrosEcConsoleLogWriteStarted(pDevice); + params.subcmd = CONSOLE_READ_NEXT; + log->DumpedInitial = TRUE; + } + else { + params.subcmd = CONSOLE_READ_RECENT; + } + + BOOLEAN gotData = FALSE; + for (int i = 0; i < CROSEC_CONSOLE_MAX_CHUNKS; i++) { + RtlZeroMemory(log->ReadBuf, log->ReadBufSize); + rv = CrosEcConsoleLogCommand(pDevice, EC_CMD_CONSOLE_READ, 1, ¶ms, sizeof(params), + log->ReadBuf, (int)log->ReadBufSize); + if (rv < 0) { + TraceEvents(TRACE_LEVEL_ERROR, TRACE_CONSOLELOG, "Console read failed: %d\n", rv); + break; + } + // Empty string means no more output + if (rv == 0 || log->ReadBuf[0] == '\0') + break; + + gotData = TRUE; + CrosEcConsoleLogAppend(log, log->ReadBuf, min(rv, (int)log->ReadBufSize)); + } + + // Don't hold back a partial line (e.g. a prompt) for more than one poll + if (log->LineLen > 0 && (Final || !gotData)) + CrosEcConsoleLogEmitLine(log); +} + +static VOID CrosEcConsoleLogThread(_In_ PVOID Context) +{ + PCROSECBUS_CONTEXT pDevice = (PCROSECBUS_CONTEXT)Context; + PCROSEC_CONSOLE_LOG log = &pDevice->ConsoleLog; + PVOID waitObjects[2] = { &log->StopEvent, &log->PollEvent }; + + for (;;) { + NTSTATUS status = KeWaitForMultipleObjects(ARRAYSIZE(waitObjects), waitObjects, WaitAny, + Executive, KernelMode, FALSE, NULL, NULL); + BOOLEAN stop = (status == STATUS_WAIT_0); + + // Read one last time when stopping + CrosEcConsoleLogPoll(pDevice, stop); + + if (stop) + break; + } + + PsTerminateSystemThread(STATUS_SUCCESS); +} + +_IRQL_requires_(PASSIVE_LEVEL) +static ULONG CrosEcConsoleLogQuerySetting(_In_opt_ WDFKEY key, _In_ PCWSTR name, ULONG defaultValue) +{ + if (!key) + return defaultValue; + + UNICODE_STRING valueName; + RtlInitUnicodeString(&valueName, name); + + ULONG value; + if (NT_SUCCESS(WdfRegistryQueryULong(key, &valueName, &value))) + return value; + return defaultValue; +} + +_IRQL_requires_(PASSIVE_LEVEL) +NTSTATUS CrosEcConsoleLogStart(_In_ PCROSECBUS_CONTEXT pDevice) +{ + PCROSEC_CONSOLE_LOG log = &pDevice->ConsoleLog; + NTSTATUS status; + + PAGED_CODE(); + + // Settings live in HKR\Settings of the device's hardware key + WDFKEY deviceKey = NULL; + WDFKEY settingsKey = NULL; + status = WdfDeviceOpenRegistryKey(pDevice->FxDevice, PLUGPLAY_REGKEY_DEVICE, KEY_READ, + WDF_NO_OBJECT_ATTRIBUTES, &deviceKey); + if (NT_SUCCESS(status)) { + DECLARE_CONST_UNICODE_STRING(settingsName, L"Settings"); + status = WdfRegistryOpenKey(deviceKey, &settingsName, KEY_READ, WDF_NO_OBJECT_ATTRIBUTES, &settingsKey); + if (!NT_SUCCESS(status)) + settingsKey = NULL; + } + + ULONG enabled = CrosEcConsoleLogQuerySetting(settingsKey, L"ConsoleLogEnabled", 1); + log->PollMs = CrosEcConsoleLogQuerySetting(settingsKey, L"ConsoleLogPollMs", CROSEC_CONSOLE_POLL_MS_DEFAULT); + if (log->PollMs < CROSEC_CONSOLE_POLL_MS_MIN) + log->PollMs = CROSEC_CONSOLE_POLL_MS_MIN; + + if (settingsKey) + WdfRegistryClose(settingsKey); + if (deviceKey) + WdfRegistryClose(deviceKey); + + if (!enabled) { + TraceEvents(TRACE_LEVEL_INFORMATION, TRACE_CONSOLELOG, "EC console logging disabled\n"); + return STATUS_SUCCESS; + } + + if (!ec_command_proto || ec_max_insize == 0) + return STATUS_NOINTERFACE; + + log->ReadBufSize = ec_max_insize; + log->ReadBuf = (PCHAR)ExAllocatePool2(POOL_FLAG_NON_PAGED, log->ReadBufSize, CROSECBUS_POOL_TAG); + if (!log->ReadBuf) + return STATUS_NO_MEMORY; + + log->DumpedInitial = FALSE; + log->LineLen = 0; + KeInitializeEvent(&log->StopEvent, NotificationEvent, FALSE); + // Start signaled so the thread polls once right away + KeInitializeEvent(&log->PollEvent, SynchronizationEvent, TRUE); + + OBJECT_ATTRIBUTES threadAttributes; + InitializeObjectAttributes(&threadAttributes, NULL, OBJ_KERNEL_HANDLE, NULL, NULL); + + HANDLE threadHandle; + status = PsCreateSystemThread(&threadHandle, THREAD_ALL_ACCESS, &threadAttributes, NULL, NULL, + CrosEcConsoleLogThread, pDevice); + if (!NT_SUCCESS(status)) { + TraceEvents(TRACE_LEVEL_ERROR, TRACE_CONSOLELOG, "PsCreateSystemThread failed %!STATUS!", status); + ExFreePoolWithTag(log->ReadBuf, CROSECBUS_POOL_TAG); + log->ReadBuf = NULL; + return status; + } + + status = ObReferenceObjectByHandle(threadHandle, THREAD_ALL_ACCESS, *PsThreadType, KernelMode, + (PVOID*)&log->Thread, NULL); + if (!NT_SUCCESS(status)) { + // Can't track the thread; stop it and wait for it before giving up + KeSetEvent(&log->StopEvent, IO_NO_INCREMENT, FALSE); + ZwWaitForSingleObject(threadHandle, FALSE, NULL); + ZwClose(threadHandle); + log->Thread = NULL; + ExFreePoolWithTag(log->ReadBuf, CROSECBUS_POOL_TAG); + log->ReadBuf = NULL; + return status; + } + ZwClose(threadHandle); + + // No-wake timer: doesn't wake the system from Modern Standby, fires on + // the next wake instead + log->Timer = ExAllocateTimer(CrosEcConsoleLogTimerCallback, pDevice, EX_TIMER_NO_WAKE); + if (log->Timer) { + EXT_SET_PARAMETERS timerParams; + ExInitializeSetTimerParameters(&timerParams); + timerParams.NoWakeTolerance = EX_TIMER_UNLIMITED_TOLERANCE; + + LONGLONG period = (LONGLONG)log->PollMs * 10000; // 100ns units + ExSetTimer(log->Timer, -period, period, &timerParams); + } + else { + TraceEvents(TRACE_LEVEL_ERROR, TRACE_CONSOLELOG, "ExAllocateTimer failed, not polling periodically\n"); + } + + CrosEcConsoleLogSetDevice(pDevice); + + TraceEvents(TRACE_LEVEL_INFORMATION, TRACE_CONSOLELOG, "EC console logging started, polling every %u ms\n", + log->PollMs); + + return STATUS_SUCCESS; +} + +_IRQL_requires_(PASSIVE_LEVEL) +VOID CrosEcConsoleLogStop(_In_ PCROSECBUS_CONTEXT pDevice) +{ + PCROSEC_CONSOLE_LOG log = &pDevice->ConsoleLog; + + PAGED_CODE(); + + CrosEcConsoleLogSetDevice(NULL); + + if (log->Timer) { + // Cancel and wait for a running callback to finish + ExDeleteTimer(log->Timer, TRUE, TRUE, NULL); + log->Timer = NULL; + } + + if (log->Thread) { + KeSetEvent(&log->StopEvent, IO_NO_INCREMENT, FALSE); + KeWaitForSingleObject(log->Thread, Executive, KernelMode, FALSE, NULL); + ObDereferenceObject(log->Thread); + log->Thread = NULL; + } + + if (log->ReadBuf) { + ExFreePoolWithTag(log->ReadBuf, CROSECBUS_POOL_TAG); + log->ReadBuf = NULL; + } +} diff --git a/crosecbus/consolelog.h b/crosecbus/consolelog.h new file mode 100644 index 0000000..fbd00a3 --- /dev/null +++ b/crosecbus/consolelog.h @@ -0,0 +1,35 @@ +#pragma once + +// +// EC console logger: periodically reads the EC console ring buffer and writes +// each line as an event to the Framework-CrosEcBus/Console event log channel. +// + +#define CROSEC_CONSOLE_LINE_MAX 512 + +typedef struct _CROSEC_CONSOLE_LOG { + PETHREAD Thread; + KEVENT StopEvent; + KEVENT PollEvent; + PEX_TIMER Timer; + ULONG PollMs; + + BOOLEAN DumpedInitial; + + PCHAR ReadBuf; + ULONG ReadBufSize; + + CHAR Line[CROSEC_CONSOLE_LINE_MAX]; + ULONG LineLen; +} CROSEC_CONSOLE_LOG, *PCROSEC_CONSOLE_LOG; + +struct _CROSECBUS_CONTEXT; + +VOID CrosEcConsoleLogRegisterProvider(VOID); +VOID CrosEcConsoleLogUnregisterProvider(VOID); + +_IRQL_requires_(PASSIVE_LEVEL) +NTSTATUS CrosEcConsoleLogStart(_In_ struct _CROSECBUS_CONTEXT* pDevice); + +_IRQL_requires_(PASSIVE_LEVEL) +VOID CrosEcConsoleLogStop(_In_ struct _CROSECBUS_CONTEXT* pDevice); diff --git a/crosecbus/crosecbus.c b/crosecbus/crosecbus.c index b203836..e999704 100644 --- a/crosecbus/crosecbus.c +++ b/crosecbus/crosecbus.c @@ -35,7 +35,10 @@ __in PUNICODE_STRING RegistryPath WPP_INIT_TRACING(DriverObject, RegistryPath); TraceEvents(TRACE_LEVEL_INFORMATION, TRACE_CROSECBUS, "DriverEntry: Entry"); + CrosEcConsoleLogRegisterProvider(); + WDF_DRIVER_CONFIG_INIT(&config, CrosEcBusEvtDeviceAdd); + config.EvtDriverUnload = CrosEcBusDriverUnload; WDF_OBJECT_ATTRIBUTES_INIT(&attributes); @@ -53,12 +56,22 @@ __in PUNICODE_STRING RegistryPath if (!NT_SUCCESS(status)) { TraceEvents(TRACE_LEVEL_ERROR, TRACE_CROSECBUS, "WdfDriverCreate failed %!STATUS!", status); + CrosEcConsoleLogUnregisterProvider(); WPP_CLEANUP(DriverObject); } return status; } +VOID +CrosEcBusDriverUnload( + _In_ WDFDRIVER Driver +) +{ + CrosEcConsoleLogUnregisterProvider(); + WPP_CLEANUP(WdfDriverWdmGetDriverObject(Driver)); +} + static NTSTATUS CrosEcCmdXferStatus( IN PCROSECBUS_CONTEXT pDevice, OUT PCROSEC_COMMAND Msg @@ -286,6 +299,12 @@ Status // TraceEvents(TRACE_LEVEL_INFORMATION, TRACE_CROSECBUS, "Warning: Failed to get ACPI device\n"); // } + // Failure to start console logging is not fatal + NTSTATUS consoleLogStatus = CrosEcConsoleLogStart(pDevice); + if (!NT_SUCCESS(consoleLogStatus)) { + TraceEvents(TRACE_LEVEL_ERROR, TRACE_CROSECBUS, "Failed to start EC console logging %!STATUS!", consoleLogStatus); + } + TraceEvents(TRACE_LEVEL_INFORMATION, TRACE_CROSECBUS, "OnPrepareHardware finished %!STATUS!", status); return status; @@ -349,6 +368,9 @@ Status PCROSECBUS_CONTEXT pDevice = GetDeviceContext(FxDevice); UNREFERENCED_PARAMETER(FxResourcesTranslated); + // Stop (and do a final read) before the EC lock goes away + CrosEcConsoleLogStop(pDevice); + if (pDevice->S0ixNotifyAcpiInterface.Context) { //Used for S0ix notifications pDevice->S0ixNotifyAcpiInterface.UnregisterForDeviceNotifications(pDevice->S0ixNotifyAcpiInterface.Context); } diff --git a/crosecbus/crosecbus.inf b/crosecbus/crosecbus.inf index e16de6b..5691dec 100644 --- a/crosecbus/crosecbus.inf +++ b/crosecbus/crosecbus.inf @@ -16,7 +16,7 @@ Signature = "$WINDOWS NT$" Class = System ClassGuid = {4d36e97d-e325-11ce-bfc1-08002be10318} Provider = Framework Computer -DriverVer = 10/24/2024,0.0.8.0 +DriverVer = 10/24/2024,0.0.9.0 CatalogFile = crosecbus.cat PnpLockdown = 1 @@ -36,9 +36,9 @@ crosecbus.sys = 1,, ;***************************************** [Manufacturer] -%StdMfg%=Standard,NT$ARCH$.10.0...16299 +%StdMfg%=Standard,NT$ARCH$.10.0...17763 -[Standard.NT$ARCH$.10.0...16299] +[Standard.NT$ARCH$.10.0...17763] %CrosEcBus.DeviceDesc%=CrosEcBus_Device, ACPI\FRMWC004 [CrosEcBus_Device.NT] @@ -53,12 +53,35 @@ crosecbus.sys [CrosEcBus_AddReg] ; Set to 1 to connect the first interrupt resource found, 0 to leave disconnected HKR,Settings,"ConnectInterrupt",0x00010001,0 +; EC console log to the Framework-CrosEcBus/Console event log channel +HKR,Settings,"ConsoleLogEnabled",0x00010001,1 +HKR,Settings,"ConsoleLogPollMs",0x00010001,15000 HKR,,Security,,"D:P(A;;GA;;;SY)(A;;GA;;;BA)(A;;GA;;;UD)" ;System, Admin, and UMDF drivers ;-------------- Service installation [CrosEcBus_Device.NT.Services] AddService = CrosEcBus,%SPSVCINST_ASSOCSERVICE%, CrosEcBus_Service_Inst +; -------------- Event log provider and channel +; Must match the provider GUID, channel name and channel value in crosecbus.man +[CrosEcBus_Device.NT.Events] +AddEventProvider = {265d94cd-c9ff-4cac-8f4f-28f037e32f68}, CrosEcBus_EventProvider + +[CrosEcBus_EventProvider] +ProviderName = Framework-CrosEcBus +ResourceFile = %13%\crosecbus.sys +MessageFile = %13%\crosecbus.sys +AddChannel = Framework-CrosEcBus/Console, 0x2, CrosEcBus_ConsoleChannel ; Operational + +[CrosEcBus_ConsoleChannel] +; Kernel-mode providers need System isolation (EventLog-System session). +; With the default Application isolation no events reach the log. +Isolation = 2 ; System +Enabled = 1 +Value = 16 +LoggingMaxSize = 10485760 ; 10 MB +LoggingRetention = 1 ; Circular, overwrite oldest events + ; -------------- WDF install section [CrosEcBus_Device.NT.Wdf] KmdfService = CrosEcBus, CrosEcBus_wdfsect diff --git a/crosecbus/crosecbus.man b/crosecbus/crosecbus.man new file mode 100644 index 0000000..3b873da --- /dev/null +++ b/crosecbus/crosecbus.man @@ -0,0 +1,95 @@ + + + + + + + + + + + + + + + + + + + + + + + + + + + + + diff --git a/crosecbus/crosecbus.rc b/crosecbus/crosecbus.rc index bc5b690..a5c3e09 100644 --- a/crosecbus/crosecbus.rc +++ b/crosecbus/crosecbus.rc @@ -21,10 +21,10 @@ Abstract: #define VER_LEGALCOPYRIGHT_YEARS "2023-2025" #define VER_LEGALCOPYRIGHT_STR "Copyright (C) " VER_LEGALCOPYRIGHT_YEARS " CoolStar, Framework Computer Inc." -#define VER_FILEVERSION 0,0,8,0 -#define VER_PRODUCTVERSION_STR "0.0.8.0" -#define VER_PRODUCTVERSION 0,0,8,0 -#define LVER_PRODUCTVERSION_STR L"0.0.8.0" +#define VER_FILEVERSION 0,0,9,0 +#define VER_PRODUCTVERSION_STR "0.0.9.0" +#define VER_PRODUCTVERSION 0,0,9,0 +#define LVER_PRODUCTVERSION_STR L"0.0.9.0" #define VER_FILEFLAGSMASK (VS_FF_DEBUG | VS_FF_PRERELEASE) #ifdef DEBUG @@ -39,3 +39,6 @@ Abstract: #define VER_PRODUCTNAME_STR "Framework EC" #include "common.ver" + +// Event manifest resources, generated by mc.exe from crosecbus.man +#include "crosecbusEvents.rc" diff --git a/crosecbus/crosecbus.vcxproj b/crosecbus/crosecbus.vcxproj index 32f8880..df0ed6f 100644 --- a/crosecbus/crosecbus.vcxproj +++ b/crosecbus/crosecbus.vcxproj @@ -87,8 +87,11 @@ true true + + %(AdditionalIncludeDirectories);$(IntDir) + - 0.0.8.0 + 0.0.9.0 SHA256 @@ -102,8 +105,11 @@ true true + + %(AdditionalIncludeDirectories);$(IntDir) + - 0.0.8.0 + 0.0.9.0 SHA256 @@ -117,8 +123,11 @@ true true + + %(AdditionalIncludeDirectories);$(IntDir) + - 0.0.8.0 + 0.0.9.0 SHA256 @@ -132,8 +141,11 @@ true true + + %(AdditionalIncludeDirectories);$(IntDir) + - 0.0.8.0 + 0.0.9.0 SHA256 @@ -148,6 +160,7 @@ + @@ -158,12 +171,25 @@ + + + + true + .\$(IntDir) + true + "$(SDK_INC_PATH)\winmeta.xml" + .\$(IntDir) + true + crosecbusEvents + true + + diff --git a/crosecbus/driver.h b/crosecbus/driver.h index e479dbe..f441509 100644 --- a/crosecbus/driver.h +++ b/crosecbus/driver.h @@ -20,6 +20,7 @@ #include #include "trace.h" +#include "consolelog.h" // // String definitions @@ -131,6 +132,8 @@ typedef struct _CROSECBUS_CONTEXT BOOLEAN isInS0ix; BOOLEAN hostSleepV1; + CROSEC_CONSOLE_LOG ConsoleLog; + } CROSECBUS_CONTEXT, *PCROSECBUS_CONTEXT; WDF_DECLARE_CONTEXT_TYPE_WITH_NAME(CROSECBUS_CONTEXT, GetDeviceContext) diff --git a/crosecbus/ec_commands.h b/crosecbus/ec_commands.h index 03f09c0..32ff1ce 100644 --- a/crosecbus/ec_commands.h +++ b/crosecbus/ec_commands.h @@ -2243,4 +2243,37 @@ enum ec_host_event_mask_type { #define EC_CMD_HOST_EVENT 0x00A4 +/*****************************************************************************/ +/* EC console commands */ + +/* Save a snapshot of the EC console output buffer (no params, no response) */ +#define EC_CMD_CONSOLE_SNAPSHOT 0x0097 + +/* + * Read data from the saved snapshot. If the subcmd parameter is + * CONSOLE_READ_NEXT, this will return data starting from the beginning of + * the latest snapshot. If it is CONSOLE_READ_RECENT, it will start from the + * end of the previous snapshot. + * + * The params are only looked at in version >= 1 of this command. Prior + * versions will just default to CONSOLE_READ_NEXT behavior. + * + * Response is null-terminated string. Empty string, if there is no more + * remaining output. + */ +#define EC_CMD_CONSOLE_READ 0x0098 + +enum ec_console_read_subcmd { + CONSOLE_READ_NEXT = 0, + CONSOLE_READ_RECENT +}; + +#include + +struct ec_params_console_read_v1 { + UINT8 subcmd; /* enum ec_console_read_subcmd */ +}; + +#include + #endif /* __CROS_EC_COMMANDS_H */ diff --git a/crosecbus/trace.h b/crosecbus/trace.h index 89643a7..8dfb7b1 100644 --- a/crosecbus/trace.h +++ b/crosecbus/trace.h @@ -18,6 +18,7 @@ WPP_DEFINE_BIT(TRACE_COMM_LPC) \ WPP_DEFINE_BIT(TRACE_COMM_MEC_LPC) \ WPP_DEFINE_BIT(TRACE_USERSPACEQUEUE) \ + WPP_DEFINE_BIT(TRACE_CONSOLELOG) \ ) #define WPP_FLAG_LEVEL_LOGGER(flag, level) WPP_LEVEL_LOGGER(flag)