Reading of file continues after download operation ends

Mpeter · August 29, 2020, 8:42pm

Support intro

Sorry to hear you’re facing problems

help.nextcloud.com is for home/non-enterprise users. If you’re running a business, paid support can be accessed via portal.nextcloud.com where we can ensure your business keeps running smoothly.

In order to help you as quickly as possible, before clicking Create Topic please provide as much of the below as you can. Feel free to use a pastebin service for logs, otherwise either indent short log examples with four spaces:

example

Or for longer, use three backticks above and below the code snippet:

longer
example
here

Some or all of the below information will be requested if it isn’t supplied; for fastest response please provide as much as you can

Nextcloud version (eg, 18.0.2): 19.0.2
Operating system and version (eg, Ubuntu 20.04): Host: Raspbian Buster, OS inside container: Debian Buster
Apache or nginx version (eg, Apache 2.4.25): Apache 2.4.38
PHP version (eg, 7.1): 7.4.9

I’m using the Apache version of the official Nextcloud docker image: https://github.com/nextcloud/docker/blob/1353c04b9fb456e76d1900be034aa746f878ac5f/19.0/apache/Dockerfile

The issue you are facing:
If I start to download a bigger file (in the example 1,2 GB), then either after the download completes successfully, or after I cancelled the download before completion, Nextcloud’s Apache webserver will keep reading the file for some time (at most 2 minutes, but at least a half. haven’t done precise measurements).

Is this the first time you’ve seen this error? (Y/N): It occurs across container restarts and host OS reboots, so I think the answer is yes, except that it’s not really an error (NC does not log errors when this happens neither on the command line output, nor in the nextcloud.log file, nor on the admin interface)

It may be an important detail that the file is on a local external storage, which is an NTFS partition mounted on /media/ with the following options: user,defaults,big_writes,nofail,noexec .
I tried to reproduce it with a big file stored on the main storage, but copying of the file to there always errored out

Steps to replicate it:

Find a big file (>= 1 GB) on your Nextcloud instance (preferably one originating from a local external storage)
Open an SSH session or a terminal on the server, and run either htop or iotop to watch io performance
Start download through “3 dots menu”\Download
Either wait until the download finishes, or cancel the download

At the end, you should see that tens of MBs will continue to be read from the disk by the same 2 processes (Apache and mount.ntfs)

I tried what would happen if I read the big file in the simplest way (cat “filepath” > /dev/null).
It was reading with the same speed as NC, but both when cat exited by itself and when I stopped it manually, the read operations stopped immediately according to iotop and htop

The output of your Nextcloud log in Admin > Logging:

gist.github.com

https://gist.github.com/MPeti1/4d2e3aa7b2257b60349268f510bec085

nextcloud.log

{"reqId":"PYH6SrUcr4M2HXLgEMQD","level":2,"time":"2020-08-28T18:26:00+00:00","remoteAddr":"192.168.16.2","user":"--","app":"no app in context","method":"GET","url":"/","message":"Could not detect any host in http:///data/htaccesstest.txt","userAgent":"Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:79.0) Gecko/20100101 Firefox/79.0","version":""}
{"reqId":"PYH6SrUcr4M2HXLgEMQD","level":2,"time":"2020-08-28T18:26:00+00:00","remoteAddr":"192.168.16.2","user":"--","app":"no app in context","method":"GET","url":"/","message":"Could not detect any host in https:///data/htaccesstest.txt","userAgent":"Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:79.0) Gecko/20100101 Firefox/79.0","version":""}
{"reqId":"PYH6SrUcr4M2HXLgEMQD","level":3,"time":"2020-08-28T18:26:00+00:00","remoteAddr":"192.168.16.2","user":"--","app":"jsresourceloader","method":"GET","url":"/","message":"Could not find resource js/setup.js to load","userAgent":"Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:79.0) Gecko/20100101 Firefox/79.0","version":""}
{"reqId":"Vt8pJicO6IJjTNCRLuVd","level":2,"time":"2020-08-28T18:26:48+00:00","remoteAddr":"192.168.16.2","user":"--","app":"no app in context","method":"POST","url":"/index.php","message":"Could not detect any host in http:///data/htaccesstest.txt","userAgent":"Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:79.0) Gecko/20100101 Firefox/79.0","version":""}
{"reqId":"Vt8pJicO6IJjTNCRLuVd","level":2,"time":"2020-08-28T18:26:48+00:00","remoteAddr":"192.168.16.2","user":"--","app":"no app in context","method":"POST","url":"/index.php","message":"Could not detect any host in https:///data/htaccesstest.txt","userAgent":"Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:79.0) Gecko/20100101 Firefox/79.0","version":""}
{"reqId":"Vt8pJicO6IJjTNCRLuVd","level":3,"time":"2020-08-28T18:26:48+00:00","remoteAddr":"192.168.16.2","user":"--","app":"jsresourceloader","method":"POST","url":"/index.php","message":"Could not find resource js/setup.js to load","userAgent":"Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:79.0) Gecko/20100101 Firefox/79.0","version":"19.0.2.2"}
{"reqId":"MAttFysg5B01lYrZ7cJk","level":3,"time":"2020-08-28T18:28:41+00:00","remoteAddr":"192.168.16.2","user":"--","app":"jsresourceloader","method":"GET","url":"/","message":"Could not find resource js/setup.js to load","userAgent":"Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:79.0) Gecko/20100101 Firefox/79.0","version":"19.0.2.2"}
{"reqId":"K1XWIzg6x0HZsI9xq4vd","level":4,"time":"2020-08-28T18:46:11+00:00","remoteAddr":"192.168.16.2","user":"admin","app":"ocs_api","method":"POST","url":"/ocs/v2.php/cloud/users","message":"Failed addUser attempt: User already exists.","userAgent":"Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:79.0) Gecko/20100101 Firefox/79.0","version":"19.0.2.2"}
{"reqId":"15HhDbMzZI5d6BeE0bBP","level":3,"time":"2020-08-28T18:46:12+00:00","remoteAddr":"192.168.16.2","user":"admin","app":"ocs_api","method":"POST","url":"/ocs/v2.php/cloud/users","message":{"Exception":"Swift_TransportException","Message":"Connection could not be established with host 127.0.0.1 :stream_socket_client(): unable to connect to 127.0.0.1:25 (Connection refused)","Code":0,"Trace":[{"function":"{closure}","class":"Swift_Transport_StreamBuffer","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/html/3rdparty/swiftmailer/swiftmailer/lib/classes/Swift/Transport/StreamBuffer.php","line":272,"function":"stream_socket_client","args":["127.0.0.1:25",111,"Connection refused",10,4,null]},{"file":"/var/www/html/3rdparty/swiftmailer/swiftmailer/lib/classes/Swift/Transport/StreamBuffer.php","line":58,"function":"establishSocketConnection","class":"Swift_Transport_StreamBuffer","type":"->","args":[]},{"file":"/var/www/html/3rdparty/swiftmailer/swiftmailer/lib/classes/Swift/Transport/AbstractSmtpTransport.php","line":143,"function":"initialize","class":"Swift_Transport_StreamBuffer","type":"->","args":[{"protocol":"","host":"127.0.0.1","port":25,"timeout":10,"blocking":1,"tls":false,"type":1,"stream_context_options":"*** sensitive parameter replaced ***"}]},{"file":"/var/www/html/3rdparty/swiftmailer/swiftmailer/lib/classes/Swift/Mailer.php","line":65,"function":"start","class":"Swift_Transport_AbstractSmtpTransport","type":"->","args":[]},{"file":"/var/www/html/lib/private/Mail/Mailer.php","line":204,"function":"send","class":"Swift_Mailer","type":"->","args":[{"__class__":"Swift_Message"},"*** sensitive parameter replaced ***"]},{"file":"/var/www/html/apps/settings/lib/Mailer/NewUserMailHelper.php","line":174,"function":"send","class":"OC\\Mail\\Mailer","type":"->","args":[{"__class__":"OC\\Mail\\Message"}]},{"file":"/var/www/html/apps/provisioning_api/lib/Controller/UsersController.php","line":342,"function":"sendMail","class":"OCA\\Settings\\Mailer\\NewUserMailHelper","type":"->","args":[{"__class__":"OC\\User\\User"},{"__class__":"OC\\Mail\\EMailTemplate"}]},{"file":"/var/www/html/lib/private/AppFramework/Http/Dispatcher.php","line":170,"function":"addUser","class":"OCA\\Provisioning_API\\Controller\\UsersController","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/html/lib/private/AppFramework/Http/Dispatcher.php","line":100,"function":"executeController","class":"OC\\AppFramework\\Http\\Dispatcher","type":"->","args":[{"__class__":"OCA\\Provisioning_API\\Controller\\UsersController"},"addUser"]},{"file":"/var/www/html/lib/private/AppFramework/App.php","line":137,"function":"dispatch","class":"OC\\AppFramework\\Http\\Dispatcher","type":"->","args":[{"__class__":"OCA\\Provisioning_API\\Controller\\UsersController"},"addUser"]},{"file":"/var/www/html/lib/private/AppFramework/Routing/RouteActionHandler.php","line":47,"function":"main","class":"OC\\AppFramework\\App","type":"::","args":["OCA\\Provisioning_API\\Controller\\UsersController","addUser",{"__class__":"OC\\AppFramework\\DependencyInjection\\DIContainer"},{"_route":"ocs.provisioning_api.Users.addUser"}]},{"function":"__invoke","class":"OC\\AppFramework\\Routing\\RouteActionHandler","type":"->","args":[{"_route":"ocs.provisioning_api.Users.addUser"}]},{"file":"/var/www/html/lib/private/Route/Router.php","line":297,"function":"call_user_func","args":[{"__class__":"OC\\AppFramework\\Routing\\RouteActionHandler"},{"_route":"ocs.provisioning_api.Users.addUser"}]},{"file":"/var/www/html/ocs/v1.php","line":88,"function":"match","class":"OC\\Route\\Router","type":"->","args":["/ocsapp/cloud/users"]},{"file":"/var/www/html/ocs/v2.php","line":24,"args":["/var/www/html/ocs/v1.php"],"function":"require_once"}],"File":"/var/www/html/3rdparty/swiftmailer/swiftmailer/lib/classes/Swift/Transport/StreamBuffer.php","Line":269,"CustomMessage":"Unable to send the invitation mail to masapeter@protonmail.com"},"userAgent":"Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:79.0) Gecko/20100101 Firefox/79.0","version":"19.0.2.2"}
{"reqId":"8bG0chz6W7txTmgdIiUm","level":3,"time":"2020-08-28T20:18:28+00:00","remoteAddr":"192.168.16.2","user":"Peti","app":"no app in context","method":"COPY","url":"/remote.php/dav/files/Peti/Elements/temp/Atlantis.S05E01.Search.and.Rescue.REMUX-Janus.mkv","message":{"Exception":"OCP\\Files\\GenericFileException","Message":"Failed write steam to files/Atlantis.S05E01.Search.and.Rescue.REMUX-Janus.mkv.ocTransferId952323966.part","Code":0,"Trace":[{"file":"/var/www/html/lib/private/Files/Storage/Wrapper/Wrapper.php","line":631,"function":"writeStream","class":"OC\\Files\\Storage\\Local","type":"->","args":["files/Atlantis.S05E01.Search.and.Rescue.REMUX-Janus.mkv.ocTransferId952323966.part",null,null]},{"file":"/var/www/html/lib/private/Files/Storage/Wrapper/Wrapper.php","line":631,"function":"writeStream","class":"OC\\Files\\Storage\\Wrapper\\Wrapper","type":"->","args":["files/Atlantis.S05E01.Search.and.Rescue.REMUX-Janus.mkv.ocTransferId952323966.part",null,null]},{"file":"/var/www/html/apps/dav/lib/Connector/Sabre/File.php","line":202,"function":"writeStream","class":"OC\\Files\\Storage\\Wrapper\\Wrapper","type":"->","args":["files/Atlantis.S05E01.Search.and.Rescue.REMUX-Janus.mkv.ocTransferId952323966.part",null]},{"file":"/var/www/html/apps/dav/lib/Connector/Sabre/Directory.php","line":154,"function":"put","class":"OCA\\DAV\\Connector\\Sabre\\File","type":"->","args":[null]},{"file":"/var/www/html/3rdparty/sabre/dav/lib/DAV/Tree.php","line":311,"function":"createFile","class":"OCA\\DAV\\Connector\\Sabre\\Directory","type":"->","args":["Atlantis.S05E01.Search.and.Rescue.REMUX-Janus.mkv",null]},{"file":"/var/www/html/3rdparty/sabre/dav/lib/DAV/Tree.php","line":135,"function":"copyNode","class":"Sabre\\DAV\\Tree","type":"->","args":[{"__class__":"OCA\\DAV\\Connector\\Sabre\\File"},{"__class__":"OCA\\DAV\\Files\\FilesHome"},"Atlantis.S05E01.Search.and.Rescue.REMUX-Janus.mkv"]},{"file":"/var/www/html/3rdparty/sabre/dav/lib/DAV/CorePlugin.php","line":687,"function":"copy","class":"Sabre\\DAV\\Tree","type":"->","args":["files/Peti/Elements/temp/Atlantis.S05E01.Search.and.Rescue.REMUX-Janus.mkv","files/Peti/Atlantis.S05E01.Search.and.Rescue.REMUX-Janus.mkv"]},{"file":"/var/www/html/3rdparty/sabre/event/lib/WildcardEmitterTrait.php","line":89,"function":"httpCopy","class":"Sabre\\DAV\\CorePlugin","type":"->","args":[{"__class__":"Sabre\\HTTP\\Request"},{"__class__":"Sabre\\HTTP\\Response"}]},{"file":"/var/www/html/3rdparty/sabre/dav/lib/DAV/Server.php","line":474,"function":"emit","class":"Sabre\\DAV\\Server","type":"->","args":["method:COPY",[{"__class__":"Sabre\\HTTP\\Request"},{"__class__":"Sabre\\HTTP\\Response"}]]},{"file":"/var/www/html/3rdparty/sabre/dav/lib/DAV/Server.php","line":251,"function":"invokeMethod","class":"Sabre\\DAV\\Server","type":"->","args":[{"__class__":"Sabre\\HTTP\\Request"},{"__class__":"Sabre\\HTTP\\Response"}]},{"file":"/var/www/html/3rdparty/sabre/dav/lib/DAV/Server.php","line":319,"function":"start","class":"Sabre\\DAV\\Server","type":"->","args":[]},{"file":"/var/www/html/apps/dav/lib/Server.php","line":320,"function":"exec","class":"Sabre\\DAV\\Server","type":"->","args":[]},{"file":"/var/www/html/apps/dav/appinfo/v2/remote.php","line":35,"function":"exec","class":"OCA\\DAV\\Server","type":"->","args":[]},{"file":"/var/www/html/remote.php","line":167,"args":["/var/www/html/apps/dav/appinfo/v2/remote.php"],"function":"require_once"}],"File":"/var/www/html/lib/private/Files/Storage/Local.php","Line":561,"CustomMessage":"--"},"userAgent":"Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:79.0) Gecko/20100101 Firefox/79.0","version":"19.0.2.2"}

This file has been truncated. show original

The output of your config.php file in /path/to/nextcloud (make sure you remove any identifiable information!):
in reply

The output of your Apache/nginx/system log in /var/log/____:
in reply

Sorry for breaking the last link a bit, but otherwise the forum said that I can’t post more than 4 links

Mpeter · August 29, 2020, 8:44pm

The forum said that I can’t post more than 4 links (?) in the same post, so here are the other 2:

config.php:

gist.github.com

https://gist.github.com/MPeti1/f2d8f96b1fbb4812ac54a4f67b8ac1d2

config.php

<?php
$CONFIG = array (
  'htaccess.RewriteBase' => '/',
  'memcache.local' => '\\OC\\Memcache\\APCu',
  'apps_paths' =>
  array (
    0 =>
    array (
      'path' => '/var/www/html/apps',
      'url' => '/apps',

This file has been truncated. show original

Apache server log:

gist.github.com

https://gist.github.com/MPeti1/568249f93472d2bccb531a959dda4d31

apache_logs.txt

Configuring Redis as session handler,
AH00558: apache2: Could not reliably determine the server's fully qualified domain name, using 192.168.16.5. Set the 'ServerName' directive globally to suppress this message,
AH00558: apache2: Could not reliably determine the server's fully qualified domain name, using 192.168.16.5. Set the 'ServerName' directive globally to suppress this message,
[Sat Aug 29 18:36:28.096257 2020] [mpm_prefork:notice] [pid 1] AH00163: Apache/2.4.38 (Debian) PHP/7.4.9 configured -- resuming normal operations,
[Sat Aug 29 18:36:28.096900 2020] [core:notice] [pid 1] AH00094: Command line: 'apache2 -D FOREGROUND',
192.168.16.2 - [Redacted] [29/Aug/2020:18:36:37 +0000] "GET /status.php HTTP/1.1" 200 1043 "-" "Mozilla/5.0 (Windows) mirall/2.6.5stable-Win64 (build 20200710) (Nextcloud)",
192.168.16.2 - - [29/Aug/2020:18:36:45 +0000] "GET /apps/files/?dir=/Elements&fileid=304 HTTP/1.1" 303 958 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:80.0) Gecko/20100101 Firefox/80.0",
192.168.16.2 - [Redacted] [29/Aug/2020:18:36:41 +0000] "PROPFIND /remote.php/dav/files/[Redacted]/ HTTP/1.1" 207 1191 "-" "Mozilla/5.0 (Windows) mirall/2.6.5stable-Win64 (build 20200710) (Nextcloud)",
[Sat Aug 29 18:36:54.582389 2020] [access_compat:error] [pid 33] [client 192.168.16.2:40360] AH01797: client denied by server configuration: /var/www/html/config,
192.168.16.2 - [Redacted] [29/Aug/2020:18:36:54 +0000] "GET /ocs/v1.php/config?format=json HTTP/1.1" 200 902 "-" "Mozilla/5.0 (Windows) mirall/2.6.5stable-Win64 (build 20200710) (Nextcloud)",

This file has been truncated. show original