diff --git a/api/docs/diagrams/code-execution-overview.md b/api/docs/diagrams/code-execution-overview.md index 293138c..c69d6b9 100644 --- a/api/docs/diagrams/code-execution-overview.md +++ b/api/docs/diagrams/code-execution-overview.md @@ -30,8 +30,9 @@ fresh per request inside `processProgram`. 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). + `processProgram`, reads back `log.log`/`webout.txt`/headers, and builds + the HTTP response. A failed session (any runtime) is embedded in that + same response, not thrown as a separate error. - `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). diff --git a/api/docs/diagrams/request-execution-flow.md b/api/docs/diagrams/request-execution-flow.md index 0c6652b..2f3d736 100644 --- a/api/docs/diagrams/request-execution-flow.md +++ b/api/docs/diagrams/request-execution-flow.md @@ -8,7 +8,7 @@ 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"] + B --> C["ExecutionController.executeProgram
or .executeFile
Execution.ts:40-77"] 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"] @@ -18,30 +18,28 @@ flowchart TD 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"] + J --> K["session.state = running
Execution.ts:78"] + K --> L["write webout.txt (empty),
reqHeaders.txt
Execution.ts:85-89"] + L --> M["processProgram(...)
Execution.ts:96-107"] 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)"] + P --> Q["poll: while state !== completed
AND state !== failed
processProgram.ts:58-63"] + Q --> R["processProgram() resolves either way -
state was set by the session's own
process exit handler in Session.ts,
see sas-execution-handshake.md"] 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 + T --> U["write code file; spawn interpreter
fresh via execFile; pipe stdout/stderr
into a log.log write stream
processProgram.ts:117-124"] + U -- "exit 0" --> Uc["session.state = completed
processProgram.ts:126"] + U -- "exit non-zero" --> Uf["session.state = failed
session.failureReason = err.toString()
processProgram.ts:131-133"] + Uc --> R + Uf --> R - 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"] + R --> V["read log.log, webout.txt,
stpsrv_header.txt
Execution.ts:109-113, 121-125"] + V --> W["guard: if state !== failed,
set state = completed
(don't overwrite a failed session)
Execution.ts:127-137"] + W --> X["build httpHeaders + result;
embed log in result if
isDebugOn(vars) or
session.failureReason is set
Execution.ts:139-164"] + X --> Y["Controller: res.send(result)
HTTP 200
(log embedded if the session failed -
same shape as a successful run)"] ``` ## Notes @@ -55,9 +53,16 @@ flowchart TD `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`). +- **A failed session never throws.** `processProgram()` resolves normally + whether the session completed or failed - a failed session (e.g. SAS + `%abort;`, or a non-zero JS/PY/R exit) is a normal outcome of running + arbitrary user code, not a request-shape/server problem. There is no + separate error path: the same `Execution.ts:139-164` logic that embeds + the log for a debug-mode successful run also embeds it when + `session.failureReason` is set, and the controller always responds 200. - **`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`. + see `Execution.ts:149-156`. - **`triggerProgram`/`triggerCode`** (fire-and-forget variants, not shown) call the same `ExecutionController` methods without awaiting them and immediately return `{ sessionId }`; the client polls diff --git a/api/docs/diagrams/sas-execution-handshake.md b/api/docs/diagrams/sas-execution-handshake.md index 22b4084..aacae17 100644 --- a/api/docs/diagrams/sas-execution-handshake.md +++ b/api/docs/diagrams/sas-execution-handshake.md @@ -33,9 +33,9 @@ sequenceDiagram 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) + Exec->>Exec: session.state = running (Execution.ts:78) + Exec->>FS: createFile(webout.txt, "") and createFile(reqHeaders.txt, ...) (Execution.ts:85-89) + Exec->>Pool: processProgram(program, session, ...) (Execution.ts:96-107) 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 @@ -45,24 +45,24 @@ sequenceDiagram 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) + Pool->>Pool: processProgram poll loop:
while state !== completed AND state !== failed (processProgram.ts:58-63) 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) + else program aborts (e.g. %abort, 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 + Note over Pool,Exec: either way processProgram() just RESOLVES here -
a failed session is a normal outcome of running user
code, not a request-shape/server problem, so it never throws
(processProgram.ts:58-63, same as the JS/PY/R branch below) - 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 } + Exec->>FS: read log.log, webout.txt, stpsrv_header.txt (Execution.ts:109-112, 121-125) + Note over Exec: if session.failureReason is set, the log is folded into
result the same way isDebugOn(vars) already does for a
successful run - no separate error shape (Execution.ts:158-164) + Exec-->>Ctrl: { httpHeaders, result } + Ctrl-->>Client: 200 + result
(log embedded in result if the session failed) ``` ## Why this design diff --git a/api/docs/diagrams/session-lifecycle.md b/api/docs/diagrams/session-lifecycle.md index d790a5e..93aad1f 100644 --- a/api/docs/diagrams/session-lifecycle.md +++ b/api/docs/diagrams/session-lifecycle.md @@ -14,10 +14,10 @@ stateDiagram-v2 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 + pending --> running: session picked for a request
executeProgram(), Execution.ts:76-78 - 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() + running --> completed: process exits 0
SAS: Session.ts:148-152 (original process)
JS/PY/R: processProgram.ts:124-129 (fresh process) + running --> failed: process exits non-zero
SAS: Session.ts:153-163
JS/PY/R: processProgram.ts:130-135
failureReason = err.toString()
neither branch throws - see request-execution-flow.md completed --> [*]: deleteSession()
scheduleSessionDestroy(), Session.ts:194-236 failed --> [*]: deleteSession()
scheduleSessionDestroy() @@ -55,7 +55,7 @@ stateDiagram-v2 | 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`) | +| `processProgram` (SAS branch poll loop) | `processProgram.ts:58-63` | `completed` or `failed` - either just stops the loop and returns normally; `failed` does **not** throw. `Execution.ts` reads `session.failureReason` afterward to fold the log into a normal (200) result, same as it already does for JS/PY/R. | | `scheduleSessionDestroy` | `Session.ts:204-236` | `running` (extends death timer instead of destroying) | ## Asymmetry between runtimes @@ -65,6 +65,13 @@ stateDiagram-v2 `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 + process is spawned fresh, per request, inside `processProgram.ts:124` and its exit drives `completed`/`failed` directly in the same function - there - is no separate poll loop for these runtimes. + is no separate poll loop for these runtimes (SAS needs one because it's + polling a state change happening in a process spawned earlier, at session + creation; JS/PY/R just `await` the process they spawn right there). +- **Both runtimes resolve `processProgram()` normally on `failed`, they + never throw for it** - a failed session (any runtime) is a normal outcome + of running arbitrary user code, not a request-shape/server problem. See + `request-execution-flow.md` for how `Execution.ts` turns that into a + response. diff --git a/api/src/controllers/code.ts b/api/src/controllers/code.ts index 37c6068..f6aaa30 100644 --- a/api/src/controllers/code.ts +++ b/api/src/controllers/code.ts @@ -114,8 +114,7 @@ const executeCode = async ( code: 400, status: 'failure', message: 'Job execution failed.', - error: typeof err === 'object' ? err.toString() : err, - log: err?.log + error: typeof err === 'object' ? err.toString() : err } } } diff --git a/api/src/controllers/internal/Execution.ts b/api/src/controllers/internal/Execution.ts index 7d5f978..7513814 100644 --- a/api/src/controllers/internal/Execution.ts +++ b/api/src/controllers/internal/Execution.ts @@ -15,24 +15,6 @@ 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 @@ -106,24 +88,23 @@ export class ExecutionController { preProgramVariables?.httpHeaders.join('\n') ?? '' ) - 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) - } + // A failed session (e.g. SAS via %abort;, or a non-zero JS/PY/R exit) + // is a normal outcome of running arbitrary user code, not a + // request-shape/server problem - processProgram resolves rather than + // throwing in that case, and the session.failureReason check below + // folds the log into the same result shape a successful run returns. + await processProgram( + program, + preProgramVariables, + vars, + session, + weboutPath, + headersPath, + tokenFile, + runTime, + logPath, + otherArgs + ) 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 1948dde..dce96aa 100644 --- a/api/src/controllers/internal/processProgram.ts +++ b/api/src/controllers/internal/processProgram.ts @@ -48,12 +48,17 @@ export const processProgram = async ( await createFile(codePath + '.bkp', program) await moveFile(codePath + '.bkp', codePath) - // 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') - } - + // we now need to poll the session status. A failed session (e.g. from + // %abort;) is not a request-shape/server problem - it's a normal + // outcome of running arbitrary user code, same as a SAS ERROR: in the + // log without %abort;. So we just stop polling rather than throwing; + // Execution.ts already knows how to turn session.failureReason into a + // 200 response with the log embedded, matching how JS/PY/R (the else + // branch below) has always handled a failed session. + while ( + session.state !== SessionState.completed && + session.state !== SessionState.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 e377d12..61a28c8 100644 --- a/api/src/controllers/internal/spec/Execution.spec.ts +++ b/api/src/controllers/internal/spec/Execution.spec.ts @@ -2,7 +2,7 @@ import path from 'path' import os from 'os' import { createFile, deleteFolder, generateTimestamp } from '@sasjs/utils' import * as ProcessProgramModule from '../processProgram' -import { ExecutionController, SessionExecutionError } from '../Execution' +import { ExecutionController } from '../Execution' import { Session, SessionState, PreProgramVars } from '../../../types' import { RunTimeType } from '../../../utils' @@ -83,8 +83,15 @@ describe('ExecutionController.executeProgram', () => { }) }) + // A failed SAS session (e.g. from %abort;) is a normal outcome of + // running arbitrary user code, not a request-shape/server problem - the + // same way a plain SAS ERROR: in the log (without %abort;) already + // returns 200 with the log embedded. This mirrors the JS/PY/R failure + // path above: resolve normally, don't throw, and let the existing + // session.failureReason check below produce the same result shape as a + // successful run. describe('SAS failure path', () => { - it('throws a SessionExecutionError carrying the complete log when the session fails', async () => { + it('returns the complete log embedded in a normal result instead of throwing, 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' @@ -94,12 +101,17 @@ describe('ExecutionController.executeProgram', () => { jest .spyOn(ProcessProgramModule, 'processProgram') .mockImplementation(async () => { - throw new Error('ERROR: SAS session terminated. See log for details.') + // mirrors the real SAS branch after the fix: sets + // state/failureReason and resolves, exactly like the JS/PY/R + // branch already does - it does not throw + session.state = SessionState.failed + session.failureReason = + 'ERROR: SAS session terminated. See log for details.' }) const controller = new ExecutionController() - const resultPromise = controller.executeProgram({ + const { result } = await controller.executeProgram({ program: '%abort;', preProgramVariables, vars: {}, @@ -107,11 +119,8 @@ describe('ExecutionController.executeProgram', () => { runTime: RunTimeType.SAS }) - await expect(resultPromise).rejects.toBeInstanceOf(SessionExecutionError) - await expect(resultPromise).rejects.toMatchObject({ - log: logContent, - message: expect.stringContaining('SAS session terminated') - }) + expect(session.state).toBe(SessionState.failed) + expect(result).toEqual(expect.stringContaining(logContent)) }) }) }) diff --git a/api/src/controllers/internal/spec/processProgram.spec.ts b/api/src/controllers/internal/spec/processProgram.spec.ts index b1a37f3..f1bd390 100644 --- a/api/src/controllers/internal/spec/processProgram.spec.ts +++ b/api/src/controllers/internal/spec/processProgram.spec.ts @@ -65,7 +65,13 @@ describe('processProgram (SAS runtime)', () => { await deleteFolder(session.path) }) - it('rejects instead of hanging when the session fails (e.g. %abort;)', async () => { + it('resolves instead of hanging when the session fails (e.g. %abort;)', async () => { + // mirrors the JS/PY/R branch below: a session failure is a normal + // outcome of running arbitrary user code (like a SAS ERROR: in the + // log without %abort;), not a server-side/request-shape problem - so + // processProgram must not throw here, just stop polling. Execution.ts + // is responsible for turning session.failureReason into a 200 response + // with the log embedded, the same way it already does for JS/PY/R. setTimeout(() => { session.state = SessionState.failed session.failureReason = @@ -84,7 +90,7 @@ describe('processProgram (SAS runtime)', () => { RunTimeType.SAS, logPath ) - ).rejects.toThrow(/SAS session terminated/) + ).resolves.toBeUndefined() }, 3000) it('resolves without throwing when the session completes normally', async () => { diff --git a/api/src/controllers/stp.ts b/api/src/controllers/stp.ts index ffe2c2e..d1797ec 100644 --- a/api/src/controllers/stp.ts +++ b/api/src/controllers/stp.ts @@ -166,8 +166,7 @@ const execute = async ( code: 400, status: 'failure', message: 'Job execution failed.', - error: typeof err === 'object' ? err.toString() : err, - log: err?.log + error: typeof err === 'object' ? err.toString() : err } } } diff --git a/api/src/routes/api/spec/code.spec.ts b/api/src/routes/api/spec/code.spec.ts index a65f212..485817e 100644 --- a/api/src/routes/api/spec/code.spec.ts +++ b/api/src/routes/api/spec/code.spec.ts @@ -104,20 +104,26 @@ describe('code', () => { ) }, 30000) - it('returns a prompt 400 (not a hang) with the complete log when the SAS session fails (%abort;)', async () => { + // A failed SAS session (e.g. %abort;) is a normal outcome of running + // arbitrary user code, not a request-shape/server problem - the HTTP + // request itself was fine, so this must respond exactly like a + // successful run (200, same body shape, no hang), with the log simply + // reflecting what happened. Regression test for #388's follow-up: the + // original #388 fix stopped the hang but over-corrected into a 400 + // with a bespoke error shape, which broke Studio's log-tab rendering. + it('returns 200 with the same shape as a successful run when the SAS session fails (%abort;), not a hang or an error shape', async () => { const response = await request(app) .post('/SASjsApi/code/execute') .auth(accessToken, { type: 'bearer' }) .send({ code: '%abort;', runTime: 'sas' }) - .expect(400) + .expect(200) - expect(response.body).toMatchObject({ - status: 'failure', - message: 'Job execution failed.' - }) - expect(response.body.log).toEqual( + expect(response.text).toEqual( expect.stringContaining('mock SAS execution') ) + expect(response.text).toEqual( + expect.stringContaining('SAS session terminated') + ) }, 30000) }) }) diff --git a/api/src/routes/api/spec/files/mockSas.js b/api/src/routes/api/spec/files/mockSas.js index bd72833..1f4587d 100755 --- a/api/src/routes/api/spec/files/mockSas.js +++ b/api/src/routes/api/spec/files/mockSas.js @@ -93,11 +93,19 @@ if (!readResult.ok) { const code = readResult.value +// real SAS writes errors/aborts directly into the log file itself, not +// just to stderr - mirror that so tests asserting on log content (what +// the API actually returns to the caller) are meaningful +const isAbort = code.includes('%abort;') +const logContent = isAbort + ? `NOTE: mock SAS execution\n${code}\nERROR: SAS session terminated. See log for details.\n` + : `NOTE: mock SAS execution\n${code}\n` + if (logPath) { - retry(() => fs.writeFileSync(logPath, `NOTE: mock SAS execution\n${code}\n`)) + retry(() => fs.writeFileSync(logPath, logContent)) } -if (code.includes('%abort;')) { +if (isAbort) { process.stderr.write('ERROR: SAS session terminated. See log for details.\n') process.exit(1) }