Since v6.4.4, incoming file's ReadStream occassionaly hangs

[BobbyWibowo]

I'm not sure how to pinpoint this
It does not appear to be specific to any files
After retrying the same exact files, they tend to go through after awhile
And those that have succeeded before may still end up hanging when tried again later

Assume the following, which can basically be simplified into:

req.multipart(async field => {
  const readStream = field.file.stream
  await new Promise((resolve, reject) => {
    const writeStream = fs.createWriteStream('/path/to/dest')
    writeStream.once('finish', resolve)
    readStream.pipe(writeStream)
  })
})

All I could tell is that, whenever that happens, readStream:data event is only ever fired once (regardless of the size of the payload), until uWebSockets forcefully closes the connection 10s later
And needless to say, neither readStream:end nor writeStream:finish events ever get fired

Using the exact same code base, but on hyper-express v6.4.2, simply works every time 😕

[kartikk221]

Hey, could try periodically logging the Request.paused property to detect if the Request is paused while it hangs? This may signify that there is an incorrect pausing/resuming behavior internally which causes this.

[BobbyWibowo]

Ah yes, additionally, that test was done locally, and connected straight to the port hyperexpress was configured to listen to
As in, no mid proxies such as nginx or such in between

And gotcha, enjoy the weekends!
It's not really urgent anyways, since v6.4.2 works fine on my production server
Just that, the issue persists since v6.4.4 till v6.4.5, when tested locally at least, and fearing it'd remain as such going forward, I figured I'd just bring it up on a discussion

[kartikk221]

Hey @BobbyWibowo could you try adding a setInterval loop or a call of Request.resume() on each iteration of your request handler to constantly resume the request if it ever gets paused? The resume call will be a no-op if the request is already flowing, so If you consistently do it and all the sudden issue resolves then we can target this problem to the pause/resume functionality.

[BobbyWibowo]

@kartikk221 Unfortunately that did not seem to help

[23:20:29.091] self.upload(): /api/upload
[23:20:29.092] await req.multipart()
[23:20:30.096] req.resume()
[23:20:31.097] req.resume()
[23:20:32.097] req.resume()
[23:20:33.098] req.resume()
[23:20:34.099] req.resume()
[23:20:35.099] req.resume()
[23:20:36.000] req.resume()
[23:20:37.000] req.resume()
[23:20:38.000] req.resume()
[23:20:39.001] req.resume()
[23:20:40.002] req.resume()
[23:20:41.084] req.multipart() resolved
[23:20:41.084] req.multipart() resolved before a file's Promise (timed out?)

Also I think I hadn't mentioned this before, but when I'm sending 3MB+ files, according to client, it indeed isn't always able to send the whole file's bytes either, as if something is indeed telling client to wait just from the very first(ish) request, or something:

Then again even the following 1MB-ish file regularly fails:

The reported bytes on client-side are from XHR progress event's loaded property, so for the first screenshot, all 3 fired events should be reporting "overall total bytes sent"

[kartikk221]

Are you able to recreate this with just a small Node.js program to upload a bunch of files or is this only reproducable when you try to upload from the browser? Also, is it reproducable without the Dropzone library or only with the library?

So this issue essentially got created once I added the optimization to inject middleman methods for all stream methods on the Request/Response components which lazy initialize the streams under the hood for less initialization costs.

The thing is I don't really know why lazy initializing the stream would cause this weird behavior where it works and then simply hangs.

[BobbyWibowo]

Unfortunately, it is still reproducible via generic HTML <form method="post" enctype="multipart/form-data"> (both Firefox 103.0 and Chrome 104.0.5112.79), and generic form POST request via Thunder Client VSCode extension (which supposedly uses Got under the hood)

[BobbyWibowo]

Adding to this again,
Initially I was afraid there was something else in my existing code base that might've been the cause for this, so I went on to write a short sample project, but alas could still reproduce the issue in it as well

https://github.com/BobbyWibowo/hyper-express-playground/blob/262ab615d9be0404e8d2a7d9aa441085914e6f0c/index.js
console logs: https://github.com/BobbyWibowo/hyper-express-playground/blob/262ab615d9be0404e8d2a7d9aa441085914e6f0c/samples/1661288107174.log

[BobbyWibowo]

Unfortunately this issue is still reproducible in release 6.4.6 😢

[kartikk221]

Unfortunately this issue is still reproducible in release 6.4.6 😢

Yeah, I aim to fix this problem in the next update as I haven't been able to properly re-create it. I'm going to try to go full manual for the testing part by uploading from the browser on a localhost API because using streams to automatically upload files even at scale seems to pass with the md5 hash of the source and the destination matching in my testing.

[kartikk221]

Hey, I was able to figure out the bug and it was due to uWebsockets.js pausing the request on HttpRequest.resume() call instead of "resuming" the request, so just solved the issue by adding a boolean flag to prevent unneccessary calls to uWS. This problem should be solved in the recent v6.4.7 release.

[BobbyWibowo]

Sweet, I can confirm it works on my end! ❤️