Sync (with large folders) gets timeout and restarts without uploading

[mpfries]

Steps to reproduce

1. Got a server at owncube.com - full of files
2. Started OC sync client for mac (1.5.) - selected 3 folders of different sizes (Move SslErrorDialog into Application #1 500 MB, Add setter for remotePollInterval #2 4GB, Owncloud client wizard setup page doesn't handle back button presses. #3 2GB) to synchronize with my local folder on my MacBook
3. Syncing starts

Expected behaviour

Syncing process would go through all the files on the server - realize which files are new (not yet in my local folder on my MacBook) and download them.

Actual behaviour

Synchronizing works for small folders (up to 500 MB) - while checking the bigger folders (4 GB) everything works fine... until a timeout. Then it jumps to the next folder (2 GB)... same procedure here... works fine... until timeout. Then it jumps again to the small folder - syncing here works fine - it jumps to the bigger folder (4 GB) again... and gets another timeout ... not with the same file, but with another one, somewhere in the process.

I've to admit... the big folders (4 GB, 2 GB) have lots of small files in different subfolders. There is no file bigger than 12 MB in it, but lots of subfolders.

Server configuration

Operating system: Linux
Database: MySQL 5.5.35-cll
PHP version: 5.4.24
ownCloud version: ownCloud 6.0.1 (stable)

Updated from an older ownCloud or fresh install:
Updated from 5 - but the problem happened in OC5 too

List of activated apps: CONTACTS, DATA/FILES

The content of config/config.php:

'XXX', 'passwordsalt' => 'XXX', 'datadirectory' => '/home/XXX/public_html/data', 'dbtype' => 'mysql', 'version' => '6.0.0.16', 'dbname' => 'XXX', 'dbhost' => '127.0.0.1', 'dbtableprefix' => 'oc_', 'dbuser' => 'XXX', 'dbpassword' => 'XXX', 'installed' => true, 'forcessl' => false, 'maxZipInputSize' => 0, 'allowZipDownload' => true, 'loglevel' => '3', 'theme' => '', 'maintenance' => false, ); **Are you using external storage, if yes which one:** NO **Are you using encryption:** NO ### Client configuration **Operating system:** Mac OS X 10.9 with OwnCloud client 10.5 I've tried 10.4 - same problem here. 10.5.1 crashes at some point of the synchronizing, so I didn't try it again. #### ownCloud log (`owncloud --logfile log.txt`) 02-26 11:41:04:131 csync_ftw: <= Closing walk for ownclouds://www.ADRESS.COM/remote.php/webdav/Shared/2ndFOLDER/Ablage/Institutionen/SLT - Sächsischer Landtag with read_from_db 0 02-26 11:41:04:131 oc_module: owncloud_stat ownclouds://www.ADRESS.COM/remote.php/webdav/Shared/2ndFOLDER/Ablage/Institutionen/SAENA called 02-26 11:41:04:131 csync_walker: directory: ownclouds://www.ADRESS.COM/remote.php/webdav/Shared/2ndFOLDER/Ablage/Institutionen/SAENA 02-26 11:41:04:131 _csync_detect_update: ==> file: Institutionen/SAENA - hash 2046379301889022076, mtime: 1392359623, fileId: 0003233452ce5e17333ef 02-26 11:41:04:131 csync_statedb_get_stat_by_hash: No result record found for phash = 2046379301889022076 02-26 11:41:04:131 _csync_detect_update: file: Institutionen/SAENA, instruction: INSTRUCTION_NEW <<= 02-26 11:41:04:131 oc_module: opendir method called on ownclouds://www.ADRESS.COM/remote.php/webdav/Shared/2ndFOLDER/Ablage/Institutionen/SAENA 02-26 11:41:09:803 \* Polling "1stFOLDER" for changes. (time since last sync: 1830 s) 02-26 11:41:09:804 Loading config: "/Users/MYUSERNAME/Library/Application Support/ownCloud/owncloud.cfg" (URL is "https://www.ADRESS.COM" ) 02-26 11:41:09:805 *\* Force Sync now, state is "Not yet Started" 02-26 11:41:09:806 Schedule folder "1stFOLDER" to sync! 02-26 11:41:09:807 II> Sync for folder "1stFOLDER" already scheduled, do not enqueue! 02-26 11:41:09:808 Currently folder "2ndFOLDER" is running, wait for finish! 02-26 11:41:11:456 \* Polling "3rdFOLDER" for changes. (time since last sync: 1950 s) 02-26 11:41:11:457 Loading config: "/Users/MYUSERNAME/Library/Application Support/ownCloud/owncloud.cfg" (URL is "https://www.ADRESS.COM" ) 02-26 11:41:11:458 *\* Force Sync now, state is "Not yet Started" 02-26 11:41:11:459 Schedule folder "3rdFOLDER" to sync! 02-26 11:41:11:460 II> Sync for folder "3rdFOLDER" already scheduled, do not enqueue! 02-26 11:41:11:461 Currently folder "2ndFOLDER" is running, wait for finish! 02-26 11:41:32:877 !!! Mirall::CheckQuotaJob created for QUrl( "https://www.ADRESS.COM" ) querying "/" 02-26 11:41:32:987 SSL-Warnings happened for url "https://www.ADRESS.COM/remote.php/webdav/" 02-26 11:41:32:989 Certs are already known and trusted, Warnings are not valid. 02-26 11:41:39:815 \* Polling "1stFOLDER" for changes. (time since last sync: 1860 s) 02-26 11:41:39:816 Loading config: "/Users/MYUSERNAME/Library/Application Support/ownCloud/owncloud.cfg" (URL is "https://www.ADRESS.COM" ) 02-26 11:41:39:818 *\* Force Sync now, state is "Not yet Started" 02-26 11:41:39:819 Schedule folder "1stFOLDER" to sync! 02-26 11:41:39:820 II> Sync for folder "1stFOLDER" already scheduled, do not enqueue! 02-26 11:41:39:822 Currently folder "2ndFOLDER" is running, wait for finish! 02-26 11:41:41:468 \* Polling "3rdFOLDER" for changes. (time since last sync: 1980 s) 02-26 11:41:41:470 Loading config: "/Users/MYUSERNAME/Library/Application Support/ownCloud/owncloud.cfg" (URL is "https://www.ADRESS.COM" ) 02-26 11:41:41:471 *\* Force Sync now, state is "Not yet Started" 02-26 11:41:41:472 Schedule folder "3rdFOLDER" to sync! 02-26 11:41:41:473 II> Sync for folder "3rdFOLDER" already scheduled, do not enqueue! 02-26 11:41:41:474 Currently folder "2ndFOLDER" is running, wait for finish! 02-26 11:42:03:467 !!! Mirall::CheckQuotaJob created for QUrl( "https://www.ADRESS.COM" ) querying "/" 02-26 11:42:05:131 SSL-Warnings happened for url "https://www.ADRESS.COM/remote.php/webdav/" 02-26 11:42:05:133 Certs are already known and trusted, Warnings are not valid. 02-26 11:42:09:828 \* Polling "1stFOLDER" for changes. (time since last sync: 1890 s) 02-26 11:42:09:830 Loading config: "/Users/MYUSERNAME/Library/Application Support/ownCloud/owncloud.cfg" (URL is "https://www.ADRESS.COM" ) 02-26 11:42:09:832 *\* Force Sync now, state is "Not yet Started" 02-26 11:42:09:833 Schedule folder "1stFOLDER" to sync! 02-26 11:42:09:834 II> Sync for folder "1stFOLDER" already scheduled, do not enqueue! 02-26 11:42:09:835 Currently folder "2ndFOLDER" is running, wait for finish! 02-26 11:42:11:480 \* Polling "3rdFOLDER" for changes. (time since last sync: 2010 s) 02-26 11:42:11:482 Loading config: "/Users/MYUSERNAME/Library/Application Support/ownCloud/owncloud.cfg" (URL is "https://www.ADRESS.COM" ) 02-26 11:42:11:483 *\* Force Sync now, state is "Not yet Started" 02-26 11:42:11:484 Schedule folder "3rdFOLDER" to sync! 02-26 11:42:11:485 II> Sync for folder "3rdFOLDER" already scheduled, do not enqueue! 02-26 11:42:11:486 Currently folder "2ndFOLDER" is running, wait for finish! 02-26 11:42:14:633 oc_module: Neon error code was 5 02-26 11:42:14:633 oc_module: Neon error code was 5 02-26 11:42:14:633 oc_module: WRN: propfind named failed with 5, request error: Could not connect to server: Operation timed out 02-26 11:42:14:633 oc_module: Errno set to 10006 02-26 11:42:14:633 csync_ftw: opendir failed for ownclouds://www.ADRESS.COM/remote.php/webdav/Shared/2ndFOLDER/Ablage/Institutionen/SAENA - Unknown error: 10006 (errno 10006) 02-26 11:42:14:633 oc_module: closedir method called 0x10dff4cc0! 02-26 11:42:14:633 oc_module: closedir method called 0x10e9216c0! 02-26 11:42:14:634 #### ERROR during csync_update : "CSync konnte sich nicht mit dem Netzwerk verbinden. Could not connect to server: Operation timed out" 02-26 11:42:14:654 -> CSync Finished slot with error false warn count 0 02-26 11:42:14:667 Starting Event logging again in 2000 milliseconds 02-26 11:42:14:668 OO folder slotSyncFinished: result: 2 02-26 11:42:14:669 Folder in overallStatus Message: Mirall::Folder(0x109b0b0a0) with name "3rdFOLDER" 02-26 11:42:14:670 Folder in overallStatus Message: Mirall::Folder(0x109b237e0) with name "1stFOLDER" 02-26 11:42:14:671 Folder in overallStatus Message: Mirall::Folder(0x103f9d3e0) with name "2ndFOLDER" 02-26 11:42:14:672 Sync state changed for folder "2ndFOLDER" : "Not availabe" 02-26 11:42:14:673 SocketApi: Sync state changed 02-26 11:42:14:674 SocketApi: Broadcasting to 0 listeners: "UPDATE_VIEW" 02-26 11:42:14:675 <===================================== sync finished for "2ndFOLDER" 02-26 11:42:14:876 XX slotScheduleFolderSync: folderQueue size: 2 02-26 11:42:14:878 Folder in overallStatus Message: Mirall::Folder(0x109b0b0a0) with name "3rdFOLDER" 02-26 11:42:14:880 Folder in overallStatus Message: Mirall::Folder(0x109b237e0) with name "1stFOLDER" 02-26 11:42:14:881 Folder in overallStatus Message: Mirall::Folder(0x103f9d3e0) with name "2ndFOLDER" 02-26 11:42:14:883 Sync state changed for folder "1stFOLDER" : "SyncPrepare" 02-26 11:42:14:885 SocketApi: Sync state changed 02-26 11:42:14:886 SocketApi: Broadcasting to 0 listeners: "UPDATE_VIEW" 02-26 11:42:14:887 **\* Start syncing 02-26 11:42:14:889 Loading config: "/Users/MYUSERNAME/Library/Application Support/ownCloud/owncloud.cfg" (URL is "https://www.ADRESS.COM" ) 02-26 11:42:14:890 ==> returning exclude file path: "/Applications/owncloud.app/Contents/Resources/sync-exclude.lst" 02-26 11:42:14:891 ==== added system ignore list to csync: "/Applications/owncloud.app/Contents/Resources/sync-exclude.lst" 02-26 11:42:14:892 csync_exclude_load: Adding entry: _.filepart 02-26 11:42:14:893 csync_exclude_load: Adding entry: *~ 02-26 11:42:14:894 csync_exclude_load: Adding entry: *.part 02-26 11:42:14:899 csync_exclude_load: Adding entry: *.crdownload 02-26 11:42:14:900 csync_exclude_load: Adding entry: *.unison_ 02-26 11:42:14:900 csync_exclude_load: Adding entry: _csync_timedif.ctmp_ 02-26 11:42:14:901 csync_exclude_load: Adding entry: csync_journal.db 02-26 11:42:14:902 csync_exclude_load: Adding entry: csync_journal.db.ctmp 02-26 11:42:14:903 csync_exclude_load: Adding entry: ._.sw? 02-26 11:42:14:903 csync_exclude_load: Adding entry: ._._sw? 02-26 11:42:14:904 csync_exclude_load: Adding entry: ].csync-progressdatabase 02-26 11:42:14:905 csync_exclude_load: Adding entry: ].DS_Store 02-26 11:42:14:905 csync_exclude_load: Adding entry: ].ds_store 02-26 11:42:14:906 csync_exclude_load: Adding entry: ]Thumbs.db 02-26 11:42:14:907 csync_exclude_load: Adding entry: desktop.ini 02-26 11:42:14:908 csync_exclude_load: Adding entry: *.kate-swp 02-26 11:42:14:908 csync_exclude_load: Adding entry: *_conflict-_ 02-26 11:42:14:909 csync_exclude_load: Adding entry: ]_.~_ 02-26 11:42:14:910 csync_exclude_load: Adding entry: ].TemporaryItems 02-26 11:42:14:911 csync_exclude_load: Adding entry: ].Trashes 02-26 11:42:14:912 csync_exclude_load: Adding entry: ].DocumentRevisions-V100 02-26 11:42:14:913 csync_exclude_load: Adding entry: .fseventd 02-26 11:42:14:913 csync_exclude_load: Adding entry: .apdisk 02-26 11:42:14:914 csync_exclude_load: Adding entry: .htaccess 02-26 11:42:14:915 csync_exclude_load: Adding entry: ]Icon\r* 02-26 11:42:14:916 csync_exclude_load: Adding entry: ~$* 02-26 11:42:14:917 csync_exclude_load: Adding entry: .~lock.* 02-26 11:42:14:918 csync_exclude_load: Adding entry: ~*.tmp 02-26 11:42:14:918 ==> returning exclude file path: "/Users/MYUSERNAME/Library/Application Support/ownCloud/sync-exclude.lst" 02-26 11:42:14:919 ==== added user defined ignore list to csync: "/Users/MYUSERNAME/Library/Application Support/ownCloud/sync-exclude.lst" 02-26 11:42:14:920 QUrl( "https://www.ADRESS.COM/remote.php/webdav/Shared/1stFOLDER" ) 02-26 11:42:14:921 \* event notification disabled 02-26 11:42:14:921 void Mirall::CSyncThread::startSync() Sync started 02-26 11:42:14:921 starting to sync QThread(0x1049030d0) QThread(0x1049ad7f0) 02-26 11:42:14:921 Loading config: "/Users/MYUSERNAME/Library/Application Support/ownCloud/owncloud.cfg" (URL is "https://www.ADRESS.COM" ) 02-26 11:42:14:921 No database Transaction to commit 02-26 11:42:14:921 >===================================== sync started for "ownCloud_1stFOLDER“ 02-26 11:42:14:922 =====sync with existing DB 02-26 11:42:14:922 #### Update start #################################################### >> 02-26 11:42:14:922 csync_update: Journal: /Users/MYUSERNAME/ownCloud_DP/1stFOLDER/.csync_journal.db 02-26 11:42:14:927 csync_ftw: Uniq ID from Database: .DS_Store -> 02-26 11:42:14:927 csync_walker: file: /Users/MYUSERNAME/ownCloud_DP/1stFOLDER/.DS_Store 02-26 11:42:14:927 _csync_detect_update: .DS_Store excluded (2) 02-26 11:42:14:928 csync_ftw: Uniq ID from Database: 00 - Politik - Transfer -> 530d0da8e58fc #### TRIED OUT: https://forum.owncloud.org/viewtopic.php?f=3&t=7995#p25921 - I've tried this one, but I can't find a "ocsync.conf" in the ApplicationFolder on my MacBook... just a "owncloud.cfg" ... and setting a timeout in that file doesn't change a single thing. It's frustrating me... and the company that wanted to start working with OwnCloud :(

[mpfries]

Same error with ownCloud-1.5.2.2332-nightly20140226 as client.
Same error with SSL turned on or off.

Only that it now (15.2.2232-nightly and SSL off) downloads part of the big folder (4 GB), but crashes because of a timeout while downloading (after 122MB this time).

I saw this post here: #1459 - seems similar, although my client setting is "No proxy".

[mpfries]

+++Tried out:
Synchronizing with small folders (up to 200 MB) works perfectly, fast and without errors... it's just if the process of checking the folder for changes and downloading new files takes too long, it always gets that timeout at some point.
Couldn't the process of checking up the whole big folder be seperated into smaller parts, so that if a timeout comes sometime, it won't interrupt and restart the whole process (ending in a never-ending loop)??

[guruz]

02-26 11:42:14:633 oc_module: WRN: propfind named failed with 5, request error: Could not connect to server: Operation timed out

It is very strange that a PROPFIND already fails. A PROPFIND is just getting a listing of a directory and 2 GB doesn't sound like much. How many files (roughly?) do you have in there?

If you remove the syncing for all folders except the 2 GB one (so you sync only this one) and restart the client, does it work? (So we don't hit some timeout issue across folders or something)

[guruz]

If already the PROPFIND times out and this is a folder with many files, I'm wondering if owncloud/core#5084 can be blamed.

[mpfries]

Issue got fixed with ownCloud-1.5.3.2392-nightly20140306.dmg !
Still got some problems with timeouts, but all in all it works now.

Thanks alot to those developing the client and fixing issues that quickly!