Context storage - Unhandled promise rejection

#1

I wanted to share an initialization issue with node_RED and how it has been recovered.

Issue:

14 Oct 10:56:45 - [info] Node-RED version: v0.19.1
14 Oct 10:56:45 - [info] Node.js  version: v8.11.1
14 Oct 10:56:45 - [info] Windows_NT 10.0.17134 x64 LE
14 Oct 10:56:47 - [info] Loading palette nodes
14 Oct 10:57:00 - [warn] rpi-gpio : Raspberry Pi specific node set inactive
14 Oct 10:57:10 - [info] Dashboard version 2.9.4 started at /ui
14 Oct 10:57:12 - [info] Settings file  : \Users\OCM\.node-red\settings.js
14 Oct 10:57:12 - [info] HTTP Static    : C:\Users\OCM\.node-red\projects
14 Oct 10:57:12 - [info] Context store  : 'default' [module=localfilesystem]
14 Oct 10:57:12 - [info] Context store  : 'memoryOnly' [module=memory]
14 Oct 10:57:12 - [info] Server now running at http://127.0.0.1:1880/
(node:2904) UnhandledPromiseRejectionWarning: SyntaxError: Unexpected token u in JSON at position 0
    at JSON.parse (<anonymous>)
    at C:\Users\OCM\AppData\Roaming\npm\node_modules\node-red\red\runtime\nodes\context\localfilesystem.js:166:40
    at Array.forEach (<anonymous>)
    at C:\Users\OCM\AppData\Roaming\npm\node_modules\node-red\red\runtime\nodes\context\localfilesystem.js:165:20
    at <anonymous>
(node:2904) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). (rejection id: 2)
(node:2904) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code.

Similar issue has been reported before here and here.

My remarks:

1- I just applied the solution from @hotNipi (edited settings.js and removed lines shown below). I was able to recover the runtime and access the flows:

,
    contextStorage: {
        default: {
            module: "localfilesystem"
        },
        memoryOnly: {
            module: "memory"
        }
     }

2- Context storage always worked nicely for me since day 1 from using version 0.19, so my guess was some flow causing the issue. The problem is that I tested many things last night and I was not sure what was the last active project and last flow tested. The initialization log was showing Server now running at http://127.0.0.1:1880/ but there was no active project.

3- As far as I could recall (barely) the last flow I tested was one taken from stackoverflow that uses jsonata to read flow context variables. That flow is very simple, the main part is a change node with the following jsonata expression:

Flow:

[{"id":"f864818f.c499b","type":"tab","label":"Jsonata - Lower Value","disabled":true,"info":""},{"id":"7d7ba759.3323c8","type":"debug","z":"f864818f.c499b","name":"","active":true,"tosidebar":true,"console":false,"tostatus":false,"complete":"true","x":790,"y":320,"wires":[]},{"id":"7764aede.47cf3","type":"change","z":"f864818f.c499b","name":"choose lower value","rules":[{"t":"set","p":"payload","pt":"msg","to":"$min([$flowContext(\"temp1\"), $flowContext(\"temp2\")])\t","tot":"jsonata"}],"action":"","property":"","from":"","to":"","reg":false,"x":590,"y":320,"wires":[["7d7ba759.3323c8"]]},{"id":"7a7122b.0c1e1dc","type":"change","z":"f864818f.c499b","name":"store temp1","rules":[{"t":"set","p":"temp1","pt":"flow","to":"payload","tot":"msg"}],"action":"","property":"","from":"","to":"","reg":false,"x":350,"y":300,"wires":[["7764aede.47cf3"]]},{"id":"20cc3eea.3d3352","type":"change","z":"f864818f.c499b","name":"store temp2","rules":[{"t":"set","p":"temp2","pt":"flow","to":"payload","tot":"msg"}],"action":"","property":"","from":"","to":"","reg":false,"x":350,"y":340,"wires":[["7764aede.47cf3"]]},{"id":"b2070ace.5df648","type":"inject","z":"f864818f.c499b","name":"temp source 2","topic":"","payload":"12","payloadType":"num","repeat":"","crontab":"","once":false,"onceDelay":"1.5","x":170,"y":340,"wires":[["20cc3eea.3d3352"]]},{"id":"9f28c215.9f756","type":"inject","z":"f864818f.c499b","name":"temp source 1","topic":"","payload":"10","payloadType":"num","repeat":"","crontab":"","once":false,"onceDelay":"1","x":170,"y":300,"wires":[["7a7122b.0c1e1dc"]]},{"id":"5484c4c4.35f03c","type":"inject","z":"f864818f.c499b","name":"","topic":"","payload":"","payloadType":"date","repeat":"","crontab":"","once":true,"onceDelay":0.1,"x":170,"y":240,"wires":[["c2b81426.619968"]]},{"id":"c2b81426.619968","type":"change","z":"f864818f.c499b","name":"set to high","rules":[{"t":"set","p":"temp1","pt":"flow","to":"999","tot":"num"},{"t":"set","p":"temp2","pt":"flow","to":"999","tot":"num"}],"action":"","property":"","from":"","to":"","reg":false,"x":350,"y":240,"wires":[[]]}]

4- Initialization log after recovering the runtime:

14 Oct 11:23:22 - [info] Node-RED version: v0.19.1
14 Oct 11:23:22 - [info] Node.js  version: v8.11.1
14 Oct 11:23:22 - [info] Windows_NT 10.0.17134 x64 LE
14 Oct 11:23:25 - [info] Loading palette nodes
14 Oct 11:23:26 - [warn] rpi-gpio : Raspberry Pi specific node set inactive
14 Oct 11:23:28 - [info] Dashboard version 2.9.4 started at /ui
14 Oct 11:23:28 - [info] Settings file  : \Users\OCM\.node-red\settings.js
14 Oct 11:23:28 - [info] HTTP Static    : C:\Users\OCM\.node-red\projects
14 Oct 11:23:28 - [info] Context store  : 'default' [module=memory]
14 Oct 11:23:28 - [info] User directory : \Users\OCM\.node-red
14 Oct 11:23:29 - [info] Server now running at http://127.0.0.1:1880/
14 Oct 11:23:31 - [info] Active project : Learn-01
14 Oct 11:23:31 - [info] Flows file     : \Users\OCM\.node-red\projects\Learn-01\flows_DESKTOP-PTRIO67.json
14 Oct 11:23:31 - [info] Starting flows
14 Oct 11:23:31 - [info] Started flows
14 Oct 11:29:31 - [info] Setting active project : Jsonata
14 Oct 11:29:31 - [info] Flows file     : \Users\OCM\.node-red\projects\Jsonata\flow.json
14 Oct 11:29:31 - [info] Stopping flows
14 Oct 11:29:31 - [info] Stopped flows
14 Oct 11:29:31 - [info] Starting flows
14 Oct 11:29:31 - [info] Started flows
14 Oct 11:34:44 - [info] Setting active project : Learn-01
14 Oct 11:34:44 - [info] Flows file     : \Users\OCM\.node-red\projects\Learn-01\flows_DESKTOP-PTRIO67.json
14 Oct 11:34:44 - [info] Stopping flows
14 Oct 11:34:44 - [info] Stopped flows
14 Oct 11:34:44 - [info] Starting flows
14 Oct 11:34:44 - [info] Started flows
14 Oct 11:59:31 - [info] Setting active project : Jsonata
14 Oct 11:59:31 - [info] Flows file     : \Users\OCM\.node-red\projects\Jsonata\flow.json
14 Oct 11:59:31 - [info] Stopping flows
14 Oct 11:59:31 - [info] Stopped flows
14 Oct 11:59:31 - [info] Starting flows
14 Oct 11:59:31 - [info] Started flows

5- The "suspicious" flow was not in the active project and it was disabled. As a matter of fact I always keep all testing flows disabled in this machine (development machine).

So I still have to investigate further to understand:

1- Is it possible that a troubled flow that is disabled and not in the active project can disturb node-RED initialization ?

2- Need to delete the suspicious flow , reconfigure settings.js and test if the issue will remain.

3- If the issue is narrowed down to the suspicious flow than report the issue to node-RED team.

1 Like
#2

Interesting... executed step #2 (delete the suspicious flow and recofigured settings.js) and issue remained.

Checking the directory C:\Users\OCM\.node-red\context i found :

Noticed that folder 8bc78dbc.ecb1f has a file named flow.json. Opened this file and found out it had only one line: undefined. I deleted this line and saved the file. After restarting node-RED all seems good. I will keep watching.

14 Oct 13:11:10 - [info] Node-RED version: v0.19.1
14 Oct 13:11:10 - [info] Node.js  version: v8.11.1
14 Oct 13:11:10 - [info] Windows_NT 10.0.17134 x64 LE
14 Oct 13:11:12 - [info] Loading palette nodes
14 Oct 13:11:13 - [warn] rpi-gpio : Raspberry Pi specific node set inactive
14 Oct 13:11:16 - [info] Dashboard version 2.9.4 started at /ui
14 Oct 13:11:16 - [info] Settings file  : \Users\OCM\.node-red\settings.js
14 Oct 13:11:16 - [info] HTTP Static    : C:\Users\OCM\.node-red\projects
14 Oct 13:11:16 - [info] Context store  : 'default' [module=localfilesystem]
14 Oct 13:11:16 - [info] Context store  : 'memoryOnly' [module=memory]
14 Oct 13:11:16 - [info] Server now running at http://127.0.0.1:1880/
14 Oct 13:11:16 - [info] User directory : \Users\OCM\.node-red
14 Oct 13:11:17 - [info] Active project : Jsonata
14 Oct 13:11:17 - [info] Flows file     : \Users\OCM\.node-red\projects\Jsonata\flow.json
14 Oct 13:11:17 - [info] Starting flows
14 Oct 13:11:17 - [info] Started flows
#3

I'd also strongly recommend you upgrade to to 0.19.4 as a number of fixes went in around the file context store.

1 Like