Client: Connection closed when unicode is present in filename

[JetUni]

Expected behaviour

The file should sync with the server, even if there is a Unicode character (specifically an emoji) in the filename

Actual behaviour

There is an error "Connection closed" and the syncing stops entirely. It won't even move on to the next files. At the very least it should move on and try that file again before it finishes syncing, but instead it just stops everything.

Steps to reproduce

1. Place a bunch of files in a sync directory and make sure that one file has a Unicode character (I haven't tested with anything other than emojis) in the filename
2. Let the client try to sync the directory
3. Notice that once the sync gets to the file with a Unicode character, it stops and doesn't sync any other files

Server configuration

Operating system:
Ubuntu 16.04

Web server:
Apache

Database:
MySQL

PHP version:
7.0.28

ownCloud version:
10.0.8.5

Storage backend (external storage):
Stored locally, Cached with Redis

Client configuration

Client version:
2.4.1

Operating system:
Windows 10

OS language:
English

Installation path of client:
A:\C\Program Files (x86)\ownCloud

Logs

1. Client logfile:

05-11 11:17:07:531 [ info gui.folder ]: #### Propagation start ####################################################
05-11 11:17:07:532 [ info gui.application ]:    Sync state changed for folder  "https://my.jarrett.tk/remote.php/dav/files/jarrett/Docs" :  "Sync Running"
05-11 11:17:09:787 [ info sync.propagator ]:    Starting INSTRUCTION_NEW propagation of "Backups/Computers/BEAST-Laptop/Downloads/Video/Relive the best of Team USA at Rio ???? ??.MP4" by OCC::PropagateUploadFileV1(0x136f5f78)
05-11 11:17:09:787 [ info sync.checksums ]: Computing "SHA1" checksum of "A:/Documents/Backups/Computers/BEAST-Laptop/Downloads/Video/Relive the best of Team USA at Rio ???? ??.MP4" in a thread
05-11 11:17:09:799 [ info sync.propagator.upload ]: "/Docs/Backups/Computers/BEAST-Laptop/Downloads/Video/Relive the best of Team USA at Rio ???? ??.MP4" "SHA1:0bbde185b00fee7d8cc4b10736d8009a37bc12d4"
05-11 11:17:09:801 [ info sync.accessmanager ]: 3 "" "https://my.jarrett.tk/remote.php/dav/files/jarrett/Docs/Backups/Computers/BEAST-Laptop/Downloads/Video/Relive the best of Team USA at Rio ???? ??.MP4" has X-Request-ID "052a1f9d-2d75-4de7-8561-549be8698051"
05-11 11:17:09:801 [ info sync.networkjob ]:    OCC::PUTFileJob created for "https://my.jarrett.tk" + "/Docs/Backups/Computers/BEAST-Laptop/Downloads/Video/Relive the best of Team USA at Rio ???? ??.MP4" "OCC::PropagateUploadFileV1"
05-11 11:17:09:871 [ warning sync.networkjob ]: QNetworkReply::NetworkError(RemoteHostClosedError) "Connection closed" QVariant(Invalid)
05-11 11:17:09:871 [ info sync.networkjob.put ]:    PUT of "https://my.jarrett.tk/remote.php/dav/files/jarrett/Docs/Backups/Computers/BEAST-Laptop/Downloads/Video/Relive the best of Team USA at Rio ???? ??.MP4" FINISHED WITH STATUS QNetworkReply::NetworkError(RemoteHostClosedError) "Connection closed" QVariant(Invalid) QVariant(Invalid)
05-11 11:17:09:871 [ warning sync.propagator ]: Could not complete propagation of "Backups/Computers/BEAST-Laptop/Downloads/Video/Relive the best of Team USA at Rio ???? ??.MP4" by OCC::PropagateUploadFileV1(0x136f5f78) with status 1 and error: "Connection closed"

1. Web server error log:
   None

2. Server logfile: ownCloud log (data/owncloud.log):
   None

[ckamm]

The remote closing the connection seems like the server is involved, but the sync should certainly not get stuck!

@JetUni Could you get another, more verbose log? (either with --logdebug or by switching on debug messages in the log window)

[ckamm]

@JetUni The sync should abort after seeing this error from the server and that can take up to 5 seconds. You are saying the folder synchronization stays in the locked-up state indefinitely and there are no more log messages?

[ckamm]

A hypothesis:

• The PUTJob in UploadV1 finishes, goes to PropagateItemJob::done, which calls rootJob->abort() with a queued connection.
• Afterwards the PUTJob calls deleteLater on itself, but the abort() gets invoked first
• So when UploadV1::abort() gets called the PUTJob is still in the _jobs list and the async abort never finishes because QNetworkReply::finished is never called again

But why doesn't the 5s abort timeout fire, and why does the server close the connection in the first place?

[ogoffart]

I think the sync gets stuck because the client understands the closed connection as if the connection was dropped.
Maybe we should actually do a connectivity test in that case before interrupting the sync instead of just cutting it.

Edit: But this might not be the problem in this issue.
Edit2: I think it does after all.

[SamuAlfageme]

@ckamm @ogoffart shouldn't the filename on the logs from the propagator be already normalized? the multiple "???" strikes me as weird. On macOS I get:

05-14 12:01:23:689 [ info sync.propagator ]:    Completed propagation of "❤️" by OCC::PropagateRemoteMove(0x7fb9ef453850) with status 4

@JetUni are you using some particular storage option as destination of your local sync folder?

[SamuAlfageme]

Also, after https://github.com/owncloud/client/issues/5661 sync should not be affected at all if one of these pops out in the process.

[SamuAlfageme]

@JetUni since:

Database:
MySQL

If you are also unable to create files with 4-byte characters on its name via webUI, check https://github.com/owncloud-docker/base/issues/4#issuecomment-336499477 for some instructions on how to migrate your DB to support these.

[ogoffart]

Right, the fact that it is not proper in the log is indeed quite strange.
On windows, the encoding used for the log is the default one which comes from qt and is QTextCodec::codecForLocale(), which i think might be dependent of the language, but is likely to be latin1.
Perhaps we should force the log file to be written in UTF-8.

[ckamm]

I've cleaned up the upload abort code, but my guess was wrong: If a job has a fatalError in done() it'll not be in _runningJobs anymore when abort() is called, so that doesn't end up being the issue.

[JetUni]

If you are also unable to create files with 4-byte characters on its name via webUI, check owncloud-docker/base#4 (comment) for some instructions on how to migrate your DB to support these.

Running occ db:convert-mysql-charset fixed it! However, I still think that the client shouldn't hang on one of these files and impede the rest of the files from being uploaded. I have another ownCloud install that I haven't changed the charset on and I'll be happy to test your changes when this is fixed! In my use case, I made a backup of my laptop before sending it for repairs and so there were thousands of files to be uploaded and it's in the same directory as all my school files, so I wasn't able to get to my new school files because the sync kept getting stuck on that one file.

[JetUni]

@JetUni Could you get another, more verbose log? (either with --logdebug or by switching on debug messages in the log window)

I tried to limit the log as much as I could to give you just what you needed, but here is a log from the debug window taken today.

https://gist.github.com/JetUni/4deaf40e1b1c8ca49b2c06b02d03a730

@JetUni The sync should abort after seeing this error from the server and that can take up to 5 seconds. You are saying the folder synchronization stays in the locked-up state indefinitely and there are no more log messages?

See the log in the gist above, but basically there are 166 files trying to be synced in that gist and once it gets to the file with the unicode character, it stops. In this case, the problem file is number 34 or something like that, and so it only syncs 33 files.

@JetUni are you using some particular storage option as destination of your local sync folder?

I'm not sure I know what you mean. Does the log answer your question? If not, could you be more specific?

[SamuAlfageme]

@JetUni glad to hear the DB commands worked out. Agree it should not block the syncing process; we will check for further client issues and track the progress here.

With "_particular storage option as destination of your local sync folder_" I meant if you e.g. might be using a different file system on the drive you're placing your sync that might have troubles with the filename encoding.

[JetUni]

Both of my drives are formatted as ext4. The first device is the main OS drive and the second is my "Data" drive. I hope this helps you understand what's going on.

---

---

$ cat /var/www/owncloud/config/config.php | grep datadirectory
  'datadirectory' => '/media/Data/ocdata',

[michaelstingl]

However, I still think that the client shouldn't hang on one of these files and impede the rest of the files from being uploaded.

Related: https://github.com/owncloud/client/issues/5859 (Never ever abort sync runs) /cc @SamuAlfageme

[ckamm]

@JetUni Thanks for the full log!

So the propagator doesn't get stuck, but the sync aborts when a "Connection closed" error is encountered.

Currently all network errors (Proxy, ssl. timeouts etc) are considered fatal. We could make RemoteHostClosedError not fatal. If the server replied with an error instead of closing the connection that also wouldn't abort the sync.

@ogoffart Your thoughts?

[ogoffart]

@ogoffart Your thoughts?

See my first comment to this issue. Where I suggested to do a connectivity check before aborting the sync.

But maybe you are right, RemoteHostClosedError probably does not indicate a connectivity error and we probably could classify it as a "NormalError"
If it is caused by a connectivity error, the next error would probably be different anyway.

[ckamm]

@SamuAlfageme The specific thing that is done and could be tested is that ConnectionClosed will no longer abort the sync.

[SamuAlfageme]

I'm using a proxy to drop the GET requests to a particular file every time.

Error is displayed prominently (i.e. up 'till the very tray menu) until the file gets to download, sync is never aborted/dropped. I'd say this can be closed 👍