Uploding e2e encrypted files seems to take forever/fails

[rugk]

I have less than 500kB files to sync (in two files) for testing. However, as far as I see they never really uploaded.
Likely also related to the issues on the Android side: nextcloud/android#3291

Expected behaviour

Sync.

Actual behaviour

It seems to retry syncing these little files and always seems to fail:

Currently:

In Nautilus I do see by their icons that it only tries to sync the (to-be) e2e encrypted folder.

Before (a try some days ago) also like this:

(Note the progress bar is not moving here – it can stay like this for minutes…)

Note it often does not even count the files (two files) correctly.

Steps to reproduce

0. e2e setup, setup on Android due to Client will not connect unless E2E has previously been set up #560
1. Created encrypted folder on Android.
2. Synced on desktop. (Everything worked so far.)
3. Put files into it.

Client configuration

Client version: 2.5.0git 371001c

Operating system: Fedora 29

OS language: de_DE

Qt version used by client package (Linux only, see also Settings dialog): Qt 5.11.1, OpenSSL 1.1.1 FIPS 11 Sep 2018

Client package (From Nextcloud or distro) (Linux only): distro

Installation path of client:
/usr/bin/nextcloud

Server configuration

Operating system: Debian-based

Web server: nginx

Database: mysql

PHP version: 7

Nextcloud version: 14

Storage backend (external storage): no

Logs

(put into details tags)

1. Client logfile: Output of nextcloud --logwindow or nextcloud --logfile log.txt
   (On Windows using cmd.exe, you might need to first cd into the Nextcloud directory)
   (See also https://docs.nextcloud.com/desktop/2.3/troubleshooting.html#log-files)

Details

[OCC::WebFlowCredentials::slotFinished 	request finished
[OCC::WebFlowCredentials::stillValid 	Still valid?
[OCC::WebFlowCredentials::stillValid 	QNetworkReply::NetworkError(NoError)
[OCC::WebFlowCredentials::stillValid 	"Unknown error"
[OCC::GetFolderEncryptStatusJob::finished 	GetFolderEncryptStatus of QUrl("https://sub.domain.example:4444/subdir/remote.php/webdav/END-TO-END/CRYPTO-PATH") finished with status QNetworkReply::NetworkError(NoError) ""
[OCC::AccessManager::createRequest 	6 "PROPFIND" "https://sub.domain.example:4444/subdir/remote.php/dav/files/<username>/END-TO-END/CRYPTO-PATH" has X-Request-ID "9d14144c-2135-43ef-83f7-26cfad1389ed"
[OCC::AbstractNetworkJob::start 	OCC::LsColJob created for "https://sub.domain.example/nextcloud" + "END-TO-END/CRYPTO-PATH-without-leading-slash" "OCC::PropagateUploadEncrypted"
[OCC::WebFlowCredentials::slotFinished 	request finished
[OCC::WebFlowCredentials::stillValid 	Still valid?
[OCC::WebFlowCredentials::stillValid 	QNetworkReply::NetworkError(NoError)
[OCC::WebFlowCredentials::stillValid 	"Unknown error"
[OCC::GetFolderEncryptStatusJob::finished 	GetFolderEncryptStatus of QUrl("https://sub.domain.example:4444/subdir/remote.php/webdav/END-TO-END/CRYPTO-PATH") finished with status QNetworkReply::NetworkError(NoError) ""
[OCC::AccessManager::createRequest 	6 "PROPFIND" "https://sub.domain.example:4444/subdir/remote.php/dav/files/<username>/END-TO-END/CRYPTO-PATH" has X-Request-ID "22e19db0-6fcd-4fcd-be6d-ca22ae12e316"
[OCC::AbstractNetworkJob::start 	OCC::LsColJob created for "https://sub.domain.example/nextcloud" + "END-TO-END/CRYPTO-PATH-without-leading-slash" "OCC::PropagateUploadEncrypted"
[OCC::WebFlowCredentials::slotFinished 	request finished
[OCC::WebFlowCredentials::stillValid 	Still valid?
[OCC::WebFlowCredentials::stillValid 	QNetworkReply::NetworkError(NoError)
[OCC::WebFlowCredentials::stillValid 	"Unknown error"
[OCC::PropfindJob::finished 	PROPFIND of QUrl("https://sub.domain.example:4444/subdir/remote.php/dav/files/<username>/") FINISHED WITH STATUS "OK"
[OCC::WebFlowCredentials::slotFinished 	request finished
[OCC::WebFlowCredentials::stillValid 	Still valid?
[OCC::WebFlowCredentials::stillValid 	QNetworkReply::NetworkError(NoError)
[OCC::WebFlowCredentials::stillValid 	"Unknown error"
[OCC::LsColJob::finished 	LSCOL of QUrl("https://sub.domain.example:4444/subdir/remote.php/dav/files/<username>/END-TO-END/CRYPTO-PATH") FINISHED WITH STATUS "OK"
[OCC::LockEncryptFolderApiJob::start 	locking the folder with id "124028" as encrypted
[OCC::AccessManager::createRequest 	4 "" "https://sub.domain.example:4444/subdir/ocs/v2.php/apps/end_to_end_encryption/api/v1/lock/124028?format=json" has X-Request-ID "abeb2fa7-b3f1-4c11-8e2a-290d04d5474e"
[OCC::AbstractNetworkJob::start 	OCC::LockEncryptFolderApiJob created for "https://sub.domain.example/nextcloud" + "ocs/v2.php/apps/end_to_end_encryption/api/v1/lock/124028" "OCC::PropagateUploadEncrypted"
[OCC::WebFlowCredentials::slotFinished 	request finished
[OCC::WebFlowCredentials::stillValid 	Still valid?
[OCC::WebFlowCredentials::stillValid 	QNetworkReply::NetworkError(NoError)
[OCC::WebFlowCredentials::stillValid 	"Unknown error"
[OCC::LsColJob::finished 	LSCOL of QUrl("https://sub.domain.example:4444/subdir/remote.php/dav/files/<username>/END-TO-END/CRYPTO-PATH") FINISHED WITH STATUS "OK"
[OCC::LockEncryptFolderApiJob::start 	locking the folder with id "124028" as encrypted
[OCC::AccessManager::createRequest 	4 "" "https://sub.domain.example:4444/subdir/ocs/v2.php/apps/end_to_end_encryption/api/v1/lock/124028?format=json" has X-Request-ID "63389dd1-b789-4b87-bd09-94dc8d1d2e4d"
[OCC::AbstractNetworkJob::start 	OCC::LockEncryptFolderApiJob created for "https://sub.domain.example/nextcloud" + "ocs/v2.php/apps/end_to_end_encryption/api/v1/lock/124028" "OCC::PropagateUploadEncrypted"
[OCC::WebFlowCredentials::slotFinished 	request finished
[OCC::AbstractNetworkJob::slotFinished 	QNetworkReply::NetworkError(ContentAccessDenied) "Error transferring https://sub.domain.example:4444/subdir/ocs/v2.php/apps/end_to_end_encryption/api/v1/lock/124028?format=json - server replied: " QVariant(int, 403)
[OCC::WebFlowCredentials::stillValid 	Still valid?
[OCC::WebFlowCredentials::stillValid 	QNetworkReply::NetworkError(ContentAccessDenied)
[OCC::WebFlowCredentials::stillValid 	"Error transferring https://sub.domain.example:4444/subdir/ocs/v2.php/apps/end_to_end_encryption/api/v1/lock/124028?format=json - server replied: "
[OCC::LockEncryptFolderApiJob::finished 	error locking file "ocs/v2.php/apps/end_to_end_encryption/api/v1/lock/124028" "Error transferring https://sub.domain.example:4444/subdir/ocs/v2.php/apps/end_to_end_encryption/api/v1/lock/124028?format=json - server replied: " 403
[OCC::WebFlowCredentials::slotFinished 	request finished
[OCC::AbstractNetworkJob::slotFinished 	QNetworkReply::NetworkError(ContentAccessDenied) "Error transferring https://sub.domain.example:4444/subdir/ocs/v2.php/apps/end_to_end_encryption/api/v1/lock/124028?format=json - server replied: " QVariant(int, 403)
[OCC::WebFlowCredentials::stillValid 	Still valid?
[OCC::WebFlowCredentials::stillValid 	QNetworkReply::NetworkError(ContentAccessDenied)
[OCC::WebFlowCredentials::stillValid 	"Error transferring https://sub.domain.example:4444/subdir/ocs/v2.php/apps/end_to_end_encryption/api/v1/lock/124028?format=json - server replied: "
[OCC::LockEncryptFolderApiJob::finished 	error locking file "ocs/v2.php/apps/end_to_end_encryption/api/v1/lock/124028" "Error transferring https://sub.domain.example:4444/subdir/ocs/v2.php/apps/end_to_end_encryption/api/v1/lock/124028?format=json - server replied: " 403
[OCC::AccessManager::createRequest 	2 "" "https://sub.domain.example:4444/subdir/ocs/v2.php/apps/notifications/api/v2/notifications?format=json" has X-Request-ID "47c45c35-c721-43ff-b818-b2bfdcea508b"
[OCC::AbstractNetworkJob::start 	OCC::JsonApiJob created for "https://sub.domain.example/nextcloud" + "ocs/v2.php/apps/notifications/api/v2/notifications" "OCC::ServerNotificationHandler"
[OCC::WebFlowCredentials::slotFinished 	request finished
[OCC::WebFlowCredentials::stillValid 	Still valid?
[OCC::WebFlowCredentials::stillValid 	QNetworkReply::NetworkError(NoError)
[OCC::WebFlowCredentials::stillValid 	"Unknown error"
[OCC::JsonApiJob::finished 	JsonApiJob of QUrl("https://sub.domain.example:4444/subdir/ocs/v2.php/apps/notifications/api/v2/notifications?format=json") FINISHED WITH STATUS "OK"
[OCC::JsonApiJob::finished 	Nothing changed so nothing to retrieve - status code:  304
[OCC::ServerNotificationHandler::slotNotificationsReceived 	Status code  304  Not Modified - No new notifications.
[OCC::AccessManager::createRequest 	6 "PROPFIND" "https://sub.domain.example:4444/subdir/remote.php/dav/files/<username>/" has X-Request-ID "fe26dbb2-5f3f-4f05-8418-7bbba8c67522"
[OCC::AbstractNetworkJob::start 	OCC::PropfindJob created for "https://sub.domain.example/nextcloud" + "/" "OCC::QuotaInfo"
[OCC::WebFlowCredentials::slotFinished 	request finished
[OCC::WebFlowCredentials::stillValid 	Still valid?
[OCC::WebFlowCredentials::stillValid 	QNetworkReply::NetworkError(NoError)
[OCC::WebFlowCredentials::stillValid 	"Unknown error"
[OCC::PropfindJob::finished 	PROPFIND of QUrl("https://sub.domain.example:4444/subdir/remote.php/dav/files/<username>/") FINISHED WITH STATUS "OK"

2. Web server error log:
   grepping for end_to_end_encryption found nothing

3. Server logfile: nextcloud log (data/nextcloud.log):

Details

{"reqId":"KYMqOqIeJsjRGFUlb774","level":0,"time":"2018-11-20T21:55:53+01:00","remoteAddr":"<IP2-REMOVED>","user":"admin","app":"no
app in context","method":"GET","url":"\/nextcloud\/index.phps","message":"No cache entry found for \/appdata_ocl8foq5dpr7\/end_to_end_encryption (storage: local::\/path-to\/data-dir\/nextcloud\
/, internalPath: appdata_ocl8foq5dpr7\/end_to_end_encryption)","userAgent":"Mozilla\/5.0 (X11; Fedora; Linux x86_64; rv:63.0) Gecko\/20100101 Firefox\/63.0","version":"14.0.3.0"}
{"reqId":"KYMqOqIeJsjRGFUlb774","level":0,"time":"2018-11-20T21:55:53+01:00","remoteAddr":"<IP2-REMOVED>","user":"admin","app":"no app in context","method":"GET","url":"\/nextcloud\/index.ph
ps","message":"No cache entry found for \/appdata_ocl8foq5dpr7\/end_to_end_encryption\/private-keys (storage: local::\/path-to\/data-dir\/nextcloud\/, internalPath: appdata_ocl8foq5dpr7\/end_to
_end_encryption\/private-keys)","userAgent":"Mozilla\/5.0 (X11; Fedora; Linux x86_64; rv:63.0) Gecko\/20100101 Firefox\/63.0","version":"14.0.3.0"}
{"reqId":"KYMqOqIeJsjRGFUlb774","level":0,"time":"2018-11-20T21:55:54+01:00","remoteAddr":"<IP2-REMOVED>","user":"admin","app":"no app in context","method":"GET","url":"\/nextcloud\/index.ph
ps","message":"No cache entry found for \/appdata_ocl8foq5dpr7\/end_to_end_encryption\/public-keys (storage: local::\/path-to\/data-dir\/nextcloud\/, internalPath: appdata_ocl8foq5dpr7\/end_to_
end_encryption\/public-keys)","userAgent":"Mozilla\/5.0 (X11; Fedora; Linux x86_64; rv:63.0) Gecko\/20100101 Firefox\/63.0","version":"14.0.3.0"}
{"reqId":"KYMqOqIeJsjRGFUlb774","level":0,"time":"2018-11-20T21:55:55+01:00","remoteAddr":"<IP2-REMOVED>","user":"admin","app":"no app in context","method":"GET","url":"\/nextcloud\/index.ph
ps","message":"No cache entry found for \/appdata_ocl8foq5dpr7\/avatar\/admin\/avatar.jpg (storage: local::\/path-to\/data-dir\/nextcloud\/, internalPath: appdata_ocl8foq5dpr7\/avatar\/admin\/a
vatar.jpg)","userAgent":"Mozilla\/5.0 (X11; Fedora; Linux x86_64; rv:63.0) Gecko\/20100101 Firefox\/63.0","version":"14.0.3.0"}
{"reqId":"9srd5xo6I0OBdBuYHZu1","level":3,"time":"2018-11-20T21:56:03+01:00","remoteAddr":"93.193.74.198","user":"--","app":"PHP","method":"GET","url":"\/nextcloud\/index.phpider\/","message
":"Zend OPcache can't be temporary enabled (it may be only disabled till the end of request) at Unknown#0","userAgent":"GuzzleHttp\/6.2.1 curl\/7.47.0 PHP\/7.0.32-0ubuntu0.16.04.1","version"
:"14.0.3.0"}
{"reqId":"5omzxrVFoKIVGo1G61pU","level":3,"time":"2018-11-20T21:57:32+01:00","remoteAddr":"<IP2-REMOVED>","user":"--","app":"PHP","method":"GET","url":"\/nextcloud\/status.php","message":"Ze
nd OPcache can't be temporary enabled (it may be only disabled till the end of request) at Unknown#0","userAgent":"Mozilla\/5.0 (Linux) mirall\/2.5.0git (Nextcloud)","version":"14.0.3.0"}
{"reqId":"ob6u2VN0Dkgu9Gk0bkSA","level":3,"time":"2018-11-20T21:57:44+01:00","remoteAddr":"<IP2-REMOVED>","user":"<username>","app":"PHP","method":"POST","url":"\/nextcloud\/ocs\/v2.php\/apps\/end
_to_end_encryption\/api\/v1\/public-key?format=json","message":"openssl_csr_sign(): cannot get CSR from parameter 1 at \/www\/apps\/end_to_end_encryption\/lib\/SignatureHandler.php#60","user
Agent":"Mozilla\/5.0 (Linux) mirall\/2.5.0git (Nextcloud)","version":"14.0.3.0"}
{"reqId":"ob6u2VN0Dkgu9Gk0bkSA","level":3,"time":"2018-11-20T21:57:44+01:00","remoteAddr":"<IP2-REMOVED>","user":"<username>","app":"end_to_end_encryption","method":"POST","url":"\/nextcloud\/ocs\
/v2.php\/apps\/end_to_end_encryption\/api\/v1\/public-key?format=json","message":"Can't create public key: could not sign the CSR, please make sure to submit a valid CSR","userAgent":"Mozill
a\/5.0 (Linux) mirall\/2.5.0git (Nextcloud)","version":"14.0.3.0"}
{"reqId":"jHVJxgGHZmF7CePXL5cj","level":3,"time":"2018-11-20T21:57:52+01:00","remoteAddr":"<IP2-REMOVED>","user":"<username>","app":"PHP","method":"GET","url":"\/nextcloud\/ocs\/v2.php\/apps\/noti
fications\/api\/v2\/notifications","message":"Zend OPcache can't be temporary enabled (it may be only disabled till the end of request) at Unknown#0","userAgent":"Mozilla\/5.0 (X11; Fedora;
Linux x86_64; rv:63.0) Gecko\/20100101 Firefox\/63.0","version":"14.0.3.0"}
{"reqId":"Pi1bOYabtW4anDZr4HBU","level":3,"time":"2018-11-20T21:59:54+01:00","remoteAddr":"<IP2-REMOVED>","user":"<username>","app":"PHP","method":"PROPFIND","url":"\/nextcloud\/remote.php\/caldav
\/calendars\/<username>\/fbf70b57-2fd3-4948-9c13-4a2177f2c6cb\/","message":"Zend OPcache can't be temporary enabled (it may be only disabled till the end of request) at Unknown#0","userAgent":"Evo
lution\/3.30.2","version":"14.0.3.0"}
{"reqId":"ppzVq88pRqPZCZjDYLzx","level":3,"time":"2018-11-20T22:01:24+01:00","remoteAddr":"<IP2-REMOVED>","user":"<username>","app":"PHP","method":"GET","url":"\/nextcloud\/ocs\/v1.php\/cloud\/use
r?format=json","message":"Zend OPcache can't be temporary enabled (it may be only disabled till the end of request) at Unknown#0","userAgent":"Mozilla\/5.0 (Linux) mirall\/2.5.0git (Nextclou
d)","version":"14.0.3.0"}
{"reqId":"61NeSpMDKDfMcpVCMYAo","level":3,"time":"2018-11-20T22:01:30+01:00","remoteAddr":"<IP2-REMOVED>","user":"<username>","app":"PHP","method":"POST","url":"\/nextcloud\/ocs\/v2.php\/apps\/end
_to_end_encryption\/api\/v1\/public-key?format=json","message":"openssl_csr_sign(): cannot get CSR from parameter 1 at \/www\/apps\/end_to_end_encryption\/lib\/SignatureHandler.php#60","user
Agent":"Mozilla\/5.0 (Linux) mirall\/2.5.0git (Nextcloud)","version":"14.0.3.0"}
{"reqId":"61NeSpMDKDfMcpVCMYAo","level":3,"time":"2018-11-20T22:01:30+01:00","remoteAddr":"<IP2-REMOVED>","user":"<username>","app":"end_to_end_encryption","method":"POST","url":"\/nextcloud\/ocs\
/v2.php\/apps\/end_to_end_encryption\/api\/v1\/public-key?format=json","message":"Can't create public key: could not sign the CSR, please make sure to submit a valid CSR","userAgent":"Mozill
a\/5.0 (Linux) mirall\/2.5.0git (Nextcloud)","version":"14.0.3.0"}
{"reqId":"JFfPheDVpZd2RZJhjf5x","level":3,"time":"2018-11-20T22:03:09+01:00","remoteAddr":"<IP-REMOVED>","user":"<username>","app":"PHP","method":"GET","url":"\/nextcloud\/ocs\/v1.php\/cloud\/use
rs\/<username>?format=json","message":"Zend OPcache can't be temporary enabled (it may be only disabled till the end of request) at Unknown#0","userAgent":"Mozilla\/5.0 (Android) ownCloud-android\
/3.3.2","version":"14.0.3.0"}

Searching in the web UI logs (for "encryption"), I get many of these:

…many of these:

…and nothing special anymore:

[rugk]

Any news here what I can do to troubleshoot/debug this, or is this "expected"??

[rugk]

Testing with a new user and although the setup works and it partially even syncs, it also seems to fail at some point: nextcloud/android#3291 (comment)

[theodiefenthal]

+1, same issue here.

[Baeda73]

+1, files put in an encrypted folder do not upload, blocking client forever. happens on iOS and macOS client. e2e not useable at all.
deletion of file reanimate client

[rugk]

Did I also already mention it actually blocks any file upload, even if you have multiple users connected in your desktop client and only one has this issue?

[kristog]

I have the same problem here, with the linux 2.5.1 AppImage and on windows.
I noticed that if I copy files one by one in the encrypted folder (waiting the first upload to finish before copying a new file) it works. I tested with files up to 50Mb. If I copy more than one file at time, the it will get stuck on uploading the second file (tested with 2 small files).

[SnejPro]

Same issue with 2.5.1 on windows.
Download and decryption of encrypted files works.
Upload and encryption does not work.

When i set a directory as encrypted on windows, the upload of files in this directory does not work on Android.

[marbetschar]

Same issue here on macOS (v2.5.2). Is there any known workaround?