diff --git a/Makefile b/Makefile index 8b09cdb..6f65362 100644 --- a/Makefile +++ b/Makefile @@ -18,7 +18,7 @@ VERSION := $(shell cat VERSION) NAME := control4free ELF := build/$(NAME).elf OBJDIR := build/payload -SOURCES := src/main.c src/log.c src/vda.c src/web.c src/net.c +SOURCES := src/main.c src/log.c src/vda.c src/klog_line.c src/web.c src/net.c OBJECTS := $(SOURCES:src/%.c=$(OBJDIR)/%.o) $(OBJDIR)/client.o CFLAGS += -std=gnu11 -Wall -Wextra -Wpointer-arith -g -O2 diff --git a/SECURITY.md b/SECURITY.md new file mode 100644 index 0000000..89c6f77 --- /dev/null +++ b/SECURITY.md @@ -0,0 +1,74 @@ +# Security + +## Reporting a problem + +Report anything you find through GitHub's private vulnerability reporting on this +repository (**Security → Report a vulnerability**), not in a public issue. + +## What Control4Free assumes + +Control4Free turns a phone or PC into a controller for your PS4 over your own +network. There is no pairing, no password and no encryption, by design: a party +guest should be able to open a link and play. + +**So treat the console's port 4264 the way you treat your TV remote.** Anyone who +can reach your PS4 over the network can: + +- take a free controller and play, on the home screen, at sign-in and in games; +- press PS and Share, which reach the system menus; +- stop Control4Free, which disconnects every controller. + +They cannot sign in as one of your users without someone at the TV choosing that +user on the PS4's own screen, and they cannot see your screen. + +Run Control4Free on a network you trust. Do not forward port 4264 through your +router, and do not run it on open or guest Wi-Fi. When you are finished, stop it +from the launcher app or the controller page, or turn the console off. + +## What is defended + +Being open to your network is not the same as being open to the internet. These +are the limits the code does enforce. + +**A website you visit cannot drive your console.** A page on the internet can send +requests to your PS4, so the service refuses the ones that matter: + +- A WebSocket handshake carrying an `Origin` that is not the page's own address is + refused with 403. A site's script cannot open the control socket. +- The page is only served for a literal IP address or `localhost` in the `Host` + header, so a domain name that resolves to your console (DNS rebinding) gets 403. +- The launcher's own `GET /api/status` and `POST /api/stop` require the header + `X-Control4Free-Launcher: 1` and refuse any request that carries an `Origin` at + all. A browser only sends a custom header cross-origin after a CORS preflight, + which this service never answers. +- The page is served with a Content-Security-Policy that keeps it to its own + resources. + +**One controller has one owner.** A slot is claimed by one WebSocket connection. +Another device asking for the same slot is refused (409), and input never claims a +slot implicitly. A client that leaves has its buttons released at once. + +**Input is validated.** Button masks, axes, trigger values and touch coordinates +are range-checked before they reach the virtual device, and a request that is not +well-formed JSON of the expected shape is rejected rather than guessed at. + +**The service cannot be made to grow.** At most 4 controllers and 8 connections +exist at a time, each connection has fixed-size buffers, and a request body larger +than those buffers is refused. + +**Stopping from the page is deliberate.** The page's Stop is refused while another +device owns a controller, so one player cannot cut another off by accident. The +launcher's `POST /api/stop` has no such guard, because the app on the console is +how you stop a service nobody is using any more. Its source address is not +checked: the app's own sandbox does not reliably appear as `127.0.0.1`, and anyone +on the network can already stop Control4Free from the page. + +**The host process is put back.** GoldHEN runs the payload inside an existing +system process. Control4Free raises that process's credentials for the virtual +device calls and restores exactly what it saved before it exits, and it refuses to +touch them at all if it could not save them first. + +## Versions + +Fixes go into the next release; there is no separate maintenance branch. Use the +most recent release. diff --git a/client/index.html b/client/index.html index c75f509..67856e4 100644 --- a/client/index.html +++ b/client/index.html @@ -1440,9 +1440,22 @@ call('claim', pads).then(applyStatus).catch(e => { lastClaim = ''; toast(e.message || 'Could not connect the controller'); - closePad(); - for (const src of gamepadSources.values()) src.pad = -1; - renderGamepads(); + call('status', []).then(s => { + applyStatus(s); + let dropped = false; + const taken = pad => pad >= 0 && status[pad].known && !status[pad].mine && status[pad].open; + if (taken(primaryPad)) { closePad(); dropped = true; } + for (const src of gamepadSources.values()) if (taken(src.pad)) { src.pad = -1; dropped = true; } + renderGamepads(); + // Only ask again when something was actually given up, so a refusal + // for any other reason cannot turn into a loop. + if (dropped && claimedPads().length) sendClaim(true); + }).catch(() => { + // No answer at all: assume nothing is ours. + closePad(); + for (const src of gamepadSources.values()) src.pad = -1; + renderGamepads(); + }); }); } @@ -2117,7 +2130,12 @@ function pollGamepads(t) { if (!gamepadsAvailable) return; let list; - try { list = navigator.getGamepads(); } catch (e) { return; } + try { + list = navigator.getGamepads(); + } catch (e) { + for (const src of gamepadSources.values()) Object.assign(src, blankSource(src.pad)); + return; + } const seen = new Set(); for (const gp of list) { if (!gp || !gp.connected) continue; @@ -2240,6 +2258,7 @@ } function padMeta(s) { + if (s.state === 'connecting') return 'Connecting to the PS4'; if (s.state === 'select') return 'Choose a user on the PS4'; if (s.state === 'ready') return 'Signed in on the PS4'; if (s.state === 'paused') return 'Input paused'; @@ -2275,6 +2294,7 @@ tile.appendChild(body); const states = el('span', 'tile-state'); if (state === 'ready') states.appendChild(stateItem('live', 'Connected')); + else if (state === 'connecting') states.appendChild(stateItem('wait', 'Connecting')); else if (state === 'select') states.appendChild(stateItem('wait', 'Choose user on TV')); else if (state === 'paused') states.appendChild(stateItem('wait', 'Paused')); else if (state === 'error') states.appendChild(stateItem('', 'Error')); @@ -2353,6 +2373,7 @@ const state = padState(s); const extra = conn.state !== 'open' ? $('#connText').textContent : state === 'ready' ? 'Signed in on the PS4' + : state === 'connecting' ? 'Connecting to the PS4' : state === 'select' ? 'Choose your user on TV with D-pad and Cross' : state === 'noslot' ? 'No free player slot' : state === 'disabled' ? 'Turned off' : ''; diff --git a/docker/Dockerfile.launcher b/docker/Dockerfile.launcher index bf95cea..8baad40 100644 --- a/docker/Dockerfile.launcher +++ b/docker/Dockerfile.launcher @@ -5,6 +5,9 @@ FROM ubuntu:20.04 AS pkgcompat RUN apt-get update && apt-get install -y --no-install-recommends libssl1.1 \ && rm -rf /var/lib/apt/lists/* FROM control4free-build:latest +# Node runs the page's own functions in the frontend test. +RUN apt-get update && apt-get install -y --no-install-recommends nodejs \ + && rm -rf /var/lib/apt/lists/* COPY --from=openorbis /opt/OpenOrbis/PS4Toolchain /opt/OpenOrbis/PS4Toolchain # The SDK's self-contained LibOrbisPkg runtime expects OpenSSL 1.1. COPY --from=pkgcompat /usr/lib/x86_64-linux-gnu/libssl.so.1.1 /usr/lib/x86_64-linux-gnu/ diff --git a/include/c4f_vda.h b/include/c4f_vda.h index 1745850..cd5bc9b 100644 --- a/include/c4f_vda.h +++ b/include/c4f_vda.h @@ -2,6 +2,9 @@ * * One C4fVirtualPad is one virtual DualShock 4 as the system sees it. The call * order and its reasons came from the spike (tag spike-final, dev notes). + * + * No function here blocks or waits, so the service can keep answering everyone + * else while a controller is being created. */ #ifndef C4F_VDA_H @@ -28,13 +31,32 @@ int c4fMbusInit(void); * NOT_INITIALIZED the other way round). Returns 0 if scePadInit succeeded. */ int c4fPadInit(void); -/* AddDevice for `vdaUser`, then capture the DeviceId from klogFd (a verified - * /dev/klog reader). Returns 0 and fills *out on success. */ -int c4fVirtualPadAddAs(C4fVirtualPad *out, int32_t userId, int32_t vdaUser, int klogFd); +/* ---- the kernel log ---- + * /dev/klog has a single reader. GoldHEN's klog server opens it only while it + * has a client and serves one client at a time; after a client leaves it can + * go minutes without serving the next one (console, 2026-10-04). So the + * service reads the device itself, only while a controller signs in, and it + * owns the reader: these are the pieces it needs to make sense of a line. */ -/* Keep existing pads reporting during the bounded klog waits for a new pad. - * The callback must not read klog, create devices, or run the network loop. */ -void c4fVdaSetWaitCallback(void (*callback)(void *), void *context); +/* /dev/klog, non-blocking; -1 if another reader has it or it cannot be opened. */ +int c4fKlogOpenDevice(void); +/* Writes one line into the kernel log, with no [c4f] prefix, so the reader can + * prove to itself that it really receives what the kernel logs. */ +void c4fKlogMark(const char *marker); +/* 1 if this is the login manager's "a virtual pad was added" event. */ +int c4fKlogIsVirtualAdd(const char *line); +/* The DeviceId named in this line, or 0. */ +uint64_t c4fKlogDeviceId(const char *line); + +/* ---- devices ---- */ + +/* AddDevice for `vdaUser`. The handle is not known yet: it is the DeviceId the + * kernel logs a moment later. Returns AddDevice's own value, which is non-zero + * even when the device is created, so the caller waits for the log either way. */ +int32_t c4fVirtualPadAdd(int32_t vdaUser); + +/* Completes a pad from the DeviceId that came out of the log. */ +void c4fVirtualPadAdopt(C4fVirtualPad *out, int32_t userId, int32_t vdaUser, uint64_t deviceId); /* A neutral sample: sticks centred, identity quaternion, connected. */ void c4fPadDataNeutral(ScePadData *data); @@ -45,20 +67,4 @@ int32_t c4fVirtualPadInsert(const C4fVirtualPad *pad, const ScePadData *data); /* DeleteDevice, if we own the handle. */ void c4fVirtualPadRemove(C4fVirtualPad *pad); -#define C4F_FRAME_MS 33 - -/* ---- klog capture ---- - * /dev/klog has a single reader. GoldHEN's klog server opens it only while it - * has a client and serves one client at a time; after a client leaves it can - * go minutes without serving the next one (console, 2026-10-04). So the - * service reads the device itself, only while a controller signs in. */ - -/* /dev/klog, verified by a fresh marker; -1 if busy or silent. */ -int c4fKlogOpenDevice(void); -void c4fKlogDrain(int fd); -/* Writes a marker to klog and reads it back. 0 = the capture path works. */ -int c4fKlogSelfTest(int fd); -/* Scans for the MBus "device added" line and returns its DeviceId. */ -int c4fKlogFindDeviceId(int fd, uint64_t *outDeviceId, int timeoutMs); - #endif /* C4F_VDA_H */ diff --git a/src/klog_line.c b/src/klog_line.c new file mode 100644 index 0000000..409a743 --- /dev/null +++ b/src/klog_line.c @@ -0,0 +1,60 @@ +/* Control4Free -- reading meaning out of a kernel-log line. + * + * Pure string work, with no PS4 calls, so the host tests run the same code the + * console does. + */ + +#include +#include +#include + +#include "c4f_vda.h" + +static uint64_t c4fParseHexAfter(const char *line, const char *key) +{ + const char *p = strstr(line, key); + uint64_t value = 0; + + if (!p) return 0; + p += strlen(key); + while (*p == ' ' || *p == '\t' || *p == ':' || *p == '=') p++; + if (p[0] == '0' && (p[1] == 'x' || p[1] == 'X')) p += 2; + if (!isxdigit((unsigned char)*p)) return 0; + + while (isxdigit((unsigned char)*p)) { + char c = *p++; + value <<= 4; + if (c >= '0' && c <= '9') value |= (uint64_t)(c - '0'); + else if (c >= 'a' && c <= 'f') value |= (uint64_t)(10 + c - 'a'); + else value |= (uint64_t)(10 + c - 'A'); + } + return value; +} + +uint64_t c4fKlogDeviceId(const char *line) +{ + static const char *keys[] = { "DeviceId", "DeviceID", "deviceId", "deviceID" }; + size_t i; + + for (i = 0; i < sizeof(keys) / sizeof(keys[0]); i++) { + uint64_t id = c4fParseHexAfter(line, keys[i]); + if (id) return id; + } + return 0; +} + +/* The login manager's line for a new virtual pad, as logged on firmware 10.01: + * + * #LOGIN MGR# Receive Event : SCE_MBUS_EVENT_DEVICE_ADDED [DeviceId:0x7030d][type:1][subType:2] + * + * subType 2 is the Remote Play pad and is the same every time. type has been 1 + * (created for user 1, which is what we do) and 4 (created for a local-user id), + * so it is not part of the match. Nothing looser is accepted: a real pad being + * plugged in, or any other MBus device appearing in the same window, would + * otherwise hand us a DeviceId that is not ours, and every input would then go + * to a device we do not own. */ +int c4fKlogIsVirtualAdd(const char *line) +{ + return strstr(line, "SCE_MBUS_EVENT_DEVICE_ADDED") != NULL && + (strstr(line, "[subType:2]") != NULL || strstr(line, "subType=2") != NULL); +} diff --git a/src/vda.c b/src/vda.c index aaf1c50..8be50d0 100644 --- a/src/vda.c +++ b/src/vda.c @@ -3,15 +3,18 @@ * Ported from seregonwar/SplashDown's psbutton.c (GPL-3.0), the only known * working caller of this API on a PS4. The call order and the klog trick for * recovering the device handle both come from there. + * + * Nothing here blocks. Adding a device takes two steps, because the handle only + * turns up in the kernel log a moment after the call: the service issues + * c4fVirtualPadAdd, keeps serving everyone else while it reads the log, and + * calls c4fVirtualPadAdopt once the line arrives. */ -#include #include #include #include #include #include -#include #include #include @@ -27,22 +30,6 @@ #define RTLD_GLOBAL 0x100 #endif -static void (*g_waitCallback)(void *); -static void *g_waitContext; - -void c4fVdaSetWaitCallback(void (*callback)(void *), void *context) -{ - g_waitCallback = callback; - g_waitContext = context; -} - -static uint64_t c4fVdaNowMs(void) -{ - struct timespec now; - clock_gettime(CLOCK_MONOTONIC, &now); - return (uint64_t)now.tv_sec * 1000 + (uint64_t)now.tv_nsec / 1000000; -} - /* ---- libSceMbus ---- */ int c4fMbusInit(void) @@ -89,31 +76,18 @@ int c4fPadInit(void) return 0; } -/* ---- /dev/klog scanning ---- +/* ---- the kernel log ---- * * AddDevice hands back a status, not a handle. The handle we need is the MBus - * DeviceId, and the only way for a payload to learn it is to read the kernel log - * while the device is being added. Ugly, but it is what works. + * DeviceId the kernel logs right after the call, and reading the log is the only + * way for a payload to learn it. Ugly, but it is what works. + * + * /dev/klog has a single reader. GoldHEN's klog server opens it only while it + * has a client and serves one client at a time; after a client leaves it can go + * minutes without serving the next one (console, 2026-10-04). So the service + * reads the device itself, and only while a controller signs in. */ - -/* Drained and proven by a marker that comes back, or closed. */ -static int c4fKlogVerified(int fd, const char *what) -{ - c4fKlogDrain(fd); - if (c4fKlogSelfTest(fd) == 0) { - c4fLog("reading klog through %s\n", what); - return fd; - } - close(fd); - return -1; -} - -/* GoldHEN's klog server opens /dev/klog only while it has a client and serves - * one client at a time. After a client leaves it can go minutes without - * serving the next one: on the console (2026-10-04) every reconnect after a - * release read 0 bytes for 4-5 minutes. So the browser service never uses the - * stream; it reads the device itself, only while a controller signs in. */ int c4fKlogOpenDevice(void) { int fd = open("/dev/klog", O_RDONLY | O_NONBLOCK); @@ -121,241 +95,31 @@ int c4fKlogOpenDevice(void) c4fLog("open(/dev/klog) failed errno=%d (16: GoldHEN's klog server has a client)\n", errno); return -1; } - return c4fKlogVerified(fd, "/dev/klog"); + c4fLog("reading klog through /dev/klog\n"); + return fd; } -/* Throws away whatever is already buffered so only new lines get scanned. A - * fresh connection to the klog server may replay a backlog, and an old "device - * added" line in it would hand us a stale DeviceId. Keep reading until the - * stream has been quiet for a while rather than stopping at the first empty - * read, because the backlog does not arrive all at once. */ -void c4fKlogDrain(int fd) +/* A line of our own, to prove the reader really delivers. It deliberately has + * no [c4f] prefix: the reader skips those, because our own mirrored log would + * otherwise come back round and feed itself. */ +void c4fKlogMark(const char *marker) { - char tmp[1024]; - int quietMs = 0; - int totalMs = 0; - long bytes = 0; - uint64_t started = c4fVdaNowMs(); - - if (fd < 0) return; - while (quietMs < 300 && totalMs < 3000 && c4fVdaNowMs() - started < 3000) { - if (g_waitCallback) g_waitCallback(g_waitContext); - ssize_t n = read(fd, tmp, sizeof(tmp)); - if (n > 0) { - bytes += n; - quietMs = 0; - continue; - } - if (n == 0 || (errno != EINTR && errno != EAGAIN && errno != EWOULDBLOCK)) break; - usleep(20000); - quietMs += 20; - totalMs += 20; - } - c4fLog("klog drain: discarded %ld bytes of backlog\n", bytes); -} - -/* Writes a marker into the kernel log and checks we can read it back. If this - * fails, a new controller cannot learn its device handle. */ -int c4fKlogSelfTest(int fd) -{ - static unsigned sequence; - char marker[96]; - char buf[512]; - char window[sizeof(buf) + sizeof(marker)]; - size_t keep = 0; - long bytes = 0; - int found = 0; - uint64_t started = c4fVdaNowMs(); - int savedKlog; - - if (fd < 0) { - c4fLog("klog self-test skipped: no klog source\n"); - return -1; - } - - /* Straight to klog, not through c4fLog, so the mirror file only gets the - * result line. */ - snprintf(marker, sizeof(marker), "c4f-klog-selftest-%d-%llu-%u", getpid(), - (unsigned long long)started, ++sequence); - klog_printf("[c4f] %s\n", marker); - - savedKlog = c4fLogKlogEnabled(); - c4fLogSetKlog(0); - while (c4fVdaNowMs() - started < 2000 && !found) { - if (g_waitCallback) g_waitCallback(g_waitContext); - ssize_t n = read(fd, window + keep, sizeof(buf)); - if (n <= 0) { - if (n == 0 || (errno != EINTR && errno != EAGAIN && errno != EWOULDBLOCK)) break; - usleep(20000); - continue; - } - bytes += n; - { - size_t total = keep + (size_t)n; - size_t tail = strlen(marker) - 1; - - window[total] = '\0'; - if (strstr(window, marker)) found = 1; - /* Carry the tail over so a marker split across two reads still matches. */ - if (total > tail) { - (void)memmove(window, window + total - tail, tail); - keep = tail; - } else { - keep = total; - } - } - } - c4fLogSetKlog(savedKlog); - - c4fLog("klog self-test: %s (%ld bytes read in %d ms)\n", - found ? "PASS, our own line came back" : "FAIL, marker never seen", - bytes, (int)(c4fVdaNowMs() - started)); - return found ? 0 : -1; -} - -static uint64_t c4fParseHexAfter(const char *line, const char *key) -{ - const char *p = strstr(line, key); - uint64_t value = 0; - - if (!p) return 0; - p += strlen(key); - while (*p == ' ' || *p == '\t' || *p == ':' || *p == '=') p++; - if (p[0] == '0' && (p[1] == 'x' || p[1] == 'X')) p += 2; - if (!isxdigit((unsigned char)*p)) return 0; - - while (isxdigit((unsigned char)*p)) { - char c = *p++; - value <<= 4; - if (c >= '0' && c <= '9') value |= (uint64_t)(c - '0'); - else if (c >= 'a' && c <= 'f') value |= (uint64_t)(10 + c - 'a'); - else value |= (uint64_t)(10 + c - 'A'); - } - return value; -} - -static uint64_t c4fParseDeviceId(const char *line) -{ - static const char *keys[] = { "DeviceId", "DeviceID", "deviceId", "deviceID" }; - size_t i; - - for (i = 0; i < sizeof(keys) / sizeof(keys[0]); i++) { - uint64_t id = c4fParseHexAfter(line, keys[i]); - if (id) return id; - } - return 0; -} - -static int c4fIsAddLine(const char *line) -{ - return strstr(line, "DEVICE_ADDED") != NULL || strstr(line, " ADD") != NULL; -} - -/* A PS4 virtual pad is logged as the Remote Play device: type 4, subType 2. */ -static int c4fIsVirtualAddLine(const char *line) -{ - int looksVirtual = strstr(line, "REMOTEPLAY") != NULL || - strstr(line, "type:4") != NULL || strstr(line, "type=4") != NULL || - strstr(line, "subType:2") != NULL || strstr(line, "subType=2") != NULL; - return c4fIsAddLine(line) && looksVirtual; -} - -int c4fKlogFindDeviceId(int fd, uint64_t *outDeviceId, int timeoutMs) -{ - char buf[512]; - char line[1024]; - size_t lineLen = 0; - uint64_t weakId = 0; - int loops = timeoutMs / 20; - int result = -1; - int savedKlog; - int i; - - if (fd < 0 || !outDeviceId) return -1; - if (loops < 1) loops = 1; - - /* Our own writes would be read straight back and bury the kernel lines. */ - savedKlog = c4fLogKlogEnabled(); - c4fLogSetKlog(0); - c4fLog("scanning /dev/klog for a virtual DeviceId, up to %d ms\n", timeoutMs); - - for (i = 0; i < loops && result != 0; i++) { - if (g_waitCallback) g_waitCallback(g_waitContext); - ssize_t n = read(fd, buf, sizeof(buf)); - ssize_t k; - - if (n < 0) { - if (errno == EAGAIN || errno == EWOULDBLOCK) { - usleep(20000); - continue; - } - c4fLog("klog read errno=%d\n", errno); - break; - } - if (n == 0) { - usleep(20000); - continue; - } - - for (k = 0; k < n; k++) { - char c = buf[k]; - uint64_t id; - - if (c == '\r') continue; - if (c != '\n' && lineLen + 1 < sizeof(line)) { - line[lineLen++] = c; - continue; - } - - line[lineLen] = '\0'; - lineLen = 0; - - id = c4fParseDeviceId(line); - if (id && c4fIsVirtualAddLine(line)) { - *outDeviceId = id; - c4fLog("matched virtual device line: %s\n", line); - result = 0; - break; - } - /* Any other "device added" line is a weaker candidate: keep the - * first one in case the exact match never arrives. */ - if (id && c4fIsAddLine(line) && !weakId) { - weakId = id; - c4fLog("weak candidate DeviceId=0x%llx from: %s\n", - (unsigned long long)weakId, line); - } - } - } - - if (result != 0 && weakId) { - *outDeviceId = weakId; - c4fLog("no exact match; taking weak candidate DeviceId=0x%llx\n", - (unsigned long long)weakId); - result = 0; - } - if (result != 0) c4fLog("no DeviceId seen in klog\n"); - - c4fLogSetKlog(savedKlog); - return result; + klog_printf("%s\n", marker); } /* ---- device lifecycle ---- */ -int c4fVirtualPadAddAs(C4fVirtualPad *out, int32_t userId, int32_t vdaUser, int klogFd) +int32_t c4fVirtualPadAdd(int32_t vdaUser) { C4fVdaParam param; - uint64_t deviceId = 0; int32_t ret; int i; - (void)memset(out, 0, sizeof(*out)); - out->handle = -1; - out->userId = C4F_USER_ID_INVALID; - (void)memset(¶m, 0, sizeof(param)); param.size = (int32_t)sizeof(param); param.userId = vdaUser; - /* A marker, so the log shows whether the call writes anything back. */ + /* A marker, so the log shows whether the call writes anything back. It never + * has on this console, which is why the DeviceId has to come from klog. */ for (i = 0; i < 6; i++) param.pad[i] = (int32_t)0xdeadbeef; c4fLog("AddDevice: size=%d userId=0x%08x type=%d\n", @@ -365,37 +129,22 @@ int c4fVirtualPadAddAs(C4fVirtualPad *out, int32_t userId, int32_t vdaUser, int (uint32_t)ret, (uint32_t)param.pad[0], (uint32_t)param.pad[1], (uint32_t)param.pad[2], (uint32_t)param.pad[3], (uint32_t)param.pad[4], (uint32_t)param.pad[5]); - /* A non-zero return does not have to mean failure: on PS5 SplashDown sees - * 0x803b0006 and the device is created anyway. So look for it regardless. */ - if (klogFd >= 0 && c4fKlogFindDeviceId(klogFd, &deviceId, 2500) == 0) { - out->deviceId = deviceId; - out->handle = (int32_t)(deviceId & 0xffffffffu); - out->owned = 1; - c4fLog("DeviceId=0x%llx handle=0x%08x\n", - (unsigned long long)deviceId, (uint32_t)out->handle); - } + * 0x803b0006 and the device is created anyway. So the caller waits for the + * log line either way. */ + return ret; +} - if (out->handle < 0) { - for (i = 0; i < 6; i++) { - if (param.pad[i] > 0 && param.pad[i] != (int32_t)0xdeadbeef) { - out->handle = param.pad[i]; - out->deviceId = (uint32_t)out->handle; - out->owned = 1; - c4fLog("handle from written-back pad[%d]=0x%08x\n", - i, (uint32_t)out->handle); - break; - } - } - } - - if (out->handle < 0) { - c4fLog("ERROR: no virtual device handle\n"); - return -1; - } +void c4fVirtualPadAdopt(C4fVirtualPad *out, int32_t userId, int32_t vdaUser, uint64_t deviceId) +{ + (void)memset(out, 0, sizeof(*out)); + out->deviceId = deviceId; + out->handle = (int32_t)(deviceId & 0xffffffffu); out->userId = userId; out->vdaUserId = vdaUser; - return 0; + out->owned = 1; + c4fLog("DeviceId=0x%llx handle=0x%08x\n", + (unsigned long long)deviceId, (uint32_t)out->handle); } void c4fPadDataNeutral(ScePadData *data) @@ -420,7 +169,7 @@ int32_t c4fVirtualPadInsert(const C4fVirtualPad *pad, const ScePadData *data) { ScePadData stamped = *data; - g_sampleStamp += C4F_FRAME_MS * 1000u; /* microseconds, like a real pad */ + g_sampleStamp += 33 * 1000u; /* microseconds, like a real pad */ g_sampleCount++; stamped.timestamp = g_sampleStamp; stamped.count = g_sampleCount; diff --git a/src/web.c b/src/web.c index 8e062ac..f8e96c8 100644 --- a/src/web.c +++ b/src/web.c @@ -36,12 +36,41 @@ typedef struct { uint32_t userId; } C4fWebPad; +/* Creating a controller means issuing AddDevice and then finding its DeviceId in + * the kernel log, which takes a moment. None of that may stop the service from + * answering the other players, so it runs as a state machine driven from the main + * loop. One creation at a time: two AddDevice calls at once would produce two log + * lines with no way to tell which device belongs to which request. */ +typedef enum { + C4F_ADD_IDLE = 0, + C4F_ADD_DRAIN, /* reading off the log's backlog, so no old line is reused */ + C4F_ADD_VERIFY, /* a marker was written; waiting for it to come back */ + C4F_ADD_DEVICE, /* AddDevice issued; waiting for the device-added line */ +} C4fAddState; + +typedef struct { + C4fAddState state; + unsigned wanted; /* the whole claim this request asked for */ + unsigned pending; /* the slots still to create */ + unsigned created; /* the slots created so far, to undo on failure */ + C4fNetClient *client; /* who asked, or NULL once they left */ + int64_t id; + int hasId; + int slot; /* the slot AddDevice was issued for, or -1 */ + uint64_t deadline; + uint64_t quietAt; /* when the log last had something to read */ + uint64_t deviceId; /* the DeviceId the reader picked up */ + char marker[64]; + int markerSeen; +} C4fAdd; + typedef struct { C4fNet net; C4fWebPad pads[C4F_MAX_PADS]; int klogFd, stop, changed, creationBlocked; char klogLine[1024]; size_t klogUsed; + C4fAdd add; uint64_t broadcastAt, stopAt, heartbeatAt; } C4fWeb; @@ -118,7 +147,8 @@ static void c4fStatus(C4fWeb *app, C4fNetClient *c, const C4fRequest *request) pos += (size_t)snprintf(json+pos, sizeof(json)-pos, "{\"version\":\"%s\",\"protocol\":2,\"pads\":[", C4F_VERSION); for (int i = 0; i < C4F_MAX_PADS; i++) { C4fWebPad *p = &app->pads[i]; - const char *state = p->error ? "error" : !p->active ? "free" : !p->owner || p->stale ? "paused" : p->assigned ? "ready" : "select"; + const char *state = p->error ? "error" : app->add.state && (app->add.pending & (1u << i)) ? "connecting" + : !p->active ? "free" : !p->owner || p->stale ? "paused" : p->assigned ? "ready" : "select"; unsigned colors[4][3] = {{32,96,255},{255,48,64},{48,200,96},{255,80,180}}; pos += (size_t)snprintf(json+pos, sizeof(json)-pos, "%s{\"pad\":%d,\"name\":\"Controller %d\",\"enabled\":true,\"open\":%s,\"connected\":%s,\"clients\":%d,\"mine\":%s,\"state\":\"%s\",\"uid\":\"%s%08x\",\"color\":[%u,%u,%u],\"reports\":%llu,\"error\":%d}", @@ -145,10 +175,8 @@ static void c4fRemove(C4fWeb *app, C4fWebPad *p) memset(p, 0, sizeof(*p)); app->changed = 1; } -/* Also called during VDA creation waits; never re-enter the network or klog. */ -static void c4fReportPads(void *context) +static void c4fReportPads(C4fWeb *app) { - C4fWeb *app = context; uint64_t now = c4fTimeMs(); for (int i = 0; i < C4F_MAX_PADS; i++) { C4fWebPad *p = &app->pads[i]; @@ -184,39 +212,62 @@ static void c4fEnqueue(C4fWebPad *p, const ScePadData *data) p->queue[(p->head+p->count)%C4F_QUEUE_SIZE] = *data; p->count++; } -static void c4fReadKlog(C4fWeb *app) +/* One kernel-log line. Our own mirrored output is skipped: c4fLog writes to klog + * too, so a line that reacted to a line would feed itself for ever. The marker + * c4fKlogMark writes carries no [c4f], which is how it gets through. */ +static void c4fKlogLine(C4fWeb *app, const char *line) +{ + unsigned long long device; + unsigned user; + const char *event; + + if (strstr(line, "[c4f]")) return; + + if (app->add.state == C4F_ADD_VERIFY && !app->add.markerSeen && + app->add.marker[0] && strstr(line, app->add.marker)) + app->add.markerSeen = 1; + + if (app->add.state == C4F_ADD_DEVICE && !app->add.deviceId && c4fKlogIsVirtualAdd(line)) + app->add.deviceId = c4fKlogDeviceId(line); + + event = strstr(line, "DEVICE_OWNER_CHANGED [DeviceId:"); + if (event && sscanf(event, "DEVICE_OWNER_CHANGED [DeviceId:0x%llx][UserId:0x%x]", &device, &user) == 2) { + for (int i = 0; i < C4F_MAX_PADS; i++) { + C4fWebPad *p = &app->pads[i]; + if (p->active && p->device.deviceId == device) { + p->assigned = user != 0xffffffffu; p->userId = user; app->changed = 1; + c4fLog("web controller %d assignment confirmed=%d\n", i+1, p->assigned); + } + } + } +} + +/* Reads whatever the log has right now and never waits. Returns the number of + * bytes taken, so the caller can tell a quiet log from a busy one. */ +static long c4fReadKlog(C4fWeb *app) { char buf[2048]; - if (app->klogFd < 0) return; + long total = 0; + if (app->klogFd < 0) return 0; for (int batch = 0; batch < 8; batch++) { ssize_t n = read(app->klogFd, buf, sizeof(buf)); if (n < 0 && errno == EINTR) continue; - if (n < 0 && (errno == EAGAIN || errno == EWOULDBLOCK)) return; + if (n < 0 && (errno == EAGAIN || errno == EWOULDBLOCK)) return total; if (n <= 0) { close(app->klogFd); app->klogFd = -1; c4fLog("klog source closed; reconnecting at the next controller request\n"); - return; + return total; } + total += (long)n; for (ssize_t j = 0; j < n; j++) { if (buf[j] == '\n') { - unsigned long long device; - unsigned user; - char *event; app->klogLine[app->klogUsed] = 0; - event = strstr(app->klogLine, "DEVICE_OWNER_CHANGED [DeviceId:"); - if (event && sscanf(event, "DEVICE_OWNER_CHANGED [DeviceId:0x%llx][UserId:0x%x]", &device, &user) == 2) { - for (int i = 0; i < C4F_MAX_PADS; i++) { - C4fWebPad *p = &app->pads[i]; - if (p->active && p->device.deviceId == device) { - p->assigned = user != 0xffffffffu; p->userId = user; app->changed = 1; - c4fLog("web controller %d assignment confirmed=%d\n", i+1, p->assigned); - } - } - } + c4fKlogLine(app, app->klogLine); app->klogUsed = 0; } else if (buf[j] != '\r' && app->klogUsed+1 < sizeof(app->klogLine)) app->klogLine[app->klogUsed++] = buf[j]; } } + return total; } static void c4fReleaseKlog(C4fWeb *app) @@ -234,10 +285,141 @@ static void c4fReleaseIdleKlog(C4fWeb *app) c4fReleaseKlog(app); } +/* Hands the claim its slots once every device it needed exists. */ +static void c4fApplyClaim(C4fWeb *app, C4fNetClient *c, unsigned wanted, C4fRequest *r) +{ + for (int i = 0; i < C4F_MAX_PADS; i++) { + C4fWebPad *p = &app->pads[i]; + if (wanted & (1u << i)) { + if (p->owner != c) c4fNeutralize(p); + p->owner = c; p->detachedAt = 0; p->lastInput = c4fTimeMs(); p->stale = 0; + } else if (p->owner == c) c4fRemove(app, p); + } + app->changed = 1; c4fStatus(app, c, r); +} + +static void c4fAddReset(C4fWeb *app) +{ + memset(&app->add, 0, sizeof(app->add)); + app->add.slot = -1; +} + +/* Gives up on the creation in progress. `blocked` means AddDevice had already + * run, so a device we can no longer address may exist. */ +static void c4fAddFail(C4fWeb *app, int code, const char *message, int blocked) +{ + C4fNetClient *client = app->add.client; + C4fRequest reply; + + if (blocked) app->creationBlocked = 1; + for (int i = 0; i < C4F_MAX_PADS; i++) + if (app->add.created & (1u << i)) c4fRemove(app, &app->pads[i]); + + memset(&reply, 0, sizeof(reply)); + reply.id = app->add.id; reply.hasId = app->add.hasId; + c4fAddReset(app); + app->changed = 1; + if (client) c4fError(client, reply.hasId ? &reply : NULL, code, message); +} + +/* Issues AddDevice for the lowest slot still waiting. */ +static void c4fAddNextDevice(C4fWeb *app, uint64_t now) +{ + for (int i = 0; i < C4F_MAX_PADS; i++) if (app->add.pending & (1u << i)) { + app->add.slot = i; + app->add.deviceId = 0; + app->add.state = C4F_ADD_DEVICE; + app->add.deadline = now + 2500; + (void)c4fVirtualPadAdd(C4F_VDA_USER_SELECT); + return; + } + app->add.slot = -1; +} + +/* One step of the creation in progress, from the main loop. */ +static void c4fAdvanceAdd(C4fWeb *app, uint64_t now, long klogBytes) +{ + if (!app->add.state) return; + + if (app->klogFd < 0) { + c4fAddFail(app, 503, "Lost the PS4's kernel log while connecting the controller; try again", + app->add.state == C4F_ADD_DEVICE); + return; + } + if (klogBytes) app->add.quietAt = now; + + switch (app->add.state) { + case C4F_ADD_DRAIN: + /* A fresh reader can replay a backlog, and an old device-added line in it + * would hand us a DeviceId that is not ours. Wait for the log to go quiet + * first, but not for ever: a busy console is still a usable one. */ + if (now - app->add.quietAt < 150 && now < app->add.deadline) return; + snprintf(app->add.marker, sizeof(app->add.marker), "c4f-klog-mark-%llu", + (unsigned long long)now); + app->add.markerSeen = 0; + app->add.state = C4F_ADD_VERIFY; + app->add.deadline = now + 2000; + c4fKlogMark(app->add.marker); + return; + + case C4F_ADD_VERIFY: + if (app->add.markerSeen) { c4fAddNextDevice(app, now); return; } + if (now < app->add.deadline) return; + /* The reader was opened but delivers nothing. Nothing was created yet, so + * drop it and let the next attempt open a fresh one. */ + c4fReleaseKlog(app); + c4fAddFail(app, 503, "Cannot read the PS4's kernel log, which sign-in needs. If a klog viewer is connected to GoldHEN, close it and try again.", 0); + return; + + case C4F_ADD_DEVICE: + if (app->add.deviceId) { + C4fWebPad *p = &app->pads[app->add.slot]; + c4fVirtualPadAdopt(&p->device, C4F_USER_ID_INVALID, C4F_VDA_USER_SELECT, app->add.deviceId); + p->active = 1; p->userId = 0xffffffffu; p->lastInput = now; + /* It has no owner until the whole claim is answered. Start its idle + * clock now so the reaper does not take it in the meantime. */ + p->detachedAt = now; + c4fNeutralize(p); + app->add.created |= 1u << app->add.slot; + app->add.pending &= ~(1u << app->add.slot); + app->changed = 1; + if (app->add.pending) { c4fAddNextDevice(app, now); return; } + /* Done. If the player left while we worked, the devices have nobody + * to drive them. */ + if (!app->add.client) { + for (int i = 0; i < C4F_MAX_PADS; i++) + if (app->add.created & (1u << i)) c4fRemove(app, &app->pads[i]); + c4fAddReset(app); + return; + } + { + C4fNetClient *client = app->add.client; + unsigned wanted = app->add.wanted; + C4fRequest reply; + memset(&reply, 0, sizeof(reply)); + reply.id = app->add.id; reply.hasId = app->add.hasId; + c4fAddReset(app); + c4fApplyClaim(app, client, wanted, reply.hasId ? &reply : NULL); + } + return; + } + if (now < app->add.deadline) return; + /* AddDevice ran and no handle came back: there may be a device out there + * we cannot address. Stop creating until the payload is restarted rather + * than collect more of them. */ + c4fLog("no virtual device line for controller %d within the wait\n", app->add.slot + 1); + c4fAddFail(app, 503, "Could not create controller; restart Control4Free before retrying", 1); + return; + + default: + return; + } +} + static void c4fClaim(C4fWeb *app, C4fNetClient *c, C4fRequest *r) { - unsigned wanted = 0, created = 0; - int needsDevice = 0, needsAssignment = 0; + unsigned wanted = 0, needed = 0; + int needsAssignment = 0; for (unsigned i = 0; i < r->argc; i++) { if (r->args[i] < 0 || r->args[i] >= C4F_MAX_PADS) { c4fError(c, r, 400, "Invalid controller"); return; } wanted |= 1u << r->args[i]; @@ -247,41 +429,30 @@ static void c4fClaim(C4fWeb *app, C4fNetClient *c, C4fRequest *r) C4fWebPad *p = &app->pads[i]; if (p->owner && p->owner != c) { c4fError(c, r, 409, "Controller is in use on another device"); return; } if (!p->active && app->creationBlocked) { c4fError(c, r, 503, "Controller creation unavailable; restart Control4Free"); return; } - if (!p->active) needsDevice = 1; + if (!p->active) needed |= 1u << i; if (p->active && !p->assigned) needsAssignment = 1; } - /* Recheck the stream before every creation. An accepted but unserved klog - * socket must never lead to AddDevice and an orphan with no known handle. */ - if (needsDevice || (needsAssignment && app->klogFd < 0)) { - if (app->klogFd >= 0) { - c4fReadKlog(app); - if (app->klogFd >= 0 && c4fKlogSelfTest(app->klogFd)) c4fReleaseKlog(app); - } - if (app->klogFd < 0) app->klogFd = c4fKlogOpenDevice(); - if (app->klogFd < 0 && needsDevice) { c4fError(c, r, 503, "Cannot read the PS4's kernel log, which sign-in needs. If a klog viewer is connected to GoldHEN, close it and try again."); return; } + if (needed && app->add.state) { + c4fError(c, r, 409, "Another controller is being connected; try again in a moment"); return; } - for (int i = 0; i < C4F_MAX_PADS; i++) if ((wanted & (1u << i)) && !app->pads[i].active) { - C4fWebPad *p = &app->pads[i]; - c4fKlogDrain(app->klogFd); app->klogUsed = 0; - if (c4fVirtualPadAddAs(&p->device, C4F_USER_ID_INVALID, 1, app->klogFd)) { - /* AddDevice may have created an orphan whose handle was lost. Do - * not accumulate more devices through automatic retries. */ - app->creationBlocked = 1; - for (int k = 0; k < C4F_MAX_PADS; k++) if (created & (1u << k)) c4fRemove(app, &app->pads[k]); - c4fError(c, r, 503, "Could not create controller; restart payload before retrying"); return; - } - p->active = 1; p->userId = 0xffffffffu; p->lastInput = c4fTimeMs(); - c4fNeutralize(p); created |= 1u << i; - c4fReportPads(app); + if ((needed || needsAssignment) && app->klogFd < 0) { + app->klogFd = c4fKlogOpenDevice(); + if (app->klogFd < 0 && needed) { c4fError(c, r, 503, "Cannot read the PS4's kernel log, which sign-in needs. If a klog viewer is connected to GoldHEN, close it and try again."); return; } } - for (int i = 0; i < C4F_MAX_PADS; i++) { - C4fWebPad *p = &app->pads[i]; - if (wanted & (1u << i)) { - if (p->owner != c) c4fNeutralize(p); - p->owner = c; p->detachedAt = 0; p->lastInput = c4fTimeMs(); p->stale = 0; - } else if (p->owner == c) c4fRemove(app, p); - } - app->changed = 1; c4fStatus(app, c, r); + if (!needed) { c4fApplyClaim(app, c, wanted, r); return; } + + /* The devices are created from the main loop, which answers this request when + * it is finished. Everyone else keeps being served in the meantime. */ + c4fAddReset(app); + app->add.state = C4F_ADD_DRAIN; + app->add.wanted = wanted; + app->add.pending = needed; + app->add.client = c; + app->add.id = r->id; + app->add.hasId = r->hasId; + app->add.quietAt = c4fTimeMs(); + app->add.deadline = app->add.quietAt + 3000; + app->changed = 1; } static void c4fUpdate(C4fWeb *app, C4fNetClient *c, C4fRequest *r) @@ -316,6 +487,7 @@ static void c4fWebEvent(C4fNetClient *c, int event, const char *text, size_t len c4fNetHttpJson(c, reply); return; } if (event == C4F_NET_HTTP_STOP) { + if (app->add.state) c4fAddFail(app, 503, "Control4Free is stopping", 0); for (int i = 0; i < C4F_MAX_PADS; i++) c4fRemove(app, &app->pads[i]); c4fNetHttpJson(c, "{\"application\":\"Control4Free\",\"stopping\":true}"); if (!app->stopAt) app->stopAt = c4fTimeMs() + 250; @@ -323,6 +495,8 @@ static void c4fWebEvent(C4fNetClient *c, int event, const char *text, size_t len } if (event == C4F_NET_OPEN) { c4fStatus(app, c, NULL); return; } if (event == C4F_NET_CLOSE) { + /* Before the slot can be reused by someone else. */ + if (app->add.client == c) app->add.client = NULL; for (int i = 0; i < C4F_MAX_PADS; i++) if (app->pads[i].owner == c) { C4fWebPad *p = &app->pads[i]; c4fNeutralize(p); p->owner = NULL; p->detachedAt = c4fTimeMs(); app->changed = 1; @@ -360,7 +534,6 @@ int c4fWebRun(int klogFd) if (klogFd >= 0) close(klogFd); free(app); return -1; } - c4fVdaSetWaitCallback(c4fReportPads, app); c4fLog("Control4Free %s: browser controller on port %d\n", C4F_VERSION, C4F_WEB_PORT); c4fNotify("Control4Free: open PS4 IP:%d in your browser", C4F_WEB_PORT); uint64_t previous = c4fTimeMs(), retryAt = 0; @@ -376,6 +549,8 @@ int c4fWebRun(int klogFd) (long long)now - (long long)previous, (long long)wall - (long long)previousWall); c4fNetClose(&app->net); /* close events neutralize and discard queued input */ c4fReleaseKlog(app); + if (app->add.state) c4fAddFail(app, 503, "Control4Free paused while connecting the controller; try again", + app->add.state == C4F_ADD_DEVICE); for (int i = 0; i < C4F_MAX_PADS; i++) if (app->pads[i].active) app->pads[i].nextReport = now; app->broadcastAt = app->heartbeatAt = now; @@ -387,20 +562,24 @@ int c4fWebRun(int klogFd) retryAt = now + 1000; } else c4fLog("listener recovered on port %d\n", C4F_WEB_PORT); } - c4fReadKlog(app); c4fReportPads(app); + long klogBytes = c4fReadKlog(app); + c4fReportPads(app); + c4fAdvanceAdd(app, now, klogBytes); for (int i = 0; i < C4F_MAX_PADS; i++) { C4fWebPad *p = &app->pads[i]; + if (app->add.created & (1u << i)) continue; /* mid-claim, not abandoned */ if (p->active && ((!p->owner && now-p->detachedAt > C4F_RELEASE_MS) || (p->owner && now-p->lastInput > C4F_RELEASE_MS))) { C4fNetClient *owner = p->owner; c4fRemove(app, p); if (owner) c4fError(owner, NULL, 408, "Controller disconnected after inactivity; select it again"); } } - c4fReleaseIdleKlog(app); + if (!app->add.state) c4fReleaseIdleKlog(app); if (now >= app->heartbeatAt) { int active = 0; for (int i = 0; i < C4F_MAX_PADS; i++) active += app->pads[i].active; - c4fLog("heartbeat: listener=%d controllers=%d klog=%d\n", app->net.fd >= 0, active, app->klogFd >= 0); + c4fLog("heartbeat: listener=%d controllers=%d klog=%d connecting=%d\n", + app->net.fd >= 0, active, app->klogFd >= 0, app->add.state); app->heartbeatAt = now + 60000; } if (app->changed || now >= app->broadcastAt) { @@ -418,6 +597,8 @@ int c4fWebRun(int klogFd) else c4fLog("network failed errno=%d; resetting connections\n", errno); c4fNetClose(&app->net); c4fReleaseKlog(app); + if (app->add.state) c4fAddFail(app, 503, "Control4Free lost the connection while connecting the controller; try again", + app->add.state == C4F_ADD_DEVICE); for (int i = 0; i < C4F_MAX_PADS; i++) if (app->pads[i].active) app->pads[i].nextReport = c4fTimeMs(); retryAt = c4fTimeMs() + (result == -2 ? 0 : 1000); @@ -427,7 +608,6 @@ int c4fWebRun(int klogFd) * creation waits from the gap between iterations. */ previous = c4fTimeMs(); previousWall = time(NULL); } - c4fVdaSetWaitCallback(NULL, NULL); for (int i = 0; i < C4F_MAX_PADS; i++) c4fRemove(app, &app->pads[i]); c4fNetClose(&app->net); if (app->klogFd >= 0) close(app->klogFd); diff --git a/tests/device_id_test.c b/tests/device_id_test.c new file mode 100644 index 0000000..8619305 --- /dev/null +++ b/tests/device_id_test.c @@ -0,0 +1,36 @@ +/* Which kernel-log lines count as "our virtual pad was added". */ +#include +#include +#include "c4f_vda.h" + +/* 0 when the line is not ours, otherwise the DeviceId it names. */ +static uint64_t ours(const char *line) +{ + return c4fKlogIsVirtualAdd(line) ? c4fKlogDeviceId(line) : 0; +} + +int main(void) +{ + /* What a virtual pad produces on firmware 10.01: type 1 when it is created + * for user 1, type 4 when it is created for a local-user id. */ + assert(ours("<118>#LOGIN MGR# Receive Event : SCE_MBUS_EVENT_DEVICE_ADDED" + " [DeviceId:0x7030d][type:1][subType:2]") == 0x7030d); + assert(ours("<118>#LOGIN MGR# Receive Event : SCE_MBUS_EVENT_DEVICE_ADDED" + " [DeviceId:0x50301][type:4][subType:2]") == 0x50301); + + /* Another MBus device turning up in the same window is not ours. A real pad + * being plugged in is subType 0, and the generic event line has no subType at + * all; taking either would send every input to a device we do not own. */ + assert(ours("DEVICE_ADDED [DeviceId:0x123401] [type:1] [subType:0]") == 0); + assert(ours("ScePsP: sceMbusEvent has been received. (eventId=1 ADD, deviceId=0x123401)") == 0); + assert(ours("<118>#LOGIN MGR# Receive Event : SCE_MBUS_EVENT_DEVICE_REMOVED" + " [DeviceId:0x7030d][type:1][subType:2]") == 0); + assert(ours("<118>#LOGIN MGR# Receive Event : SCE_MBUS_EVENT_DEVICE_OWNER_CHANGED" + " [DeviceId:0x7030d][UserId:0x1a2b3c4d]") == 0); + + /* The id is read in hex, whichever spelling the line uses. */ + assert(c4fKlogDeviceId("[DeviceID=0xABCD][subType:2]") == 0xabcd); + assert(c4fKlogDeviceId("nothing here") == 0); + + puts("PASS only the virtual pad's device-added line is accepted"); +} diff --git a/tests/frontend_test.cjs b/tests/frontend_test.cjs new file mode 100644 index 0000000..4c57d55 --- /dev/null +++ b/tests/frontend_test.cjs @@ -0,0 +1,69 @@ +// Runs the shipped page's own claim and Gamepad-polling functions under Node, +// with small state mocks. No browser and no console. +const fs = require('node:fs'); +const vm = require('node:vm'); +const assert = require('node:assert/strict'); +const page = fs.readFileSync('client/index.html', 'utf8'); +const extract = (start, end) => { + const from = page.indexOf(start); + assert.notEqual(from, -1, `page no longer contains ${JSON.stringify(start)}`); + const to = page.indexOf(end, from); + assert.notEqual(to, -1, `page no longer contains ${JSON.stringify(end)}`); + return page.slice(from, to); +}; +const sendClaimSource = extract(" let lastClaim = '';", ' const lastSent ='); +const pollSource = extract(' function pollGamepads(t)', ' function setGamepadPad('); + +function padStatus(fields) { + return Object.assign({ known: true, mine: false, open: false }, fields); +} + +(async () => { + // A claim is answered as a whole. One controller taken on another device must + // not disconnect the gamepad that was playing as a different one. + const claims = []; + const ctx = { + conn: { state: 'open' }, + keepAwake: { update() {} }, + primaryPad: -1, + status: [padStatus({ open: true }), padStatus({ mine: true, open: true }), padStatus({}), padStatus({})], + claimedPads: () => [...ctx.gamepadSources.values()].map(s => s.pad).filter(p => p >= 0).sort(), + gamepadSources: new Map([[0, { pad: 0 }], [1, { pad: 1 }]]), + call(method, params) { + claims.push([method, params]); + if (method === 'claim' && claims.filter(c => c[0] === 'claim').length === 1) + return Promise.reject({ message: 'Controller is in use on another device' }); + return Promise.resolve({ pads: [] }); + }, + applyStatus() {}, toast() {}, closePad() { ctx.primaryPad = -1; }, renderGamepads() {}, + }; + vm.createContext(ctx); + vm.runInContext(sendClaimSource, ctx); + vm.runInContext('sendClaim(true)', ctx); + for (let i = 0; i < 5; i++) await new Promise(setImmediate); + assert.equal(ctx.gamepadSources.get(0).pad, -1, 'the controller taken elsewhere is given up'); + assert.equal(ctx.gamepadSources.get(1).pad, 1, 'the controller we own is kept'); + assert.deepEqual(claims.filter(c => c[0] === 'claim').map(c => c[1]), [[0, 1], [1]], + 'the remaining controller is claimed again'); + console.log('PASS a refused claim gives up only the controllers owned elsewhere'); + + // getGamepads() can start throwing after it has worked. Held buttons must not + // stay in the source: nothing would be left to release them. + const pads = { + gamepadsAvailable: true, + primaryPad: -1, + navigator: { getGamepads() { throw Error('SecurityError'); } }, + gamepadSources: new Map([[0, { pad: 0, buttons: 0x4000, lx: 0, ly: 255, rx: 0, ry: 0, l2: 255, r2: 255, touches: [{}] }]]), + blankSource: pad => ({ pad, buttons: 0, lx: 128, ly: 128, rx: 128, ry: 128, l2: 0, r2: 0, touches: [] }), + renderGamepads() {}, sendClaim() {}, $: () => null, + }; + vm.createContext(pads); + vm.runInContext(pollSource, pads); + vm.runInContext('pollGamepads(100)', pads); + const src = pads.gamepadSources.get(0); + assert.deepEqual( + { buttons: src.buttons, lx: src.lx, ly: src.ly, rx: src.rx, ry: src.ry, l2: src.l2, r2: src.r2, touches: src.touches }, + { buttons: 0, lx: 128, ly: 128, rx: 128, ry: 128, l2: 0, r2: 0, touches: [] }); + assert.equal(src.pad, 0, 'the controller assignment is kept'); + console.log('PASS failed Gamepad polling blanks every source'); +})(); diff --git a/tests/klog_test.c b/tests/klog_test.c index 21dc290..ff984b8 100644 --- a/tests/klog_test.c +++ b/tests/klog_test.c @@ -1,5 +1,5 @@ -/* The real VDA capture functions, with only /dev/klog and the klog writer - * stubbed. Modes: direct (the device is free), busy (another reader has it). +/* The real kernel-log opener, with only /dev/klog and the klog writer stubbed. + * Modes: direct (the device is free), busy (another reader has it). * * GoldHEN's klog server on port 3232 serves one client at a time and can go * minutes without serving the next one, so the service must never reach for it. @@ -19,27 +19,26 @@ #include "c4f_vda.h" static atomic_int peer = -1; -static int direct[2] = {-1, -1}, enabled = 1, deviceBusy, directOpens, waits; -static void waitCallback(void *unused) { (void)unused; waits++; } +static int device[2] = {-1, -1}, deviceBusy, deviceOpens; void c4fLog(const char *fmt, ...) { (void)fmt; } -int c4fLogKlogEnabled(void) { return enabled; } -void c4fLogSetKlog(int value) { enabled = value; } + +/* Stands in for the kernel log's writer: what we write comes back to a reader. */ int klog_printf(const char *fmt, ...) { char line[1024]; va_list ap; va_start(ap, fmt); int n = vsnprintf(line, sizeof(line), fmt, ap); va_end(ap); - if (direct[1] >= 0) { assert(write(direct[1], line, n) == n); return n; } + if (device[1] >= 0) assert(write(device[1], line, (size_t)n) == n); return n; } int __real_open(const char *, int, ...); int __wrap_open(const char *path, int flags, ...) { if (strcmp(path, "/dev/klog")) return __real_open(path, flags); - directOpens++; + deviceOpens++; if (deviceBusy) { errno = EBUSY; return -1; } - assert(pipe(direct) == 0); - assert(fcntl(direct[0], F_SETFL, O_NONBLOCK) == 0); - return direct[0]; + assert(pipe(device) == 0); + assert(fcntl(device[0], F_SETFL, O_NONBLOCK) == 0); + return device[0]; } static void *serve(void *arg) { @@ -60,20 +59,22 @@ int main(int argc, char **argv) assert(bind(listener, (struct sockaddr *)&addr, sizeof(addr)) == 0); assert(listen(listener, 1) == 0); assert(pthread_create(&thread, NULL, serve, &listener) == 0); - c4fVdaSetWaitCallback(waitCallback, NULL); fd = c4fKlogOpenDevice(); if (!deviceBusy) { - /* Non-blocking, opened once, and verified by a marker read back, which - * the wait callback keeps existing controllers reporting through. */ - assert(fd >= 0 && (fcntl(fd, F_GETFL) & O_NONBLOCK) && directOpens == 1 && waits > 0); + char buf[256] = {0}; + assert(fd >= 0 && (fcntl(fd, F_GETFL) & O_NONBLOCK) && deviceOpens == 1); + /* A marker written through klog comes back to the reader, and carries no + * [c4f] prefix, which is how the service tells it from its own output. */ + c4fKlogMark("c4f-klog-mark-1"); + assert(read(fd, buf, sizeof(buf) - 1) > 0); + assert(strstr(buf, "c4f-klog-mark-1") && !strstr(buf, "[c4f]")); close(fd); } else { - assert(fd == -1 && directOpens == 1); + assert(fd == -1 && deviceOpens == 1); } usleep(50000); assert(peer < 0); /* GoldHEN's klog stream was never touched */ - assert(enabled == 1); pthread_cancel(thread); pthread_join(thread, NULL); diff --git a/tests/run.py b/tests/run.py index b38ec93..7c81464 100644 --- a/tests/run.py +++ b/tests/run.py @@ -10,7 +10,7 @@ import sys from pathlib import Path ROOT = Path(__file__).resolve().parents[1] -SUITES = ['test_logging', 'test_web', 'test_recovery', 'test_launcher'] +SUITES = ['test_logging', 'test_frontend', 'test_web', 'test_recovery', 'test_launcher'] def main(): diff --git a/tests/test_frontend.py b/tests/test_frontend.py new file mode 100644 index 0000000..f680a25 --- /dev/null +++ b/tests/test_frontend.py @@ -0,0 +1,10 @@ +"""The page's own claim and Gamepad functions, run under Node.""" +import subprocess + + +def main(): + subprocess.run(['node', 'tests/frontend_test.cjs'], check=True, timeout=30) + + +if __name__ == '__main__': + main() diff --git a/tests/test_logging.py b/tests/test_logging.py index eaf9e08..c53ce7a 100644 --- a/tests/test_logging.py +++ b/tests/test_logging.py @@ -11,6 +11,9 @@ def main(): subprocess.run(flags + ['src/log.c', 'tests/log_test.c', '-Wl,--wrap=clock_gettime', '-o', 'build/log-host-test'], check=True) subprocess.run(['build/log-host-test'], check=True, timeout=5) + subprocess.run(flags + ['src/klog_line.c', 'tests/device_id_test.c', + '-o', 'build/device-id-host-test'], check=True) + subprocess.run(['build/device-id-host-test'], check=True, timeout=5) if __name__ == '__main__': diff --git a/tests/test_recovery.py b/tests/test_recovery.py index c25929c..98f31a9 100644 --- a/tests/test_recovery.py +++ b/tests/test_recovery.py @@ -21,8 +21,8 @@ def connect_again(): def main(): subprocess.run(['clang-18', '-std=gnu11', '-Wall', '-Wextra', '-Werror', '-g', - '-Iinclude', '-Ivendor/jsmn', 'src/net.c', 'src/web.c', - 'tests/web_stub.c', 'tests/recovery_faults.c', 'build/client.c', + '-Iinclude', '-Ivendor/jsmn', 'src/net.c', 'src/web.c', 'src/klog_line.c', + 'tests/web_stub.c', 'tests/recovery_faults.c', 'build/client.c', '-pthread', '-Wl,--wrap=select,--wrap=accept,--wrap=getsockopt', '-o', str(web.BINARY)], check=True) with tempfile.TemporaryDirectory() as directory: fault = Path(directory) / 'fault' diff --git a/tests/test_web.py b/tests/test_web.py index 2249961..6c6d08f 100644 --- a/tests/test_web.py +++ b/tests/test_web.py @@ -9,6 +9,7 @@ import socket import struct import subprocess import tempfile +import threading import time ROOT = Path(__file__).resolve().parents[1] @@ -19,7 +20,8 @@ def build(): subprocess.run(['python3', 'tools/embed_client.py', 'client/index.html', 'build/client.c'], check=True) subprocess.run(['clang-18', '-std=gnu11', '-Wall', '-Wextra', '-Werror', '-g', '-Iinclude', '-Ivendor/jsmn', '-DC4F_STALE_MS=400', '-DC4F_RELEASE_MS=1800', - 'src/net.c', 'src/web.c', 'tests/web_stub.c', 'build/client.c', '-o', str(BINARY)], check=True) + 'src/net.c', 'src/web.c', 'src/klog_line.c', 'tests/web_stub.c', 'build/client.c', + '-pthread', '-o', str(BINARY)], check=True) class Client: @@ -218,29 +220,77 @@ def main(): server.close() # AutoRun can start the payload before GoldHEN's klog server listens. - server = Server(C4F_TEST_KLOG_FD='-1') + server = Server(C4F_TEST_KLOG_BUSY='1') try: assert server.c.request('claim', [0])['error']['code'] == 503 assert 'KLOG none' in server.rows() and not any(r.startswith('ADD') for r in server.rows()) finally: server.close() - server = Server(C4F_TEST_KLOG_FD='-1', C4F_TEST_KLOG_LATE='1') + # A reader that opens but delivers nothing is dropped before AddDevice runs. + server = Server(C4F_TEST_KLOG_DEAD='1') try: - assert server.c.request('claim', [0])['result']['pads'][0]['mine'] - assert any(r.startswith('KLOG ') and r != 'KLOG none' for r in server.rows()) - assert any(r.startswith('ADD') for r in server.rows()) + assert server.c.request('claim', [0])['error']['code'] == 503 + assert not any(r.startswith('ADD') for r in server.rows()) + assert 'released klog reader' in server.rows() + assert server.c.request('info')['result']['pads'] == 4 finally: server.close() - # A klog source that closes is reopened for the next new controller. - server = Server(C4F_TEST_KLOG_LATE='1') + # A klog source that dies is reopened for the next new controller. + server = Server() try: - os.close(server.log) - server.log = None - time.sleep(.1) - assert server.c.request('claim', [1])['result']['pads'][1]['mine'] - rows = server.rows() - assert any(r.startswith('KLOG ') and r != 'KLOG none' for r in rows) and any(r.startswith('ADD') for r in rows) - print('PASS klog missing at start or closed later: reconnected on the next controller request', flush=True) + assert server.c.request('claim', [0])['result']['pads'][0]['mine'] + os.write(server.log, b'C4F-TEST-CLOSE-KLOG\n') + end = time.monotonic() + 3 + while not any('klog source closed' in r for r in server.rows()): + assert time.monotonic() < end, server.rows() + time.sleep(.02) + assert server.c.request('claim', [0, 1])['result']['pads'][1]['mine'] + assert len([r for r in server.rows() if r.startswith('KLOG ') and r != 'KLOG none']) == 2 + print('PASS klog unavailable, silent or closed: refused safely, then reopened for the next controller', flush=True) + finally: + server.close() + + # A creation in progress must not stop anyone else being served. + server = Server(C4F_TEST_ADD_DELAY='900') + try: + first = server.c + assert first.request('claim', [0])['result']['pads'][0]['mine'] + second = Client() + result = [] + thread = threading.Thread(target=lambda: result.append(second.request('claim', [1]))) + thread.start() + time.sleep(.3) + started = time.monotonic() + state = first.request('status')['result']['pads'] + elapsed = time.monotonic() - started + assert elapsed < .1, f'status waited {elapsed:.2f}s for the other player' + assert state[1]['state'] == 'connecting' + first.input(0, 0x4000) + time.sleep(.05) + frames = [r.split() for r in server.rows() if r.startswith('FRAME')] + assert any(r[2] == '11030d' and r[3] == '16384' for r in frames), 'input stopped during creation' + thread.join(timeout=5) + assert result and result[0]['result']['pads'][1]['mine'] + second.close() + print('PASS a controller being created does not block the other players', flush=True) + finally: + server.close() + + # Two claims cannot create at once: the second is refused, not queued. + server = Server(C4F_TEST_ADD_DELAY='600') + try: + first = server.c + result = [] + thread = threading.Thread(target=lambda: result.append(first.request('claim', [0]))) + thread.start() + time.sleep(.3) + second = Client() + assert second.request('claim', [1])['error']['code'] == 409 + thread.join(timeout=5) + assert result and result[0]['result']['pads'][0]['mine'] + assert second.request('claim', [1])['result']['pads'][1]['mine'] + second.close() + print('PASS one controller is created at a time, and the next request works', flush=True) finally: server.close() diff --git a/tests/web_stub.c b/tests/web_stub.c index 4ef5e9b..cb84c96 100644 --- a/tests/web_stub.c +++ b/tests/web_stub.c @@ -1,45 +1,148 @@ -/* Local HTTP/WebSocket integration harness. No console access. */ +/* Local HTTP/WebSocket integration harness. No console access. + * + * The PS4 side is a fake kernel log: a pipe the service reads like /dev/klog, + * that this stub writes the same lines into that firmware 10.01 writes, our own + * mirrored [c4f] output included. So the real service does the real reading, + * marker verification and DeviceId matching, and only scePad is absent. + * + * A test injects its own kernel lines by writing them to the pipe named in + * C4F_TEST_KLOG_FD; they are relayed into the log. The line C4F-TEST-CLOSE-KLOG + * kills the log instead, as GoldHEN taking the device would. + * + * Environment switches: + * C4F_TEST_KLOG_FD read end of the test's injection pipe + * C4F_TEST_KLOG_BUSY /dev/klog cannot be opened: another reader has it + * C4F_TEST_KLOG_DEAD it opens, but nothing is ever delivered + * C4F_TEST_ADD_DELAY milliseconds before the device-added line turns up + * C4F_FAIL_ADD AddDevice runs but its line never arrives + * C4F_FAIL_INPUT InsertData fails while a button is held + */ #include #include #include #include #include #include +#include #include "c4f_net.h" #include "c4f_vda.h" #include "c4f_web.h" static unsigned nextId = 0x11030d; -static void (*waitFn)(void *); -static void *waitContext; -static int klogSource = -1; -void c4fLog(const char *fmt, ...) { va_list ap; va_start(ap, fmt); vprintf(fmt, ap); va_end(ap); } +static int logRead = -1, logWrite = -1; +static pthread_mutex_t logLock = PTHREAD_MUTEX_INITIALIZER; + +/* The write end is non-blocking: a log nobody drains drops lines instead of + * stalling the single-threaded service that reads it. */ +static void logLine(const char *line) +{ + pthread_mutex_lock(&logLock); + if (logWrite >= 0 && !getenv("C4F_TEST_KLOG_DEAD")) (void)!write(logWrite, line, strlen(line)); + pthread_mutex_unlock(&logLock); +} + +/* Goes to the test's trace, and into the log as klog_printf would, so the + * service has to recognise and skip its own lines. */ +void c4fLog(const char *fmt, ...) +{ + char msg[1200], line[1232]; + va_list ap; + va_start(ap, fmt); vsnprintf(msg, sizeof(msg), fmt, ap); va_end(ap); + fputs(msg, stdout); + snprintf(line, sizeof(line), "[c4f] %s", msg); + if (!strchr(line, '\n')) strncat(line, "\n", sizeof(line) - strlen(line) - 1); + logLine(line); +} void c4fNotify(const char *fmt, ...) { (void)fmt; } -void c4fVdaSetWaitCallback(void (*fn)(void *), void *ctx) { waitFn = fn; waitContext = ctx; } -void c4fKlogDrain(int fd) { (void)fd; } -int c4fKlogSelfTest(int fd) { (void)fd; return getenv("C4F_TEST_KLOG_BUSY") ? -1 : 0; } -/* A klog source that only turns up later (AutoRun before GoldHEN's klog server). */ + +/* Relays the test's injected lines into the log, and kills the log when the test + * asks for it. One thread for the whole run. */ +static void *relay(void *arg) +{ + int source = *(int *)arg; + char buf[1024]; + /* The harness hands it over non-blocking; this thread can afford to wait. */ + fcntl(source, F_SETFL, fcntl(source, F_GETFL) & ~O_NONBLOCK); + for (;;) { + ssize_t n = read(source, buf, sizeof(buf) - 1); + if (n <= 0) return NULL; + buf[n] = 0; + if (strstr(buf, "C4F-TEST-CLOSE-KLOG")) { + pthread_mutex_lock(&logLock); + if (logWrite >= 0) { close(logWrite); logWrite = -1; } + pthread_mutex_unlock(&logLock); + continue; + } + logLine(buf); + } +} + int c4fKlogOpenDevice(void) { - int fds[2]; + int fds[2], fd; if (getenv("C4F_TEST_KLOG_BUSY")) { printf("KLOG none\n"); return -1; } - if (klogSource >= 0) { int fd = dup(klogSource); printf("KLOG %d\n", fd); return fd; } - if (!getenv("C4F_TEST_KLOG_LATE") || pipe(fds)) { printf("KLOG none\n"); return -1; } - fcntl(fds[0], F_SETFL, O_NONBLOCK); - printf("KLOG %d\n", fds[0]); - return fds[0]; + pthread_mutex_lock(&logLock); + if (logWrite < 0) { + /* A fresh device, the way reopening /dev/klog gives one. */ + if (logRead >= 0) close(logRead); + logRead = -1; + if (!pipe(fds)) { + fcntl(fds[0], F_SETFL, O_NONBLOCK); + fcntl(fds[1], F_SETFL, O_NONBLOCK); + logRead = fds[0]; logWrite = fds[1]; + } + } + fd = logRead >= 0 ? dup(logRead) : -1; + pthread_mutex_unlock(&logLock); + if (fd < 0) { printf("KLOG none\n"); return -1; } + printf("KLOG %d\n", fd); + return fd; } -int c4fVirtualPadAddAs(C4fVirtualPad *p, int32_t user, int32_t vdaUser, int fd) + +void c4fKlogMark(const char *marker) { - (void)fd; - for (int i = 0; i < 3; i++) { if (waitFn) waitFn(waitContext); usleep(20000); } - if (getenv("C4F_FAIL_ADD")) return -1; - memset(p, 0, sizeof(*p)); - p->handle = nextId; p->deviceId = nextId; nextId += 0x10000; - p->userId = user; p->vdaUserId = vdaUser; p->owned = 1; - printf("ADD %x %d\n", p->handle, vdaUser); + char line[128]; + snprintf(line, sizeof(line), "%s\n", marker); + logLine(line); +} + +/* The line the login manager produces for a new virtual pad, after an optional + * delay, so a test can hold a creation open and check the service stays usable. */ +static void *announce(void *arg) +{ + char line[160]; + unsigned handle = (unsigned)(uintptr_t)arg; + const char *delay = getenv("C4F_TEST_ADD_DELAY"); + if (delay) usleep((unsigned)atoi(delay) * 1000); + snprintf(line, sizeof(line), "<118>#LOGIN MGR# Receive Event : " + "SCE_MBUS_EVENT_DEVICE_ADDED [DeviceId:0x%x][type:1][subType:2]\n", handle); + logLine(line); + return NULL; +} + +int32_t c4fVirtualPadAdd(int32_t vdaUser) +{ + pthread_t thread; + unsigned handle = nextId; + nextId += 0x10000; + printf("ADD %x %d\n", handle, vdaUser); + if (getenv("C4F_FAIL_ADD")) return 0; /* created, never announced */ + if (getenv("C4F_TEST_ADD_DELAY") && + pthread_create(&thread, NULL, announce, (void *)(uintptr_t)handle) == 0) + pthread_detach(thread); + else + announce((void *)(uintptr_t)handle); return 0; } + +void c4fVirtualPadAdopt(C4fVirtualPad *p, int32_t user, int32_t vdaUser, uint64_t deviceId) +{ + memset(p, 0, sizeof(*p)); + p->deviceId = deviceId; p->handle = (int32_t)(deviceId & 0xffffffffu); + p->userId = user; p->vdaUserId = vdaUser; p->owned = 1; + printf("ADOPT %x %d\n", (unsigned)p->handle, vdaUser); +} + void c4fVirtualPadRemove(C4fVirtualPad *p) { printf("REMOVE %x\n", p->handle); p->owned = 0; } void c4fPadDataNeutral(ScePadData *p) { @@ -51,16 +154,17 @@ int32_t c4fVirtualPadInsert(const C4fVirtualPad *p, const ScePadData *d) p->handle, d->buttons, d->lx, d->ly, d->rx, d->ry, d->l2, d->r2, d->touchData.fingers); return getenv("C4F_FAIL_INPUT") && d->buttons ? -5 : 0; } + int main(void) { + static int source; const char *fd = getenv("C4F_TEST_KLOG_FD"); - int logs[2]; + pthread_t thread; + setvbuf(stdout, NULL, _IONBF, 0); - if (fd) { klogSource = atoi(fd); return c4fWebRun(-1) != 0; } - if (pipe(logs)) return 1; - fcntl(logs[0], F_SETFL, O_NONBLOCK); - klogSource = logs[0]; - int result = c4fWebRun(-1); - close(logs[1]); - return result != 0; + if (fd && (source = atoi(fd)) >= 0 && + pthread_create(&thread, NULL, relay, &source) == 0) + pthread_detach(thread); + /* As the payload does: no reader until a controller needs one. */ + return c4fWebRun(-1) != 0; }