A catch with persistent file stores

General
1

I expect I'm being thick or just tired but I am having a problem with persistent context stores.

No, I'm not being thick, I can see the problem happening. It is because there is a delay of around 30 seconds before persistent variables are written to the fs. While that is fine normally, Node-RED, I think, should flush its cache when stopping but it doesn't.

A bug? Is there a work-around?

Given the following flow. If I press the top inject, it correctly outputs "fred" from the flow._test variable that uses the file persistent store. I can press the bottom inject and get the same result as expected.

However, if I press the top inject, then restart Node-RED, the output is undefined which is obviously not what I'd expect.

image

[{"id":"d055686e.e26f28","type":"inject","z":"5cf69d1b.d88c14","name":"","topic":"","payload":"","payloadType":"date","repeat":"","crontab":"","once":false,"onceDelay":0.1,"x":315,"y":500,"wires":[["1b20e9a0.2000b6"]],"l":false},{"id":"1b20e9a0.2000b6","type":"change","z":"5cf69d1b.d88c14","name":"","rules":[{"t":"set","p":"#:(file)::_test","pt":"flow","to":"fred","tot":"str"}],"action":"","property":"","from":"","to":"","reg":false,"x":440,"y":500,"wires":[["34ef3970.7bb026"]]},{"id":"8f47d888.d531a8","type":"debug","z":"5cf69d1b.d88c14","name":"","active":true,"tosidebar":true,"console":false,"tostatus":false,"complete":"false","x":830,"y":500,"wires":[]},{"id":"cdcf8b32.90b248","type":"inject","z":"5cf69d1b.d88c14","name":"","topic":"","payload":"","payloadType":"date","repeat":"","crontab":"","once":false,"onceDelay":0.1,"x":495,"y":560,"wires":[["34ef3970.7bb026"]],"l":false},{"id":"34ef3970.7bb026","type":"change","z":"5cf69d1b.d88c14","name":"","rules":[{"t":"set","p":"payload","pt":"msg","to":"#:(file)::_test","tot":"flow"}],"action":"","property":"","from":"","to":"","reg":false,"x":640,"y":500,"wires":[["8f47d888.d531a8"]]}]

And in settings.js:

    contextStorage: {
        default: {
            module:'memory'
        },
        file: {
            module: 'localfilesystem'
        }
    },

30 Jan 22:37:08 - [info] Node-RED version: v1.0.3
30 Jan 22:37:08 - [info] Node.js  version: v12.14.0
30 Jan 22:37:08 - [info] Windows_NT 10.0.18363 x64 LE

image

image

Incidentally, you can see the same thing just by using the context sidebar. Write to a flow variable (it happens with flow, node and global). Wait 30 sec. Then delete the variable using the icon in the sidebar and either stop the Node-RED process or restart it within 30 sec. When you restart, the variable will still be there.

2

You can always change the flush interval;

    contextStorage: {
      default: "file",
    memoryOnly: { module: 'memory' },
          file: { module: 'localfilesystem',
          config: {
                  flushInterval: '10'
                  },
           },
    },
3

How are you stopping Node-RED? If you are just killing the process abruptly, then you don't allow the file store to flush it's contents.

4

This issue seems to have come up before, and presumably was resolved in version 0.20. Or is this something new?

5

Thanks for the reminder.

Well, I'm mainly using nodemon so I'd expect it is sending a signal to the process.

I think that the point is that I believe that Node.js is capable of trapping such signals and doing some minor process before exit? Can't say that I really understand it but that's what I thought.

6

What signal does nodemon use to kill the process ?

7

You had to go and ask didn't you!

Well a quick look through the code found this:

const restartSignal = config.options.signal === 'SIGUSR2' ? 'SIGHUP' : 'SIGUSR2';

There may be more, I'll look further.

And there is a bunch of code around here that looks like it is using kill with a signal code:

I think that I was expecting Node-RED do something like this to clean up:

Obviously, as things stand, all the talk about using persistent context stores is on somewhat shaky ground if you have to be sure that your server continues to process for 30 seconds after you can something. A full deploy, for example, might wipe out an incoming update but might appear to be inconsistent (which I how I came across this).

Given the earlier discussions about this area and core processing, I'd be reluctant to add signal processing to my own code even if there was some kind of flush function for the storage modal - though this would certainly be one option.

I don't think that node.on('close', function(removed,done) { ... } is processing during this kind of exit either? Certainly, I don't get any console.log output from that function.

I'm also reluctant to change the flushInterval as per Paul's code as I'm not sure of the performance impact and it relies on users/administrators making changes to settings.js in a particular way.

1 Like
8

I've actually increased my flush interval for my pi (running on a SD card).

I've just tested whether my 'script installed' installation of node-RED writes it's cache upon shutdown/restart, and yes it does & works as expected with the following commands;
node-red-stop
node-red-restart
sudo poweroff
sudo shutdown

9

It's good to know when it does and doesn't so we probably need to create a full list for the documentation so that people don't get caught out.

Thanks for doing that research Paul.

I realise that my use-case is rather "edge" (typically me) but I think people should at least be aware.

I do also think that Node-RED potentially could trap other signals in order to close this gap though I appreciate that this is not likely to be high on the priority list.

10

Julian at the bottom of red.js we have

process.on('SIGINT', function () {...

can you try just duplicating that block and changing one to SIGUSR2 ?

11

The docs do already say this:

The flushInterval is provided to minimise wear on the underlying storage, such as on a Raspberry Pi’s SD card. Note that if Node-RED is unexpectedly killed, any data that has not yet been flushed will be lost.

https://nodered.org/docs/api/context/store/localfilesystem#options

If you feel it could say more, then please do raise a PR with a proposal.

12

Thanks Dave, started to add something along those lines - will test when I get a chance and let you know.

Thanks Nick. Perhaps needs something a bit more detailed as an addendum but lets see where we get to with the details first.

13

Title changed as I don't want to imply this is Node-RED's problem.

1 Like
14

Alternatively - just go for a cup of tea or do 20 push-ups before closing Node-RED.......

2 Likes
15

An excellent idea Simon - though coffee is my poison.

However, it does rather slow down the development process :grinning:

16

I think it is the SIGUSR2... By default we catch SIGINT - which is usual ctrl-c - break etc.... so we probably just need to expand that list sensibly... (eg probably shouldn't interrupt a SIGKILL)

probably....

17

I don't think Node.js allows you to catch SIGKILL anyway.

I added the following to the end of red.js as I couldn't see it doing anything in my own code:

process.on('SIGUSR1', function () {
    util.log('[RED] === SIGUSR1 ===')
    RED.stop().then(function() {
        process.exit();
    });
});

process.on('SIGUSR2', function () {
    util.log('[RED] === SIGUSR2 ===')
    RED.stop().then(function() {
        process.exit();
    });
});

process.on('SIGHUP', function () {
    util.log('[RED] === SIGHUP ===')
    RED.stop().then(function() {
        process.exit();
    });
});

And it did nothing!

Not only do none of those actually get caught by restarting in nodemon or issuing a kill, but the SIGINT catch doesn't help since the context store isn't written back anyway at least in the 3-5 second test that I've done so far.

Another caveat on my testing so far, I've only tested on Windows 10, I've not yet tried on the Pi and I'd like to because I know that stream handling can be slightly different between the 2.

I need to get back to my day-job now, I'll try and do some more testing over the weekend.

One other thing I noted when looking at red.js, you are using util.log which has been deprecated since Node.js v6 so I imagine that it will be removed at some point.

Also, the SIGINT processing is supposed to be synchronous and I'm not sure that processing RED.stop() is since it is promise based? I don't know enough about it to say though.

1 Like
18

util.log is our own version I think (see requires at top of file...) - but just try console.log instead.
If I also add some to packages/node_modules/@node-red/runtime/lib/nodes/context/localfilesystem.js around line 233 I can see it gets called before exiting.

19

Some of this may be a Windows/Node.js thing. Output to stdout on Windows is async but to file is sync. according to the docs. Which is why I also need to try this on the Pi.

Thanks for the references to the code by the way. I can use this as an excuse to learn some more about the core code.

I might even have some fun taking a copy of the localfilingsystem module and creating a custom one - be better than risking breaking my dev Node-RED installation :slight_smile: Also then easier to test on one of the Pi's.

20

net is I think we may need to also catch a few of the other signals...
SIGINT (as today), SIGTERM, SIGHUP and SIGUSR2

any more thoughts ?