File upload sometimes hangs - multer, busboy, or something else?

[filipabramowicz]

HI!

I encountered some strange problem while using multer - sometimes it hangs while uploading the file.

When I am testing this behavior on my Ubuntu it succeeds every time, but when I switch to development server it hangs quite often.

I compared the behavior on both environments and added some basic printouts for troubleshooting:

app.use(multer({
  dest: './uploads/',
  rename: function (fieldname, filename) {
    return filename.replace(/\W+/g, '-').toLowerCase();
  },
  onFileUploadStart: function (file) {
    process.stderr.write('Uploading file..........');
  },
  onFileUploadComplete: function (file) {
    process.stderr.write('done\n');
  },

...

}));

On development server Uploading file......... is printed in the console but done doesn't show up - which suggests it can be multer or busboy issue.

Full code in which I am using multer can be found here:
https://github.com/aplikacjespoleczne/WizualizacjaBudzetu

Also for troubleshooting I've added the simmilar logging to the multer code (in index.js) :

        fileStream.on('data', function(data) {
          console.log('Next part received!');        // ADDED
          if (data) { file.size += data.length; }
          // trigger "file data" event
          if (options.onFileUploadData) { options.onFileUploadData(file, data); }
        });

And the difference between Ubuntu and development server is the last chunk of data. In both environments Next part received! shows up but on development server done doesn't - which may suggest that the 'finish' event is not emitted.

Can it be multer or busboy? Can you give me some advice where to look further? What else could I trace?

Thanks!

[samuelngs]

Ya. I think I'm having the same problem as well.

[yjmoroz]

+1
first time I've used multer – i didnt used cors and credentials
and know when both are enabled, that's a huge problem
sometimes it goes well, but only when nodejs restarted and first time it upload small files very well,
when i'm trying to make further uploads it hangs up and seems this look like a memory overflow

UPD it works ideally with small files, very small; seems like it is something in nodejs and I suppose that when it will be on production server, there will be also some memory overflows
maybe.. it depends on a OS, for example I'm using OS X

[Albert-IV]

This isn't the best thought-out issue thread, but I am going to chime in here as well.

I've been having an issue where file uploads would randomly fail when going through a reverse proxy depending on the file. Larger files will upload fine through the reverse proxy, however certain trouble files will refuse to be received by the server. The request will time out on the client side, and the server never seems to receive anything.

At first I thought it was an nginx issue. If you can upload the file without using the proxy OK and it fails when using the proxy, it must be a reverse proxy issue, right? However the logs from nginx tell a different story.

Looking at the debug logs, the proxy gets the connection and pipes it to the application. On correct downloads, nginx will set up the proxy headers and upstream will respond with it parsing the headers and handling the buffered file. On incorrect downloads, nginx sets the proxied headers and then upstream never responds.

So the issue seems to be with the node application itself. During the investigation, I set up multer like so:

app.use(require('multer')({
  limits: {
    fieldNameSize: 999999999,
    fieldSize: 999999999
  },
  includeEmptyFields: true,
  inMemory: true,
  onFileUploadStart: function(file) {
    console.log('Starting ' + file.fieldname);
  },
  onFileUploadData: function(file, data) {
    console.log('Got a chunk of data!');
  },
  onFileUploadComplete: function(file) {
    console.log('Completed file!');
  },
  onParseStart: function() {
    console.log('Starting to parse request!');
  },
  onParseEnd: function(req, next) {
    console.log('Done parsing!');
    next();
  },
  onError: function(e, next) {
    if (e) {
      console.log(e.stack);
    }
    next();
  }
}));

On correct uploads, logs look something like this:

Starting to parse request!
Starting file
Got a chunk of data!
[ ... ]
Got a chunk of data!
Completed file!
Done parsing!

On bad uploads:

Starting to parse request!
Starting file
Got a chunk of data!
[ ... ]
Got a chunk of data!
Completed file!

On these "bad" files, the parser never finishes parsing the request! Not only that, the onError event never gets caught/ fired either! I'm completely open for this being a reverse proxy misconfiguration, but shouldn't onError or onParseEnd be fired?

That being said, there isn't an actual reduced use-case here yet. I'm going to work on getting one put together now.

Edit

Realized onParseEnd needed to have next() called. The issue persists after adding it either way.

I also checked the file sizes and they match from client > nginx file > multer temp file.

[jpfluger]

This thread has good leads and thanks to @filipabramowicz and @droppedonjapan for posting code. Also I use an nginx proxy myself, so can try to dup droppedonjapan tests if you get a particular use-case.

Re. filipabramowicz: I will get to trying the example that you have linked to but maybe s/thing I've been debugging will help you with leads to your problem. Maybe....

In my local tests, I've isolated multer hanging consistently but within the callbacks specified for options.limits. This might be representative of errors you are experiencing in that the issue is with the error callback process:

Currently in Multer:

busboy.on('filesLimit', function() {
  if (options.onFilesLimit) { options.onFilesLimit(); } 
});

So in my tests, I added the onFinish event after the options callback. This allowed my program to continue and not hang:

busboy.on('filesLimit', function() {
  if (options.onFilesLimit) { options.onFilesLimit(); } 
  onFinish(new Error('filesLimit reached: cannot upload more files than specified in options.limits.files'));
});

But onFinish doesn't handle errors. Here's the existing code currently in multer:

var onFinish = function () {
  if (!readFinished || fileCount > 0) return;

  for (var field in req.files) {
    if (req.files[field].length === 1) {
      req.files[field] = req.files[field][0];
    }
  }

  // Parse the body and create a best structure
  req.body = qs.parse(req.body);

  // when done parsing the form, pass the control to the next middleware in stack
  if (options.onParseEnd) { options.onParseEnd(req, next); }
  else { next(); }
};

I redesigned onFinish to more cleanly exit the code. (Again, this is code I'm working on locally and not in multer/develop yet)

var onFinish = function (err) {
  if( err ) {
    req.files = {};
    req.body = {};

    return next(err);
  } else {
    if( !readFinished || fileCount > 0 ) {
      return;
    }

    for( var field in req.files ) {
      if( req.files[field].length === 1) {
        req.files[field] = req.files[field][0];
      }
    }

    req.body = qs.parse(req.body);
  }

  if (options.onParseEnd) { options.onParseEnd(req, next); }
  else { next(); }
};

In the code above, the error would be passed-on to the next function (e.g the response handler). Also, if there's an error, I explicitly empty req.body and req.files. My reasoning is that if there is an error the data isn't complete and so the entire transaction should be treated as an error. Right/Wrong?

Other thoughts: I'm tempted to create either create a custom error or a special object (eg req.multerErr) and instead of emptying req.body and req.files, these could get assigned into it.

req.multerErr = { 
    files: req.files,
    body: req.body
    err: err
};

req.files = {}
req.body = {}

// onParseEnd is never reached b/c there's an error
return next(err);

Not certain if this code is the best direction but it's better than not having a direction, I guess. Thoughts?

[Albert-IV]

I've worked for a few hours to come up with a minimal example, but I can't seem to get one to fail like I expect. This seems to support the idea that my particular issue might not be multer's fault (which is fairly likely at this point).

That being said, I can back up that the filesLimit error handler isn't firing as expected. Before the patch, the onFilesLimit handler was never called. Once I altered multer, the onFilesLimit error handler works as advertised. 👍

(There was a missed brace somewhere in the above code, so I'm assuming you had wanted it like this:)

var onFinish = function (err) {
  if( err ) {
    req.files = {};
    req.body = {};

    return next(err);
  } else {
    if( !readFinished || fileCount > 0 ) {
      return;
    }

    for( var field in req.files ) {
      if( req.files[field].length === 1) {
        req.files[field] = req.files[field][0];
      }
    }

    req.body = qs.parse(req.body);
  }

  if (options.onParseEnd) { options.onParseEnd(req, next); }
  else { next(); }
};

As far as req.files and req.body, I'd support the idea that a malformed request would have no data set on the request. Adding a custom error field to the request would might be nice for those who want to handle errors down the line rather than multer's onError handler directly. I can't see a ton of people needing the feature, but I could potentially see some use-cases depending on the application. That being said, I am neither a maintainer or a regular here, so my opinions on this isn't super important!

That being said, thanks for looking around @jpfluger, I appreciate it. If I do end up finding a use-case that blows up I'll let you guys know!

[jpfluger]

Thanks for the brace fix. I updated the code. Stripped away some of my debugging helpers before I posted originally. Once busboy gets updated w/ a fix I pr'ed for, I'll put my proposed error handling changes in multer/develop and clone @filipabramowicz 's example for debugging.

[prabhash1785]

Is this issue resolved? I am using multer to upload file and face the same problem as discussed in this thread. I see file gets uploaded but the control never goes to the next middleware.

[katachthonios]

I'm actually having the same issue this week. I notice that the onFinish is still the same and hasn't been redesigned; I don't know if this is because the onFinish logic isn't the culprit or... Anyway, I'll keep plugging at it as well and post back here if I get anywhere good. I'll also try updating busboy if your pull request has been integrated.

Also figured I'd note that I am using cors.

[hacksparrow]

Can you share some files, which fail to be uploaded?

[katachthonios]

Its not consistent (i.e. a file will work fine multiple times and then fail or vice versa), but let me see if I can find one that is relatively consistent with causing a hang and post that. Also note worthy (perhaps) is this: I'm running node from the console currently and when the files fail to upload, hitting ctrl+c doesn't actually end node, instead the processing takes off again and the file causing the issue as well as other subsequent files upload with no problems until everything just hangs again. Changing the onFinish code as above changes this behavior however, instead of the ctrl+c fixing the issue (without restarting node) everything remains hung, and a second (or third - some multiple, never the first) ctrl+c kills node and drops back to the command line. The final thing to note is that I'm using the latest binary of node and everything is on Windows Server 2012R2 but I was having the same issue on my personal PC which is Windows 7 Home.

[prabhash1785]

I am running Node v.0.10.32 on Mac OS X 10.9.4.

Based on my experience, my file consistently gets uploaded. However during the hung status of server, multer runs twice (does the retry) and uploads the file twice and finally the request times out showing "No data received".

I am able to terminate my Node process with Control + c on console. Didn't have any problem with that.

I tried uploading small txt files (2 kb) to larger files (a few MB) and I was able to upload them both.

Here is my application code snippet:

index.js (root leve index.js at same level as package.json):

...
.....
app = module.exports = express();
app.use(kraken(options));

app = module.exports = express();
app.use(kraken(options));
app.on('start', function () {
console.log('Application ready to serve requests.');
console.log('Environment: %s', app.kraken.get('env:env'));
});

app.use(multer({
 dest: '/Users/abc/temp/fileuploads',
 limits: {
    fieldNameSize: 500,
    files: 2,
    fields: 5
 },
 rename: function (fieldname, filename) {
    return fieldname + filename + Date.now();
 },
 onFileUploadStart: function (file) {
    console.log('Upload starting for filename: ' + file.originalname);
 },
 onFileUploadData: function (file, data) {
    console.log(data.length + ' of ' + file.fieldname + ' arrived')
 },
 onParseStart: function () {
    console.log('Form parsing started at: ', new Date())
 },
 onParseEnd: function (req, next) {
    console.log('Form parsing completed at: ', new Date());
    next();
 },
 onFileUploadComplete: function (file) {
    console.log(file.fieldname + ' uploaded to  ' + file.path);
 },
 onFileSizeLimit: function (file) {
    console.log('Failed: ', file.originalname)
    fs.unlink('./' + file.path) // delete the partially written file
 },
 onFilesLimit: function () {
    console.log('Crossed file limit!')
 },
 onFieldsLimit: function () {
    console.log('Crossed fields limit!')
 },
 onPartsLimit: function () {
    console.log('Crossed parts limit!')
 },
 onError: function(error, next) {
    console.log("Error occurred while uploading the file!!");
    next(error);
 }
 }));

index.js (under controllers directory of Kraken application)

router.post('/upload', function (req, res) {

        console.log("File Uploaded");

        model.status = "File Uploaded!!";

        var body = req.body;
        console.log("File attributes: " + JSON.stringify(body));

        var files = req.files;
        console.log("Files: " + JSON.stringify(files));


        res.render('uploadfile/datauploadform', model);

    });

Here are the application logs after I start uploading the file (notice multer tried to upload same file twice before timing out):

Form parsing started at: Sat Jan 10 2015 01:29:45 GMT-0800 (PST)
Upload starting for filename: HelloNashorn.js
35 of file arrived
file uploaded to /Users/abc/temp/fileuploads/fileHelloNashorn1420882185450.js
Form parsing completed at: Sat Jan 10 2015 01:29:45 GMT-0800 (PST)

Form parsing started at: Sat Jan 10 2015 01:31:45 GMT-0800 (PST)
Upload starting for filename: HelloNashorn.js
35 of file arrived
file uploaded to /Users/abc/temp/fileuploads/fileHelloNashorn1420882305450.js
Form parsing completed at: Sat Jan 10 2015 01:31:45 GMT-0800 (PST)

[hacksparrow]

It would be hard to debug if other frameworks are involved. Can you guys write a short test which fails?

[katachthonios]

Most definitely, I'll do that later today and post back.