First off, thanks for telling me how to get to the log. Had to modify my keyboard settings to turn off the Dashboard for F12, but this is a far more useful function.
Files: 1.67 GB distributed amongst 514 items (from Finder, which presumably skips hidden files, but there’s nothing significant there).
I let it run for a while, and then copied the log into a text editor for analysis. It never produced a single error/warning/caution or other problem. What I learned is that it starts off fast. Nanosecond fast. It evaluates the entire directory and notes INSTRUCTION_NONE
for each file, but every folder is noted as INSTRUCTION_UPDATE_METADATA
. The fact that I haven’t interacted with any of these folders in any client doesn’t seem to matter.
Here is the point at which the process slows down to seconds. It confirms the speed of the prior evaluation(s), and then moves into something else:
04-08 09:23:52:070 0x7fa98bd139a8 csync_update: Update detection for local replica took 0.07 seconds walking 532 files.
04-08 09:23:52:070 329624 OCC::DiscoveryJob::remote_vio_opendir_hook: OCC::DiscoveryJob(0x6080000ddff0) Calling into main thread...
04-08 09:23:52:515 11934 OCC::AbstractNetworkJob::start: !!! OCC::LsColJob created for "my.domain" + "/nextcloud" "OCC::DiscoverySingleDirectoryJob"
04-08 09:23:56:662 11934 OCC::DiscoveryMainThread::singleDirectoryJobFirstDirectoryPermissionsSlot: Permissions for root dir: "RMGDNVCK"
04-08 09:23:56:663 11934 OCC::DiscoveryMainThread::singleDirectoryJobResultSlot: void OCC::DiscoveryMainThread::singleDirectoryJobResultSlot(const QList<OCC::FileStatPointer> &) Have 8 results for "/nextcloud"
04-08 09:23:56:663 329624 OCC::DiscoveryJob::remote_vio_opendir_hook: OCC::DiscoveryJob(0x6080000ddff0) ...Returned from main thread
After this, it It generated thousands of lines, most of which look like the following:
04-08 09:24:02:407 329624 OCC::DiscoveryJob::remote_vio_opendir_hook: OCC::DiscoveryJob(0x6080000ddff0) path/to/folder Calling into main thread...
04-08 09:24:02:409 11934 OCC::AbstractNetworkJob::start: !!! OCC::LsColJob created for "my.domain" + "/cloud/path/to/folder" "OCC::DiscoverySingleDirectoryJob"
04-08 09:24:08:689 11934 OCC::DiscoveryMainThread::singleDirectoryJobResultSlot: void OCC::DiscoveryMainThread::singleDirectoryJobResultSlot(const QList<OCC::FileStatPointer> &) Have 4 results for "/cloud/path/to/folder"
04-08 09:24:08:690 329624 OCC::DiscoveryJob::remote_vio_opendir_hook: OCC::DiscoveryJob(0x6080000ddff0) path/to/folder ...Returned from main thread
04-08 09:24:08:690 0x7fa98bd139a8 csync_walker: file: path/to/file1.docx [file_id=00005129oc1ba375tic7 size=104]
04-08 09:24:08:690 0x7fa98bd139a8 sqlite_profile: _SQL_ SELECT phash, pathlen, path, inode, uid, gid, mode, modtime, type, md5, fileid, remotePerm, filesize, ignoredChildrenRemote, contentChecksum, contentChecksumTypeId FROM metadata WHERE phash=?1: 0
04-08 09:24:08:690 0x7fa98bd139a8 _csync_detect_update: Database entry found, compare: 1439403475 <-> 1439403475, etag: 5ab8be143a423 <-> 5ab8be143a423, inode: 0 <-> 8593176093, size: 104 <-> 104, perms: RmGDNVW <-> RmGDNVW, ignore: 0
04-08 09:24:08:690 0x7fa98bd139a8 _csync_detect_update: file: path/to/file1.docx, instruction: INSTRUCTION_NONE <<=
04-08 09:24:08:690 0x7fa98bd139a8 csync_walker: file: path/to/file2.docx [file_id=00005130oc1ba375tic7 size=114684]
04-08 09:24:08:690 0x7fa98bd139a8 sqlite_profile: _SQL_ SELECT phash, pathlen, path, inode, uid, gid, mode, modtime, type, md5, fileid, remotePerm, filesize, ignoredChildrenRemote, contentChecksum, contentChecksumTypeId FROM metadata WHERE phash=?1: 0
04-08 09:24:08:690 0x7fa98bd139a8 _csync_detect_update: Database entry found, compare: 1506429870 <-> 1506429870, etag: 5ab8be146a7eb <-> 5ab8be146a7eb, inode: 0 <-> 8593176094, size: 114684 <-> 114684, perms: RmGDNVW <-> RmGDNVW, ignore: 0
04-08 09:24:08:690 0x7fa98bd139a8 _csync_detect_update: file: path/to/file2.docx, instruction: INSTRUCTION_NONE <<=
04-08 09:24:08:690 0x7fa98bd139a8 csync_walker: file: path/to/file3.docx [file_id=00005131oc1ba375tic7 size=110158]
04-08 09:24:08:690 0x7fa98bd139a8 sqlite_profile: _SQL_ SELECT phash, pathlen, path, inode, uid, gid, mode, modtime, type, md5, fileid, remotePerm, filesize, ignoredChildrenRemote, contentChecksum, contentChecksumTypeId FROM metadata WHERE phash=?1: 0
04-08 09:24:08:690 0x7fa98bd139a8 _csync_detect_update: Database entry found, compare: 1400515736 <-> 1400515736, etag: 5ab8be148ccb2 <-> 5ab8be148ccb2, inode: 0 <-> 8593176095, size: 110158 <-> 110158, perms: RmGDNVW <-> RmGDNVW, ignore: 0
04-08 09:24:08:690 0x7fa98bd139a8 _csync_detect_update: file: path/to/file3.docx, instruction: INSTRUCTION_NONE <<=
04-08 09:24:08:691 0x7fa98bd139a8 csync_walker: directory: path/to/subfolder1 [file_id=00005128oc1ba375tic7]
04-08 09:24:08:691 0x7fa98bd139a8 sqlite_profile: _SQL_ SELECT phash, pathlen, path, inode, uid, gid, mode, modtime, type, md5, fileid, remotePerm, filesize, ignoredChildrenRemote, contentChecksum, contentChecksumTypeId FROM metadata WHERE phash=?1: 0
04-08 09:24:08:691 0x7fa98bd139a8 _csync_detect_update: Database entry found, compare: 1523187448 <-> 1523186779, etag: 5aca26088a669 <-> 5aca236b48a15, inode: 0 <-> 8592980173, size: 0 <-> 0, perms: RmGDNVCK <-> RmGDNVCK, ignore: 0
04-08 09:24:08:691 0x7fa98bd139a8 _csync_detect_update: file: path/to/subfolder1, instruction: INSTRUCTION_EVAL <<=
Then it moves in to do the same thing in that subfolder. As you can see in the timestamps, the second line where it starts the DiscoverySingleDirectoryJob
is where speed takes a hit. I don’t know what this is doing, and Googling it didn’t turn up anything that helps me understand it.