fix(logs): send requireLog, the command that actually streams logs

README.md

@@ -101,8 +101,9 @@ iob-sync logs garage           # only lines mentioning "garage"
 iob-sync logs --level error    # only failures
 ```
 
-If `logs` shows nothing, that is usually the adapter's own log level rather than a fault
-— see [TROUBLESHOOTING.md](docs/TROUBLESHOOTING.md).
+If `logs` shows nothing at `info` and above while scripts are demonstrably running, that
+is a bug and not your instance — see [TROUBLESHOOTING.md](docs/TROUBLESHOOTING.md).
+Missing `debug` lines specifically are usually the adapter's own log level.
 
 ## Commands
 

docs/TROUBLESHOOTING.md

@@ -41,7 +41,14 @@ other tools happy, regenerate the certificate on the instance and then run
 
 ## `logs` prints the banner and nothing else
 
-It is streaming; there is simply nothing to show. Two things surprise people:
+**First: if you are on a version before the `requireLog` fix, this is a bug and no amount
+of adapter configuration will help.** `subscribeLog` used to send `subscribe(['log'])`.
+Admin's generic `subscribe` takes a _state id pattern_, so that asked to watch states
+named `log`, of which there are none — accepted, acknowledged, and silent forever. The
+wire command is `requireLog`. Upgrade; nothing about your instance is wrong.
+
+That bug was originally misdiagnosed as the two entries below, which are both real but
+were not the cause. If you are current and still see silence, they are what to check:
 
 - **`--level` only narrows what the server already sends.** An ioBroker adapter emits
   nothing below _its own_ configured log level, so asking for `--level debug` while
@@ -52,7 +59,9 @@ It is streaming; there is simply nothing to show. Two things surprise people:
   worked. Your own `log()` calls are info-level and do appear.
 
 To prove the stream is alive, run `iob-sync logs` and then any `iob-sync` command in a
-second terminal: Admin logs every connection at info, so a line appears immediately.
+second terminal: Admin logs every connection at info, so a line appears immediately. Note
+that this check is what _should_ have caught the `requireLog` bug and did not — treat a
+silent result from it as the client being broken, not as the house being quiet.
 
 ## Every script shows `Cannot find name 'log'`
 

src/client/socket.ts

@@ -347,19 +347,29 @@ export class AdminSocketClient implements SocketClient {
   /**
    * Subscribes to the server log stream.
    *
-   * The wire command is the generic `subscribe` with the literal type `log` — not a
-   * `subscribeLog` of its own. Server-side that flips `requireLog(true)` on the
-   * adapter, after which log lines arrive as ordinary `[0, null, "log", [entry]]`
-   * message frames.
+   * The wire command is `requireLog`, which is its own command and not a variant of
+   * `subscribe`. Admin's generic `subscribe` takes a *state* id pattern, so
+   * `subscribe(['log'])` is a well-formed request to watch states named `log` — of
+   * which there are none. It is accepted, it acknowledges, and it delivers nothing
+   * for the rest of time.
+   *
+   * That is exactly what it did. This was misdiagnosed once already as "the house was
+   * simply quiet" (see the docs note about adapter log levels, which is true and was
+   * not the cause), and the cost of the wrong conclusion was a whole debugging session
+   * spent on the instance rather than the client. Verified against the live instance
+   * on 2026-08-30: `requireLog([true])` delivers `javascript.*` lines within a second
+   * of a script restart, `subscribe(['log'])` delivers nothing across 25 s.
+   *
+   * Once enabled, lines arrive as ordinary `[0, <id>, "log", [entry]]` message frames.
    */
   async subscribeLog(handler: LogHandler): Promise<void> {
     this.logHandlers.push(handler);
-    await this.emit('subscribe', ['log']);
+    await this.emit('requireLog', [true]);
   }
 
   async unsubscribeLog(): Promise<void> {
     this.logHandlers.length = 0;
-    await this.emit('unsubscribe', ['log']);
+    await this.emit('requireLog', [false]);
   }
 
   private handleCallback(id: number, args: unknown[] | undefined): void {

test/commands-logs.test.ts

@@ -49,20 +49,48 @@ describe('logs', () => {
     project = await makeTempProject();
   });
 
-  it('asks the server for the log stream', async () => {
+  /**
+   * The wire command, pinned deliberately.
+   *
+   * This used to assert `subscribe:log` and passed, because the fake broadcast log
+   * frames to every connection regardless. Against the real Admin, `subscribe` takes a
+   * state id pattern — so the client was asking to watch states named `log`, getting an
+   * acknowledgement, and receiving nothing ever. Verified on the live instance
+   * 2026-08-30. Assert the command, not just that lines arrive, or a fake that is too
+   * generous hides the bug again.
+   */
+  it('asks the server for the log stream with requireLog', async () => {
     const t = await makeContext(port, project);
     const handle = await logs(t.ctx);
     try {
       assert.ok(
-        server.subscriptionRequests.includes('subscribe:log'),
-        `expected a log subscription, got ${JSON.stringify(server.subscriptionRequests)}`,
+        server.logRequests.includes('requireLog:true'),
+        `expected requireLog(true), got ${JSON.stringify(server.logRequests)}`,
+      );
+      assert.ok(
+        !server.subscriptionRequests.includes('subscribe:log'),
+        'subscribe(["log"]) is a state pattern and never delivers logs — do not send it',
       );
     } finally {
       await handle.stop();
       await t.close();
     }
   });
 
+  it('turns the log stream off again when stopped', async () => {
+    const t = await makeContext(port, project);
+    const handle = await logs(t.ctx);
+    await handle.stop();
+    try {
+      assert.ok(
+        server.logRequests.includes('requireLog:false'),
+        `expected requireLog(false) on stop, got ${JSON.stringify(server.logRequests)}`,
+      );
+    } finally {
+      await t.close();
+    }
+  });
+
   it('prints a log line as it arrives', async () => {
     const t = await makeContext(port, project);
     const handle = await logs(t.ctx);

test/fake-server.ts

@@ -164,6 +164,17 @@ export class FakeAdminServer {
   private wss: WebSocket.Server | null = null;
   private httpServer: http.Server | null = null;
   private readonly sockets = new Set<WebSocket>();
+  /**
+   * Sockets that have asked for logs with `requireLog(true)`.
+   *
+   * The fake used to broadcast log frames to every connection, which is why it happily
+   * agreed with a client that sent `subscribe(['log'])` — a command the real Admin
+   * accepts as a *state* pattern and then never acts on. The suite passed for months
+   * against a fake that shared the client's misunderstanding. Gating delivery here is
+   * the whole point: it is what makes the wire command a tested contract instead of a
+   * comment.
+   */
+  private readonly logSubscribers = new Set<WebSocket>();
   private readonly objects = new Map<string, IoBrokerObject>();
   /**
    * State *values*, stored independently of `objects` — which is the entire point.
@@ -187,6 +198,9 @@ export class FakeAdminServer {
   /** Generic `subscribe`/`unsubscribe` calls, e.g. `subscribe:log`. */
   readonly subscriptionRequests: string[] = [];
 
+  /** Every `requireLog` call, as `requireLog:true` / `requireLog:false`. */
+  readonly logRequests: string[] = [];
+
   /** Delay before sending `___ready___` after connect, in ms. */
   readyDelayMs = 0;
 
@@ -256,6 +270,7 @@ export class FakeAdminServer {
 
         ws.on('close', () => {
           this.sockets.delete(ws);
+          this.logSubscribers.delete(ws);
         });
 
         const sendReady = () => {
@@ -442,6 +457,11 @@ export class FakeAdminServer {
     this.requireCookieOnSocket = false;
     this.httpRequests.length = 0;
     this.subscriptionRequests.length = 0;
+    this.logRequests.length = 0;
+    // Not the socket set itself: `reset` runs between tests while connections from the
+    // previous one may still be closing, and dropping them here would be a different
+    // kind of lie. Only the recorded intent is cleared.
+    this.logSubscribers.clear();
   }
 
   getObject(id: string): IoBrokerObject | null {
@@ -454,8 +474,10 @@ export class FakeAdminServer {
 
   /** Broadcast an objectChange message to all connected clients (bypassing storage). */
   /**
-   * Pushes a log line to every connected client, as the real server does after a
-   * `subscribe(['log'])`. Shape mirrors ioBroker's log objects.
+   * Pushes a log line to every client that asked for logs with `requireLog(true)`,
+   * as the real server does. Shape mirrors ioBroker's log objects.
+   *
+   * A client that never sent `requireLog` receives nothing — see `logSubscribers`.
    */
   emitLog(entry: { message: string; severity?: string; from?: string; ts?: number }): void {
     const payload = {
@@ -464,7 +486,7 @@ export class FakeAdminServer {
       from: entry.from ?? 'javascript.0',
       ts: entry.ts ?? Date.now(),
     };
-    for (const ws of this.sockets) {
+    for (const ws of this.logSubscribers) {
       if (ws.readyState === WebSocket.OPEN) {
         ws.send(JSON.stringify([0, null, 'log', [payload]]));
       }
@@ -657,14 +679,29 @@ export class FakeAdminServer {
 
       case 'subscribe':
       case 'unsubscribe': {
-        // The generic subscribe, used with the literal type 'log'. Recorded so a
-        // test can assert the client asked for logs before expecting any.
+        // The generic subscribe. In the real Admin this takes a *state id pattern*,
+        // so `subscribe(['log'])` is a request to watch states named `log` — accepted,
+        // acknowledged, and silent forever. Recorded, but deliberately does not enable
+        // log delivery: that is the bug this fake now refuses to reproduce.
         const [what] = (args as string[]) ?? [];
         this.subscriptionRequests.push(`${name}:${what}`);
         this.reply(ws, id, null, null);
         return;
       }
 
+      case 'requireLog': {
+        // The actual log command. Only this turns the stream on.
+        const [enabled] = (args as [boolean]) ?? [false];
+        this.logRequests.push(`requireLog:${enabled}`);
+        if (enabled) {
+          this.logSubscribers.add(ws);
+        } else {
+          this.logSubscribers.delete(ws);
+        }
+        this.reply(ws, id, null, null);
+        return;
+      }
+
       default: {
         this.reply(ws, id, `Unknown command: ${name}`, null);
         return;