search

silverwind / droppy

**ARCHIVED** Self-hosted file storage
BSD 2-Clause "Simplified" License
1.62k stars 194 forks source link

Upload stops after 1 minute #430

Open insajd opened 3 years ago

insajd commented 3 years ago

droppy 12.0.1 node 14.5.0 Installed using docker silverwind/droppy:latest Same behavior in new Edge , Chrome. Log where error can be seen - any upload is cancelled after ~1 minute of uploading Can you suggest where should I search for the culprit?

2020-08-17 04:52:47 [INFO] xxx:49374 GET /!/token [200] [1ms],
2020-08-17 04:52:47 [INFO] xxx:56039 WebSocket [connected],
2020-08-17 04:52:56 [INFO] xxx:13395 POST /!/upload?vId=0&to=/&rename=0 [200] [6ms] Upload started,
2020-08-17 04:53:56 [INFO] xxx:13395 POST /!/upload?vId=0&to=/&rename=0 [200] [60057ms] Upload cancelled

Config file

{
  "listeners": [
    {
      "host": [
        "0.0.0.0",
        "::"
      ],
      "port": 8989,
      "protocol": "http"
    }
  ],
  "public": false,
  "timestamps": true,
  "linkLength": 5,
  "linkExtensions": false,
  "logLevel": 2,
  "maxFileSize": 0,
  "updateInterval": 1000,
  "pollingInterval": 0,
  "keepAlive": 20000,
  "allowFrame": false,
  "readOnly": false,
  "ignorePatterns": [],
  "watch": true,
  "headers": {}
}
silverwind commented 3 years ago

Is there a reverse proxy or are you connecting directly? Reverse proxies generally have very low request timeouts that need to be adjusted.

Cubox commented 3 years ago

Same issue with nginx It's nginx's fault for sure

insajd commented 3 years ago

I used domain without reverse proxy, but just tried directly using ip address, and still same issue. Public IP address:8989 -> forwarded using Mikrotik router -> local IP address. Local IP address is one of the Proxmox VMs. The machine got Debian with docker installed. On docker I'm running Droppy. Starting to think it might be something to do with Proxmox..

silverwind commented 3 years ago

60s is the default timeout of nginx. See the wiki. You want to at least set these:

proxy_connect_timeout 7200;
proxy_read_timeout 7200;
proxy_send_timeout 7200;
client_max_body_size 0;

I usually set all these timeouts:

client_body_timeout 7200;
client_header_timeout 7200;
proxy_connect_timeout 7200;
proxy_read_timeout 7200;
proxy_send_timeout 7200;
send_timeout 7200;
insajd commented 3 years ago

I'm not using nginx.

I tried different approach - Ubuntu VM on digitalocean, again installed droppy using docker, and same issue in there. 60 seconds pass - it breaks. Then I installed droppy using npm on my local machine which runs docker - then no issue is present, I uploaded file without any problems.

So far conclusion is that when using docker image, I can't upload anything for longer than 60 seconds.

insajd commented 3 years ago

Additionally what I noticed - on debian node version 10.21.0 is used(I installed whatever installed with apt install npm), in docker 14.5.0 is used.

Cubox commented 3 years ago

60s is the default timeout of nginx. See the wiki. You want to at least set these:

proxy_connect_timeout 7200;
proxy_read_timeout 7200;
proxy_send_timeout 7200;
client_max_body_size 0;

I usually set all these timeouts:

client_body_timeout 7200;
client_header_timeout 7200;
proxy_connect_timeout 7200;
proxy_read_timeout 7200;
proxy_send_timeout 7200;
send_timeout 7200;

I tried with all of those. I already had the top ones, but even with client_body_timeout and send_timeout added, same issue. I'll try to use droppy without the reverse proxy and see if I have the same issue. My guess is this change: Change: now nginx starts closing keepalive connections before all free worker connections are exhausted, and logs a warning about this to the error log. from https://nginx.org/en/CHANGES

Cubox commented 3 years ago

I just updated droppy to 12.0.1, and tried directly (connecting to the port and not using reverse proxy) and I get the same issue.

I have an Upload cancelled after 60004ms

Cubox commented 3 years ago

Droppy config: 2020-08-18 18:35:57 [INFO] Configuration: { listeners: [ { host: [ '0.0.0.0' ], port: 8989, protocol: 'http' } ], public: false, timestamps: true, linkLength: 5, linkExtensions: true, logLevel: 2, maxFileSize: 0, updateInterval: 1000, pollingInterval: 0, keepAlive: 20000, allowFrame: false, readOnly: false, ignorePatterns: [ '.*' ], watch: true, headers: {}}

2020-08-18 18:36:25 [INFO] 1:52317 POST /!/upload?vId=0&to=/&rename=0 [200] [2ms] Upload started 2020-08-18 18:37:25 [INFO] 1:52317 POST /!/upload?vId=0&to=/&rename=0 [200] [60004ms] Upload cancelled

insajd commented 3 years ago

Regarding docker issue found this, might be the reason? Docker uses IP Virtual Server and IPVS maintains its own connection table. The default timeout for CLOSE_WAIT connections in IPVS table is 60 seconds. Hence when the server sends something after 60 seconds, the IPVS connection is no longer available and the packet looks invalid for a new TCP session and gets RST. On the client side, the connection remains forever in FIN_WAIT2 state because the app still has the socket open; kernel's fin_wait timer kicks in only for orphaned TCP sockets. https://stackoverflow.com/questions/43311004/docker-services-stops-communicating-after-some-time

Cubox commented 3 years ago

@insajd Since I'm having this issue, and I don't use docker, I don't think it's that. Can you try with an instance not using docker? I'll bet you will still have this issue.

silverwind commented 3 years ago

Try with 12.1.0. I was able to reproduce behind nginx which logged

upstream prematurely closed connection while reading response header from upstream

which does point to the fault being node. Interestingly, it dit not show on macOS, only Linux.

12.1.0 adds a new uploadTimeout option that defaults to 7 days.

Cubox commented 3 years ago

Updated to 12.1.0 and I have the same behaviour, even in direct (no nginx around). After 60s it reset the upload and tried again (issued another POST) and after the second one failed, gave up.

silverwind commented 3 years ago

There's one more timeout that I can think of but it doesn't really make sense that it would be it because uploads should have their headers sent when that timeout hits.

Do you see any errors in the log when it happens or is it just a "Upload Cancelled"?

insajd commented 3 years ago

Tried a lot of test cases. Somehow now it works for me in most cases with an exception of reverse proxy:

Running natively without docker on : Linux debian 4.19.0-9-amd64 #1 SMP Debian 4.19.118-2+deb10u1 (2020-06-07) x86_64 GNU/Linux

  1. droppy 12.0.1 running on node 10.21.0 2020-08-19 07:11:13 [INFO] 192.168.192.254:9762 POST /!/upload?vId=0&to=/&rename=0 [200] [2ms] Upload started 2020-08-19 07:20:37 [INFO] 192.168.192.254:9762 POST /!/upload?vId=0&to=/&rename=0 [200] [564571ms] Received 1 files -upload works

  2. Updated nodejs to v12.18.3 droppy 12.0.1 running on node 12.18.3 2020-08-19 07:26:57 [INFO] 192.168.192.254:10995 POST /!/upload?vId=0&to=/&rename=0 [200] [4ms] Upload started 2020-08-19 07:30:16 [INFO] 192.168.192.254:10995 POST /!/upload?vId=0&to=/&rename=0 [200] [199515ms] Received 1 files -upload works

  3. Updated droppy droppy 12.1.0 running on node 12.18.3 2020-08-19 07:39:10 [INFO] 192.168.192.254:11839 POST /!/upload?vId=0&to=/&rename=0 [200] [2ms] Upload started 2020-08-19 07:42:00 [INFO] 192.168.192.254:11839 POST /!/upload?vId=0&to=/&rename=0 [200] [170091ms] Received 1 files -upload works

  4. Updated to latest node droppy 12.1.0 running on node 14.8.0 2020-08-19 07:45:54 [INFO] 192.168.192.254:12312 POST /!/upload?vId=0&to=/&rename=0 [200] [2ms] Upload started 2020-08-19 07:48:25 [INFO] 192.168.192.254:12312 POST /!/upload?vId=0&to=/&rename=0 [200] [150425ms] Received 1 files -upload works

Running in docker

  1. droppy 12.1.0 running on node 14.8.0 Built it using

    git clone https://github.com/silverwind/droppy
cd droppy
npm install
./droppy build . -t "test:droppy"

    2020-08-19 05:42:51 [INFO] 192.168.192.254:9855 POST /!/upload?vId=0&to=/&rename=0 [200] [5ms] Upload started 2020-08-19 05:45:33 [INFO] 192.168.192.254:9855 POST /!/upload?vId=0&to=/&rename=0 [200] [161817ms] Received 1 files, -upload works

  2. Using silverwind/droppy:latest image droppy 12.1.0 running on node 14.8.0 2020-08-19 05:47:02 [INFO] 192.168.192.254:10135 POST /!/upload?vId=0&to=/&rename=0 [200] [2ms] Upload started, 2020-08-19 05:49:52 [INFO] 192.168.192.254:10135 POST /!/upload?vId=0&to=/&rename=0 [200] [170372ms] Received 1 files -upload works

Added Nginx reverse proxy

droppy 12.1.0 running on node 14.8.0 Upload doesn't get cancelled, but it hangs on 100% without finishing file -upload doesn't work.

Public IP:port

droppy 12.1.0 running on node 14.8.0 2020-08-19 06:09:41 [INFO] 87.246.xxx.xxx:8189 POST /!/upload?vId=0&to=/&rename=0 [200] [1ms] Upload started, 2020-08-19 06:13:08 [INFO] 87.246.xxx.xxx:8189 POST /!/upload?vId=0&to=/&rename=0 [200] [206532ms] Received 1 files

-upload works

Cubox commented 3 years ago

There's one more timeout that I can think of but it doesn't really make sense that it would be it because uploads should have their headers sent when that timeout hits.

Do you see any errors in the log when it happens or is it just a "Upload Cancelled"?

Just Upload Cancelled

Cubox commented 3 years ago

I'm running FreeBSD 12.1-STABLE, with node v14.6.0 and npm 6.14.8