Upload of many Files really slow

myzinsky commented 11 years ago

Expected behaviour

Upload of a lot of MP3 Files (4GB) should be fast.

Actual behaviour

Upload Only 6 Files (ca 40mb) in 4 hours!

Server configuration

Operating system: Debian Stable

Web server: Apache2

Database: Mysql

PHP version: PHP Version 5.3.3-7+squeeze14

ownCloud version: 4.5.6

Client configuration

Client version: 1.2

Operating system: Debian Unstable

OS language: German

Installation path of client: /usr/bin/owncloud

Logs

ownclouds://xxx/Blue Moon 02-12 14:18:20:533 oc_module: owncloud_stat ownclouds://xxx/Blue Moon called 02-12 14:18:20:678 oc_module: Simple propfind result code 207. 02-12 14:18:20:678 oc_module: Server Date from HTTP header value: Tue, 12 Feb 2013 13:18:20 GMT 02-12 14:18:20:679 oc_module: Ok: Time delta remained (almost) the same: 0. 02-12 14:18:20:679 oc_module: => Errno after fetch resource list for ownclouds://xxx/Blue Moon: 0 02-12 14:18:20:679 oc_module: Working on file Blue Moon 02-12 14:18:20:679 oc_module: :> Subtracting 0 from modtime 1360675100 02-12 14:18:20:679 oc_module: STAT result from propfind: Blue Moon, mtime: 1360675100 02-12 14:18:20:679 oc_module: Directory of file to open exists. 02-12 14:18:20:679 oc_module: PUT request on //xxx/Blue%20Moon/Robben%20Ford%20-%20My%20Everything.mp3! 02-12 14:18:20:679 oc_module: Sendfile handling request type PUT. 02-12 14:18:20:679 oc_module: Put file size: 6858752, variable sizeof: 8

This is an example, it waits a really loooong time :( (Paths shortened with xxx)

Web server error log

Deprecated: Directive 'register_long_arrays' is deprecated in PHP 5.3 and greater in Unknown on line 0

There is a lot of this stuff, but i'm not shure if this is realted to owncloud

ownCloud log (data/owncloud.log)

{"app":"media","message":"error reading title tag in '\/var\/www\/owncloud\/xxx.mp3'","level":2,"time":1360575380}### Expected behaviour Upload of a lot of MP3 Files (4GB) should be fast.

wontolla commented 11 years ago

I would appreciate a solution to my troubles, sorry for intrusion, seems the developers are too busy with another non critic trouble. I couldn't believe a basic sync problem is unsolved from version 4.5.5 to 5.0.5. I'd too different installations, different hardware, different OS so I don't know if everybody else has the same problem or not, I really wish to know if there is some kind of limit in the number of folders & files, maybe is simply the Community Edition has some limits, no idea because nobody answer us.

In my last test, client 1.2.5 works the same, 900 MB, 20 K files, several weeks to sync.

danimo commented 11 years ago

@wontolla "seems the developers are too busy with another non critic trouble". Aha, like what? Fixing crashes? Avoiding dataloss? Is that "non-critic" (sic!).

Anyway, the issue is pretty simple: the clients upload one file at a time, so the time penalty is the highest for lots of small files, due to roundtrip losses. Others at least went ahead to propose fixes (i.e. #548), and any proposal we have needs a bit of design and implementation. Right now we are working on chunked uploading to optimize upload of big files. And after that, we will come to this use case. But being only two developers (that also have to do all the support, resolving bugs, etc), we have to chew the cake piece by piece.

Fortunately, this is an open source project, and we are glad to assist anyone who wants to tackle this problem sooner than we can. And no, there is no artificial crippling, and it may well be that the roundtrips are particulary slow due to your server setup (we heard about that before, which is why this case needs more investigation first).

wontolla commented 11 years ago

Well, I'm sure you have you priorities quite set, at least you answered. I'm a sysadmin not a developer so I only can help you a bit, testing several installations working in different platforms as I did.

I tested the platform before buying, so I really get it one opportunity, maybe three or four.

Good luck with the project

tytgatlieven commented 11 years ago

Dear

I have gone somewhat into the code in order to reduce the needed amount of updates.

I figured since update take a lot longer than selects to first check the current values in the DB before actually updating them. This way I hoped to reduce the needed amount of updates since I tought a number of updates would most likely be unneeded. I implemented this in the update function In cache.php. as follows:

public function update($id, array $data) {
list($queryParts, $params) = $this->buildParts($data);
$params[] = $id;
$updateneededquery = \OC_DB::prepare('SELECT ' . implode(', ', $queryParts) . ' FROM `*PREFIX*filecache` WHERE `fileid` = ?');
$currentvalues = $updateneededquery->execute(array($id));

if ($row = $currentvalues->fetchRow()) {
  foreach ($data as $name => $value) {
//In buildParts they calculate the md5 to store it in path_hash and change the textual mimetype into an number
     if ($name === 'path') {
       $value = md5($value);
     } elseif ($name === 'mimetype') {
       $value = $this->getMimetypeId($value);
     }
//If a value is changed, commit the update
     if ($row[$name] != $value) {
       $query = \OC_DB::prepare('UPDATE `*PREFIX*filecache` SET ' . implode(' = ?, ', $queryParts) . '=?'
    . ' WHERE fileid = ?');
       $query->execute($params);
       break;
     }
  }
}

EDIT: Traces (with wrong code, see EDIT2) are here: https://gist.github.com/tytgatlieven/5451888

EDIT2: There was a problem with above code, fixed it. (!== versus !=)

This seems to reduce the amount of updates!

Can somebody check if this improves speed? (replace the function update in file lib/files/cache/cache.php)

kind regards

tytgatlieven commented 11 years ago

I checked on my setup with a flat folder containing 1000 files. test executed: pause client sync add 1000 files in a single dir (bash: for i in {1..1000}; do touch $i; done) which the client syncs after hitting resume when sync finished, remove files, wait until sync finished

The results are: adding the files: without checking db contents first: 1.16s / file with checking db contents: 0.837s / file

removing the files: without checking db contents first: 0.28s / file with checking db contents: 0.2s / file

or about a 40% improvement

We're not there yet, but this is positive :-)

PS: More tests are welcome!

DataToddler commented 11 years ago

@danimo If you don't see too many people complaining about this issue, that's because the massive overhead traffic is the number 1 killer, and people start ditching OC right away once they experience this mega slowness, before they even encounter any "real" bugs.

I am being mean here, but I don't think OC is practically usable before this issue is properly solved. If you do statistics on the file sizes that people intend to sync with OC, you will understand why it's unbearable to spend 100 times longer on the overhead than the actually data. Why do people pay $$$ for fast connections and got stuck with OC, instead of sparing $9/mo with dropbox, when OC makes their connection sound like a 56k modem?

wontolla commented 11 years ago

It could be that rsync handles the files one by one and BiTorrent Sync, for example, several at the same time?....

that0n3guy commented 11 years ago

Just tested Bittorrent sync.... it is doing multiples at the same time, which makes sense because thats how a normal bittorrent downloader works.

I tested it like before (https://github.com/owncloud/mirall/issues/331#issuecomment-16079510) and it downloaded it in less than 3 minutes... something that takes 30min+ in OC.

That said, I don't think the individual downloads were really that fast.... I think it can just do 20 files at a time so it makes it a lot faster.

1 file at a time does seem silly for small files.

Sturmflut commented 11 years ago

I tried to sync my server to itself today to circumvent any etwork problems and delays. The result: 72 MB in one hour via localhost. It is a Dual Xeon with eight Cores and 32 GB of RAM.

I am very sorry, but ownCloud is completely unusable for file synchronization in the current state.

danimo commented 11 years ago

@Sturmflut are you using APC for the server? Are you using ownCloud 5.0 or 4.5? We need infos. Complaining will not help, sorry.

Sturmflut commented 11 years ago

@danimo OwnCloud 5.0.5-0 on Ubuntu, installed from the OpenSuSe Repository. APC is installed and configured. The server is connected to a 100 MBit/s connection, but since I synchronized against localhost this should be irrelevant.

As far as I can see from the log files the file operations itself are very slow, despite all processes (apache, PHP etc.) consuming less than 5% CPU. Slow file operations combined with syncing only one file at a time seems to be the core problem.

Do you developers not see these performance problems on your installations? Pretty much everybody seems to experience bad performance so you should also be affected.

vger72 commented 11 years ago

I agree with bittergourd, this performance problem is a killer. The other problems are (at least for me) secondary.

I think this is a great project with promising commercial implementation. I do sell IT solutions and this one looked a great option to companies needing file sync and availability but not wanting their data somewhere they don't rely on.

However, all my tests show an extremely slow sync. This kills the project from the start.

I'm not a programmer so, i can't help on that but i may test on several environments if it helps.

sargelavoie commented 11 years ago

I have installed owncloud on my NAS (Seagate Blackarmor 220) with Debian Lenny (kernel 2.6.22.18). I have compiled from source apache 2.4.4, php 5.4.14 and sqlite-autoconf-3070603. The webserver is working good in https with OwnCloud 5.0.5, but slow. Yesterday, i started the file transfer (35 GB, 60121 files). About 16h latter, i had only 14 MB of data composed only of folder. No file. In this time, the CPU was always > 95% for the httpd process.

vger72 commented 11 years ago

I reconfigured owncloud to use an external mysql server instead of sqlite. The performance is a little bit better but still unusable. Could that be some apache or php thing ? My network is fast, the nas is fast and access to the mysql server from other apps in the same owncloud server are fast.

schulmar commented 11 years ago

I am running Apache 2.2.24 and PHP 5.5.0_beta3 with oC 5.0.4 on a gentoo box. After about 2h of syncing a folder of 366MB and about 1000 files oC displays ~170MB in the browser. Looking at the load the apache process uses <5% CPU and writes with about 100KB/s to the disk (peak 1MB/s for about 1/10th of a second). All traffic is routed locally via 1GBit/s links.

chamrc commented 11 years ago

Had the same issue before, was uploading 16 GB of school works (mostly docxs & pdf) & some images, took like three days to compute files to upload and the speed is less than 10 KB/s. Seems like OwnCloud had a lot of overhead with small files.

Tried owncloud with like really large file(movies over 10GB each), speed is decent, over 2 MB/s.

In the end, I went with BitTorrent Sync & SeaFile instead, both have https option as well.

racic commented 11 years ago

Seeing the same issue here. The client machine is Ubuntu 12.04 x86_64 running latest ownCloud client from opensuse.org repo for Ubuntu. The server is running Debian 6.0.3 armv5tel with the latest oC (sqlite) server from the opensuse.org Debian repo. The connection is gigabit ethernet (through gigabit switch), both devices are sitting on muy desktop.The upload of large number of small files (~200MB, ~1500 files) is horribly slow to the point the whole solution is unusable.

vger72 commented 11 years ago

I did another test: I have a core i5 with 8GB RAM with Fedora 18 machine. Installed owncloud using sqlite from repos. I use the client on the same machine (configured the client to connect to localhost/owncloud)

the sync speed was of 30MB for each 10 minutes (aprox. 180MB per hour)

piratenpanda commented 11 years ago

Same here on Fedora 18 and a remote host

tytgatlieven commented 11 years ago

Hi guys

I believe that the devs have already gotten the message. Imo there is no need anymore to report on the slowness as a problem. Instead let's keep this thread positive!

Anybody willing to help solving the problem by reporting / helping are certainly welcome. Especially somebody who has / wants to have knowledge of php and mysql is certainly welcome imo! This is a super project which can have a significant impact, so seems to me this is a perfect student project, perhaps even a thesis topic?

Kind regards

Lieven

piratenpanda notifications@github.comschreef:

Same here on Fedora 18 and a remote host

— Reply to this email directly or view it on GitHub.

vger72 commented 11 years ago

tytgatlieven: the only way to keep this thread positive is helping identify the origin of the problem. Until now, all known configurations have problems. However, I don't believe the devs would put this in production if they've seen these problems. So, the configuration they tested should be OK. I'd like to know what that config is in order to replicate it. Maybe we are missing something in the deployment.

tytgatlieven commented 11 years ago

Hello Vger72

I do agree that the devs most likely are focussing on other issues at this point which is most likely the reason why they haven't put much attention to this issue. I believe they are working on solving the 2gb max upload file limit at this moment if I understood correctly.

I think the tests the devs are using at this point are therefore most likely a few large files, which I have already shown will not have a performance issue (see above). The problem arises when a large number of small files are uploaded. So at this point there is most likely a mismatch between what the core devs are working on and what we within this thread are expecting from them. Within our own deployment we should make sure to enable apc, which makes the parsing of the php fast in comparison to the execution time of the mysql statements. (600 of them per file put) I have already given my 2 cent about a small fix which reduces about 40% of the processing time per file, but a significant reduction of magnitude10 is still required, which will take significantly more effort than what I have put in until now.

This is the reason why I posted my last comment about requesting people to join in solving this problem. I'm no expert in php nor mysql, but still I have done my best to help identify the problem. So I'm sure there are more people like me which can help the developers to identify the root cause of this problem, so they can fix it in 1/2 the time as they would have needed without the help.

This is just my own opinion, and I'm in no way related to the devs of owncloud (Most likely they don't even know my name). However, I still believe owncloud has a magnificent future if the pain points are tackled.

Kind regards

Lieven

vger72 notifications@github.comschreef:

tytgatlieven: the only way to keep this thread positive is helping identify the origin of the problem. Until now, all known configurations have problems. However, I don't believe the devs would put this in production if they've seen these problems. So, the configuration they tested should be OK. I'd like to know what that config is in order to replicate it. Maybe we are missing something in the deployment.

— Reply to this email directly or view it on GitHub.

MTGap commented 11 years ago

Xdebug with a stack trace anyone?

butonic commented 11 years ago

@MTGap @icewind1991 and I discussed not triggering hooks for ignored files, such as *.part via mail. I had @dragotin try a hack which seems promising. @icewind1991 you proposed blacklisting files and turning off hooks for them completely. What about adding a parameter to the view methods that prevents triggering hooks? We have to look inside the passed param array and check path, newpath, oldpath and maybe others ... unless we check the path in the view and not in OC_Hook::emit(). @icewind1991 since you are already working on the hook system are you planning to add the blacklist, too? @ mention me if you need a review.

frehberg commented 11 years ago

Owncloud is a great tool, would be fantastic if the performance issue with large number of files could be fixed.

danimo commented 11 years ago

@frehberg We are working on resolving the bottlenecks on both the server and the client side.

TZer0 commented 11 years ago

Two suggestions:

Make the upload-process bundle several files under a certain threshold together as one transmission.
Upload several files at once.

Edit: having the same issue. 4500 files divded on 1.5 GB

wunderlich commented 11 years ago

I can confirm this bug. Here are some specs:

Server: Linux Mint 14, Apache, ownCloud 5.0.5
Client: Linux Mint 14, oc Sync Client 1.2.5

I already used the sync client for months. Since some days (weeks?), it works really slow. I assume the change came with version 1.2.5 of the sync client.

Copying files to the server via file browser (nemo/nautilus) works great and relatively fast (I don't think it's a network related problem). But the sync client ist unusable at the moment.

That's very disapointing, because it long time worked very well.

I would like to help you to locate the problem. Do you need some more information?

Is there a place where I can download old versions of the sync client? Then it would be possible to test if the problem came with 1.2.5.

TZer0 commented 11 years ago

I think that how the file sync works needs a rethink.

Somehow, Sparkleshare is able to check everything in the folder within seconds using git, while ownCloud takes like 5+ minutes just to check if there are any files which must be synced.

This, combined with the slowness renders ownCloud unusable for me when it comes to file syncing. However, I will most certainly use it for news etc. as google reader is going down.

wunderlich commented 11 years ago

"File checking" works fast enough for me. It's the upload process which is slow.

mathewmeconry commented 11 years ago

same problem here...

Takes a lot of time to query throught the files on the server (18.7 GB / around 16'269 Files) and upload or download them from/onto the server.

another thing I saw is that, when the client finds a newer version of a file in the local directory it looks up again if the file not exist or is older on the server.

The other thing is that the Sync-Client on Ubuntu doesn't show any chages in the info menu (see screenshot) selection_004

Server: Ubuntu 12.10 on ESX host Apache Mysql DB 4 GB Memory 1 Giga-Lan OwnCloud 5.0.5

Client: Ubuntu 13.04 6GB Memory Quad Core Sync-Client 1.2.5

Please fix this issue. For me it exists since I use OwnCloud and this is for 6 months

mathewmeconry commented 11 years ago

I also looked now through the ClientSync-Log and saw that these 3 lines everytime get repeatet:

05-21 23:11:37:401 oc_module: Server Date from HTTP header value: Tue, 21 May 2013 21:11:37 GMT 05-21 23:11:37:401 oc_module: Ok: Time delta remained (almost) the same: 0. 05-21 23:11:37:401 oc_module: => Errno after fetch resource list for owncloud://

These are now new files, which don't exist on the server. Is this Errno normal??

wunderlich commented 11 years ago

I did some upload-tests with the sync client today with oC 5.0.5 and 5.0.6.

Setup

Server

Linux Mint 13 (Ubuntu 12.04)
ownCloud 5.0.5/5.0.6
SQLite-Database

Client

Linux Mint 14 (Ubuntu 12.10)
ownCloud Sync Client 1.2.5

Network Speed

I tested the connection to my server using iperf and it looks quite good:

------------------------------------------------------------
Client connecting to xxx.xxx.xxx.xxx, TCP port 5001
TCP window size: 22.9 KByte (default)
------------------------------------------------------------
[  3] local xxx.xxx.xxx.xxx port 51621 connected with xxx.xxx.xxx.xxx port 5001
[ ID] Interval       Transfer     Bandwidth
[  3]  0.0-10.0 sec  1.09 GBytes   936 Mbits/sec

One file of 100 MB (oC 5.0.5)

Upload-time (Csync run): 4622 ms (0,077 minutes)

05-27 11:57:26:795 Toggle enabled/disabled Folder alias  "test"  - current state:  false 
05-27 11:57:26:795 Application: enable folder with alias  "test" 
05-27 11:57:26:795     * event notification  enabled 
05-27 11:57:26:795 setSyncEnabled - ############################  true 
05-27 11:57:26:795 *  "test" Poll timer disabled 
05-27 11:57:26:795 Schedule folder  "test"  to sync! 
05-27 11:57:26:795 XX slotScheduleFolderSync: folderQueue size:  1 
05-27 11:57:26:795 ==> load folder icon  "owncloud-framed" 
05-27 11:57:26:796 Returning configured owncloud url:  "https://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/" 
05-27 11:57:26:796 Check status.php from statusdialog. 
05-27 11:57:26:796 Get Request to  "status.php" 
05-27 11:57:26:796 Returning configured owncloud url:  "https://xxx.xxx.xxx.xxx/owncloud/" 
05-27 11:57:26:796 Returning configured owncloud url:  "https://xxx.xxx.xxx.xxx/owncloud/" 
05-27 11:57:26:796 Setting up host header:  "xxx.xxx.xxx.xxx" 
05-27 11:57:26:796 Folder in overallStatus Message:  Mirall::ownCloudFolder(0x1bd43b0)  with name  "test" 
05-27 11:57:26:796 Sync state changed for folder  "test" :  "SyncPrepare" 
05-27 11:57:26:796 *** Start syncing url to ownCloud:  "ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test" 
05-27 11:57:26:796 Returning configured owncloud url:  "https://xxx.xxx.xxx.xxx/owncloud/" 
05-27 11:57:26:797     * event notification  disabled 
05-27 11:57:26:797 >===================================== sync started for  "test" 
05-27 11:57:26:797 ==> load folder icon  "owncloud-framed" 
05-27 11:57:26:797 void Mirall::CSyncThread::startSync() Sync started 
05-27 11:57:26:797 starting to sync  QThread(0x174f630) QThread(0x268f7d0) 
05-27 11:57:26:797 Returning configured owncloud url:  "https://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/" 
05-27 11:57:26:797   ==> returning exclude file path:  "/etc/ownCloud/sync-exclude.lst" 
05-27 11:57:26:797 ==== added CSync exclude List:  "/etc/ownCloud/sync-exclude.lst" 
05-27 11:57:26:797 Check status.php from statusdialog. 
05-27 11:57:26:797 Get Request to  "status.php" 
05-27 11:57:26:797 Returning configured owncloud url:  "https://xxx.xxx.xxx.xxx/owncloud/" 
05-27 11:57:26:797 Returning configured owncloud url:  "https://xxx.xxx.xxx.xxx/owncloud/" 
05-27 11:57:26:797 Setting up host header:  "xxx.xxx.xxx.xxx" 
05-27 11:57:26:797 folder is sync enabled:  true 
05-27 11:57:26:800 csync_lock: Creating lock file: /home/user/.local/share/data//ownCloud//lock
05-27 11:57:26:800 _csync_lock_create: XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX
05-27 11:57:26:800 _csync_lock_create: Create temporary lock file: /home/user/.local/share/data//ownCloud/tmp_lock_XXXXXX
05-27 11:57:26:800 _csync_lock_create: Write pid (7675) to temporary lock file: /home/user/.local/share/data//ownCloud/tmp_lock_8stl86
05-27 11:57:26:800 _csync_lock_create: Create a hardlink from /home/user/.local/share/data//ownCloud/tmp_lock_8stl86 to /home/user/.local/share/data//ownCloud//lock.
05-27 11:57:26:800 csync_config_load: Config: max_depth = 50
05-27 11:57:26:800 csync_config_load: Config: max_time_difference = 10
05-27 11:57:26:800 csync_config_load: Config: sync_symbolic_links = 0
05-27 11:57:26:800 csync_config_load: Config: timeout = 0
05-27 11:57:26:800 csync_exclude_load: Loading exclude file: /usr/etc/ocsync/ocsync_exclude.conf
05-27 11:57:26:800 csync_exclude_load: Adding entry: .beagle
[...]
05-27 11:57:26:801 csync_exclude_load: Loading exclude file: /home/user/.local/share/data//ownCloud//ocsync_exclude.conf
05-27 11:57:26:801 csync_init: Could not load /home/user/.local/share/data//ownCloud//ocsync_exclude.conf - 
05-27 11:57:26:801 csync_init: Journal: /home/user/test/.csync_journal.db
05-27 11:57:26:819 SSL-Warnings happened for url  "https://xxx.xxx.xxx.xxx/owncloud/status.php" 
05-27 11:57:26:819 Certs are already known and trusted, Warnings are not valid. 
05-27 11:57:26:828 SSL-Warnings happened for url  "https://xxx.xxx.xxx.xxx/owncloud/status.php" 
05-27 11:57:26:828 Certs are already known and trusted, Warnings are not valid. 
05-27 11:57:26:838 status.php returns:  "{"installed":"true","version":"5.0.6","versionstring":"5.0.5","edition":""}"   0  Reply:  QNetworkReplyImpl(0x26926c0) 
05-27 11:57:26:838 #-------# oC found on  "https://xxx.xxx.xxx.xxx/owncloud" 
05-27 11:57:26:847 status.php returns:  "{"installed":"true","version":"5.0.6","versionstring":"5.0.5","edition":""}"   0  Reply:  QNetworkReplyImpl(0x19fe590) 
05-27 11:57:26:849 csync_vio_init: capabilities: atomar copy support: yes
05-27 11:57:26:849 csync_vio_init: capabilities: post copy stat: no
05-27 11:57:26:849 csync_vio_init: capabilities: time sync required: no
05-27 11:57:26:849 csync_vio_init: capabilities: unix extensions: 0
05-27 11:57:26:849 csync_vio_init: capabilities: use send_file: yes
05-27 11:57:26:849 csync_init: Module does not need time synchronization.
05-27 11:57:26:849 #### Update start #################################################### >> 
05-27 11:57:26:849 csync_memstat_check: Memory: 1675208K total size, 76788K resident, 33716K shared
05-27 11:57:26:849 csync_ftw: Incoming read_from_db-Flag for /home/user/test: 0
05-27 11:57:26:850 csync_ftw: Uniq ID read from Database: file.dat -> <NULL>
05-27 11:57:26:850 csync_ftw: walk: /home/user/test/file.dat
05-27 11:57:26:850 csync_walker: file: /home/user/test/file.dat
05-27 11:57:26:850 _csync_detect_update: file: file.dat - hash 10098039351086293763, mtime: 1369648638
05-27 11:57:26:850 csync_statedb_get_stat_by_hash: No result record found for phash = 10098039351086293763
05-27 11:57:26:850 _csync_detect_update: file: file.dat, instruction: INSTRUCTION_NEW
05-27 11:57:26:850 csync_ftw: .csync_journal.db excluded
05-27 11:57:26:850 csync_ftw: Uniq ID read from Database: create-files.sh -> 51a3280a40cb0
05-27 11:57:26:850 csync_ftw: walk: /home/user/test/create-files.sh
05-27 11:57:26:850 csync_walker: file: /home/user/test/create-files.sh
05-27 11:57:26:850 _csync_detect_update: file: create-files.sh - hash 9221420809855778151, mtime: 1369646962
05-27 11:57:26:850 _csync_detect_update: time compare: 1369646962 <-> 1369646962, md5: 51a3280a40cb0 <-> 51a3280a40cb0
05-27 11:57:26:850 _csync_detect_update: file: create-files.sh, instruction: INSTRUCTION_NONE
05-27 11:57:26:850 csync_ftw: .csync_journal.db.ctmp excluded
05-27 11:57:26:850 csync_ftw: Closing walk for /home/user/test with read_from_db 0
05-27 11:57:26:850 csync_update: Update detection for local replica took 0,00 seconds walking 2 files.
05-27 11:57:26:850 csync_memstat_check: Memory: 1675208K total size, 76876K resident, 33716K shared
05-27 11:57:26:850 csync_ftw: Incoming read_from_db-Flag for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test: 0
05-27 11:57:26:850 csync_ftw: Checking for read from db for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test: 0
05-27 11:57:26:850 oc_module: opendir method called on ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test
05-27 11:57:26:850 oc_module: * scheme ownclouds
05-27 11:57:26:850 oc_module: * host xxx.xxx.xxx.xxx
05-27 11:57:26:850 oc_module: * port 0
05-27 11:57:26:850 oc_module: * path /owncloud/remote.php/webdav/test
05-27 11:57:26:850 oc_module: * user 
05-27 11:57:26:851 oc_module: ne_sock_init: 0
05-27 11:57:26:900 oc_module: No proxy configured.
05-27 11:57:26:985 oc_module: Call the csync callback for SSL problems
05-27 11:57:26:985 SSL Fingerprint from neon:  "f8:6f:47:41:49:ec:cc:5a:33:fe:7a:35:fd:dc:a9:41:f0:e7:d5:49"  compared to verified:  "f8:6f:47:41:49:ec:cc:5a:33:fe:7a:35:fd:dc:a9:41:f0:e7:d5:49" 
05-27 11:57:26:985 oc_module: ## VERIFY_SSL CERT: 0
05-27 11:57:27:015 oc_module:  Set-Cookie found: 50d6f812e5283=4og6qpe6sf5f1thlqchvr0oup4; path=/; HttpOnly
05-27 11:57:27:015 oc_module: ----> Session-key: 50d6f812e5283=4og6qpe6sf5f1thlqchvr0oup4
05-27 11:57:27:015 oc_module: Authentication required 
05-27 11:57:27:015 oc_module: Call the csync callback for ownCloud
05-27 11:57:27:092 oc_module: Simple propfind result code 207.
05-27 11:57:27:092 oc_module: Server Date from HTTP header value: Mon, 27 May 2013 09:57:27 GMT
05-27 11:57:27:092 oc_module: The first time_delta is 0
05-27 11:57:27:092 oc_module: opendir returning handle 0x7fb65002b540
05-27 11:57:27:092 oc_module:   :> Subtracting 0 from modtime 1369646963
05-27 11:57:27:092 oc_module: owncloud_stat ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/create-files.sh called
05-27 11:57:27:092 csync_ftw: walk: ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/create-files.sh
05-27 11:57:27:092 csync_walker: file: ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/create-files.sh
05-27 11:57:27:092 _csync_detect_update: file: create-files.sh - hash 9221420809855778151, mtime: 1369646963
05-27 11:57:27:092 _csync_detect_update: time compare: 1369646963 <-> 1369646962, md5: 51a3280a40cb0 <-> 51a3280a40cb0
05-27 11:57:27:092 _csync_detect_update: file: create-files.sh, instruction: INSTRUCTION_NONE
05-27 11:57:27:092 oc_module: Skipping target resource.
05-27 11:57:27:093 oc_module: closedir method called 0x7fb65002b540!
05-27 11:57:27:093 csync_ftw: Closing walk for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test with read_from_db 0
05-27 11:57:27:093 csync_update: Update detection for remote replica took 0,24 seconds walking 1 files.
05-27 11:57:27:093 csync_memstat_check: Memory: 1677344K total size, 79880K resident, 33764K shared
05-27 11:57:27:093 <<#### Update end ########################################################### 
05-27 11:57:27:093 _csync_merge_algorithm_visitor: INSTRUCTION_NONE     file: create-files.sh
05-27 11:57:27:093 _csync_merge_algorithm_visitor: INSTRUCTION_NEW      file: file.dat
05-27 11:57:27:093 csync_reconcile: Reconciliation for local replica took 0,00 seconds visiting 2 files.
05-27 11:57:27:093 _csync_merge_algorithm_visitor: INSTRUCTION_NONE     file: create-files.sh
05-27 11:57:27:093 csync_reconcile: Reconciliation for remote replica took 0,00 seconds visiting 1 files.
05-27 11:57:27:093 _csync_push_file: Remote repository atomar push enabled for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file.dat (0).
05-27 11:57:27:093 oc_module: => open called for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file.dat
05-27 11:57:27:093 oc_module: Stating directory ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test
05-27 11:57:27:093 oc_module: owncloud_stat ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test called
05-27 11:57:27:093 oc_module: => Errno after fetch resource list for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test: 0
05-27 11:57:27:093 oc_module: Working on file test
05-27 11:57:27:093 oc_module:   :> Subtracting 0 from modtime 1369648321
05-27 11:57:27:093 oc_module: STAT result from propfind: test, mtime: 1369648321
05-27 11:57:27:093 oc_module: Directory of file to open exists.
05-27 11:57:27:093 oc_module: PUT request on /owncloud/remote.php/webdav/test/file.dat!
05-27 11:57:27:093 oc_module: Sendfile handling request type PUT.
05-27 11:57:27:093 oc_module: Put file size: 104857600, variable sizeof: 8
05-27 11:57:27:099     * csync thread started 
05-27 11:57:27:099 ==> load folder icon  "owncloud-framed" 
05-27 11:57:27:099 Returning configured owncloud url:  "https://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/" 
05-27 11:57:27:099 Check status.php from statusdialog. 
05-27 11:57:27:099 Get Request to  "status.php" 
05-27 11:57:27:099 Returning configured owncloud url:  "https://xxx.xxx.xxx.xxx/owncloud/" 
05-27 11:57:27:099 Returning configured owncloud url:  "https://xxx.xxx.xxx.xxx/owncloud/" 
05-27 11:57:27:099 Setting up host header:  "xxx.xxx.xxx.xxx" 
05-27 11:57:27:099 Folder in overallStatus Message:  Mirall::ownCloudFolder(0x1bd43b0)  with name  "test" 
05-27 11:57:27:099 Sync state changed for folder  "test" :  "Sync Running" 
05-27 11:57:27:117 status.php returns:  "{"installed":"true","version":"5.0.6","versionstring":"5.0.5","edition":""}"   0  Reply:  QNetworkReplyImpl(0x28ffd70) 
05-27 11:57:27:117 #-------# oC found on  "https://xxx.xxx.xxx.xxx/owncloud" 
05-27 11:57:29:870 oc_module: http request all cool, result code 201
05-27 11:57:29:870 oc_module: Add a time delta to modtime 1369648638: 0
05-27 11:57:29:870 oc_module: Setting LastModified of /owncloud/remote.php/webdav/test/file.dat to 1369648638
05-27 11:57:30:596 oc_module: owncloud_stat ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file.dat called
05-27 11:57:31:417 oc_module: Simple propfind result code 207.
05-27 11:57:31:417 oc_module: Server Date from HTTP header value: Mon, 27 May 2013 09:57:31 GMT
05-27 11:57:31:417 oc_module: Ok: Time delta remained (almost) the same: 0.
05-27 11:57:31:417 oc_module: => Errno after fetch resource list for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file.dat: 0
05-27 11:57:31:417 oc_module: Working on file file.dat
05-27 11:57:31:417 oc_module:   :> Subtracting 0 from modtime 1369648638
05-27 11:57:31:417 oc_module: STAT result from propfind: file.dat, mtime: 1369648638
05-27 11:57:31:417 oc_module: Get file ID for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file.dat: 51a32e0ae27a5
05-27 11:57:31:417 _get_md5: MD5 for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file.dat: 51a32e0ae27a5
05-27 11:57:31:417 _csync_push_file: FINAL MD5: 51a32e0ae27a5
05-27 11:57:31:417 _csync_push_file: PUSHED  file: ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file.dat
05-27 11:57:31:417 _store_id_update: SYNCED remember  dir: file.dat
05-27 11:57:31:417 csync_propagate: Propagation for local replica took 4,32 seconds visiting 2 files.
05-27 11:57:31:417 csync_propagate: Propagation for remote replica took 0,00 seconds visiting 1 files.
05-27 11:57:31:417 csync_correct_id: correct ID on dir: .
05-27 11:57:31:417 csync_propagate: Correct Id took. 0,00 seconds 
05-27 11:57:31:417 void Mirall::CSyncThread::startSync() Sync finished 
05-27 11:57:31:421 csync_statedb_query: sqlite_step error: disk I/O error - on query: DROP TABLE IF EXISTS metadata;
05-27 11:57:31:421 csync_statedb_query: sqlite_step error: disk I/O error - on query: DROP TABLE IF EXISTS version;
05-27 11:57:31:422 csync_statedb_query: sqlite_step error: file is encrypted or is not a database - on query: CREATE TABLE IF NOT EXISTS metadata(phash INTEGER(8),pathlen INTEGER,path VARCHAR(4096),inode INTEGER,uid INTEGER,gid INTEGER,mode INTEGER,modtime INTEGER(8),type INTEGER,md5 VARCHAR(32),PRIMARY KEY(phash));
05-27 11:57:31:422 csync_statedb_query: sqlite3_compile error: index metadata_phash already exists - on query CREATE INDEX metadata_phash ON metadata(phash);
05-27 11:57:31:422 csync_destroy: Unable to write statedb: 
05-27 11:57:31:422 csync_lock_remove: Removing lock file: /home/user/.local/share/data//ownCloud//lock
05-27 11:57:31:422 CSync run took  4622  Milliseconds 
05-27 11:57:31:435 -> CSync Finished slot with error  false 
05-27 11:57:31:435 Starting Event logging again in  2000  milliseconds 
05-27 11:57:31:435 OO folder slotSyncFinished: result:  4  local:  false 
05-27 11:57:31:435 ==> load folder icon  "owncloud-framed" 
05-27 11:57:31:435 Returning configured owncloud url:  "https://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/" 
05-27 11:57:31:435 Check status.php from statusdialog. 
05-27 11:57:31:435 Get Request to  "status.php" 
05-27 11:57:31:435 Returning configured owncloud url:  "https://xxx.xxx.xxx.xxx/owncloud/" 
05-27 11:57:31:435 Returning configured owncloud url:  "https://xxx.xxx.xxx.xxx/owncloud/" 
05-27 11:57:31:436 Setting up host header:  "xxx.xxx.xxx.xxx" 
05-27 11:57:31:436 Folder in overallStatus Message:  Mirall::ownCloudFolder(0x1bd43b0)  with name  "test" 
05-27 11:57:31:436 Sync state changed for folder  "test" :  "Success" 
05-27 11:57:31:436 *  "test" Poll timer enabled with  30393 milliseconds 
05-27 11:57:31:436 <===================================== sync finished for  "test"

Hundred files of 1 MB (oC 5.0.5)

Upload-time (Csync run): 1777348 ms (29,622 minutes)

05-27 10:52:10:357 >===================================== sync started for  "test" 
05-27 10:52:10:357 ==> load folder icon  "owncloud-framed" 
05-27 10:52:10:357 void Mirall::CSyncThread::startSync() Sync started 
05-27 10:52:10:357 starting to sync  QThread(0x174f630) QThread(0x1a42a70) 
05-27 10:52:10:357 Returning configured owncloud url:  "https://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/" 
05-27 10:52:10:358 Check status.php from statusdialog. 
05-27 10:52:10:358 Get Request to  "status.php" 
05-27 10:52:10:358 Returning configured owncloud url:  "https://xxx.xxx.xxx.xxx/owncloud/" 
05-27 10:52:10:358 Returning configured owncloud url:  "https://xxx.xxx.xxx.xxx/owncloud/" 
05-27 10:52:10:358 Setting up host header:  "xxx.xxx.xxx.xxx" 
05-27 10:52:10:358 folder is sync enabled:  true 
05-27 10:52:10:358   ==> returning exclude file path:  "/etc/ownCloud/sync-exclude.lst" 
05-27 10:52:10:361 ==== added CSync exclude List:  "/etc/ownCloud/sync-exclude.lst" 
05-27 10:52:10:361 csync_lock: Creating lock file: /home/user/.local/share/data//ownCloud//lock
05-27 10:52:10:361 _csync_lock_create: XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX
05-27 10:52:10:361 _csync_lock_create: Create temporary lock file: /home/user/.local/share/data//ownCloud/tmp_lock_XXXXXX
05-27 10:52:10:361 _csync_lock_create: Write pid (7675) to temporary lock file: /home/user/.local/share/data//ownCloud/tmp_lock_iZ7suf
05-27 10:52:10:361 _csync_lock_create: Create a hardlink from /home/user/.local/share/data//ownCloud/tmp_lock_iZ7suf to /home/user/.local/share/data//ownCloud//lock.
05-27 10:52:10:361 csync_config_load: Config: max_depth = 50
05-27 10:52:10:361 csync_config_load: Config: max_time_difference = 10
05-27 10:52:10:361 csync_config_load: Config: sync_symbolic_links = 0
05-27 10:52:10:361 csync_config_load: Config: timeout = 0
05-27 10:52:10:361 csync_exclude_load: Loading exclude file: /usr/etc/ocsync/ocsync_exclude.conf
05-27 10:52:10:361 csync_exclude_load: Adding entry: .beagle
[...]
05-27 10:52:10:361 csync_exclude_load: Loading exclude file: /home/user/.local/share/data//ownCloud//ocsync_exclude.conf
05-27 10:52:10:361 csync_init: Could not load /home/user/.local/share/data//ownCloud//ocsync_exclude.conf - 
05-27 10:52:10:361 csync_init: Journal: /home/user/test/.csync_journal.db
05-27 10:52:10:377 SSL-Warnings happened for url  "https://xxx.xxx.xxx.xxx/owncloud/status.php" 
05-27 10:52:10:377 Certs are already known and trusted, Warnings are not valid. 
05-27 10:52:10:381 SSL-Warnings happened for url  "https://xxx.xxx.xxx.xxx/owncloud/status.php" 
05-27 10:52:10:381 Certs are already known and trusted, Warnings are not valid. 
05-27 10:52:10:394 csync_vio_init: capabilities: atomar copy support: yes
05-27 10:52:10:394 csync_vio_init: capabilities: post copy stat: no
05-27 10:52:10:394 csync_vio_init: capabilities: time sync required: no
05-27 10:52:10:394 csync_vio_init: capabilities: unix extensions: 0
05-27 10:52:10:394 csync_vio_init: capabilities: use send_file: yes
05-27 10:52:10:394 csync_init: Module does not need time synchronization.
05-27 10:52:10:394 #### Update start #################################################### >> 
05-27 10:52:10:394 csync_memstat_check: Memory: 1196460K total size, 53352K resident, 33512K shared
05-27 10:52:10:394 csync_ftw: Incoming read_from_db-Flag for /home/user/test: 0
05-27 10:52:10:394 csync_ftw: Uniq ID read from Database: file-36.dat -> <NULL>
05-27 10:52:10:394 csync_ftw: walk: /home/user/test/file-36.dat
05-27 10:52:10:394 csync_walker: file: /home/user/test/file-36.dat
05-27 10:52:10:394 _csync_detect_update: file: file-36.dat - hash 3432768615381042473, mtime: 1369644724
05-27 10:52:10:394 csync_statedb_get_stat_by_hash: No result record found for phash = 3432768615381042473
05-27 10:52:10:394 _csync_detect_update: file: file-36.dat, instruction: INSTRUCTION_NEW
05-27 10:52:10:394 csync_ftw: Uniq ID read from Database: file-2.dat -> <NULL>
05-27 10:52:10:394 csync_ftw: walk: /home/user/test/file-2.dat
05-27 10:52:10:394 csync_walker: file: /home/user/test/file-2.dat
05-27 10:52:10:394 _csync_detect_update: file: file-2.dat - hash 6367102774639863992, mtime: 1369644724
05-27 10:52:10:395 csync_statedb_get_stat_by_hash: No result record found for phash = 6367102774639863992
05-27 10:52:10:395 _csync_detect_update: file: file-2.dat, instruction: INSTRUCTION_NEW

[...]

05-27 10:52:10:417 csync_ftw: Uniq ID read from Database: file-51.dat -> <NULL>
05-27 10:52:10:417 csync_ftw: walk: /home/user/test/file-51.dat
05-27 10:52:10:417 csync_walker: file: /home/user/test/file-51.dat
05-27 10:52:10:417 _csync_detect_update: file: file-51.dat - hash 1860622115009790842, mtime: 1369644724
05-27 10:52:10:417 csync_statedb_get_stat_by_hash: No result record found for phash = 1860622115009790842
05-27 10:52:10:417 _csync_detect_update: file: file-51.dat, instruction: INSTRUCTION_NEW
05-27 10:52:10:417 csync_ftw: Closing walk for /home/user/test with read_from_db 0
05-27 10:52:10:417 csync_update: Update detection for local replica took 0,02 seconds walking 103 files.
05-27 10:52:10:417 csync_memstat_check: Memory: 1196460K total size, 53356K resident, 33512K shared
05-27 10:52:10:417 csync_ftw: Incoming read_from_db-Flag for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test: 0
05-27 10:52:10:417 csync_ftw: Checking for read from db for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test: 0
05-27 10:52:10:417 oc_module: opendir method called on ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test
05-27 10:52:10:417 oc_module: * scheme ownclouds
05-27 10:52:10:417 oc_module: * host xxx.xxx.xxx.xxx
05-27 10:52:10:417 oc_module: * port 0
05-27 10:52:10:417 oc_module: * path /owncloud/remote.php/webdav/test
05-27 10:52:10:417 oc_module: * user 
05-27 10:52:10:418 oc_module: ne_sock_init: 0
05-27 10:52:10:427 status.php returns:  "{"installed":"true","version":"5.0.6","versionstring":"5.0.5","edition":""}"   0  Reply:  QNetworkReplyImpl(0x1f425e0) 
05-27 10:52:10:427 #-------# oC found on  "https://xxx.xxx.xxx.xxx/owncloud" 
05-27 10:52:10:459 oc_module: No proxy configured.
05-27 10:52:10:481 status.php returns:  "{"installed":"true","version":"5.0.6","versionstring":"5.0.5","edition":""}"   0  Reply:  QNetworkReplyImpl(0x1f71230) 
05-27 10:52:10:534 oc_module: Call the csync callback for SSL problems
05-27 10:52:10:534 SSL Fingerprint from neon:  "f8:6f:47:41:49:ec:cc:5a:33:fe:7a:35:fd:dc:a9:41:f0:e7:d5:49"  compared to verified:  "f8:6f:47:41:49:ec:cc:5a:33:fe:7a:35:fd:dc:a9:41:f0:e7:d5:49" 
05-27 10:52:10:534 oc_module: ## VERIFY_SSL CERT: 0
05-27 10:52:10:563 oc_module:  Set-Cookie found: 50d6f812e5283=uga4s7ipms4vimjoa888tghhg1; path=/; HttpOnly
05-27 10:52:10:563 oc_module: ----> Session-key: 50d6f812e5283=uga4s7ipms4vimjoa888tghhg1
05-27 10:52:10:563 oc_module: Authentication required 
05-27 10:52:10:563 oc_module: Call the csync callback for ownCloud
05-27 10:52:10:638 oc_module: Simple propfind result code 207.
05-27 10:52:10:638 oc_module: Server Date from HTTP header value: Mon, 27 May 2013 08:52:11 GMT
05-27 10:52:10:638 oc_module: The first time_delta is 1
05-27 10:52:10:638 oc_module: opendir returning handle 0x7fb678085740
05-27 10:52:10:638 oc_module:   :> Subtracting 1 from modtime 1369644605
05-27 10:52:10:638 oc_module: owncloud_stat ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file.dat called
05-27 10:52:10:638 csync_ftw: walk: ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file.dat
05-27 10:52:10:638 csync_walker: file: ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file.dat
05-27 10:52:10:638 _csync_detect_update: file: file.dat - hash 10098039351086293763, mtime: 1369644604
05-27 10:52:10:638 csync_statedb_get_stat_by_hash: No result record found for phash = 10098039351086293763
05-27 10:52:10:638 _csync_detect_update: file: file.dat, instruction: INSTRUCTION_NEW
05-27 10:52:10:638 oc_module:   :> Subtracting 1 from modtime 1369643663
05-27 10:52:10:638 oc_module: owncloud_stat ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file.bin called
05-27 10:52:10:638 csync_ftw: walk: ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file.bin
05-27 10:52:10:638 csync_walker: file: ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file.bin
05-27 10:52:10:638 _csync_detect_update: file: file.bin - hash 15410276376053074958, mtime: 1369643662
05-27 10:52:10:639 _csync_detect_update: time compare: 1369643662 <-> 1369643662, md5: 51a31c2b3de53 <-> 51a31c2b3de53
05-27 10:52:10:639 _csync_detect_update: file: file.bin, instruction: INSTRUCTION_NONE
05-27 10:52:10:639 oc_module:   :> Subtracting 1 from modtime 1369644494
05-27 10:52:10:639 oc_module: owncloud_stat ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/create-files.sh called
05-27 10:52:10:639 csync_ftw: walk: ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/create-files.sh
05-27 10:52:10:639 csync_walker: file: ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/create-files.sh
05-27 10:52:10:639 _csync_detect_update: file: create-files.sh - hash 9221420809855778151, mtime: 1369644493
05-27 10:52:10:639 csync_statedb_get_stat_by_hash: No result record found for phash = 9221420809855778151
05-27 10:52:10:639 _csync_detect_update: file: create-files.sh, instruction: INSTRUCTION_NEW
05-27 10:52:10:639 oc_module: Skipping target resource.
05-27 10:52:10:639 oc_module: closedir method called 0x7fb678085740!
05-27 10:52:10:639 csync_ftw: Closing walk for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test with read_from_db 0
05-27 10:52:10:639 csync_update: Update detection for remote replica took 0,22 seconds walking 3 files.
05-27 10:52:10:639 csync_memstat_check: Memory: 1198588K total size, 56088K resident, 33560K shared
05-27 10:52:10:639 <<#### Update end ########################################################### 
05-27 10:52:10:639 _csync_merge_algorithm_visitor: INSTRUCTION_NEW      file: file-67.dat
05-27 10:52:10:639 _csync_merge_algorithm_visitor: INSTRUCTION_NEW      file: file-43.dat

[...]

05-27 10:52:10:641 _csync_merge_algorithm_visitor: INSTRUCTION_NEW      file: file-6.dat
05-27 10:52:10:641 _csync_merge_algorithm_visitor: INSTRUCTION_NEW      file: file-66.dat
05-27 10:52:10:641 csync_reconcile: Reconciliation for local replica took 0,00 seconds visiting 103 files.
05-27 10:52:10:641 _csync_merge_algorithm_visitor: INSTRUCTION_NONE     file: create-files.sh
05-27 10:52:10:641 _csync_merge_algorithm_visitor: INSTRUCTION_NONE     file: file.dat
05-27 10:52:10:641 _csync_merge_algorithm_visitor: INSTRUCTION_NONE     file: file.bin
05-27 10:52:10:641 csync_reconcile: Reconciliation for remote replica took 0,00 seconds visiting 3 files.
05-27 10:52:10:641 _csync_push_file: Remote repository atomar push enabled for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file-67.dat (0).
05-27 10:52:10:641 oc_module: => open called for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file-67.dat
05-27 10:52:10:641 oc_module: Stating directory ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test
05-27 10:52:10:641 oc_module: owncloud_stat ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test called
05-27 10:52:10:641 oc_module: => Errno after fetch resource list for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test: 0
05-27 10:52:10:641 oc_module: Working on file test
05-27 10:52:10:641 oc_module:   :> Subtracting 1 from modtime 1369644650
05-27 10:52:10:641 oc_module: STAT result from propfind: test, mtime: 1369644649
05-27 10:52:10:641 oc_module: Directory of file to open exists.
05-27 10:52:10:641 oc_module: PUT request on /owncloud/remote.php/webdav/test/file-67.dat!
05-27 10:52:10:641 oc_module: Sendfile handling request type PUT.
05-27 10:52:10:641 oc_module: Put file size: 1048576, variable sizeof: 8
05-27 10:52:10:676     * csync thread started 
05-27 10:52:10:676 ==> load folder icon  "owncloud-framed" 
05-27 10:52:10:676 Returning configured owncloud url:  "https://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/" 
05-27 10:52:10:676 Check status.php from statusdialog. 
05-27 10:52:10:676 Get Request to  "status.php" 
05-27 10:52:10:676 Returning configured owncloud url:  "https://xxx.xxx.xxx.xxx/owncloud/" 
05-27 10:52:10:676 Returning configured owncloud url:  "https://xxx.xxx.xxx.xxx/owncloud/" 
05-27 10:52:10:676 Setting up host header:  "xxx.xxx.xxx.xxx" 
05-27 10:52:10:676 Folder in overallStatus Message:  Mirall::ownCloudFolder(0x1bd43b0)  with name  "test" 
05-27 10:52:10:676 Sync state changed for folder  "test" :  "Sync Running" 
05-27 10:52:10:690 status.php returns:  "{"installed":"true","version":"5.0.6","versionstring":"5.0.5","edition":""}"   0  Reply:  QNetworkReplyImpl(0x2131bd0) 
05-27 10:52:10:690 #-------# oC found on  "https://xxx.xxx.xxx.xxx/owncloud" 
05-27 10:52:12:793 oc_module: http request all cool, result code 201
05-27 10:52:12:794 oc_module: Add a time delta to modtime 1369644724: 1
05-27 10:52:12:794 oc_module: Setting LastModified of /owncloud/remote.php/webdav/test/file-67.dat to 1369644725
05-27 10:52:14:054 oc_module: owncloud_stat ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file-67.dat called
05-27 10:52:15:411 oc_module: Simple propfind result code 207.
05-27 10:52:15:411 oc_module: Server Date from HTTP header value: Mon, 27 May 2013 08:52:14 GMT
05-27 10:52:15:411 oc_module: Ok: Time delta remained (almost) the same: -1.
05-27 10:52:15:411 oc_module: => Errno after fetch resource list for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file-67.dat: 0
05-27 10:52:15:411 oc_module: Working on file file-67.dat
05-27 10:52:15:411 oc_module:   :> Subtracting -1 from modtime 1369644725
05-27 10:52:15:411 oc_module: STAT result from propfind: file-67.dat, mtime: 1369644726
05-27 10:52:15:411 oc_module: Get file ID for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file-67.dat: 51a31ebdb2f4d
05-27 10:52:15:411 _get_md5: MD5 for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file-67.dat: 51a31ebdb2f4d
05-27 10:52:15:411 _csync_push_file: FINAL MD5: 51a31ebdb2f4d
05-27 10:52:15:411 _csync_push_file: PUSHED  file: ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file-67.dat
05-27 10:52:15:411 _store_id_update: SYNCED remember  dir: file-67.dat
05-27 10:52:15:411 _csync_push_file: Remote repository atomar push enabled for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file-43.dat (0).
05-27 10:52:15:411 oc_module: => open called for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file-43.dat
05-27 10:52:15:411 oc_module: Stating directory ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test
05-27 10:52:15:411 oc_module: Dir ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test is there, we know it already.
05-27 10:52:15:411 oc_module: PUT request on /owncloud/remote.php/webdav/test/file-43.dat!
05-27 10:52:15:411 oc_module: Sendfile handling request type PUT.
05-27 10:52:15:411 oc_module: Put file size: 1048576, variable sizeof: 8
05-27 10:52:17:444 oc_module: http request all cool, result code 201
05-27 10:52:17:444 oc_module: Add a time delta to modtime 1369644724: 18446744073709551615
05-27 10:52:17:444 oc_module: Setting LastModified of /owncloud/remote.php/webdav/test/file-43.dat to 1369644723
05-27 10:52:18:576 oc_module: owncloud_stat ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file-43.dat called
05-27 10:52:19:730 oc_module: Simple propfind result code 207.
05-27 10:52:19:730 oc_module: Server Date from HTTP header value: Mon, 27 May 2013 08:52:19 GMT
05-27 10:52:19:730 oc_module: Ok: Time delta remained (almost) the same: 0.
05-27 10:52:19:731 oc_module: => Errno after fetch resource list for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file-43.dat: 0
05-27 10:52:19:731 oc_module: Working on file file-43.dat
05-27 10:52:19:731 oc_module:   :> Subtracting 0 from modtime 1369644723
05-27 10:52:19:731 oc_module: STAT result from propfind: file-43.dat, mtime: 1369644723
05-27 10:52:19:731 oc_module: Get file ID for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file-43.dat: 51a31ec25dbf2
05-27 10:52:19:731 _get_md5: MD5 for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file-43.dat: 51a31ec25dbf2
05-27 10:52:19:731 _csync_push_file: FINAL MD5: 51a31ec25dbf2
05-27 10:52:19:731 _csync_push_file: PUSHED  file: ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file-43.dat
05-27 10:52:19:731 _store_id_update: SYNCED remember  dir: file-43.dat

[...]

05-27 11:21:39:801 _csync_push_file: Remote repository atomar push enabled for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file-66.dat (0).
05-27 11:21:39:801 oc_module: => open called for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file-66.dat
05-27 11:21:39:801 oc_module: Stating directory ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test
05-27 11:21:39:801 oc_module: Dir ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test is there, we know it already.
05-27 11:21:39:801 oc_module: PUT request on /owncloud/remote.php/webdav/test/file-66.dat!
05-27 11:21:39:801 oc_module: Sendfile handling request type PUT.
05-27 11:21:39:801 oc_module: Put file size: 1048576, variable sizeof: 8
05-27 11:21:42:620 oc_module: http request all cool, result code 201
05-27 11:21:42:620 oc_module: Add a time delta to modtime 1369644724: 18446744073709551615
05-27 11:21:42:620 oc_module: Setting LastModified of /owncloud/remote.php/webdav/test/file-66.dat to 1369644723
05-27 11:21:43:844 oc_module: owncloud_stat ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file-66.dat called
05-27 11:21:46:534 oc_module: Simple propfind result code 207.
05-27 11:21:46:534 oc_module: Server Date from HTTP header value: Mon, 27 May 2013 09:21:44 GMT
05-27 11:21:46:534 oc_module: Ok: Time delta remained (almost) the same: -2.
05-27 11:21:46:534 oc_module: => Errno after fetch resource list for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file-66.dat: 0
05-27 11:21:46:534 oc_module: Working on file file-66.dat
05-27 11:21:46:534 oc_module:   :> Subtracting -2 from modtime 1369644723
05-27 11:21:46:534 oc_module: STAT result from propfind: file-66.dat, mtime: 1369644725
05-27 11:21:46:534 oc_module: Get file ID for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file-66.dat: 51a325a79574c
05-27 11:21:46:534 _get_md5: MD5 for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file-66.dat: 51a325a79574c
05-27 11:21:46:534 _csync_push_file: FINAL MD5: 51a325a79574c
05-27 11:21:46:534 _csync_push_file: PUSHED  file: ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file-66.dat
05-27 11:21:46:534 _store_id_update: SYNCED remember  dir: file-66.dat
05-27 11:21:46:534 csync_propagate: Propagation for local replica took 1775,89 seconds visiting 103 files.
05-27 11:21:46:534 csync_propagate: Propagation for remote replica took 0,00 seconds visiting 3 files.
05-27 11:21:46:534 csync_correct_id: correct ID on dir: .
05-27 11:21:46:534 csync_correct_id: correct ID on dir: .

[...]

05-27 11:21:46:536 csync_correct_id: correct ID on dir: .
05-27 11:21:46:536 csync_propagate: Correct Id took. 0,00 seconds 
05-27 11:21:46:536 void Mirall::CSyncThread::startSync() Sync finished 
05-27 11:21:47:533 _insert_metadata_visitor: SQL statement: INSERT INTO metadata_temp 
            (phash, pathlen, path, inode, uid, gid, mode, modtime, type, md5) VALUES 
            (124415436819000123, 11, file-67.dat, 5636271, 1000, 1000, 33188, 1369644724, 0, 51a31ebdb2f4d);
05-27 11:21:47:533 _insert_metadata_visitor: SQL statement: INSERT INTO metadata_temp 
            (phash, pathlen, path, inode, uid, gid, mode, modtime, type, md5) VALUES 
            (322974294914952274, 11, file-43.dat, 5636247, 1000, 1000, 33188, 1369644724, 0, 51a31ec25dbf2);

[...]

05-27 11:21:47:543 _insert_metadata_visitor: SQL statement: INSERT INTO metadata_temp 
            (phash, pathlen, path, inode, uid, gid, mode, modtime, type, md5) VALUES 
            (-80984399663678646, 11, file-66.dat, 5636270, 1000, 1000, 33188, 1369644724, 0, 51a325a79574c);
05-27 11:21:47:675 csync_destroy: Writing the statedb of 103 files to disk took 1,14 seconds
05-27 11:21:47:709 csync_lock_remove: Removing lock file: /home/user/.local/share/data//ownCloud//lock
05-27 11:21:47:709 CSync run took  1777348  Milliseconds 
05-27 11:21:47:710 -> CSync Finished slot with error  false 
05-27 11:21:47:710 Starting Event logging again in  2000  milliseconds 
05-27 11:21:47:710 OO folder slotSyncFinished: result:  4  local:  false 
05-27 11:21:47:710 ==> load folder icon  "owncloud-framed" 
05-27 11:21:47:710 Returning configured owncloud url:  "https://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/" 
05-27 11:21:47:710 Check status.php from statusdialog. 
05-27 11:21:47:710 Get Request to  "status.php" 
05-27 11:21:47:710 Returning configured owncloud url:  "https://xxx.xxx.xxx.xxx/owncloud/" 
05-27 11:21:47:711 Returning configured owncloud url:  "https://xxx.xxx.xxx.xxx/owncloud/" 
05-27 11:21:47:711 Setting up host header:  "xxx.xxx.xxx.xxx" 
05-27 11:21:47:711 Folder in overallStatus Message:  Mirall::ownCloudFolder(0x1bd43b0)  with name  "test" 
05-27 11:21:47:711 Sync state changed for folder  "test" :  "Success" 
05-27 11:21:47:711 *  "test" Poll timer enabled with  30393 milliseconds 
05-27 11:21:47:711 <===================================== sync finished for  "test"

Hundred files of 1 MB (oC 5.0.6)

Upload-time (Csync run): 735211 ms (12,253 minutes)

Hundred files of 1 KB (oC 5.0.5)

Upload-time (Csync run): 753323 ms (12,555 minutes)

05-27 11:34:17:355 >===================================== sync started for  "test" 
05-27 11:34:17:355 ==> load folder icon  "owncloud-framed" 
05-27 11:34:17:355 void Mirall::CSyncThread::startSync() Sync started 
05-27 11:34:17:355 starting to sync  QThread(0x174f630) QThread(0x22da810) 
05-27 11:34:17:355 Returning configured owncloud url:  "https://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/" 
05-27 11:34:17:355   ==> returning exclude file path:  "/etc/ownCloud/sync-exclude.lst" 
05-27 11:34:17:355 ==== added CSync exclude List:  "/etc/ownCloud/sync-exclude.lst" 
05-27 11:34:17:355 Check status.php from statusdialog. 
05-27 11:34:17:355 Get Request to  "status.php" 
05-27 11:34:17:355 Returning configured owncloud url:  "https://xxx.xxx.xxx.xxx/owncloud/" 
05-27 11:34:17:355 Returning configured owncloud url:  "https://xxx.xxx.xxx.xxx/owncloud/" 
05-27 11:34:17:355 Setting up host header:  "xxx.xxx.xxx.xxx" 
05-27 11:34:17:355 folder is sync enabled:  true 
05-27 11:34:17:355 csync_lock: Creating lock file: /home/user/.local/share/data//ownCloud//lock
05-27 11:34:17:355 _csync_lock_create: XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX
05-27 11:34:17:355 _csync_lock_create: Create temporary lock file: /home/user/.local/share/data//ownCloud/tmp_lock_XXXXXX
05-27 11:34:17:356 _csync_lock_create: Write pid (7675) to temporary lock file: /home/user/.local/share/data//ownCloud/tmp_lock_E7brtg
05-27 11:34:17:356 _csync_lock_create: Create a hardlink from /home/user/.local/share/data//ownCloud/tmp_lock_E7brtg to /home/user/.local/share/data//ownCloud//lock.
05-27 11:34:17:356 csync_config_load: Config: max_depth = 50
05-27 11:34:17:356 csync_config_load: Config: max_time_difference = 10
05-27 11:34:17:356 csync_config_load: Config: sync_symbolic_links = 0
05-27 11:34:17:356 csync_config_load: Config: timeout = 0
05-27 11:34:17:356 csync_exclude_load: Loading exclude file: /usr/etc/ocsync/ocsync_exclude.conf
05-27 11:34:17:356 csync_exclude_load: Adding entry: .beagle
[...]
05-27 11:34:17:356 csync_exclude_load: Loading exclude file: /home/user/.local/share/data//ownCloud//ocsync_exclude.conf
05-27 11:34:17:356 csync_init: Could not load /home/user/.local/share/data//ownCloud//ocsync_exclude.conf - 
05-27 11:34:17:356 csync_init: Journal: /home/user/test/.csync_journal.db
05-27 11:34:17:365 QSocketNotifier: Invalid socket 25 and type 'Read', disabling...
05-27 11:34:17:371 ownCloudInfo Network Error:  6 
05-27 11:34:17:372 status.php returns:  ""   6  Reply:  QNetworkReplyImpl(0x25bef20) 
05-27 11:34:17:372 No proper answer on  "https://xxx.xxx.xxx.xxx/owncloud/status.php" 
05-27 11:34:17:372 SSL-Warnings happened for url  "https://xxx.xxx.xxx.xxx/owncloud/status.php" 
05-27 11:34:17:372 Certs are already known and trusted, Warnings are not valid. 
05-27 11:34:17:388 status.php returns:  "{"installed":"true","version":"5.0.6","versionstring":"5.0.5","edition":""}"   0  Reply:  QNetworkReplyImpl(0x19d89e0) 
05-27 11:34:17:403 csync_vio_init: capabilities: atomar copy support: yes
05-27 11:34:17:403 csync_vio_init: capabilities: post copy stat: no
05-27 11:34:17:403 csync_vio_init: capabilities: time sync required: no
05-27 11:34:17:403 csync_vio_init: capabilities: unix extensions: 0
05-27 11:34:17:403 csync_vio_init: capabilities: use send_file: yes
05-27 11:34:17:403 csync_init: Module does not need time synchronization.
05-27 11:34:17:403 #### Update start #################################################### >> 
05-27 11:34:17:403 csync_memstat_check: Memory: 1407848K total size, 68388K resident, 33708K shared
05-27 11:34:17:403 csync_ftw: Incoming read_from_db-Flag for /home/user/test: 0
05-27 11:34:17:403 csync_ftw: Uniq ID read from Database: file-36.dat -> <NULL>
05-27 11:34:17:403 csync_ftw: walk: /home/user/test/file-36.dat
05-27 11:34:17:403 csync_walker: file: /home/user/test/file-36.dat
05-27 11:34:17:403 _csync_detect_update: file: file-36.dat - hash 3432768615381042473, mtime: 1369647250
05-27 11:34:17:403 csync_statedb_get_stat_by_hash: No result record found for phash = 3432768615381042473
05-27 11:34:17:403 _csync_detect_update: file: file-36.dat, instruction: INSTRUCTION_NEW
05-27 11:34:17:403 csync_ftw: Uniq ID read from Database: file-2.dat -> <NULL>
05-27 11:34:17:403 csync_ftw: walk: /home/user/test/file-2.dat
05-27 11:34:17:403 csync_walker: file: /home/user/test/file-2.dat
05-27 11:34:17:403 _csync_detect_update: file: file-2.dat - hash 6367102774639863992, mtime: 1369647250
05-27 11:34:17:403 csync_statedb_get_stat_by_hash: No result record found for phash = 6367102774639863992
05-27 11:34:17:403 _csync_detect_update: file: file-2.dat, instruction: INSTRUCTION_NEW

[...]

05-27 11:34:17:419 csync_ftw: Uniq ID read from Database: file-51.dat -> <NULL>
05-27 11:34:17:419 csync_ftw: walk: /home/user/test/file-51.dat
05-27 11:34:17:419 csync_walker: file: /home/user/test/file-51.dat
05-27 11:34:17:419 _csync_detect_update: file: file-51.dat - hash 1860622115009790842, mtime: 1369647250
05-27 11:34:17:419 csync_statedb_get_stat_by_hash: No result record found for phash = 1860622115009790842
05-27 11:34:17:419 _csync_detect_update: file: file-51.dat, instruction: INSTRUCTION_NEW
05-27 11:34:17:420 csync_ftw: Closing walk for /home/user/test with read_from_db 0
05-27 11:34:17:420 csync_update: Update detection for local replica took 0,02 seconds walking 101 files.
05-27 11:34:17:420 csync_memstat_check: Memory: 1407856K total size, 68392K resident, 33708K shared
05-27 11:34:17:420 csync_ftw: Incoming read_from_db-Flag for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test: 0
05-27 11:34:17:420 csync_ftw: Checking for read from db for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test: 0
05-27 11:34:17:420 oc_module: opendir method called on ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test
05-27 11:34:17:420 oc_module: * scheme ownclouds
05-27 11:34:17:420 oc_module: * host xxx.xxx.xxx.xxx
05-27 11:34:17:420 oc_module: * port 0
05-27 11:34:17:420 oc_module: * path /owncloud/remote.php/webdav/test
05-27 11:34:17:420 oc_module: * user 
05-27 11:34:17:421 oc_module: ne_sock_init: 0
05-27 11:34:17:460 oc_module: No proxy configured.
05-27 11:34:17:533 oc_module: Call the csync callback for SSL problems
05-27 11:34:17:533 SSL Fingerprint from neon:  "f8:6f:47:41:49:ec:cc:5a:33:fe:7a:35:fd:dc:a9:41:f0:e7:d5:49"  compared to verified:  "f8:6f:47:41:49:ec:cc:5a:33:fe:7a:35:fd:dc:a9:41:f0:e7:d5:49" 
05-27 11:34:17:533 oc_module: ## VERIFY_SSL CERT: 0
05-27 11:34:17:564 oc_module:  Set-Cookie found: 50d6f812e5283=t2qmcv8ibv5i5ofdlishrnov84; path=/; HttpOnly
05-27 11:34:17:564 oc_module: ----> Session-key: 50d6f812e5283=t2qmcv8ibv5i5ofdlishrnov84
05-27 11:34:17:564 oc_module: Authentication required 
05-27 11:34:17:564 oc_module: Call the csync callback for ownCloud
05-27 11:34:17:637 oc_module: Simple propfind result code 207.
05-27 11:34:17:637 oc_module: Server Date from HTTP header value: Mon, 27 May 2013 09:34:18 GMT
05-27 11:34:17:637 oc_module: The first time_delta is 1
05-27 11:34:17:637 oc_module: opendir returning handle 0x7fb664061500
05-27 11:34:17:637 oc_module:   :> Subtracting 1 from modtime 1369646963
05-27 11:34:17:637 oc_module: owncloud_stat ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/create-files.sh called
05-27 11:34:17:637 csync_ftw: walk: ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/create-files.sh
05-27 11:34:17:637 csync_walker: file: ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/create-files.sh
05-27 11:34:17:637 _csync_detect_update: file: create-files.sh - hash 9221420809855778151, mtime: 1369646962
05-27 11:34:17:638 _csync_detect_update: time compare: 1369646962 <-> 1369646962, md5: 51a3280a40cb0 <-> 51a3280a40cb0
05-27 11:34:17:638 _csync_detect_update: file: create-files.sh, instruction: INSTRUCTION_NONE
05-27 11:34:17:638 oc_module: Skipping target resource.
05-27 11:34:17:638 oc_module: closedir method called 0x7fb664061500!
05-27 11:34:17:638 csync_ftw: Closing walk for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test with read_from_db 0
05-27 11:34:17:638 csync_update: Update detection for remote replica took 0,22 seconds walking 1 files.
05-27 11:34:17:638 csync_memstat_check: Memory: 1410032K total size, 71036K resident, 33756K shared
05-27 11:34:17:638 <<#### Update end ########################################################### 
05-27 11:34:17:638 _csync_merge_algorithm_visitor: INSTRUCTION_NEW      file: file-67.dat
05-27 11:34:17:638 _csync_merge_algorithm_visitor: INSTRUCTION_NEW      file: file-43.dat

[...]

05-27 11:34:17:639 _csync_merge_algorithm_visitor: INSTRUCTION_NEW      file: file-66.dat
05-27 11:34:17:639 csync_reconcile: Reconciliation for local replica took 0,00 seconds visiting 101 files.
05-27 11:34:17:639 _csync_merge_algorithm_visitor: INSTRUCTION_NONE     file: create-files.sh
05-27 11:34:17:639 csync_reconcile: Reconciliation for remote replica took 0,00 seconds visiting 1 files.
05-27 11:34:17:640 _csync_push_file: Remote repository atomar push enabled for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file-67.dat (0).
05-27 11:34:17:640 oc_module: => open called for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file-67.dat
05-27 11:34:17:640 oc_module: Stating directory ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test
05-27 11:34:17:640 oc_module: owncloud_stat ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test called
05-27 11:34:17:640 oc_module: => Errno after fetch resource list for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test: 0
05-27 11:34:17:640 oc_module: Working on file test
05-27 11:34:17:640 oc_module:   :> Subtracting 1 from modtime 1369647199
05-27 11:34:17:640 oc_module: STAT result from propfind: test, mtime: 1369647198
05-27 11:34:17:640 oc_module: Directory of file to open exists.
05-27 11:34:17:640 oc_module: PUT request on /owncloud/remote.php/webdav/test/file-67.dat!
05-27 11:34:17:640 oc_module: Sendfile handling request type PUT.
05-27 11:34:17:640 oc_module: Put file size: 1024, variable sizeof: 8
05-27 11:34:17:671     * csync thread started 
05-27 11:34:17:671 ==> load folder icon  "owncloud-framed" 
05-27 11:34:17:671 Returning configured owncloud url:  "https://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/" 
05-27 11:34:17:671 Check status.php from statusdialog. 
05-27 11:34:17:671 Get Request to  "status.php" 
05-27 11:34:17:671 Returning configured owncloud url:  "https://xxx.xxx.xxx.xxx/owncloud/" 
05-27 11:34:17:671 Returning configured owncloud url:  "https://xxx.xxx.xxx.xxx/owncloud/" 
05-27 11:34:17:671 Setting up host header:  "xxx.xxx.xxx.xxx" 
05-27 11:34:17:671 Folder in overallStatus Message:  Mirall::ownCloudFolder(0x1bd43b0)  with name  "test" 
05-27 11:34:17:672 Sync state changed for folder  "test" :  "Sync Running" 
05-27 11:34:17:685 status.php returns:  "{"installed":"true","version":"5.0.6","versionstring":"5.0.5","edition":""}"   0  Reply:  QNetworkReplyImpl(0x2914700) 
05-27 11:34:17:685 #-------# oC found on  "https://xxx.xxx.xxx.xxx/owncloud" 
05-27 11:34:19:005 oc_module: http request all cool, result code 201
05-27 11:34:19:005 oc_module: Add a time delta to modtime 1369647250: 1
05-27 11:34:19:005 oc_module: Setting LastModified of /owncloud/remote.php/webdav/test/file-67.dat to 1369647251
05-27 11:34:19:734 oc_module: owncloud_stat ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file-67.dat called
05-27 11:34:20:590 oc_module: Simple propfind result code 207.
05-27 11:34:20:590 oc_module: Server Date from HTTP header value: Mon, 27 May 2013 09:34:20 GMT
05-27 11:34:20:590 oc_module: Ok: Time delta remained (almost) the same: 0.
05-27 11:34:20:590 oc_module: => Errno after fetch resource list for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file-67.dat: 0
05-27 11:34:20:590 oc_module: Working on file file-67.dat
05-27 11:34:20:590 oc_module:   :> Subtracting 0 from modtime 1369647251
05-27 11:34:20:590 oc_module: STAT result from propfind: file-67.dat, mtime: 1369647251
05-27 11:34:20:590 oc_module: Get file ID for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file-67.dat: 51a3289c0391d
05-27 11:34:20:590 _get_md5: MD5 for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file-67.dat: 51a3289c0391d
05-27 11:34:20:590 _csync_push_file: FINAL MD5: 51a3289c0391d
05-27 11:34:20:590 _csync_push_file: PUSHED  file: ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file-67.dat
05-27 11:34:20:590 _store_id_update: SYNCED remember  dir: file-67.dat
05-27 11:34:20:590 _csync_push_file: Remote repository atomar push enabled for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file-43.dat (0).
05-27 11:34:20:590 oc_module: => open called for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file-43.dat
05-27 11:34:20:590 oc_module: Stating directory ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test
05-27 11:34:20:590 oc_module: Dir ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test is there, we know it already.
05-27 11:34:20:590 oc_module: PUT request on /owncloud/remote.php/webdav/test/file-43.dat!
05-27 11:34:20:590 oc_module: Sendfile handling request type PUT.
05-27 11:34:20:590 oc_module: Put file size: 1024, variable sizeof: 8
05-27 11:34:21:907 oc_module: http request all cool, result code 201
05-27 11:34:21:907 oc_module: Add a time delta to modtime 1369647250: 0
05-27 11:34:21:907 oc_module: Setting LastModified of /owncloud/remote.php/webdav/test/file-43.dat to 1369647250
05-27 11:34:22:634 oc_module: owncloud_stat ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file-43.dat called
05-27 11:34:23:449 oc_module: Simple propfind result code 207.
05-27 11:34:23:449 oc_module: Server Date from HTTP header value: Mon, 27 May 2013 09:34:23 GMT
05-27 11:34:23:449 oc_module: Ok: Time delta remained (almost) the same: 0.
05-27 11:34:23:449 oc_module: => Errno after fetch resource list for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file-43.dat: 0
05-27 11:34:23:449 oc_module: Working on file file-43.dat
05-27 11:34:23:449 oc_module:   :> Subtracting 0 from modtime 1369647250
05-27 11:34:23:449 oc_module: STAT result from propfind: file-43.dat, mtime: 1369647250
05-27 11:34:23:449 oc_module: Get file ID for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file-43.dat: 51a3289edfa40
05-27 11:34:23:449 _get_md5: MD5 for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file-43.dat: 51a3289edfa40
05-27 11:34:23:449 _csync_push_file: FINAL MD5: 51a3289edfa40
05-27 11:34:23:449 _csync_push_file: PUSHED  file: ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file-43.dat
05-27 11:34:23:449 _store_id_update: SYNCED remember  dir: file-43.dat

[...]

05-27 11:46:25:869 _csync_push_file: Remote repository atomar push enabled for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file-6.dat (0).
05-27 11:46:25:869 oc_module: => open called for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file-6.dat
05-27 11:46:25:869 oc_module: Stating directory ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test
05-27 11:46:25:869 oc_module: Dir ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test is there, we know it already.
05-27 11:46:25:869 oc_module: PUT request on /owncloud/remote.php/webdav/test/file-6.dat!
05-27 11:46:25:869 oc_module: Sendfile handling request type PUT.
05-27 11:46:25:869 oc_module: Put file size: 1024, variable sizeof: 8
05-27 11:46:31:613 oc_module: http request all cool, result code 201
05-27 11:46:31:613 oc_module: Add a time delta to modtime 1369647250: 18446744073709551614
05-27 11:46:31:613 oc_module: Setting LastModified of /owncloud/remote.php/webdav/test/file-6.dat to 1369647248
05-27 11:46:34:546 oc_module: owncloud_stat ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file-6.dat called
05-27 11:46:37:676 oc_module: Simple propfind result code 207.
05-27 11:46:37:676 oc_module: Server Date from HTTP header value: Mon, 27 May 2013 09:46:35 GMT
05-27 11:46:37:676 oc_module: Ok: Time delta remained (almost) the same: -2.
05-27 11:46:37:676 oc_module: => Errno after fetch resource list for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file-6.dat: 0
05-27 11:46:37:676 oc_module: Working on file file-6.dat
05-27 11:46:37:676 oc_module:   :> Subtracting -2 from modtime 1369647248
05-27 11:46:37:676 oc_module: STAT result from propfind: file-6.dat, mtime: 1369647250
05-27 11:46:37:676 oc_module: Get file ID for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file-6.dat: 51a32b789cda3
05-27 11:46:37:676 _get_md5: MD5 for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file-6.dat: 51a32b789cda3
05-27 11:46:37:676 _csync_push_file: FINAL MD5: 51a32b789cda3
05-27 11:46:37:676 _csync_push_file: PUSHED  file: ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file-6.dat
05-27 11:46:37:676 _store_id_update: SYNCED remember  dir: file-6.dat
05-27 11:46:37:676 _csync_push_file: Remote repository atomar push enabled for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file-66.dat (0).
05-27 11:46:37:676 oc_module: => open called for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file-66.dat
05-27 11:46:37:676 oc_module: Stating directory ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test
05-27 11:46:37:676 oc_module: Dir ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test is there, we know it already.
05-27 11:46:37:676 oc_module: PUT request on /owncloud/remote.php/webdav/test/file-66.dat!
05-27 11:46:37:676 oc_module: Sendfile handling request type PUT.
05-27 11:46:37:676 oc_module: Put file size: 1024, variable sizeof: 8
05-27 11:46:43:175 oc_module: http request all cool, result code 201
05-27 11:46:43:175 oc_module: Add a time delta to modtime 1369647250: 18446744073709551614
05-27 11:46:43:175 oc_module: Setting LastModified of /owncloud/remote.php/webdav/test/file-66.dat to 1369647248
05-27 11:46:46:161 oc_module: owncloud_stat ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file-66.dat called
05-27 11:46:49:430 oc_module: Simple propfind result code 207.
05-27 11:46:49:430 oc_module: Server Date from HTTP header value: Mon, 27 May 2013 09:46:47 GMT
05-27 11:46:49:430 oc_module: Ok: Time delta remained (almost) the same: -2.
05-27 11:46:49:430 oc_module: => Errno after fetch resource list for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file-66.dat: 0
05-27 11:46:49:430 oc_module: Working on file file-66.dat
05-27 11:46:49:430 oc_module:   :> Subtracting -2 from modtime 1369647248
05-27 11:46:49:430 oc_module: STAT result from propfind: file-66.dat, mtime: 1369647250
05-27 11:46:49:430 oc_module: Get file ID for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file-66.dat: 51a32b843215c
05-27 11:46:49:430 _get_md5: MD5 for ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file-66.dat: 51a32b843215c
05-27 11:46:49:430 _csync_push_file: FINAL MD5: 51a32b843215c
05-27 11:46:49:430 _csync_push_file: PUSHED  file: ownclouds://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/test/file-66.dat
05-27 11:46:49:430 _store_id_update: SYNCED remember  dir: file-66.dat
05-27 11:46:49:430 csync_propagate: Propagation for local replica took 751,79 seconds visiting 101 files.
05-27 11:46:49:430 csync_propagate: Propagation for remote replica took 0,00 seconds visiting 1 files.
05-27 11:46:49:430 csync_correct_id: correct ID on dir: .
05-27 11:46:49:430 csync_correct_id: correct ID on dir: .
05-27 11:46:49:430 csync_correct_id: correct ID on dir: .
05-27 11:46:49:430 csync_correct_id: correct ID on dir: .
05-27 11:46:49:430 csync_correct_id: correct ID on dir: .

[...]

05-27 11:46:49:431 csync_correct_id: correct ID on dir: .
05-27 11:46:49:431 csync_correct_id: correct ID on dir: .
05-27 11:46:49:431 csync_propagate: Correct Id took. 0,00 seconds 
05-27 11:46:49:432 void Mirall::CSyncThread::startSync() Sync finished 
05-27 11:46:50:485 _insert_metadata_visitor: SQL statement: INSERT INTO metadata_temp 
            (phash, pathlen, path, inode, uid, gid, mode, modtime, type, md5) VALUES 
            (124415436819000123, 11, file-67.dat, 5636460, 1000, 1000, 33188, 1369647250, 0, 51a3289c0391d);
05-27 11:46:50:485 _insert_metadata_visitor: SQL statement: INSERT INTO metadata_temp 
            (phash, pathlen, path, inode, uid, gid, mode, modtime, type, md5) VALUES 
            (322974294914952274, 11, file-43.dat, 5636436, 1000, 1000, 33188, 1369647250, 0, 51a3289edfa40);

[...]

05-27 11:46:50:495 _insert_metadata_visitor: SQL statement: INSERT INTO metadata_temp 
            (phash, pathlen, path, inode, uid, gid, mode, modtime, type, md5) VALUES 
            (-80984399663678646, 11, file-66.dat, 5636459, 1000, 1000, 33188, 1369647250, 0, 51a32b843215c);
05-27 11:46:50:636 csync_destroy: Writing the statedb of 101 files to disk took 1,20 seconds
05-27 11:46:50:677 csync_lock_remove: Removing lock file: /home/user/.local/share/data//ownCloud//lock
05-27 11:46:50:678 CSync run took  753323  Milliseconds 
05-27 11:46:50:679 -> CSync Finished slot with error  false 
05-27 11:46:50:679 Starting Event logging again in  2000  milliseconds 
05-27 11:46:50:679 OO folder slotSyncFinished: result:  4  local:  false 
05-27 11:46:50:679 ==> load folder icon  "owncloud-framed" 
05-27 11:46:50:679 Returning configured owncloud url:  "https://xxx.xxx.xxx.xxx/owncloud/remote.php/webdav/" 
05-27 11:46:50:679 Check status.php from statusdialog. 
05-27 11:46:50:679 Get Request to  "status.php" 
05-27 11:46:50:679 Returning configured owncloud url:  "https://xxx.xxx.xxx.xxx/owncloud/" 
05-27 11:46:50:679 Returning configured owncloud url:  "https://xxx.xxx.xxx.xxx/owncloud/" 
05-27 11:46:50:679 Setting up host header:  "xxx.xxx.xxx.xxx" 
05-27 11:46:50:680 Folder in overallStatus Message:  Mirall::ownCloudFolder(0x1bd43b0)  with name  "test" 
05-27 11:46:50:680 Sync state changed for folder  "test" :  "Success" 
05-27 11:46:50:680 *  "test" Poll timer enabled with  30393 milliseconds 
05-27 11:46:50:680 <===================================== sync finished for  "test"

Summary

The upload time increases dramatically with the number of files, e. g. 0,077 (one file of 100 MB) vs. 12,253 (hundred files of 1MB) minutes. The difference became smaller with the update to oC 5.0.6 but is unfortunately still very great.

danimo commented 11 years ago

Can you take these numbers to https://github.com/owncloud/core/issues/2846? It's the server we need to wait for. This also explains why there has been an improvement for you in 5.0.6: One such file-count-dependent SQL-queries has been fixed there.

wunderlich commented 11 years ago

Ah, that would be an explanation.

Do you mean the whole logs or only the results?

danimo commented 11 years ago

The result, with a reference to the log posted here.

dragnovich commented 11 years ago

Hello first sorry if my english is bad... I had been using OC for 3 months now, and this issue is the biggest one that sould to be FIXED as VITAL. ( if this issue is also in the enterprice version, so there's no reason to pay for it )

I think I know what is the problem, and reading the reports here, I think you are missing one BIG variable that is in fact THE PROBLEM ( I think ), the problem is.....

THE OC WINDOWS SYNC CLIENT !!! (say windows because I had not tested other platforms, but if are the same routines then maybe all of them ) and in combination with the OC webdav php handler routines, they make a gloroius glasiar slow combo for uploads....

Here's my story ... (will try to be short)

3 months ago ... I installed OC 5.0.0 and put it to work in no time... after a 2 days of IT tests, I find this slowness really anoying but livable... then I install it to all My Office co workers (8 stations), and they try to upload hundreds of files (of less than 2mb each all PDF's) to the server via OC Windows Sync Client (there where no notice for the problem because all them did this before go home on a weekend), and after a little time (1 day, on sunday) I receive a report of the server down, they succesfully crash the brand new Dual Hex Core Xeon Server (that's a 12 core), and 48GB ram server. of the company (at first we thinked it was a DoSS attack, and when we whent to try to block the attackers IP's and found that ALL them where internal, we deducted that the attacker whas the sync client) So we Uninstalled all the OC Windows Sync Client's, and just used the web interface for single file uploads and everything returned to the normallity. (for large amounts of files we use FTP (as in the past), while we found a solution for this.

As mentioned in an earlier report, the server got queried TOO MANY TIMES for no usefull reason ( the server was crashed because the successfull overheaded the mysql server with exponential connections), it seems that the client connected, did some queries and not closed the connection (then the connection is open but SLEEP), then returned and open a new connection and leave it open again, and so on... and as some one pointed before fixing the cache function, seems to increase speed (in my tests where a little lower near 25-30%) how ever they still overload the server after a while.

But if you think was great to elimiate the redundancy with the cache function, but WHY NOT TO STOP THIS BEHEAVOR FROM THE SOURCE !! which is... yes... THE SYNC CLIENT!! if he is asking the server I DONT KNOW HOW MANY TIMES, FOR DO, I DONT KNOW WHAT, for each and every file, that is in sync at the moment.

Then 5 terminals, uploading, hundreds of files at the same moment become thousands of requests, and hundred of thousands mysql connections.That's a unintentional DoSS attack.

This maybe also the reason that in some cases when you upload a file "it gets hanged or freezed"... and never finished to upload. Becuse it is waiting the server to finished all requests it did, but they are all sleep, with no way to wake up...

Is there any GIT or SVN where we can get our hands in to the source code for the sync client??

I hate complaining... but I can't help to fix the problem if i had no access to the code =D

regards

mathewmeconry commented 11 years ago

I experience the same problems at the moment. I've at the moment no logfile here but when you start the syncclient over the terminal (Ubuntu) you see the logfile entries and there are a lot of queries BEFORE the syncclient tries to upload or download files.

So the problem is not only windows based. it's also on the linux client and it's annoying because I need 5 minutes or more to upload two files (very small files 50kb and 25kb)

please fix this issue. It seems to be a problem for a long time.

Maybe I could help you in the PHP section of the problem, but just maybe ;)

best regards

frehberg commented 11 years ago

sorry to say, but the deficits of owncloud forced me to switch to alternative setup, I am using SVN in combination with WebDav now. Important for me is the possibility of versioning of huge number of files (scaling), possibility to query local workspace about status, eg which files have been modified and need to be synced. My experience with Owncloud was that I did not know if local files had been synced yet, and I did not get notification about files having been modified with latest update (pull).

dragnovich commented 11 years ago

Yes as I suspected the source code of the Sync Clients is the same for all platforms, so the problem is in all the sync clients for info of how to help here are the links..

How to build the clients on all platforms.... http://doc.owncloud.org/desktop/1.2/building.html

The source code ... https://github.com/owncloud/mirall

Im trying to understand it, but my C days where way.. so looooooong ago, I had not make anything in C project (formally since 1996 :P )

dragotin commented 11 years ago

The most time is probably wasted on server side, so better do PHP and some SQL wizardry.

mkpelletier commented 11 years ago

Hello all I have tested this with both server 5.0.6 and 4.5.11 and clients 1.2.5 and 1.0.5. From what i can see the problem is on the server side. Both clients synced at a reasonable speed with server 4.5.11; what took only hours with 4.5.11 took days to upload with 5.0.6. I tested both clients with 4.5.11. You could downgrade to get the need performance, however I notice that a new version of each server has just been released (5.0.7 and 4.5.12). I see in the changelog for 5.0.7 this line: "Several performance improvements of file handling". Does anyone know if this is meant to address mirall issue 331?

dragotin commented 11 years ago

I did some investigation on that recently and it turned out that the filesystem cache code did too much analyzing after every WebDAV PUT. There were fixes on server side on this but AFAIK these went already into the 5.0.6 release, so that would not align with what @mkpelletier says here.

This was the worst thing I found out:

1) rename hooks

I think the main problem is the way we rename an uploaded file from foobar.part -> foobar. That triggers a lot of hooks, and I think one of the most hurting is the Shared_Updater hook. It ends up in Files\Cache\Scanner, function scan which iterates over all files in the directory to scan again. That kills.

This is the relevant part of the call stack:

lib/files/cache/cache.php.OC\Files\Cache\Cache->put:177   
lib/files/cache/scanner.php.OC\Files\Cache\Scanner->scanFile:89   
lib/files/cache/scanner.php.OC\Files\Cache\Scanner->scan:117   
lib/files/cache/watcher.php.OC\Files\Cache\Watcher->checkUpdate:48   
lib/files/view.php.OC\Files\View->getFileInfo:708   
lib/files/filesystem.php.OC\Files\Filesystem::getFileInfo:607   
apps/files_sharing/lib/updater.php.OC\Files\Cache\Shared_Updater::correctFolders:34
apps/files_sharing/lib/updater.php.OC\Files\Cache\Shared_Updater::renameHook:72
lib/hook.php.call_user_func:72   
lib/hook.php.OC_Hook::emit:72   
lib/files/view.php.OC\Files\View->rename:387   
lib/files/filesystem.php.OC\Files\Filesystem::rename:512   
lib/connector/sabre/directory.php.OC_Connector_Sabre_Directory->createFile:85

I wonder if it makes sense at all to handle the .part-file as a normal file that has to go through all the filecache mechanisms. It's just a temporar file.

but as said, that should be fixed sinced 5.0.6. Maybe somebody wants to verify that? I used xDebug in Netbeans to get to that.

@butonic that's why I just asked...

racic commented 11 years ago

Just wanted to report that with ownCloud 5.0.7 and client 1.2.5 situation hasn't changed. To see what is going on in my network see the attached picture. Orange is upload blue is download.

ocnetusage

The visible spikes correspond to ownCloud activity.

Meanwhile on my NAS apache2 process eats 100% of CPU time and there are still hundreds of files waiting to be synced (judging by the contents of the files/clientsync folder because statistics in the client shows only zeros ....).

godfuture commented 11 years ago

Hey guys, same issue here.

Sync statics show often 0 even if there should be some upload due to newly added files. Even the initial upload short after setting up a new folder sync was just partially done. It never went to complete sync. Also sync is quite slow for around 500 mb mixed with pictures in jpg, few videos with sizes from 40 to 150 mb and text files.

I am using Owncloud 5.07. and sync client 1.2.5 on WIN7 x64.

cheers

Burtan commented 11 years ago

I've got that problem as well. This holds me from using owncloud as I have used dropbox before :(

octocat-mona commented 11 years ago

I just tried ownCloud instead of Seafile today, but Seafile took max 30 minutes for a few gigs but after HOURS ownCloud has only uploaded about 150 megs! (I'm using nginx with sqlite if that matters)

TiZ-HugLife commented 11 years ago

I'm very interested in using this, but I'm experiencing the same kind of agonizingly slow sync. So for now I'll have to stick with Dropbox or use Seafile.

hamiller commented 11 years ago

What's the current status of this bug? Is someone working on it, do you need further infos? -> 1.3.0 still unusable slow :(

poliferroso commented 11 years ago

Hi:

I'm new with owncloud, and I want to replace the Dropbox system for this one. Sometimes I have a great upload speed using the client, but not always. Also, if I use the web version, the difference is huge... It's is the same reported issue.

Cheers,

Poliferroso

owncloud / client