Log start and end of repochecker checks with user, repo and time needed

[Apollon77]

Users get 504 responses from /api/repochecker/ while the server logs look fine. The nginx proxy log shows upstream timed out ... while reading response header from upstream, which means a check took longer than the proxy's read timeout (60s by default). Until now the backend didn't log when a check started or how long it took, so this couldn't be seen from the server side.

Changes

Each check gets an id and logs these lines:

Repochecker #12 by someuser for "https://github.com/owner/ioBroker.x" requested (running: 1, queued: 0)
Repochecker #12 by someuser for "https://github.com/owner/ioBroker.x" started after 8.3s in queue
Repochecker #12 by someuser for "https://github.com/owner/ioBroker.x" finished with status 200 (2 errors, 5 warnings), time needed 71.9s (queued 8.3s, checking 63.6s)

• If the check throws, the last line is ... failed, time needed Xs instead. The error itself and the token are still never logged.
• If the client or the proxy closes the connection before the result is sent, which is what happens on a proxy timeout, a warning is logged: ... connection closed by client or proxy after 60.0s, before the result was sent.
• The user name comes from the existing getGitHubLogin in api/user.ts, which is now exported. It caches the token-to-login lookup for an hour. If the lookup fails, the log shows unknown and the check still runs.
• The branch is added to the log when it's given. URL and branch are JSON-quoted, so a crafted query string can't inject fake log lines.

Tests

npm test in express/backend: 8/8 pass. The new tests cover the requested, started and finished lines and the warning when the connection is closed early. The existing tests now use a mocked login lookup, so they make no GitHub requests.

🤖 Generated with Claude Code

https://claude.ai/code/session_01BSR3invYVCrhJk7Swpp9qn

---

Generated by Claude Code

[Copilot]

🟡 Changes recommended

The login lookup creates an unbounded-queue race and can miss disconnect events.

5 open findings

• Queue admission is non-atomic across asynchronous login lookup · New
• Register disconnect listener before asynchronous login lookup · New
• Use singular labels for counts of one · New
• Measure queue duration from actual queue entry · New
• Update test to expect singular warning label · New

What changed in this PR

Adds lifecycle logging to diagnose slow repository checks and proxy timeouts.

Changes:

• Logs check identity, queue/check duration, result, and disconnects.
• Resolves and caches GitHub usernames for logs.
• Adds logging and disconnect tests.

File	Description
express/​backend/​src/​api/​repochecker.ts	Implements lifecycle logging and timing.
express/​backend/​src/​api/​user.ts	Exports GitHub login resolution.
express/​backend/​test/​repochecker.test.js	Tests logging and early disconnects.

🧠 Review effort: Balanced

---

💡 Add a code-review agent skill or configure MCP servers for context-aware, tailored reviews. Learn more in the docs.

[Copilot]

🔵 Needs a closer look

The logged running and queued counts omit the current request, making the new telemetry inaccurate.

0 open findings

5 resolved since last review

• Queue admission is non-atomic across asynchronous login lookup
• Register disconnect listener before asynchronous login lookup
• Update test to expect singular warning label
• Measure queue duration from actual queue entry
• Use singular labels for counts of one

Previously missed (1)

In code that hasn't changed since last review

Queue telemetry snapshot omits the newly admitted request

express/​backend/​src/​api/​repochecker.ts:119

The queue snapshot excludes the request being logged because it is captured before withCheckSlot() increments runningChecks or appends to waitingChecks. Consequently, the first accepted check reports running: 0, queued: 0, and every queued check under-reports the queue by one, contradicting the advertised telemetry and making the capacity logs misleading. Include the newly admitted request in this snapshot.

🧠 Review effort: Balanced