Strange issue with reading files cyclic from a local drive on windows [Error: EBUSY: resource busy or locked, lstat 'C:\hiberfil.sys'] maybe [red] Uncaught Exception:

Hi,

I have a strange behavior by my flow ...

I ingest by timer a message. This will be added with a starting dir and pattern and forwarded to a watcher node. After some time (hours till days) the node red stops with this message in the log:

Error: EBUSY: resource busy or locked, lstat 'C:\hiberfil.sys'

Thats weird, cause I do the following:

Source Block for import

[{"id":"dd11a718.04fdf8","type":"inject","z":"64e1771d.871f68","name":"once per 30min","props":[{"p":"payload"},{"p":"topic","vt":"str"}],"repeat":"1800","crontab":"","once":true,"onceDelay":0.1,"topic":"","payload":"","payloadType":"date","x":220,"y":740,"wires":[["cbe8c8be.c36f68"]]},{"id":"cbe8c8be.c36f68","type":"link out","z":"64e1771d.871f68","name":"Ordner Auswahl OUT","links":["38386dfe.4f4272"],"x":435,"y":740,"wires":[]},{"id":"22c65f85.3a625","type":"group","z":"64e1771d.871f68","name":"Pollingbasierte Dateierfassung","style":{"label":true,"fill":"#d1d1d1"},"nodes":["e43dec4c.b7b16","38386dfe.4f4272","d5907a3.ac77288","144c3e43.465112","ff300fcc.4b453","e94f7204.7d1ca","bc132755.1c9008","312c88c9.b0c1a8","36939d78.225552","e4063dc7.8e511","7fe2615b.6f6ed","a23a8274.1aeb8","72121d60.230f44","d5b7fe0b.685a5","b3b8ba28.865c78","90f761ee.5f366","e3836b81.b5c018","3182b457.d18a7c","2c34607d.48314","20f49c7b.639864","3a8061f.ce50d9e","80678346.f5a99","6df8a7dd.00cdd8","891a7ec9.813e8","87c63ac6.c15cc8","9366693b.e0ee88","871acd27.ee0e8","df774996.3857d8"],"x":54,"y":59,"w":1222,"h":622},{"id":"e43dec4c.b7b16","type":"link out","z":"64e1771d.871f68","g":"22c65f85.3a625","name":"Ordner Auswahl OUT","links":[],"x":1235,"y":340,"wires":[]},{"id":"38386dfe.4f4272","type":"link in","z":"64e1771d.871f68","g":"22c65f85.3a625","name":"Ordner Auswahl IN","links":["cbe8c8be.c36f68"],"x":95,"y":340,"wires":[["ff300fcc.4b453","e94f7204.7d1ca","a23a8274.1aeb8","e4063dc7.8e511"]],"icon":"node-red/arrow-in.svg"},{"id":"d5907a3.ac77288","type":"function","z":"64e1771d.871f68","g":"22c65f85.3a625","name":"C:\\MyTest","func":"msg={};\nmsg.payload={};\nmsg.payload.start=\"C:\\\\MyTest\";\nmsg.payload.pattern=\"*\";\nreturn msg;","outputs":1,"noerr":0,"initialize":"","finalize":"","libs":[],"x":440,"y":240,"wires":[["90f761ee.5f366"]]},{"id":"144c3e43.465112","type":"function","z":"64e1771d.871f68","g":"22c65f85.3a625","name":"O:\\MyFolder\\Sub1","func":"msg={};\nmsg.payload={};\nmsg.payload.start=\"O:\\\\MyFolder\\\\Sub1\";\nmsg.payload.pattern=\"*\";\nreturn msg;","outputs":1,"noerr":0,"initialize":"","finalize":"","libs":[],"x":470,"y":380,"wires":[["3a8061f.ce50d9e"]]},{"id":"ff300fcc.4b453","type":"gate","z":"64e1771d.871f68","g":"22c65f85.3a625","name":"GATE 3","controlTopic":"control","defaultState":"closed","openCmd":"open","closeCmd":"close","toggleCmd":"toggle","defaultCmd":"default","statusCmd":"status","persist":false,"storeName":"default","x":260,"y":420,"wires":[["144c3e43.465112"]]},{"id":"e94f7204.7d1ca","type":"gate","z":"64e1771d.871f68","g":"22c65f85.3a625","name":"GATE 2","controlTopic":"control","defaultState":"closed","openCmd":"open","closeCmd":"close","toggleCmd":"toggle","defaultCmd":"default","statusCmd":"status","persist":false,"storeName":"default","x":260,"y":280,"wires":[["d5907a3.ac77288"]]},{"id":"bc132755.1c9008","type":"inject","z":"64e1771d.871f68","g":"22c65f85.3a625","name":"ON/OFF","props":[{"p":"payload"},{"p":"topic","vt":"str"}],"repeat":"","crontab":"","once":false,"onceDelay":0.1,"topic":"control","payload":"toggle","payloadType":"str","x":260,"y":240,"wires":[["e94f7204.7d1ca"]]},{"id":"312c88c9.b0c1a8","type":"inject","z":"64e1771d.871f68","g":"22c65f85.3a625","name":"ON/OFF","props":[{"p":"payload"},{"p":"topic","vt":"str"}],"repeat":"","crontab":"","once":false,"onceDelay":0.1,"topic":"control","payload":"toggle","payloadType":"str","x":260,"y":380,"wires":[["ff300fcc.4b453"]]},{"id":"36939d78.225552","type":"inject","z":"64e1771d.871f68","g":"22c65f85.3a625","name":"ON/OFF","props":[{"p":"payload"},{"p":"topic","vt":"str"}],"repeat":"","crontab":"","once":false,"onceDelay":0.1,"topic":"control","payload":"toggle","payloadType":"str","x":260,"y":520,"wires":[["e4063dc7.8e511"]]},{"id":"e4063dc7.8e511","type":"gate","z":"64e1771d.871f68","g":"22c65f85.3a625","name":"GATE 4","controlTopic":"control","defaultState":"closed","openCmd":"open","closeCmd":"close","toggleCmd":"toggle","defaultCmd":"default","statusCmd":"status","persist":false,"storeName":"default","x":260,"y":560,"wires":[["7fe2615b.6f6ed"]]},{"id":"7fe2615b.6f6ed","type":"function","z":"64e1771d.871f68","g":"22c65f85.3a625","name":"\\\\myshare\\input\\","func":"msg={};\nmsg.payload={};\nmsg.payload.start=\"\\\\\\\\myshare\\\\input\\\\\";\nmsg.payload.pattern=\"*\";\nreturn msg;","outputs":1,"noerr":0,"initialize":"","finalize":"","libs":[],"x":460,"y":520,"wires":[["20f49c7b.639864"]]},{"id":"a23a8274.1aeb8","type":"gate","z":"64e1771d.871f68","g":"22c65f85.3a625","name":"GATE 1","controlTopic":"control","defaultState":"open","openCmd":"open","closeCmd":"close","toggleCmd":"toggle","defaultCmd":"default","statusCmd":"status","persist":false,"storeName":"default","x":260,"y":140,"wires":[["72121d60.230f44"]]},{"id":"72121d60.230f44","type":"function","z":"64e1771d.871f68","g":"22c65f85.3a625","name":"\\\\someothershare\\input","func":"msg={};\nmsg.payload={};\nmsg.payload.start=\"\\\\\\\\someothershare\\\\input\";\nmsg.payload.pattern=\"*\";\nreturn msg;","outputs":1,"noerr":0,"initialize":"","finalize":"","libs":[],"x":480,"y":100,"wires":[["e3836b81.b5c018"]]},{"id":"d5b7fe0b.685a5","type":"inject","z":"64e1771d.871f68","g":"22c65f85.3a625","name":"ON/OFF","props":[{"p":"payload"},{"p":"topic","vt":"str"}],"repeat":"","crontab":"","once":false,"onceDelay":0.1,"topic":"control","payload":"toggle","payloadType":"str","x":260,"y":100,"wires":[["a23a8274.1aeb8"]]},{"id":"b3b8ba28.865c78","type":"function","z":"64e1771d.871f68","g":"22c65f85.3a625","name":"Unpack Array to msg.file","func":"var file;\nvar sTime=new Date().toISOString();\nnode.status({text:msg.payload.length+\" Files @ \" + sTime});\n//scan array\nfor (iFile=0;iFile<msg.payload.length;iFile++)\n{\n var outmsg={};\n // outmsg.filename=\"c:\\\\temp\\\\kis\\\\1620275840176[0] - Kopie.txt\";\n outmsg.filename=msg.payload[iFile];\n var sPath=\"\";\n var sFile=\"\";\n var iEndDir=outmsg.filename.lastIndexOf(\"\\\\\");\n if (iEndDir>0)\n {\n //found a path\n sFile=outmsg.filename.slice(iEndDir+1);\n sPath=outmsg.filename.slice(0,iEndDir);\n }\n else\n {\n node.warn(\"can't find path in \" + outmsg.filename + \"! Result=\" + iEndDir);\n }\n outmsg.filedir=sPath;\n outmsg.file=sFile;\n node.send(outmsg);\n}\n//drop the original array\nreturn;\n\nfunction getPath(sFileAndPath)\n{\n\nreturn sPath;\n}","outputs":1,"noerr":0,"initialize":"","finalize":"","libs":[],"x":670,"y":280,"wires":[["e43dec4c.b7b16"]]},{"id":"90f761ee.5f366","type":"fs-file-lister","z":"64e1771d.871f68","g":"22c65f85.3a625","name":"List by Inject","start":"C:\\Temp","pattern":"*.*","folders":"*","hidden":true,"lstype":"files","path":true,"single":true,"depth":"2","stat":false,"showWarnings":true,"x":450,"y":280,"wires":[["b3b8ba28.865c78","9366693b.e0ee88"]]},{"id":"e3836b81.b5c018","type":"fs-file-lister","z":"64e1771d.871f68","g":"22c65f85.3a625","name":"List by Inject","start":"C:\\Temp","pattern":"*.*","folders":"*","hidden":true,"lstype":"files","path":true,"single":true,"depth":"2","stat":false,"showWarnings":true,"x":450,"y":140,"wires":[["3182b457.d18a7c","6df8a7dd.00cdd8"]]},{"id":"3182b457.d18a7c","type":"function","z":"64e1771d.871f68","g":"22c65f85.3a625","name":"Unpack Array to msg.file","func":"var file;\nvar sTime=new Date().toISOString();\nnode.status({text:msg.payload.length+\" Files @ \" + sTime});\n//scan array\nfor (iFile=0;iFile<msg.payload.length;iFile++)\n{\n var outmsg={};\n // outmsg.filename=\"c:\\\\temp\\\\kis\\\\1620275840176[0] - Kopie.txt\";\n outmsg.filename=msg.payload[iFile];\n var sPath=\"\";\n var sFile=\"\";\n var iEndDir=outmsg.filename.lastIndexOf(\"\\\\\");\n if (iEndDir>0)\n {\n //found a path\n sFile=outmsg.filename.slice(iEndDir+1);\n sPath=outmsg.filename.slice(0,iEndDir);\n }\n else\n {\n node.warn(\"can't find path in \" + outmsg.filename + \"! Result=\" + iEndDir);\n }\n outmsg.filedir=sPath;\n outmsg.file=sFile;\n node.send(outmsg);\n}\n//drop the original array\nreturn;\n\nfunction getPath(sFileAndPath)\n{\n\nreturn sPath;\n}","outputs":1,"noerr":0,"initialize":"","finalize":"","libs":[],"x":670,"y":140,"wires":[["e43dec4c.b7b16"]]},{"id":"2c34607d.48314","type":"function","z":"64e1771d.871f68","g":"22c65f85.3a625","name":"Unpack Array to msg.file","func":"var file;\nvar sTime=new Date().toISOString();\nnode.status({text:msg.payload.length+\" Files @ \" + sTime});\n//scan array\nfor (iFile=0;iFile<msg.payload.length;iFile++)\n{\n var outmsg={};\n // outmsg.filename=\"c:\\\\temp\\\\kis\\\\1620275840176[0] - Kopie.txt\";\n outmsg.filename=msg.payload[iFile];\n var sPath=\"\";\n var sFile=\"\";\n var iEndDir=outmsg.filename.lastIndexOf(\"\\\\\");\n if (iEndDir>0)\n {\n //found a path\n sFile=outmsg.filename.slice(iEndDir+1);\n sPath=outmsg.filename.slice(0,iEndDir);\n }\n else\n {\n node.warn(\"can't find path in \" + outmsg.filename + \"! Result=\" + iEndDir);\n }\n outmsg.filedir=sPath;\n outmsg.file=sFile;\n node.send(outmsg);\n}\n//drop the original array\nreturn;\n\nfunction getPath(sFileAndPath)\n{\n\nreturn sPath;\n}","outputs":1,"noerr":0,"initialize":"","finalize":"","libs":[],"x":670,"y":560,"wires":[["e43dec4c.b7b16"]]},{"id":"20f49c7b.639864","type":"fs-file-lister","z":"64e1771d.871f68","g":"22c65f85.3a625","name":"List by Inject","start":"C:\\Temp","pattern":"*.*","folders":"*","hidden":true,"lstype":"files","path":true,"single":true,"depth":"2","stat":false,"showWarnings":true,"x":450,"y":560,"wires":[["2c34607d.48314","df774996.3857d8"]]},{"id":"3a8061f.ce50d9e","type":"fs-file-lister","z":"64e1771d.871f68","g":"22c65f85.3a625","name":"List by Inject","start":"C:\\Temp","pattern":"*.*","folders":"*","hidden":true,"lstype":"files","path":true,"single":true,"depth":"2","stat":false,"showWarnings":true,"x":450,"y":420,"wires":[["80678346.f5a99","871acd27.ee0e8"]]},{"id":"80678346.f5a99","type":"function","z":"64e1771d.871f68","g":"22c65f85.3a625","name":"Unpack Array to msg.file","func":"var file;\nvar sTime=new Date().toISOString();\nnode.status({text:msg.payload.length+\" Files @ \" + sTime});\n//scan array\nfor (iFile=0;iFile<msg.payload.length;iFile++)\n{\n var outmsg={};\n // outmsg.filename=\"c:\\\\temp\\\\kis\\\\1620275840176[0] - Kopie.txt\";\n outmsg.filename=msg.payload[iFile];\n var sPath=\"\";\n var sFile=\"\";\n var iEndDir=outmsg.filename.lastIndexOf(\"\\\\\");\n if (iEndDir>0)\n {\n //found a path\n sFile=outmsg.filename.slice(iEndDir+1);\n sPath=outmsg.filename.slice(0,iEndDir);\n }\n else\n {\n node.warn(\"can't find path in \" + outmsg.filename + \"! Result=\" + iEndDir);\n }\n outmsg.filedir=sPath;\n outmsg.file=sFile;\n node.send(outmsg);\n}\n//drop the original array\nreturn;\n\nfunction getPath(sFileAndPath)\n{\n\nreturn sPath;\n}","outputs":1,"noerr":0,"initialize":"","finalize":"","libs":[],"x":670,"y":420,"wires":[["e43dec4c.b7b16"]]},{"id":"6df8a7dd.00cdd8","type":"link out","z":"64e1771d.871f68","g":"22c65f85.3a625","name":"FileWatch Found 1","links":["891a7ec9.813e8"],"x":595,"y":200,"wires":[],"icon":"node-red/light.svg"},{"id":"891a7ec9.813e8","type":"link in","z":"64e1771d.871f68","g":"22c65f85.3a625","name":"","links":["9366693b.e0ee88","df774996.3857d8","871acd27.ee0e8","6df8a7dd.00cdd8"],"x":855,"y":640,"wires":[["87c63ac6.c15cc8"]],"icon":"node-red/light.svg"},{"id":"87c63ac6.c15cc8","type":"debug","z":"64e1771d.871f68","g":"22c65f85.3a625","name":"FileWatch-Found","active":false,"tosidebar":true,"console":false,"tostatus":false,"complete":"true","targetType":"full","statusVal":"","statusType":"auto","x":1010,"y":640,"wires":[]},{"id":"9366693b.e0ee88","type":"link out","z":"64e1771d.871f68","g":"22c65f85.3a625","name":"FileWatch Found 2","links":["891a7ec9.813e8"],"x":575,"y":340,"wires":[],"icon":"node-red/light.svg"},{"id":"871acd27.ee0e8","type":"link out","z":"64e1771d.871f68","g":"22c65f85.3a625","name":"FileWatch Found 3","links":["891a7ec9.813e8"],"x":575,"y":480,"wires":[],"icon":"node-red/light.svg"},{"id":"df774996.3857d8","type":"link out","z":"64e1771d.871f68","g":"22c65f85.3a625","name":"FileWatch Found 4","links":["891a7ec9.813e8"],"x":575,"y":620,"wires":[],"icon":"node-red/light.svg"}]

I dont access C:\ by the ingests or settings. There is always a directory given. It's weird.

I ran into those problems with Node RED 1.3 and also 2.1.3 on different machines.

Since the other parts of the flow are only about reading the file and calculating stuff, I don't think, that the error come from those nodes. I testet the flow before by manually locking reading by API on certain files and the standard errorhandling of NodeRED caught them well.

Do you have any ideas why this is happening?

I modified the settings.json to do a [trace] instead of [warn] maybe this will give more informations.

Why would you think that to be weird? That file is a system file and if something messes with it, you won't be able to recover from hibernation.

Indeed, you shouldn't be messing with ANYTHING in c:\ as a general rule and indeed, I think that Windows 10 stops you anyway these days.


OK, so you don't think you are messing with c:. I don't have time to load your flow but I'm thinking that the first part of your flow may not be doing what you think? Perhaps it is scanning c:\ instead of c:\My Test/?

Indeed, as you have a space in that name, have you accounted for that?

@TotallyInformation ... I got the point in the space in "C:\My Test" ... agreed. But to be honest, I am using more complex shares and dirstructures, which I did not like to share, as they do not indicate the problem. Since every machine I use this flow shows the same behavior with different shares and directories set, I really wonder why it should try to access 'C:\hiberfil.sys'. I thing I got to wait more time until I get a proper [trace] log.

And furthermore, the routine runs for aprox 4 hours until the problems occure. While doing so, it processes aprox 500.000 files without problems.

Anyway and to explain a bit more, when running in a docker or service, you will not see the error, cause it just restarts node red. It's just visible, if you run node red per commandline like:

node.exe node_modules/node-red/red.js --settings=C:\\NodeRED\\node-red_home\\settings.js

Can you trigger that section of the flow manually? Does that trigger the problem? Clearly something is scanning the root folder, we need to find out exactly what. Otherwise, hopefully the trace log will show it. Might also be worth putting in a catch node and output to both the debug panel and to the console log so we can be sure of seeing it.

1 Like

No. I did this for more than 100 times. I just find NodeRED next morning having stopped by this error. So I guess, we got to wait another day.

I started another flow like the same .... with directly accessing C:\

but NodeRED continues to work.

On the other machines nodeRED stopped by an "Uncaught Exception:"

Maybe the conincidence is just random?

OK, so you've now given more info and shown us that it is the fs-ops-stats node and fs-file-lister nodes causing the issue.

If you put a catch & debug node in place, you should be able to find out exactly which of the deployed nodes is triggering the error then you can work out why.

Hey,

first of all ... Happy New Year :slight_smile: .

second: I will implement the node you proposed and have a look.

Okay guys, looks I can reproduce the behavior:

I played around a bit to create some other logic for watching the dirs and I think I found the problematic constellation.

I activated "trace" logging ... and it stopped without any notice where the source is:

But after I have seen this happening twice within minutes, I knew what I did on the machine. I found more details and I can reproduce very fast:

Create the flow like this:

[{"id":"809a302f9bb08e6c","type":"tab","label":"Demonstrator Error","disabled":false,"info":"","env":[]},{"id":"777695dcd442bb18","type":"comment","z":"809a302f9bb08e6c","name":"how to reprodurce the following error","info":"Make sure you dont have only dir 1 and 2 (if 3 and 4 exist, please erase BEFORE you start nodered)\n\nC:\\Dir1\nC:\\Dir2\nC:\\Dir3\nC:\\Dir4\n\nSetup the Watchers to the dirs\n\nDeploy flow\n\nWait aprox 30s\n\nCreate \"dir3\" or \"dir4\" ... it will crash","x":190,"y":80,"wires":[]},{"id":"184a9ce7da6260b4","type":"watch","z":"809a302f9bb08e6c","name":"watch dir1","files":"c:\\\\dir1","recursive":"","x":180,"y":160,"wires":[["e502bca0f70fdb41"]]},{"id":"478352a49749057c","type":"watch-directory","z":"809a302f9bb08e6c","folder":"c:\\dir2","recursive":0,"typeEvent":"create","ignoreInitial":true,"ignoredFiles":"","ignoredFilesType":"re","name":"watch-directory dir2","x":210,"y":260,"wires":[["e502bca0f70fdb41"]]},{"id":"31392672ac1aeaef","type":"watch","z":"809a302f9bb08e6c","name":"watch dir3","files":"c:\\\\dir3","recursive":"","x":180,"y":200,"wires":[["e502bca0f70fdb41"]]},{"id":"9ea3790711e036f7","type":"watch-directory","z":"809a302f9bb08e6c","folder":"c:\\dir4","recursive":0,"typeEvent":"create","ignoreInitial":true,"ignoredFiles":"","ignoredFilesType":"re","name":"watch-directory dir4","x":210,"y":320,"wires":[["e502bca0f70fdb41"]]},{"id":"e502bca0f70fdb41","type":"debug","z":"809a302f9bb08e6c","name":"","active":true,"tosidebar":true,"console":true,"tostatus":true,"complete":"true","targetType":"full","statusVal":"payload","statusType":"auto","x":550,"y":220,"wires":[]},{"id":"af191e3ba6bb08a1","type":"catch","z":"809a302f9bb08e6c","name":"","scope":null,"uncaught":false,"x":470,"y":360,"wires":[["e502bca0f70fdb41"]]}]

image

If you deploy, you will see, the logs are ok so far

Then create dir3 or dir4 - it does not matter what dir you create.

You will instantly get this error and node-red is crashed:

It seems to happen, if some watcher (the one from node red or the alternative one) was trying to monitor a folder which did not exist and after that this one is created.

Since in my original flows I was using network drives too, maybe the got lost due to network issues and reconnected some time later.

As a conclusion .... it is caused by something both nodes use.

Related nodes:

  • node-red-watch (node-red - core - 23 watch.js)
  • node-red-contrib-watch (GIT , using chokidar)

I am using this node RED: 2.1.3 (and i have seen the error on 1.3.4 too).

@knolleary ... we had a similar issue with the watch node some time before, if you remember. ( Watch node throws errors if new files deleted by hardillb · Pull Request #2997 · node-red/node-red (github.com)))

I worked around this bug by automaticly restarting node red ...

Reason for node RED crashing at this point is a bad handling of the watch-directory using chokidar.
I worked around by changing the throw(err) in line 66 to node.errror(err). THX to the guys from nodered for this.
I am still working on a workaround, which keeps the watch alive ...

This topic was automatically closed 60 days after the last reply. New replies are no longer allowed.