[2.2.2] [Windows 7] Sync stop after few seconds: Connection Closed

reipes commented 8 years ago

Expected behaviour

Owncloud sync the complete folder tree with no interrupts

Actual behaviour

After ownclient made his check of changes and starts to sync, the connection aborts after few seconds and go to red. Than I have to suspend synchronisation and start it again but the problem repeats again and again.

Steps to reproduce

Ownclient sync a big folder tree (>100GB) with files to < 4 mb. Client make his search for changes and when it begins to sync the connection aborts after some secondes. This happen mostly remote with a slow upload. Locally the problem does not appear. If I mount owncloud as webdav I can copy the files without problems. I already change the apache2 config to keppalive connections and improved timeouts. Also in php.ini I improved memory_limit and timeouts

Server configuration

Operating system: Debian 8 Web server: Apache/2.4.10 (Debian) Database: mysql Ver 14.14 Distrib 5.5.46, for debian-linux-gnu PHP version: PHP 5.6.14-0+deb8u1 ownCloud version: 9.0.3 Storage backend: samba

Client configuration

Client version: 2.2.2 Operating system: win7 OS language: german Installation path of client: c:\owncloud

Logs

Please use Gist (https://gist.github.com/) or a similar code paster for longer logs.

Template for output < 10 lines

Output of owncloud --logwindow or owncloud --logfile log.txt (On Windows using cmd.exe, you might need to first cd into the ownCloud directory) (See also http://doc.owncloud.org/desktop/2.2/troubleshooting.html#client-logfile )

https://gist.github.com/reipes/6c0522f8fb87bc24da0fae7d88797d61 https://gist.github.com/reipes/5a561111cba9c628a1bca319f5ea9ca4

Web server error log: [edited, it contained a password and a token]
ownCloud log (data/owncloud.log):

https://gist.github.com/reipes/a47ec94252fe67e938f410587f51531e

guruz commented 8 years ago

Unfortunately your client log does not contain the actual error, only unrelated graphics messages after the sync.

What is the error displayed in the UI?

guruz commented 8 years ago

Ah you're the same as https://github.com/owncloud/client/issues/3967#issuecomment-231471651 :)

guruz commented 8 years ago

I already change the apache2 config to keppalive connections and improved timeouts.

Do you think this happens with 2.2.2 but did not happen with a previous client version?

Do you use encryption on the server?

How exactly did you configure the samba storage backend?

Does the error always happen with the same file?

What happens if you set bandwidth limiting to "automatic" in the client?

reipes commented 8 years ago

Yes I'm the same :)

No, it happens also with previous version of client and server. No, I have no encryption It is a simple samba share with username and password. No it syncs always few new files... It takes very long for discovering and than it sync only few mb of data but always a step forward. The upload of server is not very fast and I set a limit of the upload speed in apache2 to avoid saturation of bandwidth It did not help. The config of bandwidth on the client have no influence on the behaviour. Also with limit set or also automatic I have the same problem.

guruz commented 8 years ago

@reipes By samba share you mean locally mounted on Linux? Or as ownCloud storage?

This is indeed odd because we think we've fixed all the "Connection Closed" situations.

Does the client error message coincide with the filename we see in your log? stream does not support seeking at \/var\/www\/owncloud-9.0.3\/apps\/files_external\/3rdparty\/icewind\/streams\/src\/Wrapper.php#74","level":3,"time":"2016-07-11T18:56:34+00:00","method":"GET","url":"\/owncloud\/remote.php\/webdav\/Daten\/Manifestaziuns\/Incuntada%20a%20Livigno\/Livigno\/Pr%C3%A4sentation%20Livigno%202013.ppt ?

FYI @PVince81 @icewind1991

reipes commented 8 years ago

I mount (I don't know if you say so) the linux samba share in owncloud. I have a storage in owncloud that is the samba share linux...

yes it seems so. But the client error does not coincide always with the same file

59922b7c-455d-11e6-9009-684c6395ffe5

typorian commented 8 years ago

I'm having the same issue. I'm running owncloud 2.2 on LinuxMint 17. I'm not hosting the server myself, but it is running the current version of owncloud. I can only access the logs that can be seen in the OwnCloud Admin account under logs. Will these be helpful and how do I know what I need to edit out?

guruz commented 8 years ago

@typorian Ideally you'd look at the log file, then run the client to provoke the error, then look at the log again to see what changed. Feel free to edit filenames etc.. Should not be more than a few lines?

Can you also tell us what it says in the client as version & Qt version under Settings->General

typorian commented 8 years ago

The Version is 2.2.2, what else would you need from the settings>general menu?

here is an extract from the log. the first part I see very very often and repeatedly. The second part may have something to do with the issue, it's the only thing I can find that looks different. I removed some IP addresses. {"reqId":"V4dpPZT7smAAAFmSmDUAAAAE","remoteAddr":"109.192.","app":"PHP","message":"unlink(): No such file or directory at \/home\/kumowyff\/public_html\/lib\/private\/helper.php#227","level":3,"time":"2016-07-14T10:28:13+00:00","method":"GET","url":"\/cron.php","user":"--"} {"reqId":"V4dpPZT7smAAAFmSmDUAAAAE","remoteAddr":"109.","app":"PHP","message":"rmdir(\/tmp\/oc_tmp_sqMOCW-folder\/news\/vendor\/bin): Permission denied at \/home\/kumowyff\/public_html\/lib\/private\/helper.php#225","level":3,"time":"2016-07-14T10:28:13+00:00","method":"GET","url":"\/cron.php","user":"--"} {"reqId":"V4dpPZT7smAAAFmSmDUAAAAE","remoteAddr":"109.192.","app":"PHP","message":"rmdir(\/tmp\/oc_tmp_sqMOCW-folder\/news\/vendor): Permission denied at \/home\/kumowyff\/public_html\/lib\/private\/helper.php#225","level":3,"time":"2016-07-14T10:28:13+00:00","method":"GET","url":"\/cron.php","user":"--"} {"reqId":"V4dpPZT7smAAAFmSmDUAAAAE","remoteAddr":"109.192.","app":"PHP","message":"rmdir(\/tmp\/oc_tmp_sqMOCW-folder\/news): Permission denied at \/home\/kumowyff\/public_html\/lib\/private\/helper.php#225","level":3,"time":"2016-07-14T10:28:13+00:00","method":"GET","url":"\/cron.php","user":"--"} {"reqId":"V4dpPZT7smAAAFmSmDUAAAAE","remoteAddr":"109.192.","app":"PHP","message":"rmdir(\/tmp\/oc_tmp_sqMOCW-folder): Operation not permitted at \/home\/kumowyff\/public_html\/lib\/private\/helper.php#231","level":3,"time":"2016-07-14T10:28:13+00:00","method":"GET","url":"\/cron.php","user":"--"} {"reqId":"V4dpPZT7smAAAFmSmDUAAAAE","remoteAddr":"109.192.","app":"core","message":"Error while running background job (class: OC\\Command\\CommandJob, arguments: O:33:\"OCA\\Files_Trashbin\\Command\\Expire\":1:{s:39:\"\u0000OCA\\Files_Trashbin\\Command\\Expire\u0000user\";s:6:\"Adrian\";}): {\"Exception\":\"InvalidArgumentException\",\"Message\":\"Invalid serialized command\",\"Code\":0,\"Trace\":\"#0 \\\/home\\\/kumowyff\\\/public_html\\\/lib\\\/private\\\/backgroundjob\\\/job.php(52): OC\\\\Command\\\\CommandJob->run('O:33:\\\"OCA\\\\\\\\Files...')\\n#1 \\\/home\\\/kumowyff\\\/public_html\\\/lib\\\/private\\\/backgroundjob\\\/queuedjob.php(42): OC\\\\BackgroundJob\\\\Job->execute(Object(OC\\\\BackgroundJob\\\\JobList), Object(OC\\\\Log))\\n#2 \\\/home\\\/kumowyff\\\/public_html\\\/cron.php(171): OC\\\\BackgroundJob\\\\QueuedJob->execute(Object(OC\\\\BackgroundJob\\\\JobList), Object(OC\\\\Log))\\n#3 {main}\",\"File\":\"\\\/home\\\/kumowyff\\\/public_html\\\/lib\\\/private\\\/command\\\/commandjob.php\",\"Line\":36}","level":3,"time":"2016-07-14T10:28:13+00:00","method":"GET","url":"\/cron.php","user":"--"}

guruz commented 8 years ago

@typorian You can cut/paste the line that says Built from Git revision 3a7707 on Jun 28 2016, 08:09:45 using Qt 5.4.0, OpenSSL 1.0.2h 3 May 2016

guruz commented 8 years ago

@DeepDiver1975 @PVince81 Do we think those background job messages could have anything to do with the Connection Closed? What about those Permission Denied messages?

typorian commented 8 years ago

@guruz

the only thing that it says in my client is inserted below. Additionally I can see in synaptic that the version is 2.2.2-18.3

Version 2.2.2. For more information visit owncloud.com By Klaas Freitag, Daniel Molkentin, Jan-Christoph Borchardt, Olivier Goffart, Markus Götz and others. Copyright ownCloud, Inc. Licensed under the GNU General Public License (GPL) Version 2.0 ownCloud and the ownCloud Logo are registered trademarks of ownCloud, Inc. in the United States, other countries, or both.

PVince81 commented 8 years ago

The background jobs shouldn't influence syncing as they are not part of the same request. Unless there are locks involved, but even then it will not trigger connection aborting.

Edit: added "not"

guruz commented 8 years ago

@typorian Do you use external storage in your oC server? Do you use encryption? Which server version? etc

typorian commented 8 years ago

I am using the most current stable version (I'll add the exact version later), no external storage, no encryption.

@guruz I just checked and it is 9.0.2 stable.

On July 15, 2016 2:59:10 PM GMT+02:00, Markus Goetz notifications@github.com wrote:

@typorian Do you use external storage in your oC server? Do you use encryption? Which server version? etc

You are receiving this because you were mentioned. Reply to this email directly or view it on GitHub: https://github.com/owncloud/client/issues/5050#issuecomment-232944503

Sent from my Android device with K-9 Mail. Please excuse my brevity.

luetm commented 8 years ago

I'm having the same issue. Here is the info:

Screenshot:

Client Log: clientlog.txt

There is no log entry on the server, log level is set to DEBUG.

(Hopefully helpful) Details

ownCloud version: Server: ownCloud 8.2.6 (stable), Client: 2.2.2 (build 6192)
The backup seems to hang only on certain files. I thought to have fixed the issue by removing two failing files from the backup by deleting them in the webinterface. This resulted in the backup being performed on all but the latest files now. But it hangs again, always on the same files. The backups are all about the same size (almost 40MB).
PHP variables Taken from phpinfo() in index.php PHP Version 5.6.21 (varname, local, master) always_populate_raw_post_data -1 -1 memory_limit 4096M 4048M post_max_size 4G 16G upload_max_filesize 4G 16G
It's running on a Synology Rackstation. Uploading the files seems to work fine, it's just downloading that's hanging itself up. So this is on a secondary backup location (redundancy), Windows Server 2012.
The backup is (or at least should be) performed over an OpenVPN connection. This seems to work fine for all other backups though.

EDIT: Read above that this could also be relevant:

I use external storage (to access all the RAID1 devices created by the Synology Rack Station, we sync stuff for about 10 different sites there)
I use server side encryption

I'm happy to mention anything else that is important.

Thanks for the help in advance!

dragotin commented 8 years ago

Interesting detail: It seems to be a range request failing

07-20 07:53:14:136 0x337860 OCC::GETFileJob::start: Retry with range  "bytes=11167944-"

luetm commented 8 years ago

Interesting detail: It seems to be a range request failing

07-20 07:53:14:136 0x337860 OCC::GETFileJob::start: Retry with range "bytes=11167944-"

OK. How do I fix this?

Also, I noticed that there was a File 2016-07-20 00:30:00.7zip with a red cross as an icon. I deleted it and tried again (while logging), but I still have these entries:

OCC::GETFileJob::start: Retry with range "bytes=1856391-" for 'File 2016-07-20 00-30.7z' OCC::GETFileJob::start: Retry with range "bytes=38201723-" for 'File 2016-07-19 12-30.7z'

ckamm commented 8 years ago

@luetm The "Retry with range" message is not indicative of an error, it just says that the client is attempting to resume a download, probably because a previous sync aborted midway through a download. Is it always the same file that's failing with "Connection closed" (i.e. "http://xx.xx.xx.xx/owncloud/remote.php/webdav/backup-database/File 01-02-2015 00-30.7z"?)

In your log file it's the third parallel download that fails at the start of the propagation phase. Can you try what happens when you set the environment variable OWNCLOUD_MAX_PARALLEL=1?

luetm commented 8 years ago

@ckamm

Is it always the same file that's failing with "Connection closed"

Hard to answer. It uploaded the 20.07.2016 apparently, but the 01-02-2015 00-30.7z still hangs... so I guess yes?

Can you try what happens when you set the environment variable OWNCLOUD_MAX_PARALLEL=1?

I did. I rebooted the machine so I was sure that it took that change. I added the variable in the user and the system scope. Unfortunately, the error stays the same, just "Connection Closed" as a single message, instead of 3 ("Operation Cancelled"). The error occures on the 01-02-2015 00-30.7z file. I attached the log file again.

clientlog2.txt

Also: It doesn't seem to be a problem of the "recentness" of the files. Todays backups were both uploaded without issue.

ckamm commented 8 years ago

@luetm It does indeed look like that file is stuck somehow. You could try forcing a non-resuming upload like this (sorry, it's a bit involved):

Get a program to view and edit sqlite databases with, like http://sqlitebrowser.org/
Quit your owncloud client
Open the hidden .csync_journal.db file in the root of your sync folder with it
Go to browse data, select the uploadinfo table and delete all records
Save the database, close the program

This will make the client forget about all the uploads it has started previously. Now run the client again and capture the log. If it still fails, that log file may be interesting!

guruz commented 8 years ago

Moving to 2.3 as this is probably a server/configuration issue. We're already too late for 2.2.3 unless new info comes fast on how we can fix this (if it is a client bug)

luetm commented 8 years ago

@ckamm Sorry, I missed the update on your post!

I did what you said, unfortunately, the uploadinfo table is already empty select count(*) from uploadinfo yields 0.

To test, I moved the file in question, now it hangs on another, namely Database 05-09-2015 12-30.7z. I see no apparent correlation between the two. Do you want me to make a new log dump anyway?

luetm commented 8 years ago

@guruz Can I somehow tickle some information out of the server? It doesn't give me any error despite the debug level being DEBUG...

fliszer commented 8 years ago

Hello,

I have the same situation, however problem occurs only when client is running out of LAN. When I have local (LAN) connection all files synchronize well. What debug information would be interesting for you (developers) to find out the problem.

guruz commented 8 years ago

@fliszer OS and Qt version. Also if you enabled HTTP keep-alive in your server and with which values (timeout etc). Also anything interesting in client log and server owncloud.log

luetm commented 8 years ago

@guruz Do I set keep-alive in PHP or Apache? Or something completely different?

guruz commented 8 years ago

Just noticed: The problem for @reipes and @luetm might also be that they are using HTTP instead of HTTPS. @RealRancor @dragotin Something to remember: HTTP is more prone to the 'Connection Closed' issue.

@luetm It's an Apache setting -> https://github.com/owncloud/documentation/wiki/Performance-Tuning-(unofficial)

fliszer commented 8 years ago

@guruz: client OS - Windows 7 Home Premium SP1 x64, Client Version 2.2.2 (build 6192) Built from Git revision c81ed0 on Jun 20 2016, 16:55:15 using Qt 5.4.0, OpenSSL 1.0.2h 3 May 2016

Server OS - Ubuntu 14.04 LTS Owncloud 9.0.2 (stable)

HTTP keep-alive: KeepAlive on Timeout 300 MaxKeepAliveRequest 100 KeepAliveTimeot 5

The problem disappeared when I switch into https protocol - now all files synchronize well.

luetm commented 8 years ago

@guruz Now https with valid root certificate authority, keep alive settings in the config, still the same problem.

reipes commented 8 years ago

@guruz i can confirm that https did not resolve the problem

luetm commented 8 years ago

Any more information I could provide to fix the issue? Would a RDP session bring anything?

guruz commented 8 years ago

@fliszer Sure https fixed the problem? Even if you upload/download some more files to find out?

@luetm If you say it always is with the same 7z files: Is there a chance that a local oder server virus scanner/firewall somehow influences this? If you create a file with a similar name, same size and also .7z extension and try to upload/download/whatever it, does it then also break with Connection Closed? @PVince81 Wasn't there a server bug related to server side encryption that also triggers 'Connection Closed'? Although I don't see anything now.

@reipes Did you try to corelate the client sync operation with an associated error in owncloud.log to see if the Connection Closed triggers a message in the server log?

fliszer commented 8 years ago

@guruz now it works without any problems regardless the number of downloaded / uploaded files - I have approx. 15 000 files to sync.

luetm commented 8 years ago

@guruz I now readded all the folders. Not it synced all the way through. For anyone coming here it might have been:

switching to HTTPS
Settings in Apache (keep-alive)
Adding owncloud.exe to trusted applications in TrendMicro admin console

If anything breaks I'll check back in, but for now it seems to work! Thanks everyone!

guruz commented 8 years ago

I'm removing this from 2.3 milestone unless we can get more info what this could be. For several people at other sources upgrading the owncloud server helped. Also make sure to configure web firewalls or mod_security properly

typorian commented 8 years ago

It went away with a server upgrade for me (I think that is what did the trick)

guruz commented 7 years ago

I'll close this then, I hope it's solved for everyone.

owncloud / client