denoland / deno

A modern runtime for JavaScript and TypeScript.
https://deno.com
MIT License
97.3k stars 5.36k forks source link

Slow upload speed for http server #13608

Open devalexqt opened 2 years ago

devalexqt commented 2 years ago

I tested upload speed for varius file sizes: 10M, 100M, 1000M in comparison of node.js upload speed in Deno is about 2x-3x slower and on 1G file deno is 10x slower and use almost all CPU resources (my ubuntu 20.04 vps server has 2 cpu cores and 2G ram). What I'm doing wrong or how to improve upload speed??

Send test data to server(localhost) via curl:

time curl -H "Content-Type:application/octet-stream" --data-binary @/dir/dev/foo1000M.bin  http://127.0.0.1:8080/upload/foo.bin

Test file for uploading was created by command:

truncate -s 10M foo10M.bin
import { serve } from "https://deno.land/std@0.125.0/http/server.ts";
import { config } from "./modules/config.js"
import * as path from "https://deno.land/std/path/mod.ts"
import {
    writableStreamFromWriter,
    readableStreamFromReader,
} from "https://deno.land/std/streams/mod.ts";

const PORT=8080

async function handler(req){
    console.log(`>>>new request: ${req.method}, ${req.url}, path: ${req.pathname} params: ${req.searchParams}`)
    console.log("HEADERS:",req.headers)

    if (req.body) {
        console.log("==>hasBody!");
        const file = await Deno.open(path.join(config.upload_dir, "native_deno.bin"), { create: true, write: true })
        const writableStream = writableStreamFromWriter(file)
        await req.body.pipeTo(writableStream)
    }
    console.log(">>upload complete!")
    return new Response("upload complete!");
}

serve(handler, { port: PORT })
console.log(">>>server listen...",PORT)

Results:

for 10M file:
   Deno:  60 - 90ms      Node:  35-40ms

for 100M file:
    Deno:  500-600ms   Node:  260ms

for 1000M file:
    Deno:  20s-5m          Node: 1000-1700ms

I repeat upload test multiple times and every time on 1G file deno server become slower and slower (for 10M and 100M test file I don't see any performance reduction) but node server upload time stay the same avery time.

lucacasonato commented 2 years ago

Please include your node code too.

devalexqt commented 2 years ago

This is my simple test node code:

const express = require('express')
const morgan = require('morgan')
const fs = require('fs')
const path = require('path')
const stream = require('stream/promises')

const app = express()
const port = 8081

app.use(morgan('tiny'))

app.get('/', (req, res) => {
    res.send('Hello World! ' + new Date())
})

app.post("/upload/:filename", async (req, res) => {

    //check file name
    if (!req?.params?.filename || !/^[0-9a-zA-Z\.\-\_]+$/.test(req?.params?.filename)) {
        return res.send("Invalid file name!")
    }

    const fs_stream = fs.createWriteStream(path.join("/dir/www/upload", req.params?.filename), { flags: "w" })

    //stream body to file
    await stream.pipeline(req, fs_stream)
    res.send("File successfully uploaded to node server!")
    fs_stream.close()
})

app.listen(port, () => {
    console.log(`==>listening on port ${port}`)
})
devalexqt commented 2 years ago

Then I test uploading of 1G file multiple times I see performance degrades.

kitsonk commented 2 years ago

Duplicate of #10157?

lucacasonato commented 2 years ago

@kitsonk Maybe - I have some stuff to do on Monday, but I'll try to investigate this on Tuesday.

lucacasonato commented 2 years ago

@devalexqt So I can reproduce Deno being slower than Node here, but not catastrophically slower like your benchmark suggests. I measured 1GB uploads to the Node server at 1.24 secs, and the Deno upload at 3.40 secs. I am using your exact script and commands, except that I am writing to /tmp instead of cwd.

Is there anything else I should know to be able to reproduce your results? What Deno version are you on?

devalexqt commented 2 years ago

@devalexqt So I can reproduce Deno being slower than Node here, but not catastrophically slower like your benchmark suggests. I measured 1GB uploads to the Node server at 1.24 secs, and the Deno upload at 3.40 secs. I am using your exact script and commands, except that I am writing to /tmp instead of cwd.

Is there anything else I should know to be able to reproduce your results? What Deno version are you on?

Try to upload 1g file multiple times in the row, every time it's slower and slower...

2x-3x slower that node, looks catastrophic in my eyes, something wrong in deno code under the hood.

I'm using latest deno version, and node 16.

Also, I had 2 cpu and 2g ram server.

lucacasonato commented 2 years ago

I'll try that, thanks.

2x-3x slower that node, looks catastrophic in my eyes, something wrong in deno code under the hood.

I agree it isn't great, but 5s is much faster than 5 minutes (60x faster) šŸ˜…

Also, I had 2 cpu and 2g ram server.

Ah, I think this may be related. I'll take this into account.

devalexqt commented 2 years ago

Deno also uses almost all CPU resource during upload 1G file.

devalexqt commented 2 years ago

Any news?

kitsonk commented 2 years ago

No.

ry commented 2 years ago

We've recently added the ability to use Web Streams directly with file system files.

https://deno.com/blog/v1.19#files-network-sockets-and-stdio-are-now-native-web-streams

@devalexqt I'd be interested to see your benchmark again with this new interface:

async function handler(req) {
    console.log(`>>>new request: ${req.method}, ${req.url}, path: ${req.pathname} params: ${req.searchParams}`)
    console.log("HEADERS:",req.headers)

    if (req.body) {
        console.log("==>hasBody!");
        const file = await Deno.create(path.join(config.upload_dir, "native_deno.bin"))
        await req.body.pipeTo(file.writable)
    }
    console.log(">>upload complete!")
    return new Response("upload complete!");
}
devalexqt commented 2 years ago

Thanks, will try today.

devalexqt commented 2 years ago

Hi! Tested new version:

deno --version
deno 1.19.0 (release, x86_64-unknown-linux-gnu)
v8 9.9.115.7
typescript 4.5.2

I tested 1G file uploading and with new version total uploading time is reduced from 16.5 to 5.3 seconds (3x improvement and result more stable if I repeat test multiple times). But node.js has 2.3 seconds! (2x faster) and uses 2x less CPU power on my VPS server: 2 CPU & 2G RAM. I also want to try to run test on 4-8 core CPU.

devalexqt commented 2 years ago

Hi! Running the tests on another VPS with 4 CPUs and 8 GB of RAM gives exactly the same result. Basycally deno has 1G/5s =200MByte/secod throughput , but node has 450MByte/s throughput. So, deno is 2x slower and it's a huge difference.

How we can improve it?

devalexqt commented 2 years ago

Tested again on new deno and std versions:

deno 1.19.2
std@0.128.0

Deno still 2x slower vs node : 2.3sec vs 5.5sec

devalexqt commented 2 years ago
deno 1.21.0
std@0.136.0

Deno still 2x slower vs node : 2.3sec vs 5.5sec

devalexqt commented 2 years ago

Tested new deno release:

deno 1.21.1
std@0.137.0

Deno is slightly faster than previous version 4.5s, but still 2x slower than node 2.3s

devalexqt commented 2 years ago

Same results as before...

deno 1.21.3
std@0.139.0
devalexqt commented 2 years ago

Same result as before....

deno 1.22.0
std@0.140.0
devalexqt commented 2 years ago

Same result as before....

deno 1.22.1
std@0.141.0
devalexqt commented 2 years ago

Same result as before....

deno 1.23.0
std@0.144.0
devalexqt commented 2 years ago

Same result as before....

deno 1.24.0
std@0.149.0
bartlomieju commented 2 years ago

We are actively working on improving performance of HTTP server.

devalexqt commented 2 years ago

I'm tested same server but with new Deno.serve(), result is the same: 2x slower vs node.

deno 1.25.0 (release, x86_64-unknown-linux-gnu)
v8 10.6.194.5
typescript 4.7.4
devalexqt commented 2 years ago

Same slow results.

deno 1.25.1 (release, x86_64-unknown-linux-gnu)
v8 10.6.194.5
typescript 4.7.4
marcosc90 commented 2 years ago

ReadableStreams are quite slow as compared to the old Reader/Writer interface, because the buffer is not being reused. Allocating a new Uint8Array on every chunk is one of the reasons of the slow performance on big uploads.

https://github.com/denoland/deno/blob/d7b27ed63bf74c19b0bc961a52665960c199c53a/ext/http/01_http.js#L383-L390

By reusing the buffer (not using ReadableStream) uploading a 2gb file takes around 3 seconds, the same upload using a ReadableStream takes 4.8 seconds on my computer.

I love having spec compliant Response and Request, but when dealing with a lot of data is nice to have some lower level APIs. I think we should expose lower level APIs for users that really need that speed.

The same bottleneck happens in fetch when downloading large files.

marcosc90 commented 2 years ago

I'm working on this, I'll try to have a PR by tomorrow.

lucacasonato commented 2 years ago

Xref #16046

devalexqt commented 2 years ago

Same slow results.

deno 1.26.1 (release, x86_64-unknown-linux-gnu)
v8 10.7.193.3
typescript 4.8.3
ripanioan commented 2 years ago

On Windows, the gap between deno and node is getting closer. \ Results for uploading an 1GB file:

node ~ 3.5 sec deno ~ 3.8 sec

deno 1.27.0 (release, x86_64-pc-windows-msvc)
v8 10.8.168.4
typescript 4.8.3
devalexqt commented 2 years ago

Little bit faster but still 2x slower vs node.

deno 1.27.0 (release, x86_64-unknown-linux-gnu)
v8 10.8.168.4
typescript 4.8.3
coderbuzz commented 1 year ago

Hi, any update?

devalexqt commented 1 year ago
deno 1.29.4 (release, x86_64-unknown-linux-gnu)
std  0.173.0

Same slow results...

coderbuzz commented 1 year ago

How it compared with Bun?

On Wed, Jan 18, 2023, 17:12 devalexqt @.***> wrote:

deno 1.29.4 (release, x86_64-unknown-linux-gnu) std 0.173.0

Same slow results...

ā€” Reply to this email directly, view it on GitHub https://github.com/denoland/deno/issues/13608#issuecomment-1386802366, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAJZVS2VOV3XINOIM27NZQLWS66XLANCNFSM5NVO2WJQ . You are receiving this because you commented.Message ID: @.***>

aapoalas commented 1 year ago

What's the current code you're running by the way? I think writableStreamFromReader etc. are no longer needed as there's now a .readable and .writable property in the Deno.open result: https://deno.land/api@v1.29.4?s=Deno.FsFile#prop_readable

aapoalas commented 1 year ago

I tested this with the .writable property from Deno.open. I had to use my browser as the sending side because CURL would always set Content-Length to 10, and if I set it manually the upload would hang (presumably from Deno waiting for more data while CURL would not send any more).

Using the browser I sent 107374182 bytes, that is about 103M, in 880-920 milliseconds. So, based on that it seems like with the new APIs allotted that use the fast streams feature behind the scenes, performance is now on par with Node.

EDIT: Never mind, you were already using the new APIs so it seems like my results are not in line with what you see.

After some more tinkering I got a 512M buffer sent over taking 4687 ms on the browser from start to finish, and 2947 ms on Deno end to save the file (including file open), so that seems to be more in line with what @devalexqt has been seeing.

aapoalas commented 1 year ago

Example performance graph of one upload: image

Zoomed in: image

If I'm not badly mistaken, this means that the stream isn't actually taking the "fast stream API", right? As that would happen behind the scenes, outside of JavaScript.

aapoalas commented 1 year ago

Profiling can be done by setting up the server from the topic statement (change to use Deno.serve or some other API if preferred) and start the server with deno run --unstable -A --inspect server.ts. Then connect via Chrome profiler, start a performance recording and start a curl session to upload 1000MB or 1GB file (use -X POST -T 1GB_file.bin if you run into curl memory issues).

I'll come back with a proper profiling code and setup later today.

aapoalas commented 1 year ago

Here's the way I profiled this:

// test.ts
import { dirname, fromFileUrl, join } from "https://deno.land/std/path/mod.ts";

const directory = dirname(fromFileUrl(import.meta.url));

Deno.serve(async (req) => {
  console.group("Request to", req.method, req.url);
  console.log(`Headers:`, req.headers);

  if (req.body) {
    console.log("Initiating upload");
    const start = performance.now();
    const file = await Deno.open(join(directory, "native_deno.bin"), {
      create: true,
      write: true,
    });
    await req.body.pipeTo(file.writable);
    console.log("Finished upload in", performance.now() - start, "ms");
  }
  console.groupEnd();
  return new Response();
});

And start the server with deno run --inspect --unstable --allow-net=0.0.0.0 --allow-write=. test.ts. Then start up a debugger with either Chrome / Chromium, or VS Code or some other way if that's your preference.

Create a 1 GB file with

truncate -s 1G foo1GB.bin

then start a Performance recording in debugger and send the file to the server with

time curl -H "Content-Type:application/octet-stream" -XPOST -T foo1G.bin  http://127.0.0.1:8000

Side note about profiling performance:

Locally currently when I do not have a debugger connected, the 1GB upload finishes in just about a second.

When I connected a debugger but do not start up a performance recording, the upload takes anything from 3.5 to more than 4 seconds.

If I start a performance recording, the upload again goes down to about a second. This may indicate some issue with Deno regarding a connected-but-idle debugger client. This same happens with Node as well.

rsgilbert commented 1 year ago

Any update?

devalexqt commented 1 year ago

Upload 1G file: (This is test for 4 core VPS server)

deno 1.34.3 (release, x86_64-unknown-linux-gnu)
v8 11.5.150.2
typescript 5.0.4
std 0.192.0

deno: 2.7s node: 1.8s

1.5X slower

lino-levan commented 1 year ago

ref: #19737