Parent context variable accessed in subflow's first function node yields undefined?

General
1

I remember that earlier (<NR-1.0.5) there was a problem when parent context variables were accessed in a subflow right in the first function node. Is it possible that it can still happen (NR-2.0.5 or 1.2.9)? I'm chasing quite a rare issue when in the first function node of a subflow of a subflow (!) I sometimes get undefined after a flow.get("$parent..."). However, the flow context variable is set in the parent subflow almost before calling the failing subflow and I'm pretty sure that there is no concurrent node being executed that could set that variable undefined since the parent subflow is behind a queue gate.

I attached the exported parent subflow with all its sub-subflows as it's too big to paste it here but it should look like this once imported:

image
image808×255 21.1 KB

The failing subflow is called 'calculate channel sum' where the error is: TypeError: cannot read property 'spectrum' of undefined. The context variables that cannot be accessed (most probably only the first one) are set in the function node FileSeparate_Diagram as ch_0 ... ch_7. Any comments are welcome :slight_smile:

flows.json (38.0 KB)

2

Here is a quick "How to" flow that works accessing the parent flow's context.

It is basic, but I hope it helps.

You have to press the Set flow variable node first.
The press the Just a trigger signal node and you see the output.

[{"id":"7d297bcb6d394137","type":"subflow","name":"Subflow 1","info":"","in":[{"x":90,"y":80,"wires":[{"id":"0e60e8c38370930d"}]}],"out":[{"x":310,"y":80,"wires":[{"id":"0e60e8c38370930d","port":0}]}]},{"id":"0e60e8c38370930d","type":"function","z":"7d297bcb6d394137","name":"","func":"var my_variable = flow.get(\"$parent.example\");\n\nmsg.payload = my_variable;\n\nreturn msg;","outputs":1,"noerr":0,"initialize":"","finalize":"","libs":[],"x":200,"y":80,"wires":[[]]},{"id":"dc1a1c3b66ff7585","type":"comment","z":"1747bdb12f3df9d0","name":"Access flow variables in subflow.","info":"","x":500,"y":430,"wires":[]},{"id":"a88c04c0743eae1d","type":"change","z":"1747bdb12f3df9d0","name":"set `flow.example` with `msg.payload`","rules":[{"t":"set","p":"example","pt":"flow","to":"payload","tot":"msg"}],"action":"","property":"","from":"","to":"","reg":false,"x":610,"y":470,"wires":[[]]},{"id":"3a7947469363c259","type":"inject","z":"1747bdb12f3df9d0","name":"Set flow variable","props":[{"p":"payload"},{"p":"topic","vt":"str"}],"repeat":"","crontab":"","once":false,"onceDelay":0.1,"topic":"","payload":"example message","payloadType":"str","x":250,"y":470,"wires":[["a88c04c0743eae1d"]]},{"id":"e93ac63fe1624162","type":"inject","z":"1747bdb12f3df9d0","name":"Just a trigger signal","props":[{"p":"payload"},{"p":"topic","vt":"str"}],"repeat":"","crontab":"","once":false,"onceDelay":0.1,"topic":"","payloadType":"date","x":260,"y":520,"wires":[["ea090d89e3973113"]]},{"id":"ea090d89e3973113","type":"subflow:7d297bcb6d394137","z":"1747bdb12f3df9d0","x":520,"y":520,"wires":[["d863c884443c14e7"]]},{"id":"d863c884443c14e7","type":"debug","z":"1747bdb12f3df9d0","name":"","active":true,"tosidebar":true,"console":false,"tostatus":false,"complete":"false","statusVal":"","statusType":"auto","x":710,"y":520,"wires":[]}]
3

Thanks for your help but I don't think I have a problem with the basic usage of context variables unless you spotted something in the flow attached that indicates this :wink:

The problem I described is rather tricky. Just to sum it up based on the picture above: a context variable is set in the function node 'FileSeparate_Diagram' which is accessed in the subflow 'calculate channel sum' but occasionally the context variable is undefined for which I don't see any reason. I read through the code quite a many times (static code analysis) looking for any possible object reference by which the context variable could be set to undefined and haven't found any. There's also no other place where that context variable is set by flow.set() within the subflow and there's no concurrent node execution since the subflow on the picture is behind a queue gate which ensures that only one message is processed by this flow and only after that's done the next message gets released for processing.

4

Ok, spit balling....

I have had similar things that have dogged me for months/years and recently I got really fed up with it and looked a lot more.

To make it like you, the problems weren't exactly predictable.

Make a small flow something like this idea:
inject node repeating its output at maybe 2 second interval.
change node getting the flow.context you are using - putting it into msg.payload
switch node that only passes if the msg.payload is not defined.
Then send that to something to notify you that a not defined payload was received.

Sorry, but that's the best I can offer at this stage.

Something like this:

[{"id":"248aee937e922515","type":"inject","z":"7e987ddf260bdf0d","name":"clock","props":[{"p":"payload"},{"p":"topic","vt":"str"}],"repeat":"2","crontab":"","once":false,"onceDelay":0.1,"topic":"","payloadType":"date","x":130,"y":80,"wires":[["5f35b51020a4d640"]]},{"id":"5f35b51020a4d640","type":"change","z":"7e987ddf260bdf0d","name":"EDIT THIS NODE!","rules":[{"t":"set","p":"payload","pt":"msg","to":"SetAsNeeded","tot":"flow"}],"action":"","property":"","from":"","to":"","reg":false,"x":490,"y":80,"wires":[["f0b5d30180f02044"]]},{"id":"f0b5d30180f02044","type":"switch","z":"7e987ddf260bdf0d","name":"Not sure this is correct","property":"payload","propertyType":"msg","rules":[{"t":"null"}],"checkall":"true","repair":false,"outputs":1,"x":180,"y":130,"wires":[["d8782858a5c895fc"]]},{"id":"f0eff10b0dc474db","type":"function","z":"7e987ddf260bdf0d","name":"What ever you want here.","func":"\nreturn msg;","outputs":1,"noerr":0,"initialize":"","finalize":"","libs":[],"x":510,"y":130,"wires":[["5ac792beea9ec39c"]]},{"id":"5ac792beea9ec39c","type":"debug","z":"7e987ddf260bdf0d","name":"","active":true,"tosidebar":true,"console":false,"tostatus":false,"complete":"false","statusVal":"","statusType":"auto","x":730,"y":130,"wires":[]},{"id":"d8782858a5c895fc","type":"change","z":"7e987ddf260bdf0d","name":"","rules":[{"t":"set","p":"payload","pt":"msg","to":"ATTENTION","tot":"str"}],"action":"","property":"","from":"","to":"","reg":false,"x":335,"y":130,"wires":[["f0eff10b0dc474db"]],"l":false}]

Just to show you the example.
You will need to edit things.
The compact change node just before the function node is only to generate the message.

5

The only other things which comes to mind is POWER SUPPLY!

6

Thanks again for your suggestions. I added several node.warns() last friday to put in syslog when such a thing happens but no luck till now, caught nothing red-handed. What I actually suspect is that the json.parse() in 'FileSeparate_Diagram' fails to create a json object from the file read by the 'file in' node and the context variables in which certain properties of that json object are stored are simply undefined. But then again why does it happen only occasionally?

Concerning the power supply, I don't get what you mean :thinking: However, there's a UPS as battery backup for any blackout period and that's also read by our node-red flows to send a notification if the system is on battery. If the battery is over and the system gets restarted later, that should not matter I think.

7

I got caught for about 10 months with problems.

I reluctantly replaced the power supplies as a last ditch effort and.... low and behold: problem went away.

Don't underestimate problems the power supply can give you.

WRT catching the error with code:
Alas this is messy and uses a lot of space.

Is the problem at least happening with some frequency? Daily, weekly.... etc?

Use something like what I suggested with the small flow I posted and get it to start a while before the time it is known to happen and write to a file what it gets as the flow.context reading.

Let it go beyond when it normally happens and hope it fails. Then at least you will have something on which to work.

Hope that helps too.

I'm saying to monitor the flow.context a lot to monitor what it is....

There may be some code that is messing with it.
Or!
A message could sneak through and when it gets to that piece of code, it corrupts the flow.context and so.... it hits the fan.

So creating/getting a log of what the flow.context is may go some way to finding out why it is failing.

The UPS:
Again, if any voltage is not nice, it can have a real bad affect on the RasPi.
So even if it is a UPS.... If the voltage is not up to spec...... All bets are off on what happens.

8

Unfortunately, I cannot do much with the power supply as it's at customer site but the system was built by professional electricians -not that they cannot make mistakes. Currently, I'm doing the same what you suggested: sit and wait :slight_smile: I would not change the flow now but the flow context is logged as you also pointed out but via node.warn(). Till now, logging via node.warn() has always worked reliably just sometimes it needs too many logpoints to add to the source but for me it's not messy. Concerning, the frequency of the problem, it's unknown. A new functionality was developed and added to this system a few (3-4) weeks ago and since then this symptom developed only 3 times out of which 2 happened right after deploying the change. The 3rd occasion was last friday. So now I'm just watching if anything pops up in syslog.

9

I haven't been following this in detail, but is the file being modified externally? Is it possible that you are reading it at a moment when the contents are invalid?

10

No, it's not changed but might be read at the same time. Though, I don't expect that to be a problem.

11

Yeah, no problems.

But please understand the power supply can cause problems.

WRT catching the error:
Well, I would still get the node looking at the flow.context and writing it to a file.

The more frequent you do it the better. But I guess you could do it every minute at first and look if things stand out.

Write this to a specific file so you can look at it and it alone.

I know it is taking up a lot of disc space, but I feel you may need to do it.
I am only saying this because I suffered for a LONG time with problems and it was put down to power supplies.
I know that is not in your scope of what you can do.
But you need to log things to see what is happening.

12

Oh, sorry....

out of which 2 happened right after deploying the change.

Ok.

From the CLI, stop node-red and start it again.
Watch if anything happens.

Things can happen then which may blind side you also.

13

I'm not monitoring the context variable periodically but on the spot:

var ppfCorrections = msg.payload;


var channels_length = flow.get("$parent.channels_length");

var j=0;
var i=0;


for(j = 0; j < channels_length; j++){
    var channel = [];
    node.warn("ch_"+j+":"+JSON.stringify(flow.get("$parent.ch_" + j)));
    for(i = 0; i < flow.get("$parent.ch_" + j).spectrum.length; i++){
        channel[i] = (flow.get("$parent.slider_" + j)/100) * flow.get("$parent.ch_" + j).max_ppf * flow.get("$parent.ch_" + j).spectrum[i] * ppfCorrections[j];
    }
    flow.set("$parent.channel_" + j ,channel);
}


var channel_SUM = [];
for(i = 0; i < flow.get("$parent.ch_0").spectrum.length; i++){
    var sum = 0;
    for(j = 0; j < channels_length; j++){
        sum += flow.get("$parent.channel_" + j)[i];
    }
   channel_SUM[i] = sum;
}
msg.payload=channel_SUM;
return msg;

As it fails here with "cannot read 'spectrum' of undefined" when accessing

flow.get("$parent.ch_" + j).spectrum.length

I added a node.warn() just one line before that access to the spectrum property to log the content of the whole context variable. That should be sufficient I think.

14

I'd do something like this.
(Understand I am not good with programming)

var ppfCorrections = msg.payload;


var channels_length = flow.get("$parent.channels_length");
if (channels_length == undefined)
{
	//	WE HAVE A PROBLEM
}

(and the rest)

Stick some stuff in there and see if that helps you with what is happening.

15

The system was restarted after that happened and since then the only occasion was the 3rd and last one on friday :frowning:

16

Ok. That's kind of good. As I hope that rules things not being set up at time of access out.

I've been bitten by that a few times.
So, moving on....

17

Yepp. Thanks for all your help! :slight_smile:

18

Do you agree that you maybe should add some code where I showed you from your code?

It is just that way it helps you get a better picture of what the node is seeing and maybe help you find out what is happening.

If you really feel sneaky, add another output on the function node and send a message from that piece of code so you know the problem has happened and can trigger more code to indicate what just happened.

19

I added the node.warn() right before reading the spectrum length as that's where the error pops up. I tried earlier what you suggested but it has never caught anything since channels_length was never (two occasions out of three I mean) undefined when the spectrum property was so I just removed logging that.

20

I would put the code in the function node.

Looking at what you just said though it seems not to be as simple as you originally made out.
(No worries. I do that a lot myself. Problems are not always easy to explain and as you go on, your picture gets better and you sometimes forget to explain the new development)

Your original thing was that it wasn't defined. (undefined)

And now you are going from channels_length to spectrum.

Maybe you need to check both. Or more so: log both.

I know it is painful. Believe me.
But something is maybe throwing in a rogue message somewhere along the line and causing things to go bad.

Until you get a good log of what the node is seeing you are flying blind.
I had a node and was splitting the message to set context.
Every day it would fail. Don't know why.
I asked and people found some of my bad programming and I thought all was good.
It fixed ONE of the problems. But there were actually TWO. The second one was hidden but the first and I only found it by sheer luck that I restarted NR and noticed it throw up an error.
As it was real time and I was watching it I saw the rogue message in my scenario and fixed it.
This would never have been this easy had I just let things be and deal with the error every day.

I get that yours isn't that predictable.
But I really really really suggest you either log those values or capture what is happening with that node fairly intensely as it only takes one errant message and you get a big headache.