# Troubleshooting a custom node using logging

**URL:** <https://discourse.nodered.org/t/troubleshooting-a-custom-node-using-logging/17296>\
**Category:** Developing Nodes\
**Created:** [29 October 2019 21:05 UTC](https://discourse.nodered.org/t/troubleshooting-a-custom-node-using-logging/17296 "2019-10-29T21:05:16Z")\
**Posts on this page:** 3\
**Page:** 1

<div class="post-metadata">

**Author:** ![BartButenaers](https://sea2.discourse-cdn.com/flex026/user_avatar/discourse.nodered.org/bartbutenaers/32/10476_2.png) [@BartButenaers](https://discourse.nodered.org/u/BartButenaers)\
**Post date:** [29 October 2019 21:05 UTC](https://discourse.nodered.org/t/troubleshooting-a-custom-node-using-logging/17296/1 "2019-10-29T21:05:16Z")

</div>

Hi folks,

I got a question about my **node-red-contrib-interval-length** node, which measures the time interval between consecutive input messages. In the config screen you can specify in which output message field that measurement needs to be stored. For example I want the measurement to be stored in `msg.customfield`:

![image](https://us1.discourse-cdn.com/flex026/uploads/nodered/original/2X/1/12ef20b5cb2f3a6e4704965e0f271a469dcc2987.png)

When I use for example this simple test flow:

![image](https://us1.discourse-cdn.com/flex026/uploads/nodered/original/2X/1/182948da356583dbfb3cd84f02a821ebb90626ca.png)

```auto
[{"id":"23df382c.058f38","type":"interval-length","z":"dc82a538.a81ba8","format":"mills","bytopic":false,"minimum":"","maximum":"","window":"","timeout":false,"msgTimeout":"","minimumunit":"msecs","maximumunit":"msecs","windowunit":"msecs","msgTimeoutUnit":"msecs","reset":false,"startup":false,"msgField":"customfield","timestampField":"timestamp","repeatTimeout":false,"name":"","x":840,"y":840,"wires":[["2cf9022f.d3f66e"],[]]},{"id":"be32c12.fd5c84","type":"inject","z":"dc82a538.a81ba8","name":"","topic":"","payload":"","payloadType":"date","repeat":"","crontab":"","once":false,"onceDelay":0.1,"x":640,"y":840,"wires":[["23df382c.058f38"]]},{"id":"2cf9022f.d3f66e","type":"debug","z":"dc82a538.a81ba8","name":"","active":true,"tosidebar":true,"console":false,"tostatus":false,"complete":"true","targetType":"full","x":1030,"y":840,"wires":[]}]

```

This works fine for me (i.e. the timeinterval is stored in `msg.customfield`):

![image](https://us1.discourse-cdn.com/flex026/uploads/nodered/original/2X/1/1f67e40b92665a35d8325d59ad0c00aaacc7912c.png)

However the user responded that this field doesn't show in his output message...  
I have no clue what is going on there, since _there is very little code involved_. So I have created an _"extra\_logging"_ **branch** in my Github repository which he could install like this:

```auto
npm install bartbutenaers/node-red-contrib-interval-length#extra_logging

```

In this branch I have added some extra logging [code](https://github.com/bartbutenaers/node-red-contrib-interval-length/blob/extra_logging/interval_length.js):

```auto
console.log(" *************START EXTRA LOGGING*************");
console.log("outputValue = " + outputValue);
console.log("node.msgField = " + node.msgField);
            
// Normally the interval value will be put in the msg,payload (overwriting the original input msg.payload value).
// But the user can explicitly require to put the interval value in another message field.
try {
   console.log("Now we will set the message property");
   RED.util.setMessageProperty(msg, node.msgField, outputValue, true);
   console.log("Now we have set the message property");
   console.log("msg[" + node.msgField + "] = " + msg[node.msgField]);
} catch(err) {
   console.log("Something went wrong: " + err.message);
   node.error("Error setting interval value in msg." + node.msgField + " : " + err.message);
}
         
console.log(" *************STOP EXTRA LOGGING*************");

```

In my test setups I now see nicely some extra log lines:

![image](https://us1.discourse-cdn.com/flex026/uploads/nodered/original/2X/1/158fdd5f0be054dc83f3dfb689700a3deef87c2d.png)

But the user doesn't see this extra logging.  
Does anybody have any tips of how I can troubleshoot this issue?

Thanks !!!  
Bart

---

<div class="post-metadata">

**Author:** ![dceejay](https://sea2.discourse-cdn.com/flex026/user_avatar/discourse.nodered.org/dceejay/32/38_2.png) [@dceejay](https://discourse.nodered.org/u/dceejay)\
**Post date:** [29 October 2019 22:31 UTC](https://discourse.nodered.org/t/troubleshooting-a-custom-node-using-logging/17296/2 "2019-10-29T22:31:35Z")

</div>

as usual - which versions of node.js and Node-RED are they running ? - on what platform ? are they running default install or embedded, docker etc. If you have a custom branch then add some debug at node load time also (ie at head of the .js file) so you know it has loaded ok.

---

<div class="post-metadata">

**Author:** ![moment](https://avatars.discourse-cdn.com/v4/letter/m/e495f1/32.png) [@moment](https://discourse.nodered.org/u/moment)\
**Post date:** [8 November 2019 16:16 UTC](https://discourse.nodered.org/t/troubleshooting-a-custom-node-using-logging/17296/3 "2019-11-08T16:16:35Z")

</div>

i'm running node-red on my pi ,i'm not at home right now but i managed to find a workaround for that problem:  
i used a change node right before the interval node and moved msg.payload to something else in my case msg.val 😉  
It might just be a problem with my pi to be honest missing some dependencies or something it's such an easy fix i don't really care to investigate further,the node saved me a lot of time thank you Bart