Occasional double message

[qabi]

I am using the node with cron pattern "1 ". Sometimes I see two messages sent from this node a few seconds apart. For example a second before the correct time, and 2 seconds after.

What can be done debug and fix this? Can I help?

[buglss]

@qabi thank you for feedback. I'm sorry for the late reply. Which version of this package are you using? Could it be related to issue #6 which was closed before?

[qabi]

Using version 2.2.2. This happens how and then, without any messing around or re-deployments necessary.

I have one triggering one minute after each hour. I typically see this on the midnight triggering - but not always. And I also see it fairly often on other times of the day.

Is there anything I can do to try troubleshooting it?

By the way: it is a really nice and very useful node. Oddly, I am using it in several flows, but only seeing this problem in this single instance. There is even one for every second hour (on the hour) in the same flow, but I don't think this has the problem (although this one is not watched closely or logging anything, so it might be there - should I check?)

[buglss]

Release Note: https://github.com/buglss/node-red-crontinject/releases/tag/v2.2.3

[buglss]

@qabi thank you so much for your feedback and good thoughts.

Thinking about what you said, the Race Condition situation came to my mind. The occasional occurrence indicates exactly this situation.

I just released a new patch in the cronjo package for this issue. (https://github.com/buglss/cronjo/issues/7)

You can install the latest version 2.2.3.

[qabi]

Looks like the issue is still there in 2.2.3.

No idea why I only see it in this one instance of the node, though.

[buglss]

@qabi hi. You have to make sure your Node is updated. Can you try uninstalling and reinstalling with npm?

npm rm @buglss/node-red-crontinject
npm i @buglss/node-red-crontinject

If the problem persists, can you send the flow?

[qabi]

I updated normally (in node-red) and restarted, but that did not solve it. I also tried the above with removing and reinstalling from the command line, and then restarting. But it still happens.

I'm not sure I can send the flow here. It is fairly large and complicated, and has a number of dependencies. Is there anything else I can do?

[buglss]

It is enough to share the problematic flow (node chain). You don't need to send the entire flow file of the project.

I could not detect any problems in my own experiments. Can you share the versions of the cronti and cronjo packages used (the version written in the package.json file in cronjo and cronji directories in the node_modules directory)?

[qabi]

cronjo 1.1.4 cronti 3.1.6

All nodes connected to this issue:

[{"id":"189f92f3cefc1d4a","type":"crontinject","z":"89ebabdd43b154de","name":"Every hour","props":[{"p":"payload"},{"p":"topic","vt":"str"}],"repeat":"","crontab":"","once":true,"onceDelay":0.1,"topic":"Hourly","payload":"","payloadType":"date","crontiMethod":"onCrontime","crontiArgs":"[\"1 * * * *\"]","inputs":0,"hasButton":true,"x":110,"y":220,"wires":[["2cab3ab2c12a3a2c","2ac9e808d66b20ba","d326814c724a2c62"]]},{"id":"2ac9e808d66b20ba","type":"delay","z":"89ebabdd43b154de","name":"","pauseType":"delay","timeout":"20","timeoutUnits":"seconds","rate":"1","nbRateUnits":"1","rateUnits":"second","randomFirst":"1","randomLast":"5","randomUnits":"seconds","drop":false,"allowrate":false,"outputs":1,"x":240,"y":500,"wires":[["a2dc3bf95d20c757"]]},{"id":"a2dc3bf95d20c757","type":"function","z":"89ebabdd43b154de","name":"Financial query","func":"let outMsg = { \"payload\": \"See queryParameters\", \"topic\": 'hourly-solar', \"queryParameters\": {}};\n\nlet d = new Date();\n\nd.setDate(d.getDate());\n\n//day.queryParameters[\"to\"] = date.format(d, \"YYYYMMDDHH\");\n//year.queryParameters[\"to\"] = day.queryParameters[\"to\"];\n\nd.setHours(0);\nd.setMinutes(0);\nd.setSeconds(0);\nd.setMilliseconds(0);\n\noutMsg.queryParameters[\"fromDay\"] = date.format(d, \"YYYYMMDDHH\");\n\nd.setMonth(0);\nd.setDate(1);\nd.setHours(0)\noutMsg.queryParameters[\"fromYear\"] = date.format(d, \"YYYYMMDDHH\");\n\nreturn outMsg;","outputs":1,"noerr":0,"initialize":"","finalize":"","libs":[{"var":"date","module":"date-and-time"}],"x":420,"y":500,"wires":[["bfcf9cde43ba3c85"]]},{"id":"bfcf9cde43ba3c85","type":"postgresql","z":"89ebabdd43b154de","name":"Day","query":"select (d.income+d.savings) as dayTotal, (y.income+y.savings) as yearTotal\nfrom (select round(sum(s.gridout*p.sell),2) as income, round(sum((s.consumption-s.gridin)*buy),2) as savings\nfrom solar s, prices p where s.hour = p.hour and s.hour >= $fromDay) as d, \n(select round(sum(s.gridout*p.sell),2) as income, round(sum((s.consumption-s.gridin)*buy),2) as savings\nfrom solar s, prices p where s.hour = p.hour and s.hour >= $fromYear) as y;","postgreSQLConfig":"5ebed02a5fe31f9f","split":false,"rowsPerMsg":1,"outputs":1,"x":590,"y":500,"wires":[["017deb9034303de1"]]},{"id":"017deb9034303de1","type":"ui_text","z":"89ebabdd43b154de","group":"4e23359882516fc2","order":17,"width":0,"height":0,"name":"","label":"Besparelse","format":"{{msg.payload[0].daytotal}} i dag, {{msg.payload[0].yeartotal}} i år","layout":"row-spread","className":"","x":930,"y":500,"wires":[]},{"id":"045d4e87c8c51b89","type":"postgresql","z":"89ebabdd43b154de","name":"SELECT prices","query":"SELECT * FROM prices \nWHERE hour >= $vts\nORDER BY hour ASC;","postgreSQLConfig":"5ebed02a5fe31f9f","split":false,"rowsPerMsg":1,"outputs":1,"x":460,"y":300,"wires":[["572697be0c6e6fd3"]]},{"id":"d326814c724a2c62","type":"delay","z":"89ebabdd43b154de","name":"","pauseType":"delay","timeout":"5","timeoutUnits":"seconds","rate":"1","nbRateUnits":"1","rateUnits":"second","randomFirst":"1","randomLast":"5","randomUnits":"seconds","drop":false,"allowrate":false,"outputs":1,"x":580,"y":420,"wires":[["3470421391ad5264"]]},{"id":"572697be0c6e6fd3","type":"function","z":"89ebabdd43b154de","name":"Planner","func":"// Prepare and split for chart, and also store current hour's value in global context\n\nfunction roundAmount(am) { return Math.round(am * 100) / 100 }\n\nif (msg.payload.length < 7) {\n node.error(\"Price information is available for less than 6 hours ahead!\");\n}\n\nlet buyData = []; \nlet sellData = [];\nlet outMsg = {\n \"payload\": [{\n \"series\": [\"Køb\", \"Salg\"],\n \"data\": [buyData, sellData],\n \"labels\": []\n }],\n \"powerPrice\": {}\n}\n\n// 24h data\nlet min = 100, max = 0, sum = 0, count = 0;\nfor (let e of msg.payload) {\n let p = e.buy;\n if (p) { // Disregard unkown values\n buyData.push(roundAmount(p));\n sellData.push(roundAmount(e.sell));\n outMsg.payload[0].labels.push(e.hour.slice(-2));\n\n if (p < min) min = p;\n if (p > max) max = p;\n sum += p;\n count++;\n }\n}\n\noutMsg.powerPrice.min24h = roundAmount(min);\noutMsg.powerPrice.max24h = roundAmount(max);\n//outMsg.powerPrice.avg24h = roundAmount(sum / count);\n\n// 6h\nmin = 100; max = 0; sum = 0; count = 0;\nlet minTime;\nfor (let i=0; i<6; i++) {\n let e = msg.payload[i];\n let p = e.buy;\n if (p) { // Disregard unkown values\n if (p < min) {min = p; minTime=e.hour;}\n if (p > max) max = p;\n sum += p;\n count++;\n }\n}\n\nlet current = msg.payload[0].buy;\n\n// General \noutMsg.powerPrice.buy = roundAmount(current);\noutMsg.powerPrice.sell = roundAmount(msg.payload[0].sell);\n\nlet q = Math.max(1, Math.ceil((current - min) / (max - min) * 4));\nlet score = (max-min<0.2) || current < 0.5 ? 1 : q; // Almost same rates or below 0.5 DKK scores 1\n\noutMsg.powerPrice.min6h = roundAmount(min);\noutMsg.powerPrice.max6h = roundAmount(max);\n//outMsg.powerPrice.avg6h = roundAmount(sum / count);\noutMsg.powerPrice.quartile = q; // 6h\noutMsg.powerPrice.score = score; // 6h\noutMsg.powerPrice.nextLow = minTime;\nlet now = new Date(); now.setMinutes(0); now.setSeconds(0); now.setMilliseconds(0);\noutMsg.powerPrice.nextHours = (date.parse(minTime, \"YYYYMMDDHH\").getTime() - now.getTime()) / 3600000;\n\n// Set global power values for this current hour, based on 'buy' price\nglobal.set(\"powerPrice\", outMsg.powerPrice);\n\nreturn outMsg;","outputs":1,"noerr":0,"initialize":"","finalize":"","libs":[{"var":"date","module":"date-and-time"}],"x":640,"y":300,"wires":[["2bc30dedda7f0acd","71b44f9bc123c0ef","ff665a39ef9a49ef"]]},{"id":"3470421391ad5264","type":"function","z":"89ebabdd43b154de","name":"Inverter settings","func":"////////////////////////////////////////////////////\n//// Calculate current recommended battery charging current, based on forecast\n////////////////////////////////////////////////////\nconst NO_CHARGE_A = 0;\nconst CHARGE_A = 70;\nconst REQUIRED_ENERGY = 16000;\nconst CHARGE_HOUR_START = 13;\nconst MAX_SOLAR_PRODUCTION = 15600;\n\nlet inv = flow.get(\"lastInverter\");\nlet energyInChargeWindow = flow.get(\"energyInChargeWindow\");\nlet now = new Date();\n\n// Calculate recommended charging Amperes\n// Before charging time window and sufficient power in charge time window\nlet sell = global.get(\"powerPrice\").sell >= 0;\nlet delay = sell && now.getHours() < CHARGE_HOUR_START && energyInChargeWindow >= REQUIRED_ENERGY;\nlet recommendedChargeA = delay ? NO_CHARGE_A : CHARGE_A;\nlet produce = global.get(\"powerPrice\").buy >= 0;\nlet maxSolarPower = produce ? MAX_SOLAR_PRODUCTION : 1000;\n\nnode.status({\n fill: produce ? \"green\" : \"red\",\n shape: delay ? \"ring\" : \"dot\",\n text: \"🔋 \" + recommendedChargeA + \" \" + \n \"💰 \" + (sell ? \"Yes \" : \"No \") + \n \"☀️ \" + maxSolarPower\n});\n\nmsg = {\"update\": {}, \"topic\": \"InverterUpdate\" };\n\nif (sell !== inv.solarSell)\n msg.update.solarSell = sell;\n\nif (recommendedChargeA != inv.maxChargeA)\n msg.update.maxChargeA = recommendedChargeA;\n\nif (maxSolarPower != inv.maxSolarPower) {\n msg.update.maxSolarPower = maxSolarPower; \n // Buying price is negative, so potentially also set for time period:\n // SoC 100% and GridCharge=true\n}\n\nif (Object.keys(msg.update).length > 0)\n return msg;","outputs":1,"noerr":0,"initialize":"","finalize":"","libs":[],"x":760,"y":420,"wires":[["02d1c9a453240281","e6062f6696556d5f","1896919c31b3c59c","5084929c08ec0e6e"]]},{"id":"2bc30dedda7f0acd","type":"change","z":"89ebabdd43b154de","name":"score","rules":[{"t":"set","p":"payload","pt":"msg","to":"powerPrice.score","tot":"global"}],"action":"","property":"","from":"","to":"","reg":false,"x":750,"y":220,"wires":[["cdcc8203a089fc5c"]]},{"id":"cdcc8203a089fc5c","type":"ui_led","z":"89ebabdd43b154de","order":2,"group":"4e23359882516fc2","width":3,"height":1,"label":"Pris {{msg.powerPrice.buy|number }} kr.","labelPlacement":"left","labelAlignment":"left","colorForValue":[{"color":"#73cc49","value":"1","valueType":"num"},{"color":"#deda61","value":"2","valueType":"num"},{"color":"#df985c","value":"3","valueType":"num"},{"color":"#e1454b","value":"4","valueType":"num"}],"allowColorForValueInMessage":false,"shape":"circle","showGlow":true,"name":"Price LED","x":920,"y":220,"wires":[]},{"id":"71b44f9bc123c0ef","type":"ui_chart","z":"89ebabdd43b154de","name":"","group":"4e23359882516fc2","order":1,"width":0,"height":0,"label":"Strømpriser","chartType":"bar","legend":"false","xformat":"HH:mm:ss","interpolate":"linear","nodata":"","dot":false,"ymin":"","ymax":"","removeOlder":1,"removeOlderPoints":"","removeOlderUnit":"3600","cutout":0,"useOneColor":true,"useUTC":false,"colors":["#cc4c3d","#4aa34f","#ff7f0e","#2ca02c","#98df8a","#466d83","#ff9896","#9467bd","#c5b0d5"],"outputs":1,"useDifferentColor":false,"className":"","x":930,"y":260,"wires":[[]]},{"id":"ff665a39ef9a49ef","type":"ui_text","z":"89ebabdd43b154de","group":"4e23359882516fc2","order":3,"width":4,"height":1,"name":"Next lowpoint","label":"Næste lavpunkt","format":"{{msg.powerPrice.nextHours}} timer","layout":"row-spread","className":"","x":940,"y":300,"wires":[]},{"id":"02d1c9a453240281","type":"switch","z":"89ebabdd43b154de","name":"update?","property":"update.solarSell","propertyType":"msg","rules":[{"t":"nnull"}],"checkall":"true","repair":false,"outputs":1,"x":980,"y":360,"wires":[["a1feca0783226336"]]},{"id":"e6062f6696556d5f","type":"switch","z":"89ebabdd43b154de","name":"update","property":"update.maxChargeA","propertyType":"msg","rules":[{"t":"nnull"}],"checkall":"true","repair":false,"outputs":1,"x":980,"y":400,"wires":[["b4aef074f4a20b5a"]]},{"id":"5084929c08ec0e6e","type":"switch","z":"89ebabdd43b154de","name":"update","property":"update.maxSolarPower","propertyType":"msg","rules":[{"t":"nnull"}],"checkall":"true","repair":false,"outputs":1,"x":980,"y":440,"wires":[["e981ed568603c1b5"]]},{"id":"e981ed568603c1b5","type":"change","z":"89ebabdd43b154de","name":"Produce ntfy","rules":[{"t":"set","p":"headers","pt":"msg","to":"{\"Tags\":\"battery, electric_plug\"}","tot":"jsonata"},{"t":"set","p":"payload","pt":"msg","to":"\"Max. solar production: \" & msg.update.maxSolarPower & \"W\"","tot":"jsonata"},{"t":"set","p":"topic","pt":"msg","to":"Notify","tot":"str"}],"action":"","property":"","from":"","to":"","reg":false,"x":1130,"y":440,"wires":[[]]},{"id":"b4aef074f4a20b5a","type":"change","z":"89ebabdd43b154de","name":"Charge ntfy","rules":[{"t":"set","p":"headers","pt":"msg","to":"{\"Tags\":\"battery, electric_plug\"}","tot":"jsonata"},{"t":"set","p":"payload","pt":"msg","to":"\"Battery charging: \" & msg.update.maxChargeA & \"A\"","tot":"jsonata"},{"t":"set","p":"topic","pt":"msg","to":"Notify","tot":"str"}],"action":"","property":"","from":"","to":"","reg":false,"x":1130,"y":400,"wires":[["0772c5e57e0aa09e"]]},{"id":"a1feca0783226336","type":"change","z":"89ebabdd43b154de","name":"Sell ntfy","rules":[{"t":"set","p":"headers","pt":"msg","to":"{\"Tags\":\"sun, electric_plug\"}","tot":"jsonata"},{"t":"set","p":"payload","pt":"msg","to":"\"Solar export: \" & msg.update.solarSell","tot":"jsonata"},{"t":"set","p":"topic","pt":"msg","to":"Notify","tot":"str"}],"action":"","property":"","from":"","to":"","reg":false,"x":1120,"y":360,"wires":[["0772c5e57e0aa09e"]]},{"id":"0772c5e57e0aa09e","type":"http request","z":"89ebabdd43b154de","name":"ntfy.sh","method":"POST","ret":"txt","paytoqs":"ignore","url":"ntfy.sh/vesterheden-nodered","tls":"","persist":false,"proxy":"","insecureHTTPParser":false,"authType":"","senderr":false,"headers":[],"x":1430,"y":80,"wires":[[]]},{"id":"5ebed02a5fe31f9f","type":"postgreSQLConfig","name":"postgres@nas","host":"nas","hostFieldType":"str","port":"8432","portFieldType":"num","database":"nodered","databaseFieldType":"str","ssl":"false","sslFieldType":"bool","applicationName":"","applicationNameType":"str","max":"10","maxFieldType":"num","idle":"10000","idleFieldType":"num","connectionTimeout":"100000","connectionTimeoutFieldType":"num","user":"postgres","userFieldType":"str","password":"cars.PIC.loot","passwordFieldType":"str"},{"id":"4e23359882516fc2","type":"ui_group","name":"Default","tab":"8577600541c1c2c6","order":1,"disp":false,"width":7,"collapse":false,"className":""},{"id":"8577600541c1c2c6","type":"ui_tab","name":"El","icon":"dashboard","disabled":false,"hidden":false}]

[qabi]

Now also reproduced in a much simpler setup with just the croninject node (copied and pasted to an other flow) and a debug node.

[buglss]

@qabi Sorry, due to personal reasons, I could not deal with these issues. Did cloning the node produce a permanent solution? I'll be reviewing the flow you sent this week.

[buglss]

This issue is being reexamined.

[qabi]

Did cloning the node produce a permanent solution?

No, that did not seem to fix it. Let me know if there is anything I can do to help :)

[qabi]

Still seeing this issue in 2.2.5 a few times every day. Can I do something to help troubleshoot it?

[KjellRanda]

I am seeing the same problem with crontime 1 in version 2.2.5 Multiple (two) messages are generated with one second between several times every day.

[KjellRanda]

I have now switched to node-red-contrib-cron-plus and this package does not have this problem.

[buglss]

I am in a period where I am busy in my social and business life. I need supports with PR. Thank you for your feedback. I will provide support as soon as possible.

[buglss]

Changed has been stora method by repeaters. (904352e7a25923e701ef878fd0216109aa934b55)