[Owncloud] own cloud client lags behind on MacOSX (last sync log time ago)

Wed Sep 18 08:50:18 UTC 2013

Hello,

This is the followup about long running MacOSX client problem.

I managed to capture the logfile - my MacOSX client has been now stuck since Aug 28. During that time I was mainly offline and several times over shaky and unreliable wireless connections closing the lid several times a day and switching networks.

The current symptom is: the client process is alive but not syncing. 
Mirall 1.3.0 reports last sync 8569 minutes ago. The icon in the tray is available and functional.

>pgrep -lf owncloud
10956 /Applications/owncloud.app/Contents/MacOS/owncloud -psn_0_143038561

Below are the detailes. I have two sync folders which are setup: one ~/ownCloud is my main folder, the other ~/box/doc is a folder shared by another user.

The relevant excerpt of the last log file produced by the client on Aug 28.

Remarks: 
   - it seems that the client did not properly recovered from a Network Error 99 (Timeout)
   - this triggers tons of (possibly unhandled or stacked) callbacks from the FolderWatcher
   - eventually on 04 September mirall decides to shutdown (however, the process stays around and the icon in the system tray as well -> so something is wrong here too).

Let me know if there is more input to be provided that could be useful to hunt this bug.

kuba

--

….
08-29 07:35:15:157 csync_ftw: Uniq ID from Database: webdav2.txt -> 52187c5125e89
08-29 07:35:15:157 csync_walker: file: /Users/moscicki/ownCloud/webdav2.txt
08-29 07:35:15:157 _csync_detect_update: ==> file: webdav2.txt - hash 16676229649074815153, mtime: 1368184621
08-29 07:35:15:157 _csync_detect_update: Database entry found, compare: 1368184621 <-> 1368184621, md5: 52187c5125e89 <-> 52187c5125e89
08-29 07:35:15:157 _csync_detect_update: file: webdav2.txt, instruction: INSTRUCTION_NONE <<=
08-29 07:35:15:157 csync_ftw:  <= Closing walk for /Users/moscicki/ownCloud with read_from_db 0
08-29 07:35:15:157 csync_update: Update detection for local replica took 1.32 seconds walking 4758 files.
08-29 07:35:15:157 csync_ftw:   => Starting to ftw ownclouds://box.cern.ch/owncloud/remote.php/webdav/clientsync, read_from_db-Flag for: 0
08-29 07:35:15:157 csync_ftw: Checking for read from db for ownclouds://box.cern.ch/owncloud/remote.php/webdav/clientsync: 0
08-29 07:35:15:157 oc_module: opendir method called on ownclouds://box.cern.ch/owncloud/remote.php/webdav/clientsync
08-29 07:35:15:157 oc_module: * scheme ownclouds
08-29 07:35:15:157 oc_module: * host box.cern.ch
08-29 07:35:15:157 oc_module: * port 0
08-29 07:35:15:157 oc_module: * path /owncloud/remote.php/webdav/clientsync
08-29 07:35:15:157 oc_module: * user 
08-29 07:35:15:158 oc_module: ne_sock_init: 0
08-29 07:35:15:158 oc_module: No proxy configured.
08-29 07:35:15:761 oc_module: Call the csync callback for SSL problems
08-29 07:35:15:761 SSL Fingerprint from neon:  "fc:91:73:a8:7d:86:c7:0e:c3:06:c7:5c:19:25:bd:37:06:00:0b:e1"  compared to verified:  "fc:91:73:a8:7d:86:c7:0e:c3:06:c7:5c:19:25:
bd:37:06:00:0b:e1" 
08-29 07:35:15:761 oc_module: ## VERIFY_SSL CERT: 0
08-29 07:35:16:439 oc_module: Authentication required 
08-29 07:35:16:439 oc_module: Call the csync callback for ownCloud
08-29 10:50:15:603 ownCloudInfo Network Error 99 : "Operation timed out" 
08-29 10:50:15:659 status.php returns:  ""   99  Reply:  QNetworkReplyImpl(0x10b506f90) 
08-29 10:50:15:661 No proper answer on  "https://box.cern.ch/owncloud/status.php" 
08-31 14:50:54:186 FolderWatcherPrivate::callback by OS X 
09-01 18:12:00:546 FolderWatcherPrivate::callback by OS X 
09-01 18:12:00:684 FolderWatcherPrivate::callback by OS X 
09-01 18:12:00:716 * Pending events for "/Users/moscicki/box/doc" will be processed after events stop for 1000 milliseconds ( "18:28:40" ). 1 events until now ) 
09-01 18:12:00:723 FolderWatcherPrivate::callback by OS X 
….
tons of "FolderWatcherPrivate::callback by OS X"
….
09-01 18:12:02:069 FolderWatcherPrivate::callback by OS X 
09-01 18:12:03:071 * Processing of event queue for "/Users/moscicki/box/doc" 
09-01 18:12:03:072   * Notify 1 change items for "/Users/moscicki/box/doc" 
09-01 18:12:03:073 ** Changed was notified on  ("/Users/moscicki/box/doc") 
09-01 18:12:03:074 *  "box/doc " Poll timer disabled 
09-01 18:12:03:075 Schedule folder  "box/doc "  to sync! 
09-01 18:12:03:075  II> Sync for folder  "box/doc "  already scheduled, do not enqueue! 
09-01 18:12:03:075 Currently folder  "ownCloud"  is running, wait for finish! 
09-01 18:12:04:100 FolderWatcherPrivate::callback by OS X 
09-01 18:12:04:101 * Pending events for "/Users/moscicki/box/doc" will be processed after events stop for 1000 milliseconds ( "18:28:44" ). 1 events until now ) 
09-01 18:12:04:102 FolderWatcherPrivate::callback by OS X 
09-01 18:12:04:102 FolderWatcherPrivate::callback by OS X 
…
tons of "FolderWatcherPrivate::callback by OS X"
…
9-01 18:12:04:884 FolderWatcherPrivate::callback by OS X 
09-01 18:12:04:892 FolderWatcherPrivate::callback by OS X 
09-01 18:12:04:892 FolderWatcherPrivate::callback by OS X 
09-01 18:12:04:905 FolderWatcherPrivate::callback by OS X 
09-01 18:12:04:905 FolderWatcherPrivate::callback by OS X 
09-01 18:12:04:926 FolderWatcherPrivate::callback by OS X 
09-01 18:12:04:926 FolderWatcherPrivate::callback by OS X 
09-01 18:12:05:926 * Processing of event queue for "/Users/moscicki/box/doc" 
09-01 18:12:05:926   * Notify 1 change items for "/Users/moscicki/box/doc" 
09-01 18:12:05:927 ** Changed was notified on  ("/Users/moscicki/box/doc") 
09-01 18:12:05:927 *  "box/doc " Poll timer disabled 
09-01 18:12:05:927 Schedule folder  "box/doc "  to sync! 
09-01 18:12:05:927  II> Sync for folder  "box/doc "  already scheduled, do not enqueue! 
09-01 18:12:05:927 Currently folder  "ownCloud"  is running, wait for finish! 
09-03 09:04:41:647 FolderWatcherPrivate::callback by OS X 
09-04 18:07:11:465 FolderWatcherPrivate::callback by OS X 
09-04 18:07:11:616 FolderWatcherPrivate::callback by OS X 
09-04 18:36:25:313 opening local url  "/Users/moscicki/box/doc/" 
09-04 18:37:13:339 * Mirall shutdown 

On Aug 20, 2013, at 10:40 AM, Jakub Moscicki <Jakub.Moscicki at cern.ch>
 wrote:

> Hello,
> 
> This is an issue that I have had several times over past weeks: on MacOSX laptop the client (1.3.0) gets stuck after some time - last sync time is reported to be more than 24 hours ago. My laptop gets to sleep quite often (closed lid) and changes wifi networks at least twice a day. I would assume this it the primary reason and the process is sync interrupted and the client eventually confused.
> 
> As a side effect the client does not really quit - the tray icon disappears but the process is hanging around consuming now 100% CPU:
> 
>> pgrep -lf owncloud
> 
> 94440 /Applications/owncloud.app/Contents/MacOS/owncloud -psn_0_96922729
> 
> I have restarted the client to get the logfiles which I will be reporting later. 
> 
> In the meantime I would like to know if anyone has similar issues or maybe the problem is solved already in 1.4.0 ?
> 
> kuba
> 
> --
> 
> _______________________________________________
> Owncloud mailing list
> Owncloud at kde.org
> https://mail.kde.org/mailman/listinfo/owncloud