Runtime: improve order of state tidyups

* Runtime: move cleaning of state from expression to step 1. Moves the cleaning of state after a job expression has been executed to the step level 2. Moves tests for state cleaning to step 3. Updates step state cloning to use safe-stringify * Runtime: update job success/error log wording * Runtime: update changelog * versions --------- Co-authored-by: Farhan Yahaya <[email protected]>
OpenFn · Nov 21, 2024 · 4376f7b · 4376f7b
1 parent 6b6ff2d
commit 4376f7b
Show file tree

Hide file tree

Showing 21 changed files with 260 additions and 178 deletions.
diff --git a/integration-tests/execute/CHANGELOG.md b/integration-tests/execute/CHANGELOG.md
@@ -1,5 +1,12 @@
 # @openfn/integration-tests-execute
 
+## 1.0.8
+
+### Patch Changes
+
+- Updated dependencies [f6bd593]
+  - @openfn/runtime@1.5.2
+
 ## 1.0.7
 
 ### Patch Changes

diff --git a/integration-tests/execute/package.json b/integration-tests/execute/package.json
@@ -1,7 +1,7 @@
 {
   "name": "@openfn/integration-tests-execute",
   "private": true,
-  "version": "1.0.7",
+  "version": "1.0.8",
   "description": "Job execution tests",
   "author": "Open Function Group <[email protected]>",
   "license": "ISC",

diff --git a/integration-tests/worker/CHANGELOG.md b/integration-tests/worker/CHANGELOG.md
@@ -1,5 +1,13 @@
 # @openfn/integration-tests-worker
 
+## 1.0.66
+
+### Patch Changes
+
+- @openfn/engine-multi@1.4.2
+- @openfn/lightning-mock@2.0.23
+- @openfn/ws-worker@1.8.3
+
 ## 1.0.65
 
 ### Patch Changes

diff --git a/integration-tests/worker/package.json b/integration-tests/worker/package.json
@@ -1,7 +1,7 @@
 {
   "name": "@openfn/integration-tests-worker",
   "private": true,
-  "version": "1.0.65",
+  "version": "1.0.66",
   "description": "Lightning WOrker integration tests",
   "author": "Open Function Group <[email protected]>",
   "license": "ISC",

diff --git a/packages/cli/CHANGELOG.md b/packages/cli/CHANGELOG.md
@@ -1,5 +1,12 @@
 # @openfn/cli
 
+## 1.8.9
+
+### Patch Changes
+
+- Updated dependencies [f6bd593]
+  - @openfn/runtime@1.5.2
+
 ## 1.8.8
 
 ### Patch Changes

diff --git a/packages/cli/package.json b/packages/cli/package.json
@@ -1,6 +1,6 @@
 {
   "name": "@openfn/cli",
-  "version": "1.8.8",
+  "version": "1.8.9",
   "description": "CLI devtools for the openfn toolchain.",
   "engines": {
     "node": ">=18",

diff --git a/packages/engine-multi/CHANGELOG.md b/packages/engine-multi/CHANGELOG.md
@@ -1,5 +1,12 @@
 # engine-multi
 
+## 1.4.2
+
+### Patch Changes
+
+- Updated dependencies [f6bd593]
+  - @openfn/runtime@1.5.2
+
 ## 1.4.1
 
 ### Patch Changes

diff --git a/packages/engine-multi/package.json b/packages/engine-multi/package.json
@@ -1,6 +1,6 @@
 {
   "name": "@openfn/engine-multi",
-  "version": "1.4.1",
+  "version": "1.4.2",
   "description": "Multi-process runtime engine",
   "main": "dist/index.js",
   "type": "module",

diff --git a/packages/lightning-mock/CHANGELOG.md b/packages/lightning-mock/CHANGELOG.md
@@ -1,5 +1,13 @@
 # @openfn/lightning-mock
 
+## 2.0.23
+
+### Patch Changes
+
+- Updated dependencies [f6bd593]
+  - @openfn/runtime@1.5.2
+  - @openfn/engine-multi@1.4.2
+
 ## 2.0.22
 
 ### Patch Changes

diff --git a/packages/lightning-mock/package.json b/packages/lightning-mock/package.json
@@ -1,6 +1,6 @@
 {
   "name": "@openfn/lightning-mock",
-  "version": "2.0.22",
+  "version": "2.0.23",
   "private": true,
   "description": "A mock Lightning server",
   "main": "dist/index.js",

diff --git a/packages/runtime/CHANGELOG.md b/packages/runtime/CHANGELOG.md
@@ -1,5 +1,11 @@
 # @openfn/runtime
 
+## 1.5.2
+
+### Patch Changes
+
+- f6bd593: Move cleaning of state from expression to step, resulting in clearer logs.
+
 ## 1.5.1
 
 ### Patch Changes

diff --git a/packages/runtime/package.json b/packages/runtime/package.json
@@ -1,6 +1,6 @@
 {
   "name": "@openfn/runtime",
-  "version": "1.5.1",
+  "version": "1.5.2",
   "description": "Job processing runtime.",
   "type": "module",
   "exports": {

diff --git a/packages/runtime/src/execute/expression.ts b/packages/runtime/src/execute/expression.ts
@@ -1,5 +1,4 @@
 import { printDuration, Logger } from '@openfn/logger';
-import stringify from 'fast-safe-stringify';
 import type { Operation, State } from '@openfn/lexicon';
 
 import loadModule from '../modules/module-loader';
@@ -76,20 +75,9 @@ export default (
 
       duration = Date.now() - duration;
 
-      const finalState = prepareFinalState(
-        result,
-        logger,
-        opts.statePropsToRemove
-      );
-      // return the final state
-      resolve(finalState);
+      resolve(result);
     } catch (e: any) {
       // whatever initial state looks like now, clean it and report it back
-      const finalState = prepareFinalState(
-        input,
-        logger,
-        opts.statePropsToRemove
-      );
       duration = Date.now() - duration;
       let finalError;
       try {
@@ -103,7 +91,7 @@ export default (
         finalError = e;
       }
 
-      reject({ state: finalState, error: finalError } as ExecutionErrorWrapper);
+      reject({ state: input, error: finalError } as ExecutionErrorWrapper);
     }
   });
 
@@ -167,30 +155,3 @@ const prepareJob = async (
     return { operations: expression as Operation[] };
   }
 };
-
-// TODO this is suboptimal and may be slow on large objects
-// (especially as the result get stringified again downstream)
-const prepareFinalState = (
-  state: any,
-  logger: Logger,
-  statePropsToRemove?: string[]
-) => {
-  if (state) {
-    if (!statePropsToRemove) {
-      // As a strict default, remove the configuration key
-      // tbh this should happen higher up in the stack but it causes havoc in unit testing
-      statePropsToRemove = ['configuration'];
-    }
-
-    statePropsToRemove.forEach((prop) => {
-      if (state.hasOwnProperty(prop)) {
-        delete state[prop];
-        logger.debug(`Removed ${prop} from final state`);
-      }
-    });
-
-    const cleanState = stringify(state);
-    return JSON.parse(cleanState);
-  }
-  return state;
-};
diff --git a/packages/runtime/src/execute/step.ts b/packages/runtime/src/execute/step.ts
@@ -15,6 +15,7 @@ import {
   NOTIFY_JOB_ERROR,
   NOTIFY_JOB_START,
 } from '../events';
+import stringify from 'fast-safe-stringify';
 
 const loadCredentials = async (
   job: Job,
@@ -72,6 +73,36 @@ const calculateNext = (job: CompiledStep, result: any, logger: Logger) => {
   return next;
 };
 
+// TODO this is suboptimal and may be slow on large objects
+// (especially as the result get stringified again downstream)
+const prepareFinalState = (
+  state: any,
+  logger: Logger,
+  statePropsToRemove?: string[]
+) => {
+  if (state) {
+    if (!statePropsToRemove) {
+      // As a strict default, remove the configuration key
+      // tbh this should happen higher up in the stack but it causes havoc in unit testing
+      statePropsToRemove = ['configuration'];
+    }
+
+    const removedProps: string[] = [];
+    statePropsToRemove.forEach((prop) => {
+      if (state.hasOwnProperty(prop)) {
+        delete state[prop];
+        removedProps.push(prop);
+      }
+    });
+    logger.debug(
+      `Cleaning up state. Removing keys: ${removedProps.join(', ')}`
+    );
+
+    const cleanState = stringify(state);
+    return JSON.parse(cleanState);
+  }
+  return state;
+};
 // The job handler is responsible for preparing the job
 // and working out where to go next
 // it'll resolve credentials and state and notify how long init took
@@ -138,13 +169,16 @@ const executeStep = async (
     } catch (e: any) {
       didError = true;
       if (e.hasOwnProperty('error') && e.hasOwnProperty('state')) {
-        const { error, state } = e as ExecutionErrorWrapper;
+        const { error, state: errState } = e as ExecutionErrorWrapper;
+        let state = errState;
 
+        const duration = logger.timer(timerId);
+        logger.error(`${jobName} aborted with error (${duration})`);
+
+        state = prepareFinalState(state, logger, ctx.opts.statePropsToRemove);
         // Whatever the final state was, save that as the intial state to the next thing
         result = state;
 
-        const duration = logger.timer(timerId);
-        logger.error(`Failed step ${jobName} after ${duration}`);
         report(state, jobId, error);
 
         next = calculateNext(step, result, logger);
@@ -169,7 +203,8 @@ const executeStep = async (
 
     if (!didError) {
       const humanDuration = logger.timer(timerId);
-      logger.success(`Completed step ${jobName} in ${humanDuration}`);
+      logger.success(`${jobName} completed in ${humanDuration}ms`);
+      result = prepareFinalState(result, logger, ctx.opts.statePropsToRemove);
 
       // Take a memory snapshot
       // IMPORTANT: this runs _after_ the state object has been serialized

diff --git a/packages/runtime/src/util/clone.ts b/packages/runtime/src/util/clone.ts
@@ -1,5 +1,6 @@
 import type { State } from '@openfn/lexicon';
+import stringify from 'fast-safe-stringify';
 
 // TODO I'm in the market for the best solution here - immer? deep-clone?
 // What should we do if functions are in the state?
-export default (state: State) => JSON.parse(JSON.stringify(state));
+export default (state: State) => JSON.parse(stringify(state));