Node-red + MCP23017 (x5) slowing down

Hardware
1

Hey
So I'm facing a problem with a project. I made a board with 5 MCP23017 expander ICs and everything works. The problem I'm facing is that after a day of running Node Red starts to slow down, I can see in HTOP that the CPU load jumps up every few seconds. I have a led toggling on one of the MCP pins and i can see that it is not constant. It should toggle every 500ms but it bogs down to a second or a little more (like some kind of pauses) , I can also see this in the Node Red flow.
How can i diagnose this? i know the connections are good since no errors re reported in the debug window.
I'm using @joe-ab1do/mcp-pcf-aio
I'm running this on RPi3 and I also tested the flow on OrangePi5 and it is the same. Also When i start Node Red it consumes 195Mb of RAM and after a day I can see it is only up to 215Mb, so to me this shouldn't be a problem
Thanks

2

Are you using a dashboard with Charts? A very common cause of things slowing down after a while is using charts with thousands of points across the chart, which all have to be moved along each time a sample comes in.

Can you see which process that is? Is it a consistent 'few seconds' and if so does that match anything that happens in your flow?

[Edit] Also, are you running the browser on the same machine as node-red?
What hardware/OS are node red and the browser running on?

3

No I don't have charts. I know about the chart problem.
No I don't run a browser on the Pi,
Yes I see that node-red process is spiking
I' also unsing dashboard2 and there is just some logic and mainly buttons on the dash. Maybe two gauges for the CPU load and temperature but that is it.
I thing there is some weird thing with the i2c node. I restarted the process and it works normaly now so I need to wait.
Some aditional info, restarting the flows does not help, only a reboot or process restart helps

4

I journalctl -u node-red -b 0 and saw this

open '/dev/i2c-1'
Nov 15 08:44:35 DietPi node-red[265745]: PinOn = false; invPinOn = false
Nov 15 08:44:35 DietPi node-red[265745]: MCP23017 setOutput 76769d2e6b9332b5  > Addr = 0X21  PinNum=13 _newState:false > opening bus...
Nov 15 08:44:35 DietPi node-red[265745]:     ...status update >>  _onOffStatus: -2   globalState= 2  Node_id=76769d2e6b9332b5
Nov 15 08:44:35 DietPi node-red[265745]: Reading current state failed. Bus=1 Addr = 0X21 Pin=13 NewState=false Error: EMFILE: too many open files, open '/dev/i2c-1'
Nov 15 08:44:35 DietPi node-red[265745]: 15 Nov 08:44:35 - [error] [mcp pcf out:76769d2e6b9332b5] Reading current state failed. Bus=1 Addr = 0X21 Pin=13 NewState=false,Error: EMFILE: too many open files, open '/dev/i2c-1'
Nov 15 08:44:35 DietPi node-red[265745]: PinOn = false; invPinOn = false
Nov 15 08:44:35 DietPi node-red[265745]: MCP23017 setOutput 1ac43c078859da74  > Addr = 0X21  PinNum=14 _newState:false > opening bus...
Nov 15 08:44:35 DietPi node-red[265745]:     ...status update >>  _onOffStatus: -2   globalState= 2  Node_id=1ac43c078859da74
Nov 15 08:44:35 DietPi node-red[265745]: Reading current state failed. Bus=1 Addr = 0X21 Pin=14 NewState=false Error: EMFILE: too many open files, open '/dev/i2c-1'
Nov 15 08:44:35 DietPi node-red[265745]: 15 Nov 08:44:35 - [error] [mcp pcf out:1ac43c078859da74] Reading current state failed. Bus=1 Addr = 0X21 Pin=14 NewState=false,Error: EMFILE: too many open files, open '/dev/i2c-1'
Nov 15 08:44:35 DietPi node-red[265745]: PinOn = false; invPinOn = false
Nov 15 08:44:35 DietPi node-red[265745]: MCP23017 setOutput 8cbe0ea4f4596ba0  > Addr = 0X21  PinNum=15 _newState:false > opening bus...
Nov 15 08:44:35 DietPi node-red[265745]:     ...status update >>  _onOffStatus: -2   globalState= 2  Node_id=8cbe0ea4f4596ba0
Nov 15 08:44:35 DietPi node-red[265745]: Reading current state failed. Bus=1 Addr = 0X21 Pin=15 NewState=false Error: EMFILE: too many open files, open '/dev/i2c-1'
Nov 15 08:44:35 DietPi node-red[265745]: 15 Nov 08:44:35 - [error] [mcp pcf out:8cbe0ea4f4596ba0] Reading current state failed. Bus=1 Addr = 0X21 Pin=15 NewState=false,Error: EMFILE: too many open files,

This is not there now (after reboot)

5

The node-red-contrib-easybotics-ina219 nodes used to have a simliar issue: "Error: EMFILE: too many open files, open '/dev/i2c-1'" · Issue #2 · easybotics/node-red-contrib-easybotics-ina219 · GitHub

You might want to raise this as an issue on this nodes repository: Issues · Joe-ab1do/MCP230xx-PCF857x-AIO · GitHub

6

ok will do, I hope the node is still maintained

7

The node is (more or less) still maintained. I'm not quite sure what is leading to the error. Are you still having problems. If so, a few questions. I have been running a production system here on a Pi4B with two MCP2008s, a MCP23017 a PCF8574 and a PCF8575, using nodes as inputs and outputs with no issues. Admittedly I am not switching stuff constantly, just checking every now and again to see if it all still works. I am using 3 i2c busses, so only 1 to 2 devices on a bus.

  • It looks like you are only using /dev/i2c1. How many devices are you using on this bus? Just the 5 MCP23017s or...?
  • Are you using the MCP23017 ports only as outputs or also inputs?
  • Regarding the 1 led, I assume you are switching this using an inject node repeating every 500ms?
  • What happens if you only connect the one MCP23017 that the led is connected to and disconnect all the others. Reboot and restart NodeRed. Do you still get the same error?
8
  • Yes I am using only one i2c bus, and all expanders are MCP23017
  • I have a mixed wiring scheme, some are outputs only some are inputs only and some are both
  • Yes I use an inject node and a function node, the function node reads flow context data (bool) and inverts it and saves it back and sends it to the output node
  • I didn't try connecting only one, i will do that but I would first like to try increasing the toggling of LED and the read interval (I think it is at 100ms). This error is not there at start but it creeps up later. I just found the log entries so I need to investigate more.
    Restarting flows does nothing, only restarting nodered or rebooting helps
9

Entering node-red-log while the flow is running should show you everything that gets logged. There are various messages that are logged when the node does something. When an output changes it always reads the states of all the ports before it changes a port. I don't know if this is leading to the problem. If it does, I could look into making logging optional. Anyway, that being said, I am running a blinking led on MCP23017 port 10, blinking at a rate of 500ms on/500ms off. We'll see what happens...
I could look into making logging optional if the problem persists.

10

ok thank you for the info I will investigate and report back. I really hope we come to an solution I spent two weeks designing the I/O card for my friends smart house :smiley:

11

Am I seeing this right? this is the printout of journalctl, all of this happens in a second?!
This is the first half

Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=56664a5006b1250a
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=124
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput db710d946ffdfc53  > Addr = 0X21  PinNum=10 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=db710d946ffdfc53
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 877325f24766f07d  > Addr = 0X21  PinNum=11 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=877325f24766f07d
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 85b723fff6052e01  > Addr = 0X21  PinNum=12 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=85b723fff6052e01
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 76769d2e6b9332b5  > Addr = 0X21  PinNum=13 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=76769d2e6b9332b5
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 1ac43c078859da74  > Addr = 0X21  PinNum=14 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=1ac43c078859da74
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 8cbe0ea4f4596ba0  > Addr = 0X21  PinNum=15 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=8cbe0ea4f4596ba0
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 6d21298faf45bdb2  > Addr = 0X22  PinNum=0 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000001111100
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000001111100
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=6d21298faf45bdb2
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=124
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 56664a5006b1250a  > Addr = 0X22  PinNum=1 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000001111100
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000001111100
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=56664a5006b1250a
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=124
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput db710d946ffdfc53  > Addr = 0X21  PinNum=10 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=db710d946ffdfc53
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 877325f24766f07d  > Addr = 0X21  PinNum=11 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=877325f24766f07d
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 85b723fff6052e01  > Addr = 0X21  PinNum=12 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=85b723fff6052e01
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 76769d2e6b9332b5  > Addr = 0X21  PinNum=13 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=76769d2e6b9332b5
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 1ac43c078859da74  > Addr = 0X21  PinNum=14 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=1ac43c078859da74
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 8cbe0ea4f4596ba0  > Addr = 0X21  PinNum=15 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=8cbe0ea4f4596ba0
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 6d21298faf45bdb2  > Addr = 0X22  PinNum=0 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000001111100
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000001111100
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=6d21298faf45bdb2
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=124
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 56664a5006b1250a  > Addr = 0X22  PinNum=1 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000001111100
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000001111100
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=56664a5006b1250a
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=124
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput db710d946ffdfc53  > Addr = 0X21  PinNum=10 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=db710d946ffdfc53
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 877325f24766f07d  > Addr = 0X21  PinNum=11 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=877325f24766f07d
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 85b723fff6052e01  > Addr = 0X21  PinNum=12 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=85b723fff6052e01
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 76769d2e6b9332b5  > Addr = 0X21  PinNum=13 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=76769d2e6b9332b5
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 1ac43c078859da74  > Addr = 0X21  PinNum=14 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=1ac43c078859da74
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 8cbe0ea4f4596ba0  > Addr = 0X21  PinNum=15 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=8cbe0ea4f4596ba0
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 6d21298faf45bdb2  > Addr = 0X22  PinNum=0 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000001111100
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000001111100
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=6d21298faf45bdb2
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=124
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 56664a5006b1250a  > Addr = 0X22  PinNum=1 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000001111100
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000001111100
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=56664a5006b1250a
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=124
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 Read success ipA00=01111111  ipB00=01111111   ipALL =0111111101111111
Nov 15 14:12:49 DietPi node-red[584]: PinOn = true; invPinOn = true
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput d19dd54af036f0d4  > Addr = 0X24  PinNum=13 _newState:true > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0001100000000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0011100000000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: true   globalState= 1  Node_id=d19dd54af036f0d4
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=14336
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 Read success ipA00=00001111  ipB00=01111000   ipALL =0111100000001111
Nov 15 14:12:49 DietPi node-red[584]: MCP23017  > Existing States:                0111100000001111
Nov 15 14:12:49 DietPi node-red[584]: MCP23017  > New States:                     0001100000001111
Nov 15 14:12:49 DietPi node-red[584]: MCP23017  >!Change! of an input: Diff Mask= 0110000000000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: true   globalState= 1  Node_id=d19dd54af036f0d4
Nov 15 14:12:49 DietPi node-red[584]:   MCP/PCF > New input Debounce timer set.  TimeEnd=20  State=true
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 Read success ipA00=01111100  ipB00=01111111   ipALL =0111111101111100
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 Read success ipA00=00001111  ipB00=01111000   ipALL =0111100000001111
Nov 15 14:12:49 DietPi node-red[584]:   MCP/PCF > Input timer Bounce Ended. [NewState=1]   [Last State=0]  [Deb.state=true]  [Bit=14]  Ellapsed=NaNms
Nov 15 14:12:49 DietPi node-red[584]: MCP23017  > Pin 14 changed from 0 to 1;  id=1d6e002bd76462a7
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: 1   globalState= 1  Node_id=1d6e002bd76462a7
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput db710d946ffdfc53  > Addr = 0X21  PinNum=10 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=db710d946ffdfc53
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 877325f24766f07d  > Addr = 0X21  PinNum=11 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=877325f24766f07d
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 85b723fff6052e01  > Addr = 0X21  PinNum=12 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=85b723fff6052e01
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 76769d2e6b9332b5  > Addr = 0X21  PinNum=13 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=76769d2e6b9332b5
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 1ac43c078859da74  > Addr = 0X21  PinNum=14 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=1ac43c078859da74
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 8cbe0ea4f4596ba0  > Addr = 0X21  PinNum=15 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=8cbe0ea4f4596ba0
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 6d21298faf45bdb2  > Addr = 0X22  PinNum=0 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000001111100
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000001111100
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=6d21298faf45bdb2
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=124
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 56664a5006b1250a  > Addr = 0X22  PinNum=1 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000001111100
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000001111100
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=56664a5006b1250a
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=124
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput db710d946ffdfc53  > Addr = 0X21  PinNum=10 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=db710d946ffdfc53
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 877325f24766f07d  > Addr = 0X21  PinNum=11 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=877325f24766f07d
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
12

This is the second half ( this totals to 448 lines!!??)

Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 85b723fff6052e01  > Addr = 0X21  PinNum=12 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=85b723fff6052e01
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 76769d2e6b9332b5  > Addr = 0X21  PinNum=13 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=76769d2e6b9332b5
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 1ac43c078859da74  > Addr = 0X21  PinNum=14 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=1ac43c078859da74
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 8cbe0ea4f4596ba0  > Addr = 0X21  PinNum=15 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=8cbe0ea4f4596ba0
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 6d21298faf45bdb2  > Addr = 0X22  PinNum=0 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000001111100
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000001111100
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=6d21298faf45bdb2
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=124
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 56664a5006b1250a  > Addr = 0X22  PinNum=1 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000001111100
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000001111100
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=56664a5006b1250a
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=124
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput db710d946ffdfc53  > Addr = 0X21  PinNum=10 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=db710d946ffdfc53
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 877325f24766f07d  > Addr = 0X21  PinNum=11 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=877325f24766f07d
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 85b723fff6052e01  > Addr = 0X21  PinNum=12 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=85b723fff6052e01
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 76769d2e6b9332b5  > Addr = 0X21  PinNum=13 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=76769d2e6b9332b5
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 1ac43c078859da74  > Addr = 0X21  PinNum=14 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=1ac43c078859da74
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 8cbe0ea4f4596ba0  > Addr = 0X21  PinNum=15 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=8cbe0ea4f4596ba0
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 6d21298faf45bdb2  > Addr = 0X22  PinNum=0 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000001111100
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000001111100
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=6d21298faf45bdb2
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=124
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 56664a5006b1250a  > Addr = 0X22  PinNum=1 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000001111100
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000001111100
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=56664a5006b1250a
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=124
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput db710d946ffdfc53  > Addr = 0X21  PinNum=10 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=db710d946ffdfc53
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 877325f24766f07d  > Addr = 0X21  PinNum=11 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=877325f24766f07d
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 85b723fff6052e01  > Addr = 0X21  PinNum=12 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=85b723fff6052e01
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 76769d2e6b9332b5  > Addr = 0X21  PinNum=13 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=76769d2e6b9332b5
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 1ac43c078859da74  > Addr = 0X21  PinNum=14 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=1ac43c078859da74
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 8cbe0ea4f4596ba0  > Addr = 0X21  PinNum=15 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=8cbe0ea4f4596ba0
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 6d21298faf45bdb2  > Addr = 0X22  PinNum=0 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000001111100
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000001111100
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=6d21298faf45bdb2
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=124
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 56664a5006b1250a  > Addr = 0X22  PinNum=1 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000001111100
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000001111100
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=56664a5006b1250a
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=124
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput db710d946ffdfc53  > Addr = 0X21  PinNum=10 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=db710d946ffdfc53
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 877325f24766f07d  > Addr = 0X21  PinNum=11 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=877325f24766f07d
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 85b723fff6052e01  > Addr = 0X21  PinNum=12 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=85b723fff6052e01
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 76769d2e6b9332b5  > Addr = 0X21  PinNum=13 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=76769d2e6b9332b5
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 1ac43c078859da74  > Addr = 0X21  PinNum=14 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=1ac43c078859da74
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 8cbe0ea4f4596ba0  > Addr = 0X21  PinNum=15 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=8cbe0ea4f4596ba0
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 6d21298faf45bdb2  > Addr = 0X22  PinNum=0 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000001111100
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000001111100
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=6d21298faf45bdb2
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=124
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 56664a5006b1250a  > Addr = 0X22  PinNum=1 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000001111100
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000001111100
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=56664a5006b1250a
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=124
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 Read success ipA00=01111111  ipB00=01111111   ipALL =0111111101111111
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput d19dd54af036f0d4  > Addr = 0X24  PinNum=13 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0111100000000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0101100000000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=d19dd54af036f0d4
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=22528
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 Read success ipA00=00001111  ipB00=00011000   ipALL =0001100000001111
Nov 15 14:12:49 DietPi node-red[584]: MCP23017  > Existing States:                0001100000001111
Nov 15 14:12:49 DietPi node-red[584]: MCP23017  > New States:                     0111100000001111
Nov 15 14:12:49 DietPi node-red[584]: MCP23017  >!Change! of an input: Diff Mask= 0110000000000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=d19dd54af036f0d4
Nov 15 14:12:49 DietPi node-red[584]:   MCP/PCF > New input Debounce timer set.  TimeEnd=20  State=false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 Read success ipA00=01111100  ipB00=01111111   ipALL =0111111101111100
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 Read success ipA00=00001111  ipB00=00011000   ipALL =0001100000001111
Nov 15 14:12:49 DietPi node-red[584]:   MCP/PCF > Input timer Bounce Ended. [NewState=0]   [Last State=1]  [Deb.state=false]  [Bit=14]  Ellapsed=NaNms
Nov 15 14:12:49 DietPi node-red[584]: MCP23017  > Pin 14 changed from 1 to 0;  id=1d6e002bd76462a7
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: 0   globalState= 1  Node_id=1d6e002bd76462a7
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput db710d946ffdfc53  > Addr = 0X21  PinNum=10 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=db710d946ffdfc53
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 877325f24766f07d  > Addr = 0X21  PinNum=11 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=877325f24766f07d
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 85b723fff6052e01  > Addr = 0X21  PinNum=12 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=85b723fff6052e01
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 76769d2e6b9332b5  > Addr = 0X21  PinNum=13 _newState:false > opening bus...
Nov 15 14:12:49 DietPi node-red[584]:     Read before write success ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     Updated pin ip16=0000000100000000
Nov 15 14:12:49 DietPi node-red[584]:     ...status update >>  _onOffStatus: false   globalState= 1  Node_id=76769d2e6b9332b5
Nov 15 14:12:49 DietPi node-red[584]: :-) MCP23017 setOutput finished. Closing bus. ip1=256
Nov 15 14:12:49 DietPi node-red[584]: PinOn = false; invPinOn = false
Nov 15 14:12:49 DietPi node-red[584]: MCP23017 setOutput 1ac43c078859da74  > Addr = 0X21  PinNum=14 _newState:false > opening bus...
13

Yes, that is all the logging that goes on. Because of the issues this creates in your case and actually the log file is only needed when debugging I have made the decision to make logging optional. No promises on when I'll have this done, but probably somewhere in the next two weeks, RL and my poor brain permitting.

14

Hey no rush, I'm just happy that you maintain the code <3. I get what you mean with the logging, but so much of it? I would expect that the log occurs when something happens (a change from the flow). To me it seems that your nodes get manipulated too often from my flow, but I don't see how? all configuration nodes are configured to 500ms refresh interval and only the 500ms LED toggle is active all the time. other I/O nodes get data only when I push a button on the dashboard, and then the flows idle

15

Ok a took a look at the logs and I saw that the same 8 ports are being written to constantly. So I discovered I do have a problem with my flow.
The logic for 8 stair lights is the problem. The logic is used for turning them on in a sequence and it depends on if you trip the top sensor or bottom. The thing is that I have it poorly written and it constantly (every 100ms) updates the outputs (even t idle), I will change that and leave it running for a couple of days and report back.
Maybe if you turn off logging it would help because it takes at least a day for it to bog down.
Also I'm running dietPi so logging is in RAM and flushed hourly

1 Like
16

Yup, writing the same data to a port will log data. So hey, not all is lost - at least the superfluous logging lead to streamlining of your code :wink:

That being said, I agree logging should should only occur during debugging. Once a flow is running you never look at the log again anyway (at least I don't). I think I have figured out a way to optionally allow logging, by using a checkbox on the configuration node. If checked logging occurs. Initially this will be set to unchecked, so no logging will occur.

More to follow...

1 Like
17

I agree just like release and debug compile optionions. When you put the machine in "production" or in our case "in to use" you don't look at the logs anymore. That is why I install dietpi to run node-red. No llogging and this extends the SD card life, I had one fail but that was because of an power outage.
The checkbox solution is the perfect way IMHO

18

20 hour in ant it boged down again. The output toggling LED doesn't blink in a steady interval and also reading the the input is not constant in flow editor (I have one of the outputs connected to an input, like a loop back): here are some pictures, one is 30min running and the other is 20 hours, and a screenshot of journalctl. At least I don't see any errors

OrangePi5_nodered_Not_working_journalctl
OrangePi5_nodered_Not_working_journalctl1327Ă—958 288 KB

OrangePi5_nodered_Not_working
OrangePi5_nodered_Not_working1894Ă—696 114 KB

OrangePi5_nodered_working
OrangePi5_nodered_working1536Ă—928 161 KB

19

I deleted the whole flow and am now testing with minimal (writing and reading to all 5 expanders). 6 hours in and no slowdown

20

Yes it is clear the logging is bogging everything down. I'm working on things now, but it took me a while even to figure out to run a program locally without releasing it. Figured it out finally - I am not a programmer and this was kind of a one-off for me. I tried adding a "Enable Logging" checkbox to the configuration node in the HTML code, but nothing happened. I suspect the Tip/Note is covering the checkbox and I remember in the past I found a way to raise the class = "form-tips", but can't find any CSS relating to that class. It will slowly come to me....

1 Like