Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[app.files] expected filesize 10485760 got 10477568 #15200

Closed
evilham opened this issue Apr 23, 2019 · 12 comments
Closed

[app.files] expected filesize 10485760 got 10477568 #15200

evilham opened this issue Apr 23, 2019 · 12 comments
Labels
0. Needs triage Pending check for reproducibility or if it fits our roadmap bug needs info

Comments

@evilham
Copy link
Contributor

evilham commented Apr 23, 2019

Steps to reproduce

  1. use nextcloud 16.0RC2
  2. produce some files, say 10M big with for i in $(seq 1 50); do dd if=/dev/zero of=$i.bin; done
  3. try to upload these files via the files app
  4. on a random selection of these files, upload will fail
    Nginx log shows the request having a 408
    Error in nextcloud log: is expected filesize 10485760 got 10477568
{
  "reqId": "y4Z0RHLWJcPsvfDHVWFi",
  "level": 4,
  "time": "2019-04-23 22:56:36.071700",
  "remoteAddr": "${RemoteIPv6}",
  "user": "${UUID}",
  "app": "webdav",
  "method": "PUT",
  "url": "\\/remote.php\\/webdav\\/Test\\/25.bin",
  "message": {
    "Exception": "Sabre\\DAV\\Exception\\BadRequest",
    "Message": "expected filesize 10485760 got 10477568",
    "Code": 0,
    "Trace": [
      {
        "file": "\\/srv\\/www\\/nextcloud\\/apps\\/dav\\/lib\\/Connector\\/Sabre\\/Directory.php",
        "line": 156,
        "function": "put",
        "class": "OCA\\DAV\\Connector\\Sabre\\File",
        "type": "->",
        "args": [
          null
        ]
      },
      {
        "file": "\\/srv\\/www\\/nextcloud\\/3rdparty\\/sabre\\/dav\\/lib\\/DAV\\/Server.php",
        "line": 1096,
        "function": "createFile",
        "class": "OCA\\DAV\\Connector\\Sabre\\Directory",
        "type": "->",
        "args": [
          "25.bin",
          null
        ]
      },
      {
        "file": "\\/srv\\/www\\/nextcloud\\/3rdparty\\/sabre\\/dav\\/lib\\/DAV\\/CorePlugin.php",
        "line": 525,
        "function": "createFile",
        "class": "Sabre\\DAV\\Server",
        "type": "->",
        "args": [
          "Test\\/25.bin",
          null,
          null
        ]
      },
      {
        "function": "httpPut",
        "class": "Sabre\\DAV\\CorePlugin",
        "type": "->",
        "args": [
          {
            "absoluteUrl": "https:\\/\\/nextcloud\\/remote.php\\/webdav\\/Test\\/25.bin",
            "__class__": "Sabre\\HTTP\\Request"
          },
          {
            "__class__": "Sabre\\HTTP\\Response"
          }
        ]
      },
      {
        "file": "\\/srv\\/www\\/nextcloud\\/3rdparty\\/sabre\\/event\\/lib\\/EventEmitterTrait.php",
        "line": 105,
        "function": "call_user_func_array",
        "args": [
          [
            {
              "__class__": "Sabre\\DAV\\CorePlugin"
            },
            "httpPut"
          ],
          [
            {
              "absoluteUrl": "https:\\/\\/nextcloud\\/remote.php\\/webdav\\/Test\\/25.bin",
              "__class__": "Sabre\\HTTP\\Request"
            },
            {
              "__class__": "Sabre\\HTTP\\Response"
            }
          ]
        ]
      },
      {
        "file": "\\/srv\\/www\\/nextcloud\\/3rdparty\\/sabre\\/dav\\/lib\\/DAV\\/Server.php",
        "line": 479,
        "function": "emit",
        "class": "Sabre\\Event\\EventEmitter",
        "type": "->",
        "args": [
          "method:PUT",
          [
            {
              "absoluteUrl": "https:\\/\\/nextcloud\\/remote.php\\/webdav\\/Test\\/25.bin",
              "__class__": "Sabre\\HTTP\\Request"
            },
            {
              "__class__": "Sabre\\HTTP\\Response"
            }
          ]
        ]
      },
      {
        "file": "\\/srv\\/www\\/nextcloud\\/3rdparty\\/sabre\\/dav\\/lib\\/DAV\\/Server.php",
        "line": 254,
        "function": "invokeMethod",
        "class": "Sabre\\DAV\\Server",
        "type": "->",
        "args": [
          {
            "absoluteUrl": "https:\\/\\/nextcloud\\/remote.php\\/webdav\\/Test\\/25.bin",
            "__class__": "Sabre\\HTTP\\Request"
          },
          {
            "__class__": "Sabre\\HTTP\\Response"
          }
        ]
      },
      {
        "file": "\\/srv\\/www\\/nextcloud\\/apps\\/dav\\/appinfo\\/v1\\/webdav.php",
        "line": 80,
        "function": "exec",
        "class": "Sabre\\DAV\\Server",
        "type": "->",
        "args": []
      },
      {
        "file": "\\/srv\\/www\\/nextcloud\\/remote.php",
        "line": 163,
        "args": [
          "\\/srv\\/www\\/nextcloud\\/apps\\/dav\\/appinfo\\/v1\\/webdav.php"
        ],
        "function": "require_once"
      }
    ],
    "File": "\\/srv\\/www\\/nextcloud\\/apps\\/dav\\/lib\\/Connector\\/Sabre\\/File.php",
    "Line": 222,
    "CustomMessage": "--"
  },
  "userAgent": ""
}

Expected behaviour

Upload should finish for all files. Maybe even retry if a particular upload fails.

Actual behaviour

Randomly about 8% of the files uploaded fail with the same message

Server configuration

Operating system: Debian

Web server: Nginx

Database: MariaDB

PHP version: v.7.3.3-1

Nextcloud version: 16.0RC2

Updated from an older Nextcloud/ownCloud or fresh install: Updated from 15 through 16.0beta1

Where did you install Nextcloud from: signed tarballs

Nextcloud configuration:

Config report
{
    "system": {
        "debug": "true",
        "logdateformat": "Y-m-d H:i:s.u",
        "loglevel": 2,
        "logtimezone": "Europe\/Berlin",
        "memcache.local": "\\OC\\Memcache\\Redis",
        "memcache.locking": "\\OC\\Memcache\\Redis",
        "redis": {
            "host": "***REMOVED SENSITIVE VALUE***",
            "password": "***REMOVED SENSITIVE VALUE***",
            "port": "6379"
        },
        "skeletondirectory": "",
        "trusted_domains": [
            "nextcloud"
        ],
        "updatechecker": true,
        "updater.release.channel": "production",
        "passwordsalt": "***REMOVED SENSITIVE VALUE***",
        "secret": "***REMOVED SENSITIVE VALUE***",
        "datadirectory": "***REMOVED SENSITIVE VALUE***",
        "dbtype": "mysql",
        "version": "16.0.0.8",
        "overwrite.cli.url": "http:\/\/localhost",
        "dbname": "***REMOVED SENSITIVE VALUE***",
        "dbhost": "***REMOVED SENSITIVE VALUE***",
        "dbport": "",
        "dbtableprefix": "oc_",
        "mysql.utf8mb4": true,
        "dbuser": "***REMOVED SENSITIVE VALUE***",
        "dbpassword": "***REMOVED SENSITIVE VALUE***",
        "installed": true,
        "instanceid": "***REMOVED SENSITIVE VALUE***",
        "ldapIgnoreNamingRules": false,
        "ldapProviderFactory": "OCA\\User_LDAP\\LDAPProviderFactory",
        "theme": "${theme}",
        "mail_domain": "***REMOVED SENSITIVE VALUE***",
        "mail_from_address": "***REMOVED SENSITIVE VALUE***",
        "mail_sendmailmode": "smtp",
        "mail_smtpauth": true,
        "mail_smtpauthtype": "LOGIN",
        "mail_smtphost": "***REMOVED SENSITIVE VALUE***",
        "mail_smtpmode": "smtp",
        "mail_smtpname": "***REMOVED SENSITIVE VALUE***",
        "mail_smtppassword": "***REMOVED SENSITIVE VALUE***",
        "mail_smtpport": 587,
        "mail_smtpsecure": "tls",
        "maintenance": false,
        "integrity.check.disabled": true,
        "defaultapp": "apporder"
    }
}

Are you using external storage, if yes which one: local

Are you using encryption: no

Are you using an external user-backend, if yes which one: LDAP

LDAP configuration (delete this part if not used)

Used, should not be relevant.

Client configuration

Browser: Firefox

Operating system: FreeBSD 12.0

Solution

While documenting this bug, I noticed that the client's request stays hanging and that the web server logs a 408. This meant that it was cutting the connection.

Setting client_body_timeout 300s; (a significantly higher value than the default) fixed this for me.

Why this is still a bug, albeit not code wise, but documentation wise:

Since the web client now defaults to 10 parallel uploads, with IIRC 10MB chunks, this means that when uploading a large number of larger files, the client will in reality be uploading 100MB at any time, expecting all of those to always finish within the default client_body_timeout value of 60s means expecting a consistent upload speed for data of about 13Mbps , it is not reasonable for the general use-case!

I still open this issue, so the documentation for the upgrade and installation notes points out that this change in the web server will be needed.

PS: NextCloud 16 will be great; the files app appears to (finally!) work just as expected.

@evilham evilham added 0. Needs triage Pending check for reproducibility or if it fits our roadmap bug labels Apr 23, 2019
@kesselb
Copy link
Contributor

kesselb commented Apr 24, 2019

Ref #13855

https://github.com/nextcloud/documentation/edit/master/admin_manual/installation/nginx.rst we may add this to the nginx template and/or .htaccess for apache2 then. What value do you suggest?

cc @nextcloud/documentation @tomasz-grobelny

@evilham
Copy link
Contributor Author

evilham commented Apr 24, 2019

The value heavily depends on the use-case and the main location of the instance's users and the quality of the connection to the server.

Taking into account that all connections must be successful, because otherwise uploading a large folder won't be reliable, I think it goes something like:

expected_client_bandwidth_mbps > (chunk_size_megabytes * 8_bits_per_byte
                                                       * parallel_chunk_count
                                                       * 1.3_conservative_network_overhead
                                 ) / client_body_timeout_seconds

client_body_timeout_seconds    > (chunk_size_megabytes * 8_bits_per_byte
                                                       * parallel_chunk_count
                                                       * 1.3_conservative_network_overhead
                                 ) /  expected_client_bandwidth_mbps

So, with chunk_size_megabytes being 10 and parallel_chunk_count being 10 too, we are looking at minimum (up-rounded) values like:

Mbps | client_body_timeout
1    | 1040s
5    | 240s
10   | 120s
20   | 60s (nginx default)
50   | 20s

@tomasz-grobelny
Copy link
Contributor

The question is then whether we should keep parallel_chunk_count and chunk_size_megabytes as constants or adjust them automatically based on connection quality?

@evilham
Copy link
Contributor Author

evilham commented Apr 26, 2019

I don't think those should be constant, e.g. chuk_size_megabytes already isn't, it can be changed on the database; I doubt the parallel_chunk_count stays constant as well in the long run.

A better approach could be, e.g. link to my previous comment from the documentation (I know it can be a bit dense to put there directly) and note that it can be an issue in function of user's bandwidth (I don't think server bandwidth is the issue normally).

If I had to suggest a default value for client_body_timeout it'd likely be around the 540s, , which allows for a bandwidth of about 2Mbps, but in the end each server admin has to be aware and decide for themselves.

@unix0r
Copy link

unix0r commented Aug 5, 2019

I'm using the nextcloud docker instance (Version: 16.0.3.0) on a synology NAS and I'm getting the same error.

Friends are uploading a couple of files via their mobile web browser to my server and a couple of files wont get uploaded due to Sabre\DAV\Exception\BadRequest: expected filesize x got y.

Gonna try it now with disabled HTTP2.

Edit:
Disabled HTTP2 in the Reverse Proxy Settings of the synology NAS but the problem still exists:
[webdav] Fatal: Sabre\DAV\Exception\BadRequest: expected filesize 1895277 got 1773568 at <>

  1. /var/www/html/apps/dav/lib/Connector/Sabre/Directory.php line 156
    OCA\DAV\Connector\Sabre\File->put(null)
  2. /var/www/html/3rdparty/sabre/dav/lib/DAV/Server.php line 1096
    OCA\DAV\Connector\Sabre\Directory->createFile("85EB31F9-58E1-4 ... g", null)
  3. /var/www/html/3rdparty/sabre/dav/lib/DAV/CorePlugin.php line 525
    Sabre\DAV\Server->createFile("85EB31F9-58E1-4 ... g", null, null)
  4. <>
    Sabre\DAV\CorePlugin->httpPut(Sabre\HTTP\Reque ... "}, Sabre\HTTP\Response {})
  5. /var/www/html/3rdparty/sabre/event/lib/EventEmitterTrait.php line 105
    undefinedundefinedcall_user_func_array([Sabre\DAV\CorePlugin {},"httpPut"], [Sabre\HTTP\Requ ... }])
  6. /var/www/html/3rdparty/sabre/dav/lib/DAV/Server.php line 479
    Sabre\Event\EventEmitter->emit("method:PUT", [Sabre\HTTP\Requ ... }])
  7. /var/www/html/3rdparty/sabre/dav/lib/DAV/Server.php line 254
    Sabre\DAV\Server->invokeMethod(Sabre\HTTP\Reque ... "}, Sabre\HTTP\Response {})
  8. /var/www/html/apps/dav/appinfo/v1/publicwebdav.php line 107
    Sabre\DAV\Server->exec()
  9. /var/www/html/public.php line 79
    undefinedundefinedrequire_once("/var/www/html/a ... p")

PUT /public.php/webdav/85EB31F9-58E1-4A86-A00A-9777B8AD1824.jpeg
from x.x.x.x at 2019-08-05T08:11:39+00:00

@unix0r
Copy link

unix0r commented Aug 7, 2019

Changed the reqtimeout_module configuration and now i think it works like a charm.
Uploaded 187 files without an error. Before there were about 20-30 errors.
The new parameters for /etc/apache2/mods-available/reqtimeout.conf are:

<IfModule reqtimeout_module>
	RequestReadTimeout header=20-40,minrate=250
	RequestReadTimeout body=40,minrate=250
</IfModule>

@mr44er
Copy link

mr44er commented Aug 31, 2019

Problem still exists, but I don't know when it started. I'm mostly using calendar, not files.

Due to the thingie with mod_reqtimeout I updated Apache to 2.4.41 and additionally tested with deactivating the module - same error.

Log is on max debug, but gives only this:

[Sat Aug 31 12:52:55.821229 2019] [mpm_prefork:notice] [pid 5741] AH00163: Apache/2.4.41 (FreeBSD) PHP/7.2.21 configured -- resuming normal operations
[Sat Aug 31 12:52:55.821310 2019] [mpm_prefork:info] [pid 5741] AH00164: Server built: unknown
[Sat Aug 31 12:52:55.821334 2019] [core:notice] [pid 5741] AH00094: Command line: '/usr/local/sbin/httpd -D NOHTTPACCEPT'
[Sat Aug 31 12:52:55.821348 2019] [core:debug] [pid 5741] log.c(1568): AH02639: Using SO_REUSEPORT: no (1)
[Sat Aug 31 12:52:55.821363 2019] [mpm_prefork:debug] [pid 5741] prefork.c(914): AH00165: Accept mutex: none (default: flock)

Nextcloud:


[webdav] Fatal: Sabre\DAV\Exception\BadRequest: expected filesize 333656 got 65645 at <<closure>>

0. /usr/local/www/nextcloud/apps-pkg/dav/lib/Connector/Sabre/Directory.php line 156
   OCA\DAV\Connector\Sabre\File->put(null)
1. /usr/local/www/nextcloud/3rdparty/sabre/dav/lib/DAV/Server.php line 1096
   OCA\DAV\Connector\Sabre\Directory->createFile("schredder2.webm", null)
2. /usr/local/www/nextcloud/3rdparty/sabre/dav/lib/DAV/CorePlugin.php line 525
   Sabre\DAV\Server->createFile("nicht in den Na ... m", null, null)
3. <<closure>>
   Sabre\DAV\CorePlugin->httpPut(Sabre\HTTP\Reque ... "}, Sabre\HTTP\Response {})
4. /usr/local/www/nextcloud/3rdparty/sabre/event/lib/EventEmitterTrait.php line 105
   undefinedundefinedcall_user_func_array([Sabre\DAV\CorePlugin {},"httpPut"], [Sabre\HTTP\Requ ... }])
5. /usr/local/www/nextcloud/3rdparty/sabre/dav/lib/DAV/Server.php line 479
   Sabre\Event\EventEmitter->emit("method:PUT", [Sabre\HTTP\Requ ... }])
6. /usr/local/www/nextcloud/3rdparty/sabre/dav/lib/DAV/Server.php line 254
   Sabre\DAV\Server->invokeMethod(Sabre\HTTP\Reque ... "}, Sabre\HTTP\Response {})
7. /usr/local/www/nextcloud/apps-pkg/dav/appinfo/v1/webdav.php line 80
   Sabre\DAV\Server->exec()
8. /usr/local/www/nextcloud/remote.php line 163
   undefinedundefinedrequire_once("/usr/local/www/ ... p")

Name           : apache24
Version        : 2.4.41
Installed on   : Fri Aug 30 19:04:06 2019 CEST
Origin         : www/apache24
Architecture   : FreeBSD:12:amd64
Prefix         : /usr/local
Categories     : ipv6 www
Licenses       : APACHE20
Maintainer     : [email protected]
WWW            : https://httpd.apache.org/
Comment        : Version 2.4.x of Apache web server
Options        :
        ACCESS_COMPAT  : on
        ACTIONS        : on
        ALIAS          : on
        ALLOWMETHODS   : on
        ASIS           : on
        AUTHNZ_FCGI    : on
        AUTHNZ_LDAP    : off
        AUTHN_ANON     : on
        AUTHN_CORE     : on
        AUTHN_DBD      : on
        AUTHN_DBM      : on
        AUTHN_FILE     : on
        AUTHN_SOCACHE  : on
        AUTHZ_CORE     : on
        AUTHZ_DBD      : on
        AUTHZ_DBM      : on
        AUTHZ_GROUPFILE: on
        AUTHZ_HOST     : on
        AUTHZ_OWNER    : on
        AUTHZ_USER     : on
        AUTH_BASIC     : on
        AUTH_DIGEST    : on
        AUTH_FORM      : on
        AUTOINDEX      : on
        BROTLI         : off
        BUCKETEER      : off
        BUFFER         : on
        CACHE          : on
        CACHE_DISK     : on
        CACHE_SOCACHE  : on
        CASE_FILTER    : off
        CASE_FILTER_IN : off
        CERN_META      : on
        CGI            : on
        CGID           : on
        CHARSET_LITE   : on
        DATA           : on
        DAV            : on
        DAV_FS         : on
        DAV_LOCK       : on
        DBD            : on
        DEFLATE        : on
        DIALUP         : on
        DIR            : on
        DOCS           : off
        DUMPIO         : on
        ECHO           : off
        ENV            : on
        EXAMPLE_HOOKS  : off
        EXAMPLE_IPC    : off
        EXPIRES        : on
        EXT_FILTER     : on
        FILE_CACHE     : on
        FILTER         : on
        HEADERS        : on
        HEARTBEAT      : on
        HEARTMONITOR   : on
        HTTP2          : off
        IDENT          : off
        IMAGEMAP       : on
        INCLUDE        : on
        INFO           : off
        IPV4_MAPPED    : off
        LBMETHOD_BYBUSYNESS: on
        LBMETHOD_BYREQUESTS: on
        LBMETHOD_BYTRAFFIC: on
        LBMETHOD_HEARTBEAT: on
        LDAP           : off
        LOGIO          : on
        LOG_DEBUG      : on
        LOG_FORENSIC   : on
        LUA            : off
        LUAJIT         : off
        MACRO          : on
        MD             : off
        MIME           : on
        MIME_MAGIC     : on
        MPM_EVENT      : off
        MPM_PREFORK    : on
        MPM_SHARED     : on
        MPM_WORKER     : off
        NEGOTIATION    : on
        OPTIONAL_FN_EXPORT: off
        OPTIONAL_FN_IMPORT: off
        OPTIONAL_HOOK_EXPORT: off
        OPTIONAL_HOOK_IMPORT: off
        PROXY          : on
        PROXY_AJP      : on
        PROXY_BALANCER : on
        PROXY_CONNECT  : on
        PROXY_EXPRESS  : on
        PROXY_FCGI     : on
        PROXY_FDPASS   : on
        PROXY_FTP      : on
        PROXY_HCHECK   : on
        PROXY_HTML     : on
        PROXY_HTTP     : on
        PROXY_HTTP2    : on
        PROXY_SCGI     : on
        PROXY_UWSGI    : on
        PROXY_WSTUNNEL : on
        RATELIMIT      : on
        REFLECTOR      : on
        REMOTEIP       : on
        REQTIMEOUT     : on
        REQUEST        : on
        REWRITE        : on
        SED            : on
        SESSION        : on
        SESSION_COOKIE : on
        SESSION_CRYPTO : on
        SESSION_DBD    : on
        SETENVIF       : on
        SLOTMEM_PLAIN  : on
        SLOTMEM_SHM    : on
        SOCACHE_DBM    : on
        SOCACHE_DC     : off
        SOCACHE_MEMCACHE: on
        SOCACHE_REDIS  : off
        SOCACHE_SHMCB  : on
        SPELING        : on
        SSL            : on
        STATUS         : on
        SUBSTITUTE     : on
        SUEXEC         : off
        UNIQUE_ID      : on
        USERDIR        : on
        USERTRACK      : on
        VERSION        : on
        VHOST_ALIAS    : on
        WATCHDOG       : on
        XML2ENC        : on
Shared Libs required:
        libaprutil-1.so.0
        libpcre.so.1
        libnghttp2.so.14
        libapr-1.so.0
        libexpat.so.1
        libxml2.so.2
Annotations    :
        FreeBSD_version: 1200086
        cpe            : cpe:2.3:a:apache:http_server:2.4.41:::::freebsd12:x64

Name           : nextcloud-php72
Version        : 16.0.4
Installed on   : Sat Aug 31 02:40:43 2019 CEST
Origin         : www/nextcloud
Architecture   : FreeBSD:12:*
Prefix         : /usr/local
Categories     : www
Licenses       : AGPLv3
Maintainer     : [email protected]
WWW            : https://nextcloud.com
Comment        : Personal cloud which runs on your own server
Options        :
        APCU           : on
        EXIF           : on
        IMAGICK        : on
        INTL           : on
        LDAP           : on
        MEMCACHED      : off
        MYSQL          : on
        OPCACHE        : on
        PCNTL          : off
        PGSQL          : off
        REDIS          : off
        SMB            : off
        SQLITE         : off
        SSL            : on
Annotations    :
        cpe            : cpe:2.3:a:nextcloud:nextcloud:16.0.4:::::freebsd12:x64
        flavor         : php72

Really don't know, what to do now.

@cpegel

This comment has been minimized.

@szaimen
Copy link
Contributor

szaimen commented Jun 7, 2021

Is this Issue still valid in NC21.0.2? If not, please close this issue. Thanks! :)

@simonspa
Copy link
Contributor

simonspa commented Jun 7, 2021

@szaimen the solution is actually in the initial report. I think for now, adding the

client_body_timeout 300s;

to the default nginx configuration should be fine for most cases, just the default 60s is a bit tight, especially on small servers at home.

@szaimen
Copy link
Contributor

szaimen commented Jun 7, 2021

Thanks for the feedback! So can this issue be closed then? :)

@simonspa
Copy link
Contributor

simonspa commented Jun 7, 2021

Yes, let me close it, I'll open a PR against the docs in a minute.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
0. Needs triage Pending check for reproducibility or if it fits our roadmap bug needs info
Projects
None yet
Development

No branches or pull requests

9 participants