In Depth Description of Issue
During the past month, files have started disappearing somewhat randomly from my GCrypt mount at a rate of roughly 10 out of 20000 per day. About 9 of those are uploaded on the same day as they disappear, while the remaining 1 is completely random. Running ls -a with both regular and superuser accounts confirms that the files are no longer present in the mount. Restarting the GCrypt mount shows the files again.
Additionally, I would like to note that I had this issue beginning about a month ago, so this is not specific to rclone v1.50.0. I am also running a MergerFS mount if that is relevant (however, note that I made sure to check the files in the original GCrypt mount point).
Selective RClone Log File
I see the following errors appear about once every five minutes. I initially ran with DEBUG level logging and searched for files that had disappeared, but saw no errors associated with them.
Google drive root 'GCryptCenter': Failed to get StartPageToken: Get https://www.googleapis.com/drive/v3/changes/startPageToken?alt=json&prettyPrint=false&supportsAllDrives=true: stream error: stream ID 2141; INTERNAL_ERROR
Google drive root 'GCryptCenter': Change notify listener failure: Get https://www.googleapis.com/drive/v3/changes?alt=json&fields=nextPageToken%2CnewStartPageToken%2Cchanges%28fileId%2Cfile%28name%2Cparents%2CmimeType%29%29&includeItemsFromAllDrives=true&pageSize=1000&pageToken={Removed}&prettyPrint=false&supportsAllDrives=true: stream error: stream ID 623; INTERNAL_ERROR
This sounds like a known issue we worked on during 1.49.4 and 1.49.5
The problem here is that your changes-on-drive polling is failing and thus the VFS cache is not being updated correctly. You could confirm this by turning on the remote control --rc
and sending one of these commands
rclone rc vfs/forget
or
rclone rc vfs/refresh
to either purge or refresh the VFS cache (while running). Either should result in new listings and making those files re-appear. Restarting the mount is effectively the same as a VFS purge, so that explains why that would temporarily fix the issue.
But that's not the underlying problem I think. It's those "INTERNAL ERROR" errors.
I thought/hoped we had gotten rid of this.
@ncw will probably want to be aware of this (he should come along soon tomorrow I bet).
But long story short I suspect this is an rclone problem that will need to be fixed - and not due to user-error. Either that or it is actually possible this is some temporary issue on Google's side. We are aware of some recent issues and suspect they may be restructuring parts of the system (but this is just speculation). We aren't 100% sure on the root cause yet and the fix implemented in 1.50 for this issue was more of a speculative one...
Unless by chance you happen to use this in your Gdrive remote config: disable_http2 = false
(because this would disable the speculative fix)
but this is not something you would enable by accident exactly...
I have added the --rc option to my mount options and will report if your commands are successful tomorrow (this gives some time for files to disappear).
I do not use the option "disable_http2=false" in my Gdrive remote config.
You are definitely seeing these INTERNAL_ERROR messages with rclone 1.50.0? Can you double check? If you use rclone rc core/version it will show you the version of the running rclone.
And if you do this
rclone about gcrypt: -vv --dump headers 2>&1 | grep HTTP/
2019/10/30 07:56:05 DEBUG : GET /drive/v3/files?alt=json&fields=files%28id%2Cname%2Csize%2Cmd5Checksum%2Ctrashed%2CmodifiedTime%2CcreatedTime%2CmimeType%2Cparents%2CwebViewLink%29%2CnextPageToken&includeItemsFromAllDrives=true&pageSize=1000&prettyPrint=false&q=trashed%3Dfalse+and+%28%{Redacted}%27+in+parents%29+and+%28name%3D%27Media%27%29+and+mimeType%3D%27application%2Fvnd.google-apps.folder%27&supportsAllDrives=true HTTP/1.1
2019/10/30 07:56:06 DEBUG : HTTP/1.1 200 OK
2019/10/30 07:56:06 DEBUG : GET /drive/v3/about?alt=json&fields=exportFormats%2CimportFormats&prettyPrint=false HTTP/1.1
2019/10/30 07:56:06 DEBUG : HTTP/1.1 200 OK
2019/10/30 07:56:06 DEBUG : GET /drive/v3/files?alt=json&fields=files%28id%2Cname%2Csize%2Cmd5Checksum%2Ctrashed%2CmodifiedTime%2CcreatedTime%2CmimeType%2Cparents%2CwebViewLink%29%2CnextPageToken&includeItemsFromAllDrives=true&pageSize=1000&prettyPrint=false&q=trashed%3Dfalse+and+%28%{Redacted}%27+in+parents%29+and+%28name%3D%27Media%27%29+and+mimeType%3D%27application%2Fvnd.google-apps.folder%27&supportsAllDrives=true HTTP/1.1
2019/10/30 07:56:06 DEBUG : HTTP/1.1 200 OK
2019/10/30 07:56:06 DEBUG : GET /drive/v3/about?alt=json&fields=storageQuota&prettyPrint=false HTTP/1.1
2019/10/30 07:56:06 DEBUG : HTTP/1.1 200 OK
However, the rclone mount has not lost any files today and I do not see any INTERNAL_ERROR messages as of late. I may have forgotten to restart the rclone mount after updating to rclone 1.50.0. I'll report if I see more INTERNAL_ERROR messages. For now, I will mark the issue as solved.
