diff --git a/CHANGELOG.md b/CHANGELOG.md index 093f087..9d64ac0 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,3 +1,12 @@ +## [0.39.5](https://github.com/sasjs/server/compare/v0.39.4...v0.39.5) (2026-07-14) + + +### Bug Fixes + +* **api:** harden mock SAS executable and timeouts for CI ([67fce47](https://github.com/sasjs/server/commit/67fce475a3c53b3c20919902edb45dce809dffb9)) +* **api:** return prompt error response instead of hanging when a SAS session fails ([f84af4a](https://github.com/sasjs/server/commit/f84af4ac0639625fee4508e764f0eed07d7b4e8a)) +* fix code.spec.ts failing on a fresh checkout (CI) ([0af6b63](https://github.com/sasjs/server/commit/0af6b63ffa770bfa2b77505d74778be517f8d631)) + ## [0.39.4](https://github.com/sasjs/server/compare/v0.39.3...v0.39.4) (2025-12-21) diff --git a/api/docs/diagrams/code-execution-overview.md b/api/docs/diagrams/code-execution-overview.md new file mode 100644 index 0000000..293138c --- /dev/null +++ b/api/docs/diagrams/code-execution-overview.md @@ -0,0 +1,38 @@ +# Code execution & session diagrams + +Mermaid diagrams describing how `@sasjs/server` executes submitted code +(SAS/JS/PY/R) against pooled "sessions". Written for fast context-loading by +an AI coding agent: each diagram is self-contained, node/edge labels carry +the actual file:line references, and prose is kept to the minimum needed to +disambiguate the diagram. + +| File | Covers | +|---|---| +| [session-lifecycle.md](session-lifecycle.md) | `SessionState` state machine; how it differs between the SAS runtime and the JS/PY/R runtimes | +| [sas-execution-handshake.md](sas-execution-handshake.md) | The SYSIN/AUTOEXEC file-swap mechanism a SAS session uses to turn one long-lived `sas` process into a single-use execution slot | +| [request-execution-flow.md](request-execution-flow.md) | End-to-end flowchart from HTTP request to response, covering session-pool acquisition and both runtime branches (SAS vs JS/PY/R) | + +## Core concept + +A "session" is not a request-scoped object. It is a pooled, reusable +execution slot with a filesystem folder (`session.path`) and a state +(`SessionState`). For the SAS runtime specifically, a session also owns one +real OS process, spawned at session-*creation* time and consumed by exactly +one code submission (see `sas-execution-handshake.md`). For JS/PY/R, a +session is just an ID + folder; the actual interpreter process is spawned +fresh per request inside `processProgram`. + +## Key source files + +- `api/src/controllers/internal/Session.ts` — session pool + lifecycle + (`SessionController`, `SASSessionController`), `SessionState` transitions. +- `api/src/controllers/internal/processProgram.ts` — writes the submitted + code into the session and drives it to completion/failure, per runtime. +- `api/src/controllers/internal/Execution.ts` — `ExecutionController`, + the entry point controllers call; acquires a session, calls + `processProgram`, reads back `log.log`/`webout.txt`/headers, builds the + HTTP response (or a `SessionExecutionError` on failure). +- `api/src/controllers/internal/create{SAS,JS,Python,R}Program.ts` — + per-runtime code templating (wraps the user's submitted code with + boilerplate: variable injection, `_webout` redirection, etc). +- `api/src/types/Session.ts` — `SessionState` enum and `Session` interface. diff --git a/api/docs/diagrams/request-execution-flow.md b/api/docs/diagrams/request-execution-flow.md new file mode 100644 index 0000000..0c6652b --- /dev/null +++ b/api/docs/diagrams/request-execution-flow.md @@ -0,0 +1,64 @@ +# Request execution flow (end-to-end) + +Full path from an inbound HTTP request to the HTTP response, covering +session-pool acquisition and the two structurally different runtime +branches: SAS (reuses a parked long-lived process) vs JS/PY/R (spawns a +fresh interpreter process per request). + +```mermaid +flowchart TD + A["HTTP request
POST /SASjsApi/code/execute
or /SASjsApi/stp/execute"] --> B["Controller
code.ts / stp.ts
try/catch wrapper"] + B --> C["ExecutionController.executeProgram
or .executeFile
Execution.ts:58-91"] + C --> D{"session already provided?
(e.g. file-upload flow)"} + D -- no --> E["getSessionController(runTime).getSession()
Session.ts:59-69"] + D -- yes --> F["use provided session"] + E --> G{"pending session
available in pool?"} + G -- yes --> H["reuse it"] + G -- no --> I["createSession()
SAS: spawns a real sas process, see
sas-execution-handshake.md
JS/PY/R: cheap - folder + id only"] + H --> J["pre-warm: if pool has fewer
than 3 pending, fire off more
createSession() calls (not awaited)
Session.ts:66"] + I --> J + F --> K + J --> K["session.state = running
Execution.ts:96"] + K --> L["write webout.txt (empty),
reqHeaders.txt
Execution.ts:103-107"] + L --> M["processProgram(...)
processProgram.ts:16-27"] + + M --> N{"runTime?"} + + N -- SAS --> O["createSASProgram():
wrap user code with _webout
filename, macro vars, autoexec"] + O --> P["write code.sas via .bkp + rename
processProgram.ts:48-49"] + P --> Q["poll: while session.state !== completed
processProgram.ts:52-58"] + Q -- "state becomes completed" --> R["resolve"] + Q -- "state becomes failed" --> S["throw Error(session.failureReason)"] + + N -- "JS / PY / R" --> T["createJSProgram / createPythonProgram /
createRProgram: wrap user code similarly"] + T --> U["write code file; spawn interpreter
fresh via execFile; pipe stdout/stderr
into a log.log write stream
processProgram.ts:108-134"] + U -- "exit 0" --> R + U -- "exit non-zero" --> S + + R --> V["read log.log, webout.txt,
stpsrv_header.txt
Execution.ts:128-131"] + V --> W["build httpHeaders + result
return ExecuteReturnRaw
Execution.ts:128-151"] + W --> X["Controller: res.send(result)
HTTP 200"] + + S --> Y["catch in Execution.ts:109-126:
read whatever log exists,
throw SessionExecutionError(message, log)"] + Y --> Z["Controller catch block
rethrow { code: 400, status: 'failure',
message, error, log }"] + Z --> AA["res.status(err.code).send(err)
HTTP 400 with complete log"] +``` + +## Notes + +- **Session pool is per-runtime.** SAS sessions and JS/PY/R sessions live in + separate controllers/pools (`process.sasSessionController` vs + `process.sessionController`, `Session.ts:239-253`) - a pending SAS session + is never handed out for a JS request or vice versa. +- **The SAS branch and the JS/PY/R branch converge** on the same + success/failure signal shape: `session.state` becomes `completed` or + `failed` either way, and both paths flow through the same log/webout + reading logic in `Execution.ts` afterward. The mechanics of *how* that + state gets set differ substantially (see `session-lifecycle.md`). +- **`includePrintOutput`** (SAS only) additionally appends `output.lst` + content to the result when debug mode is on - omitted above for brevity; + see `Execution.ts:135-142`. +- **`triggerProgram`/`triggerCode`** (fire-and-forget variants, not shown) + call the same `ExecutionController` methods without awaiting them and + immediately return `{ sessionId }`; the client polls + `GET /SASjsApi/session/{sessionId}/state` separately. diff --git a/api/docs/diagrams/sas-execution-handshake.md b/api/docs/diagrams/sas-execution-handshake.md new file mode 100644 index 0000000..22b4084 --- /dev/null +++ b/api/docs/diagrams/sas-execution-handshake.md @@ -0,0 +1,81 @@ +# SAS session execution handshake + +How one long-lived `sas` process is turned into a single-use execution slot +via a SYSIN file-swap trick. This is the mechanism specific to +`RunTimeType.SAS`; JS/PY/R sessions spawn a fresh interpreter process per +request instead (see `request-execution-flow.md`). + +```mermaid +sequenceDiagram + participant Client as HTTP client + participant Ctrl as Controller
(code.ts / stp.ts) + participant Exec as ExecutionController
(Execution.ts) + participant Pool as SASSessionController
(Session.ts) + participant FS as Filesystem
(session.path) + participant SAS as spawned "sas" process + + Note over Pool,SAS: SESSION CREATION - happens ahead of any request,
pool pre-warms up to 3 sessions (Session.ts:59-69) + Pool->>FS: createFile(code.sas, "") - empty dummy SYSIN (Session.ts:117-118) + Pool->>FS: readFile(sysInitCompiledPath) - compiled system-init
macros, produced by `npm run compileSysInit` (Session.ts:105) + Note over Pool: throws if this file doesn't exist yet -
session creation never reaches execFile below + Pool->>FS: createFile(autoexec.sas, autoExecContent) (Session.ts:108-114) + Pool->>SAS: execFile(sasLoc, -SYSIN code.sas -AUTOEXEC autoexec.sas -LOG log.log ...) (Session.ts:127-147) + activate SAS + Note right of SAS: process stays active (this box)
from spawn until it finally exits below + SAS->>FS: autoexec step 1: delete code.sas, the dummy SYSIN (Session.ts:257-261) + Pool->>FS: waitForSession() polls fileExists(code.sas) (Session.ts:175-192) + FS-->>Pool: code.sas no longer exists + Pool->>Pool: session.state = pending (Session.ts:190) + SAS->>SAS: autoexec step 2: busy-wait for code.sas to reappear,
up to 15 minutes (Session.ts:263-274) + Note over SAS: process is now idle, parked mid-autoexec,
waiting on the filesystem.
Counts as "pending" in the pool. + + Note over Client,SAS: REQUEST ARRIVES - reuses the parked process above + Client->>Ctrl: POST .../execute { code, runTime: sas } + Ctrl->>Exec: executeProgram({ program, runTime: SAS, ... }) + Exec->>Pool: getSession() returns the pending session (Session.ts:59-69) + Exec->>Exec: session.state = running (Execution.ts:96) + Exec->>FS: createFile(webout.txt, "") and createFile(reqHeaders.txt, ...) (Execution.ts:103-107) + Exec->>Pool: processProgram(program, session, ...) (Execution.ts:110-121) + Pool->>FS: createSASProgram() wraps user code with macro vars,
_webout filename, autoexec injection (createSASProgram.ts) + Pool->>FS: write code.sas.bkp, then rename to code.sas (processProgram.ts:48-49) + Note over FS: write-then-rename, not a direct write,
so SAS never reads a partial file + + FS-->>SAS: code.sas exists again + SAS->>SAS: autoexec step 2 loop exits, sleeps 0.01s, autoexec ends (Session.ts:267-271) + Note over SAS: -SYSIN has pointed at code.sas from the start,
so SAS now executes ITS CONTENT as the main job + SAS->>FS: writes log.log, output.lst, webout.txt while running + + Pool->>Pool: processProgram poll loop:
while session.state !== completed (processProgram.ts:52-58) + + alt program reaches EOF normally + SAS->>SAS: exits with code 0 + SAS-->>Pool: execFilePromise resolves - .then() (Session.ts:148-152) + Pool->>Pool: session.state = completed + Pool-->>Exec: processProgram() resolves + else program aborts (fatal error, license failure, hard STOP) + SAS->>SAS: exits with non-zero code + SAS-->>Pool: execFilePromise rejects - .catch() (Session.ts:153-163) + Pool->>Pool: session.state = failed
session.failureReason = err.toString() + Pool-->>Exec: processProgram() throws (processProgram.ts:53-55) + end + deactivate SAS + + Exec->>FS: read log.log, webout.txt, stpsrv_header.txt (Execution.ts:123, 128-131) + Exec-->>Ctrl: { httpHeaders, result }
or throws SessionExecutionError{ message, log } (Execution.ts:109-126) + Ctrl-->>Client: 200 + result
or 400 { status, message, error, log } +``` + +## Why this design + +- SAS has meaningful startup cost (loading the engine, running system init + macros). Spawning a fresh `sas` process per request would pay that cost + every time. Instead, a process is spawned once and parked, ready to run + exactly one job the moment code shows up at a path it's already watching. +- The pool (`SessionController.getSession`, `Session.ts:59-69`) keeps up to + 3 such parked processes ready, so most requests get an instant handoff + instead of waiting through the ~15-minute autoexec spin-wait or a cold + start. +- A session is single-use: once its process consumes the real SYSIN content + and exits (success or failure), that process is gone. The session object + itself is deleted later by `scheduleSessionDestroy` (`Session.ts:204-236`), + not reused for a second job. diff --git a/api/docs/diagrams/session-lifecycle.md b/api/docs/diagrams/session-lifecycle.md new file mode 100644 index 0000000..d790a5e --- /dev/null +++ b/api/docs/diagrams/session-lifecycle.md @@ -0,0 +1,70 @@ +# Session lifecycle (`SessionState`) + +Enum defined in `api/src/types/Session.ts`. A `Session` is `{ id, state, +path, creationTimeStamp, deathTimeStamp, expiresAfterMins?, failureReason? }`. +Sessions live in an in-memory array on a per-runtime singleton controller +(`process.sasSessionController` for SAS, `process.sessionController` shared +by JS/PY/R — see `getSessionController()` in `Session.ts:239-253`). + +```mermaid +stateDiagram-v2 + [*] --> initialising: SAS runtime
SASSessionController.createSession()
Session.ts:77-95 + [*] --> pending: JS/PY/R runtime, no process yet
SessionController.createSession()
Session.ts:30-57 + + initialising --> pending: dummy SYSIN file deleted
by SAS's autoexec
waitForSession(), Session.ts:175-192 + initialising --> failed: spawned SAS process exits
before handshake completes
Session.ts:153-163, 184-188 + + pending --> running: session picked for a request
executeProgram(), Execution.ts:94-96 + + running --> completed: process exits 0
SAS: Session.ts:148-152 (original process)
JS/PY/R: processProgram.ts:116-120 (fresh process) + running --> failed: process exits non-zero
SAS: Session.ts:153-163
JS/PY/R: processProgram.ts:121-131
failureReason = err.toString() + + completed --> [*]: deleteSession()
scheduleSessionDestroy(), Session.ts:194-236 + failed --> [*]: deleteSession()
scheduleSessionDestroy() + + note right of initialising + SAS only. The real sas + executable is already + running, spin-waiting + inside its AUTOEXEC for + real code to arrive. + See sas-execution-handshake.md + end note + + note right of pending + Session sits in the pool, + reusable. Pre-warmed up to + 3 pending sessions per + runtime (getSession(), + Session.ts:59-69) + end note + + note right of running + SAS: no new process spawned + here, request just feeds + code to the already-running + process. + JS/PY/R: a brand new + interpreter process is + spawned right now. + end note +``` + +## Consumers of `state` + +| Reader | Location | Watches for | +|---|---|---| +| `waitForSession` | `Session.ts:175-192` | `failed` (breaks early) or the dummy SYSIN file disappearing (implies session survived init) | +| `processProgram` (SAS branch poll loop) | `processProgram.ts:52-58` | `completed` (success exit) or `failed` (throws, carrying `session.failureReason`) | +| `scheduleSessionDestroy` | `Session.ts:204-236` | `running` (extends death timer instead of destroying) | + +## Asymmetry between runtimes + +- **SAS**: one OS process per session, spawned once at `createSession()` + time and reused for exactly one job (see `sas-execution-handshake.md`). + `running`/`completed`/`failed` are all driven by that *same* process's + eventual exit. +- **JS/PY/R**: a session is cheap (folder + id, no process). The interpreter + process is spawned fresh, per request, inside `processProgram.ts:115` and + its exit drives `completed`/`failed` directly in the same function - there + is no separate poll loop for these runtimes. diff --git a/api/src/controllers/code.ts b/api/src/controllers/code.ts index f6aaa30..37c6068 100644 --- a/api/src/controllers/code.ts +++ b/api/src/controllers/code.ts @@ -114,7 +114,8 @@ const executeCode = async ( code: 400, status: 'failure', message: 'Job execution failed.', - error: typeof err === 'object' ? err.toString() : err + error: typeof err === 'object' ? err.toString() : err, + log: err?.log } } } diff --git a/api/src/controllers/internal/Execution.ts b/api/src/controllers/internal/Execution.ts index d256275..7d5f978 100644 --- a/api/src/controllers/internal/Execution.ts +++ b/api/src/controllers/internal/Execution.ts @@ -15,6 +15,24 @@ export interface ExecutionVars { [key: string]: string | number | undefined } +// Thrown when the session itself fails (e.g. SAS exits abnormally via +// %abort;). Carries the complete log - by the time this is thrown, the +// session's process has already exited, so the log file it wrote is final, +// not a partial/truncated snapshot. +export class SessionExecutionError extends Error { + constructor( + message: string, + public log?: string + ) { + super(message) + + // required for `instanceof` to work when compiling to ES5, since the + // default __extends helper does not preserve the prototype chain for + // classes extending built-ins like Error + Object.setPrototypeOf(this, SessionExecutionError.prototype) + } +} + export interface ExecuteReturnRaw { httpHeaders: HTTPHeaders result: string | Buffer @@ -88,18 +106,24 @@ export class ExecutionController { preProgramVariables?.httpHeaders.join('\n') ?? '' ) - await processProgram( - program, - preProgramVariables, - vars, - session, - weboutPath, - headersPath, - tokenFile, - runTime, - logPath, - otherArgs - ) + try { + await processProgram( + program, + preProgramVariables, + vars, + session, + weboutPath, + headersPath, + tokenFile, + runTime, + logPath, + otherArgs + ) + } catch (err: any) { + const log = (await fileExists(logPath)) ? await readFile(logPath) : '' + + throw new SessionExecutionError(err.message, log) + } const log = (await fileExists(logPath)) ? await readFile(logPath) : '' const headersContent = (await fileExists(headersPath)) diff --git a/api/src/controllers/internal/processProgram.ts b/api/src/controllers/internal/processProgram.ts index 0557c0f..1948dde 100644 --- a/api/src/controllers/internal/processProgram.ts +++ b/api/src/controllers/internal/processProgram.ts @@ -50,6 +50,10 @@ export const processProgram = async ( // we now need to poll the session status while (session.state !== SessionState.completed) { + if (session.state === SessionState.failed) { + throw new Error(session.failureReason || 'SAS session failed') + } + await delay(50) } } else { diff --git a/api/src/controllers/internal/spec/Execution.spec.ts b/api/src/controllers/internal/spec/Execution.spec.ts index ec91cfe..e377d12 100644 --- a/api/src/controllers/internal/spec/Execution.spec.ts +++ b/api/src/controllers/internal/spec/Execution.spec.ts @@ -1,17 +1,11 @@ import path from 'path' import os from 'os' -import { deleteFolder, generateTimestamp } from '@sasjs/utils' +import { createFile, deleteFolder, generateTimestamp } from '@sasjs/utils' import * as ProcessProgramModule from '../processProgram' -import { ExecutionController } from '../Execution' +import { ExecutionController, SessionExecutionError } from '../Execution' import { Session, SessionState, PreProgramVars } from '../../../types' import { RunTimeType } from '../../../utils' -// Regression coverage: for JS/PY/R, processProgram sets session.state to -// `failed` itself (without throwing) on a non-zero interpreter exit. -// ExecutionController.executeProgram used to unconditionally overwrite -// that back to `completed` right after processProgram returned, silently -// losing the failure for anything downstream that inspects session.state. - const preProgramVariables: PreProgramVars = { username: 'testUser', userId: 1, @@ -20,7 +14,7 @@ const preProgramVariables: PreProgramVars = { httpHeaders: [] } -describe('ExecutionController.executeProgram (JS/PY/R failure path)', () => { +describe('ExecutionController.executeProgram', () => { let session: Session beforeEach(() => { @@ -39,46 +33,85 @@ describe('ExecutionController.executeProgram (JS/PY/R failure path)', () => { await deleteFolder(session.path) }) - it('does not overwrite a failed session state back to completed', async () => { - // mirrors processProgram's real JS/PY/R branch on a non-zero exit: - // it sets state/failureReason itself and resolves - it does not throw - jest - .spyOn(ProcessProgramModule, 'processProgram') - .mockImplementation(async () => { - session.state = SessionState.failed - session.failureReason = 'Error: process exited with code 1' + // Regression coverage: for JS/PY/R, processProgram sets session.state to + // `failed` itself (without throwing) on a non-zero interpreter exit. + // ExecutionController.executeProgram used to unconditionally overwrite + // that back to `completed` right after processProgram returned, silently + // losing the failure for anything downstream that inspects session.state. + describe('JS/PY/R failure path', () => { + it('does not overwrite a failed session state back to completed', async () => { + // mirrors processProgram's real JS/PY/R branch on a non-zero exit: + // it sets state/failureReason itself and resolves - it does not throw + jest + .spyOn(ProcessProgramModule, 'processProgram') + .mockImplementation(async () => { + session.state = SessionState.failed + session.failureReason = 'Error: process exited with code 1' + }) + + const controller = new ExecutionController() + + await controller.executeProgram({ + program: 'throw new Error("boom")', + preProgramVariables, + vars: {}, + session, + runTime: RunTimeType.JS }) - const controller = new ExecutionController() - - await controller.executeProgram({ - program: 'throw new Error("boom")', - preProgramVariables, - vars: {}, - session, - runTime: RunTimeType.JS + expect(session.state).toBe(SessionState.failed) }) - expect(session.state).toBe(SessionState.failed) + it('still marks a genuinely successful session as completed', async () => { + jest + .spyOn(ProcessProgramModule, 'processProgram') + .mockImplementation(async () => { + session.state = SessionState.completed + }) + + const controller = new ExecutionController() + + await controller.executeProgram({ + program: 'console.log("hello")', + preProgramVariables, + vars: {}, + session, + runTime: RunTimeType.JS + }) + + expect(session.state).toBe(SessionState.completed) + }) }) - it('still marks a genuinely successful session as completed', async () => { - jest - .spyOn(ProcessProgramModule, 'processProgram') - .mockImplementation(async () => { - session.state = SessionState.completed + describe('SAS failure path', () => { + it('throws a SessionExecutionError carrying the complete log when the session fails', async () => { + const logPath = path.join(session.path, 'log.log') + const logContent = + 'NOTE: SAS session\nERROR: SAS session terminated. See log for details.\n' + + await createFile(logPath, logContent) + + jest + .spyOn(ProcessProgramModule, 'processProgram') + .mockImplementation(async () => { + throw new Error('ERROR: SAS session terminated. See log for details.') + }) + + const controller = new ExecutionController() + + const resultPromise = controller.executeProgram({ + program: '%abort;', + preProgramVariables, + vars: {}, + session, + runTime: RunTimeType.SAS }) - const controller = new ExecutionController() - - await controller.executeProgram({ - program: 'console.log("hello")', - preProgramVariables, - vars: {}, - session, - runTime: RunTimeType.JS + await expect(resultPromise).rejects.toBeInstanceOf(SessionExecutionError) + await expect(resultPromise).rejects.toMatchObject({ + log: logContent, + message: expect.stringContaining('SAS session terminated') + }) }) - - expect(session.state).toBe(SessionState.completed) }) }) diff --git a/api/src/controllers/internal/spec/processProgram.spec.ts b/api/src/controllers/internal/spec/processProgram.spec.ts new file mode 100644 index 0000000..b1a37f3 --- /dev/null +++ b/api/src/controllers/internal/spec/processProgram.spec.ts @@ -0,0 +1,109 @@ +import path from 'path' +import os from 'os' +import { createFile, deleteFolder, generateTimestamp } from '@sasjs/utils' +import { processProgram } from '../processProgram' +import { Session, SessionState, PreProgramVars } from '../../../types' +import { + RunTimeType, + getSessionsFolder, + generateUniqueFileName +} from '../../../utils' + +const preProgramVariables: PreProgramVars = { + username: 'testUser', + userId: 1, + displayName: 'Test User', + serverUrl: 'http://localhost:5000', + httpHeaders: [] +} + +const makeSession = (): Session => { + const sessionId = generateUniqueFileName(generateTimestamp()) + const sessionFolder = path.join(getSessionsFolder(), sessionId) + const creationTimeStamp = sessionId.split('-').pop() as string + const deathTimeStamp = ( + parseInt(creationTimeStamp) + + 15 * 60 * 1000 - + 1000 + ).toString() + + return { + id: sessionId, + state: SessionState.running, + creationTimeStamp, + deathTimeStamp, + path: sessionFolder + } +} + +describe('processProgram (SAS runtime)', () => { + let session: Session + let logPath: string + let weboutPath: string + let headersPath: string + let tokenFile: string + + beforeAll(() => { + const root = path.join( + os.tmpdir(), + `sasjs-processProgram-spec-${generateTimestamp()}` + ) + process.sasjsRoot = root + process.driveLoc = path.join(root, 'drive') + }) + + beforeEach(async () => { + session = makeSession() + logPath = path.join(session.path, 'log.log') + weboutPath = path.join(session.path, 'webout.txt') + headersPath = path.join(session.path, 'stpsrv_header.txt') + tokenFile = path.join(session.path, 'reqHeaders.txt') + await createFile(weboutPath, '') + }) + + afterEach(async () => { + await deleteFolder(session.path) + }) + + it('rejects instead of hanging when the session fails (e.g. %abort;)', async () => { + setTimeout(() => { + session.state = SessionState.failed + session.failureReason = + 'ERROR: SAS session terminated. See log for details.' + }, 100) + + await expect( + processProgram( + '%abort;', + preProgramVariables, + {}, + session, + weboutPath, + headersPath, + tokenFile, + RunTimeType.SAS, + logPath + ) + ).rejects.toThrow(/SAS session terminated/) + }, 3000) + + it('resolves without throwing when the session completes normally', async () => { + setTimeout(() => { + session.state = SessionState.completed + }, 100) + + await expect( + processProgram( + '%put hello world;', + preProgramVariables, + {}, + session, + weboutPath, + headersPath, + tokenFile, + RunTimeType.SAS, + logPath + ) + ).resolves.toBeUndefined() + }, 3000) +}) diff --git a/api/src/controllers/stp.ts b/api/src/controllers/stp.ts index d1797ec..ffe2c2e 100644 --- a/api/src/controllers/stp.ts +++ b/api/src/controllers/stp.ts @@ -166,7 +166,8 @@ const execute = async ( code: 400, status: 'failure', message: 'Job execution failed.', - error: typeof err === 'object' ? err.toString() : err + error: typeof err === 'object' ? err.toString() : err, + log: err?.log } } } diff --git a/api/src/routes/api/spec/code.spec.ts b/api/src/routes/api/spec/code.spec.ts new file mode 100644 index 0000000..a65f212 --- /dev/null +++ b/api/src/routes/api/spec/code.spec.ts @@ -0,0 +1,132 @@ +import path from 'path' +import { createFile, fileExists } from '@sasjs/utils' +import { Express } from 'express' +import mongoose, { Mongoose } from 'mongoose' +import { MongoMemoryServer } from 'mongodb-memory-server' +import request from 'supertest' +import { + UserController, + PermissionController, + PermissionType, + PermissionSettingForRoute, + PrincipalType +} from '../../../controllers/' +import { + generateAccessToken, + saveTokensInDB, + RunTimeType, + sysInitCompiledPath +} from '../../../utils' + +// Real, unmocked end-to-end test of the SAS execution pipeline (session +// spawn -> autoexec handshake -> exit code -> HTTP response), using a fake +// "SAS executable" (mockSas.js) in place of a real SAS install. This is the +// regression test for issue #388: SAS code that aborts (%abort;) used to +// hang the request forever instead of returning an error response. +const mockSasPath = path.join(__dirname, 'files', 'mockSas.js') + +const clientId = 'codeSpecClientID' + +const user = { + displayName: 'Code Spec User', + username: 'codeSpecUsername', + password: '87654321', + isAdmin: false, + isActive: true +} + +let app: Express +let accessToken: string + +describe('code', () => { + let con: Mongoose + let mongoServer: MongoMemoryServer + let userController: UserController + let permissionController: PermissionController + + beforeAll(async () => { + // SASSessionController.createSession() unconditionally reads this file + // (Session.ts:105) before it ever spawns the SAS process. It's normally + // produced by `npm run compileSysInit` (part of the `initial`/`build` + // scripts), which `npm test` does not run - so on a fresh checkout + // (e.g. CI, where "Run Unit Tests" happens before "Build Package") it + // doesn't exist yet. Content is irrelevant here since mockSas.js never + // interprets it; it just needs to exist and be readable. + if (!(await fileExists(sysInitCompiledPath))) { + await createFile(sysInitCompiledPath, '') + } + + mongoServer = await MongoMemoryServer.create() + process.env.DB_CONNECT = mongoServer.getUri() + process.env.MODE = 'server' + process.env.RUN_TIMES = 'sas' + process.env.SAS_PATH = mockSasPath + + const appPromise = (await import('../../../app')).default + app = await appPromise + + con = await mongoose.connect(mongoServer.getUri()) + + userController = new UserController() + permissionController = new PermissionController() + + const dbUser = await userController.createUser(user) + accessToken = await generateAndSaveToken(dbUser.id) + + await permissionController.createPermission({ + path: '/SASjsApi/code/execute', + type: PermissionType.route, + principalType: PrincipalType.user, + principalId: dbUser.id, + setting: PermissionSettingForRoute.grant + }) + + process.runTimes = [RunTimeType.SAS] + process.sasLoc = mockSasPath + }, 30000) + + afterAll(async () => { + await con.connection.dropDatabase() + await con.connection.close() + await mongoServer.stop() + }) + + describe('execute', () => { + it('returns 200 with the mock log when the SAS program completes normally', async () => { + const response = await request(app) + .post('/SASjsApi/code/execute') + .auth(accessToken, { type: 'bearer' }) + .send({ code: '%put hello world;', runTime: 'sas' }) + .expect(200) + + expect(response.text).toEqual( + expect.stringContaining('mock SAS execution') + ) + }, 30000) + + it('returns a prompt 400 (not a hang) with the complete log when the SAS session fails (%abort;)', async () => { + const response = await request(app) + .post('/SASjsApi/code/execute') + .auth(accessToken, { type: 'bearer' }) + .send({ code: '%abort;', runTime: 'sas' }) + .expect(400) + + expect(response.body).toMatchObject({ + status: 'failure', + message: 'Job execution failed.' + }) + expect(response.body.log).toEqual( + expect.stringContaining('mock SAS execution') + ) + }, 30000) + }) +}) + +const generateAndSaveToken = async (userId: number) => { + const accessToken = generateAccessToken({ + clientId, + userId + }) + await saveTokensInDB(userId, clientId, accessToken, 'refreshToken') + return accessToken +} diff --git a/api/src/routes/api/spec/files/mockSas.js b/api/src/routes/api/spec/files/mockSas.js new file mode 100755 index 0000000..bd72833 --- /dev/null +++ b/api/src/routes/api/spec/files/mockSas.js @@ -0,0 +1,105 @@ +#!/usr/bin/env node + +// Minimal fake "SAS executable" used by tests in place of a real SAS +// install. It only fulfils the CLI/filesystem handshake contract that +// Session.ts / processProgram.ts rely on: +// +// -SYSIN the file used as a signal channel: it starts out +// containing a dummy (empty) placeholder, we delete it +// to signal "session ready", then wait for it to be +// rewritten with the real submitted program. +// -LOG where we write a fake log so downstream fileExists()/ +// readFile() calls have something to find. +// +// It does NOT interpret real SAS syntax. Exit code is the only thing that +// matters to the Node side: 0 mimics a normal SAS termination, non-zero +// mimics an abnormal one (e.g. %abort;). + +const fs = require('fs') + +const arg = (flag) => { + const idx = process.argv.indexOf(flag) + + return idx === -1 ? undefined : process.argv[idx + 1] +} + +const sysin = arg('-SYSIN') +const logPath = arg('-LOG') + +// Give up waiting for the real program after this long, so an unused +// pre-warmed session (sasjs pools up to 3 ready sessions) doesn't linger +// forever and keep a test process alive. Generous rather than tight: CI +// runners are frequently slower/more contended than a local dev machine +// (shared CPU, coverage instrumentation on the Node side slowing down the +// round trip this process is waiting on), and this cost is only ever paid +// by sessions nothing is actually waiting on - the session actually used +// by a request gets its real code written far sooner than this in practice. +const GIVE_UP_AFTER_MS = 8000 + +const sleepSync = (ms) => { + const until = Date.now() + ms + + while (Date.now() < until) { + /* busy-wait, mirroring the real autoexec's SAS-side sleep() loop */ + } +} + +// Any of the filesystem calls below can legitimately race against +// processProgram's own write-then-rename (e.g. existsSync sees the file, +// then a rename mid-flight makes the following read miss). Treat that as +// "not ready yet" and retry a few times, rather than letting an uncaught +// exception crash this process with a non-zero exit - which would be +// indistinguishable, to the Node side, from a genuine SAS failure. +const retry = (fn, attempts = 5, delayMs = 20) => { + for (let i = 0; i < attempts; i++) { + try { + return { ok: true, value: fn() } + } catch (err) { + if (i === attempts - 1) return { ok: false, error: err } + + sleepSync(delayMs) + } + } +} + +// 1. remove the dummy SYSIN, signalling "session ready" to waitForSession() +if (sysin) { + retry(() => { + if (fs.existsSync(sysin)) fs.unlinkSync(sysin) + }) +} + +// 2. wait for the real program to be written back to the same path +const deadline = Date.now() + GIVE_UP_AFTER_MS + +while (!sysin || !fs.existsSync(sysin)) { + if (Date.now() > deadline) process.exit(0) + + sleepSync(10) +} + +// small settle delay, mirroring the real autoexec's sleep(0.01,1) after +// detecting the file, so a fast-moving rename isn't read mid-write +sleepSync(50) + +const readResult = retry(() => fs.readFileSync(sysin, 'utf-8')) + +if (!readResult.ok) { + process.stderr.write( + `mockSas.js: failed to read ${sysin}: ${readResult.error}\n` + ) + process.exit(1) +} + +const code = readResult.value + +if (logPath) { + retry(() => fs.writeFileSync(logPath, `NOTE: mock SAS execution\n${code}\n`)) +} + +if (code.includes('%abort;')) { + process.stderr.write('ERROR: SAS session terminated. See log for details.\n') + process.exit(1) +} + +process.exit(0)