ocis: Client displays Connection timed out after token expiration

Pre-submission Checks

  • I checked for similar issues, but could not find any. I also checked the closed issues. I could not contribute additional information to any existing issue.
  • I will take the time to fill in all the required fields. I know that the bug report may be dismissed otherwise due to lack of information.

Describe the bug

@michaelstingl showed me that when the client is uploading a folder with lots of files and the upload sync of the folder take longer than the access token lifetime, then the client eventually displays “Connection timed out”.

Then it takes either an unknown amount of time or a client restart to make the client sync again.

Expected behavior

The client should refresh the access token and transparently use the new token for the uploads.

Steps to reproduce the issue

  1. Clone the ocis repo: https://github.com/owncloud/ocis
  2. Navigate to the ocis_keycloak example: cd ocis/deployments/examples/ocis_keycloak/
  3. Add the following to the /etc/hosts file:
127.0.0.1	ocis.owncloud.test
127.0.0.1	keycloak.owncloud.test
  1. Start the services docker-compose up -d
  2. Connect the Desktop Client with ocis.owncloud.test
  3. Login with einstein:relativity
  4. Upload large folder (needs to take longer than 5 minutes since the token expires after 5 minutes, maybe use bandwidth limit)
  5. After some time see the client displaying the Connection timed out error

Screenshots

No response

Logs

client_test.log This is a mitmproxy flows file. Load it with mitmproxy -rfile=client_test.log In there you can see that after the few successful uploads, the token expired and then a bunch of PROPFINDs fail with 401 errors. Then for some reason a bunch of PROPFINDs work again and then all remaining PROPFINDs fail with 401.

Client logs:

09-13 12:26:58:713 [ info sync.propagator ]:	Starting SyncInstruction(CSYNC_INSTRUCTION_NEW) propagation of "Scott_Pilgrim/1/161.jpg" by OCC::PropagateUploadFileTUS(0x55f32533b620)
09-13 12:26:58:713 [ info sync.checksums ]:	Computing "SHA1" checksum of "/home/corby/ownCloud6/Scott_Pilgrim/1/161.jpg" in a thread
09-13 12:26:58:714 [ info sync.checksums ]:	Computing "SHA1" checksum of "/home/corby/ownCloud6/Scott_Pilgrim/1/161.jpg" in a thread
09-13 12:26:58:715 [ debug sync.database.sql ]	[ OCC::SqlQuery::bindValue ]:	SQL bind 1 "Scott_Pilgrim/1/161.jpg"
09-13 12:26:58:715 [ debug sync.propagator.upload.tus ]	[ OCC::PropagateUploadFileTUS::startNextChunk ]:	Starting creation with upload: "/Scott_Pilgrim/1/161.jpg"
09-13 12:26:58:715 [ debug sync.propagator.upload.tus ]	[ OCC::PropagateUploadFileTUS::makeCreationWithUploadJob ]:	FullPath: "/Scott_Pilgrim/1/161.jpg"
09-13 12:26:58:715 [ debug sync.propagator.upload.tus ]	[ OCC::PropagateUploadFileTUS::startNextChunk ]:	Offset: 0 0 Chunk: 220401 0
09-13 12:26:58:715 [ info sync.accessmanager ]:	4 "" "https://localhost:4242/remote.php/dav/files/einstein/" has X-Request-ID "0a3a67c5-a62a-4179-8ee0-d6941fbbc075"
09-13 12:26:58:715 [ debug sync.cookiejar ]	[ OCC::CookieJar::cookiesForUrl ]:	QUrl("https://localhost:4242/remote.php/dav/files/einstein/") requests: ()
09-13 12:26:58:715 [ info sync.httplogger ]:	"0a3a67c5-a62a-4179-8ee0-d6941fbbc075: Request: POST https://localhost:4242/remote.php/dav/files/einstein/ Header: { X-OC-Mtime: 1491235624, Content-Type: application/offset+octet-stream, Content-Length: 220401, Upload-Offset: 0, Tus-Resumable: 1.0.0, Upload-Metadata: filename L1Njb3R0X1BpbGdyaW0vMS8xNjEuanBn,checksum U0hBMSAyYThiNmVkYjUwNGQxOTI4YjIxZmI0MmVlMjFhOGUwMzFkN2VlMjQ1, Upload-Length: 220401, Authorization: Bearer [redacted], User-Agent: Mozilla/5.0 (Linux) mirall/2.10.1 (build 7187) (ownCloud, pop-5.19.0-76051900-generic ClientArchitecture: x86_64 OsArchitecture: x86_64), Accept: */*, X-Request-ID: 0a3a67c5-a62a-4179-8ee0-d6941fbbc075, Original-Request-ID: 0a3a67c5-a62a-4179-8ee0-d6941fbbc075, } Data: [220401 bytes of application/offset+octet-stream data]"
09-13 12:26:58:715 [ info sync.networkjob ]:	Created OCC::SimpleNetworkJob("https://localhost:4242/remote.php/dav/files/einstein/", "0a3a67c5-a62a-4179-8ee0-d6941fbbc075", "0a3a67c5-a62a-4179-8ee0-d6941fbbc075") for OCC::PropagateUploadFileTUS(0x55f32533b620)
09-13 12:26:59:618 [ debug sync.bandwidthmanager ]	[ OCC::BandwidthManager::absoluteLimitTimerExpired ]:	100000 1 100000
09-13 12:26:59:618 [ debug sync.bandwidthmanager ]	[ OCC::BandwidthManager::absoluteLimitTimerExpired ]:	Gave  97.6563  kB to OCC::UploadDevice(0x55f3253b8a90)
09-13 12:27:00:618 [ debug sync.bandwidthmanager ]	[ OCC::BandwidthManager::absoluteLimitTimerExpired ]:	100000 1 100000
09-13 12:27:00:618 [ debug sync.bandwidthmanager ]	[ OCC::BandwidthManager::absoluteLimitTimerExpired ]:	Gave  97.6563  kB to OCC::UploadDevice(0x55f3253b8a90)
09-13 12:27:00:924 [ info gui.socketapi ]:	Received SocketAPI message <-- "GET_MENU_ITEMS:/home/corby/ownCloud6/Orientation/\u001E/home/corby/ownCloud6/Scott_Pilgrim/" from QLocalSocket(0x55f32442ffd0)
09-13 12:27:00:924 [ info gui.socketapi ]:	Sending SocketAPI message --> "GET_MENU_ITEMS:BEGIN" to QLocalSocket(0x55f32442ffd0)
09-13 12:27:00:925 [ info gui.socketapi ]:	Sending SocketAPI message --> "GET_MENU_ITEMS:END" to QLocalSocket(0x55f32442ffd0)
09-13 12:27:01:617 [ debug sync.bandwidthmanager ]	[ OCC::BandwidthManager::absoluteLimitTimerExpired ]:	100000 1 100000
09-13 12:27:01:618 [ debug sync.bandwidthmanager ]	[ OCC::BandwidthManager::absoluteLimitTimerExpired ]:	Gave  97.6563  kB to OCC::UploadDevice(0x55f3253b8a90)
09-13 12:27:01:624 [ info gui.socketapi ]:	Received SocketAPI message <-- "GET_MENU_ITEMS:/home/corby/ownCloud6/Orientation/\u001E/home/corby/ownCloud6/Scott_Pilgrim/" from QLocalSocket(0x55f32442ffd0)
09-13 12:27:01:624 [ info gui.socketapi ]:	Sending SocketAPI message --> "GET_MENU_ITEMS:BEGIN" to QLocalSocket(0x55f32442ffd0)
09-13 12:27:01:624 [ info gui.socketapi ]:	Sending SocketAPI message --> "GET_MENU_ITEMS:END" to QLocalSocket(0x55f32442ffd0)
09-13 12:27:01:710 [ info sync.httplogger ]:	"0a3a67c5-a62a-4179-8ee0-d6941fbbc075: Response: POST 401 https://localhost:4242/remote.php/dav/files/einstein/ Header: { Content-Length: 0, Date: Tue, 13 Sep 2022 10:27:01 GMT, Www-Authenticate: Bearer realm=\"ocis.owncloud.test\", charset=\"UTF-8\", } Data: []"
09-13 12:27:01:710 [ debug sync.networkjob.jobqueue ]	[ OCC::JobQueue::retry ]:	Direct retry OCC::SimpleNetworkJob("https://localhost:4242/remote.php/dav/files/einstein/", "0a3a67c5-a62a-4179-8ee0-d6941fbbc075", "0a3a67c5-a62a-4179-8ee0-d6941fbbc075", "Host requires authentication")
09-13 12:27:01:710 [ info sync.networkjob ]:	Restarting "POST" QUrl("https://localhost:4242/remote.php/dav/files/einstein/") for the 1 time
09-13 12:27:01:710 [ info sync.accessmanager ]:	4 "" "https://localhost:4242/remote.php/dav/files/einstein/" has X-Request-ID "f1a0e3dc-8168-4574-aa82-31555acefa1a"
09-13 12:27:01:710 [ debug sync.cookiejar ]	[ OCC::CookieJar::cookiesForUrl ]:	QUrl("https://localhost:4242/remote.php/dav/files/einstein/") requests: ()
09-13 12:27:01:710 [ info sync.httplogger ]:	"f1a0e3dc-8168-4574-aa82-31555acefa1a: Request: POST https://localhost:4242/remote.php/dav/files/einstein/ Header: { X-OC-Mtime: 1491235624, Content-Type: application/offset+octet-stream, Content-Length: 220401, Upload-Offset: 0, Tus-Resumable: 1.0.0, Upload-Metadata: filename L1Njb3R0X1BpbGdyaW0vMS8xNjEuanBn,checksum U0hBMSAyYThiNmVkYjUwNGQxOTI4YjIxZmI0MmVlMjFhOGUwMzFkN2VlMjQ1, Upload-Length: 220401, Original-Request-ID: 0a3a67c5-a62a-4179-8ee0-d6941fbbc075, Authorization: Bearer [redacted], User-Agent: Mozilla/5.0 (Linux) mirall/2.10.1 (build 7187) (ownCloud, pop-5.19.0-76051900-generic ClientArchitecture: x86_64 OsArchitecture: x86_64), Accept: */*, X-Request-ID: f1a0e3dc-8168-4574-aa82-31555acefa1a, } Data: [220401 bytes of application/offset+octet-stream data]"
09-13 12:27:01:710 [ debug sync.networkjob ]	[ OCC::AbstractNetworkJob::slotFinished ]:	Queuing:  QUrl("https://localhost:4242/remote.php/dav/files/einstein/")  for retry
09-13 12:27:04:618 [ info sync.accessmanager ]:	6 "PROPFIND" "https://localhost:4242/remote.php/webdav/" has X-Request-ID "c42ac82f-15e8-442b-afca-a252c4cc6265"
09-13 12:27:04:618 [ debug sync.cookiejar ]	[ OCC::CookieJar::cookiesForUrl ]:	QUrl("https://localhost:4242/remote.php/webdav/") requests: ()
09-13 12:27:04:619 [ info sync.httplogger ]:	"c42ac82f-15e8-442b-afca-a252c4cc6265: Request: PROPFIND https://localhost:4242/remote.php/webdav/ Header: { Depth: 0, Authorization: Bearer [redacted], User-Agent: Mozilla/5.0 (Linux) mirall/2.10.1 (build 7187) (ownCloud, pop-5.19.0-76051900-generic ClientArchitecture: x86_64 OsArchitecture: x86_64), Accept: */*, Content-Type: text/xml; charset=utf-8, X-Request-ID: c42ac82f-15e8-442b-afca-a252c4cc6265, Original-Request-ID: c42ac82f-15e8-442b-afca-a252c4cc6265, Content-Length: 144, } Data: [<?xml version=\"1.0\" encoding=\"utf-8\"?><d:propfind xmlns:d=\"DAV:\"><d:prop><d:quota-available-bytes/><d:quota-used-bytes/></d:prop>M</d:propfind>\n]"
09-13 12:27:04:619 [ info sync.networkjob ]:	Created OCC::PropfindJob("https://localhost:4242/remote.php/webdav/", "c42ac82f-15e8-442b-afca-a252c4cc6265", "c42ac82f-15e8-442b-afca-a252c4cc6265") for OCC::QuotaInfo(0x55f325419b68)
09-13 12:27:04:705 [ info sync.httplogger ]:	"c42ac82f-15e8-442b-afca-a252c4cc6265: Response: PROPFIND 401 https://localhost:4242/remote.php/webdav/ Header: { Content-Length: 211, Content-Type: text/xml; charset=utf-8, Date: Tue, 13 Sep 2022 10:27:04 GMT, Www-Authenticate: Bearer realm=\"ocis.owncloud.test\", charset=\"UTF-8\", } Data: [<?xml version=\"1.0\" encoding=\"UTF-8\"?>\n<d:error xmlns:d=\"DAV\" xmlns:s=\"http://sabredav.org/ns\"><s:Exception>Sabre\\DAV\\Exception\\PermissionDenied</s:Exception><s:Message>Authentication error</s:Message></d:error>]"
09-13 12:27:04:705 [ debug sync.networkjob.jobqueue ]	[ OCC::JobQueue::retry ]:	Direct retry OCC::PropfindJob("https://localhost:4242/remote.php/webdav/", "c42ac82f-15e8-442b-afca-a252c4cc6265", "c42ac82f-15e8-442b-afca-a252c4cc6265", "Host requires authentication")
09-13 12:27:04:705 [ info sync.networkjob ]:	Restarting "PROPFIND" QUrl("https://localhost:4242/remote.php/webdav/") for the 1 time
09-13 12:27:04:705 [ info sync.accessmanager ]:	6 "PROPFIND" "https://localhost:4242/remote.php/webdav/" has X-Request-ID "efcd84b3-6633-45ec-8b84-5bd713942ab8"
09-13 12:27:04:705 [ debug sync.cookiejar ]	[ OCC::CookieJar::cookiesForUrl ]:	QUrl("https://localhost:4242/remote.php/webdav/") requests: ()
09-13 12:27:04:705 [ info sync.httplogger ]:	"efcd84b3-6633-45ec-8b84-5bd713942ab8: Request: PROPFIND https://localhost:4242/remote.php/webdav/ Header: { Depth: 0, Original-Request-ID: c42ac82f-15e8-442b-afca-a252c4cc6265, Content-Length: 144, Authorization: Bearer [redacted], User-Agent: Mozilla/5.0 (Linux) mirall/2.10.1 (build 7187) (ownCloud, pop-5.19.0-76051900-generic ClientArchitecture: x86_64 OsArchitecture: x86_64), Accept: */*, Content-Type: text/xml; charset=utf-8, X-Request-ID: efcd84b3-6633-45ec-8b84-5bd713942ab8, } Data: [<?xml version=\"1.0\" encoding=\"utf-8\"?><d:propfind xmlns:d=\"DAV:\"><d:prop><d:quota-available-bytes/><d:quota-used-bytes/></d:prop>M</d:propfind>\n]"
09-13 12:27:04:705 [ debug sync.networkjob ]	[ OCC::AbstractNetworkJob::slotFinished ]:	Queuing:  QUrl("https://localhost:4242/remote.php/webdav/")  for retry
09-13 12:27:04:805 [ info sync.httplogger ]:	"efcd84b3-6633-45ec-8b84-5bd713942ab8: Response: PROPFIND 401 https://localhost:4242/remote.php/webdav/ Header: { Content-Length: 211, Content-Type: text/xml; charset=utf-8, Date: Tue, 13 Sep 2022 10:27:04 GMT, Www-Authenticate: Bearer realm=\"ocis.owncloud.test\", charset=\"UTF-8\", } Data: [<?xml version=\"1.0\" encoding=\"UTF-8\"?>\n<d:error xmlns:d=\"DAV\" xmlns:s=\"http://sabredav.org/ns\"><s:Exception>Sabre\\DAV\\Exception\\PermissionDenied</s:Exception><s:Message>Authentication error</s:Message></d:error>]"
09-13 12:27:04:805 [ debug sync.networkjob.jobqueue ]	[ OCC::JobQueue::retry ]:	Direct retry OCC::PropfindJob("https://localhost:4242/remote.php/webdav/", "c42ac82f-15e8-442b-afca-a252c4cc6265", "efcd84b3-6633-45ec-8b84-5bd713942ab8", "Host requires authentication")
09-13 12:27:04:805 [ info sync.networkjob ]:	Restarting "PROPFIND" QUrl("https://localhost:4242/remote.php/webdav/") for the 2 time
09-13 12:27:04:805 [ info sync.accessmanager ]:	6 "PROPFIND" "https://localhost:4242/remote.php/webdav/" has X-Request-ID "49f8d52f-88a2-4162-a47a-891bb0f80dc3"
09-13 12:27:04:805 [ debug sync.cookiejar ]	[ OCC::CookieJar::cookiesForUrl ]:	QUrl("https://localhost:4242/remote.php/webdav/") requests: ()
09-13 12:27:04:805 [ info sync.httplogger ]:	"49f8d52f-88a2-4162-a47a-891bb0f80dc3: Request: PROPFIND https://localhost:4242/remote.php/webdav/ Header: { Depth: 0, Original-Request-ID: c42ac82f-15e8-442b-afca-a252c4cc6265, Content-Length: 144, Authorization: Bearer [redacted], User-Agent: Mozilla/5.0 (Linux) mirall/2.10.1 (build 7187) (ownCloud, pop-5.19.0-76051900-generic ClientArchitecture: x86_64 OsArchitecture: x86_64), Accept: */*, Content-Type: text/xml; charset=utf-8, X-Request-ID: 49f8d52f-88a2-4162-a47a-891bb0f80dc3, } Data: [<?xml version=\"1.0\" encoding=\"utf-8\"?><d:propfind xmlns:d=\"DAV:\"><d:prop><d:quota-available-bytes/><d:quota-used-bytes/></d:prop>M</d:propfind>\n]"
09-13 12:27:04:805 [ debug sync.networkjob ]	[ OCC::AbstractNetworkJob::slotFinished ]:	Queuing:  QUrl("https://localhost:4242/remote.php/webdav/")  for retry
09-13 12:27:04:909 [ info sync.httplogger ]:	"49f8d52f-88a2-4162-a47a-891bb0f80dc3: Response: PROPFIND 401 https://localhost:4242/remote.php/webdav/ Header: { Content-Length: 211, Content-Type: text/xml; charset=utf-8, Date: Tue, 13 Sep 2022 10:27:04 GMT, Www-Authenticate: Bearer realm=\"ocis.owncloud.test\", charset=\"UTF-8\", } Data: [<?xml version=\"1.0\" encoding=\"UTF-8\"?>\n<d:error xmlns:d=\"DAV\" xmlns:s=\"http://sabredav.org/ns\"><s:Exception>Sabre\\DAV\\Exception\\PermissionDenied</s:Exception><s:Message>Authentication error</s:Message></d:error>]"
09-13 12:27:04:909 [ debug sync.networkjob.jobqueue ]	[ OCC::JobQueue::retry ]:	Direct retry OCC::PropfindJob("https://localhost:4242/remote.php/webdav/", "c42ac82f-15e8-442b-afca-a252c4cc6265", "49f8d52f-88a2-4162-a47a-891bb0f80dc3", "Host requires authentication")
09-13 12:27:04:909 [ info sync.networkjob ]:	Restarting "PROPFIND" QUrl("https://localhost:4242/remote.php/webdav/") for the 3 time
09-13 12:27:04:909 [ info sync.accessmanager ]:	6 "PROPFIND" "https://localhost:4242/remote.php/webdav/" has X-Request-ID "be5f664a-b37e-4f24-8fbb-549aaf77b4a2"
09-13 12:27:04:910 [ debug sync.cookiejar ]	[ OCC::CookieJar::cookiesForUrl ]:	QUrl("https://localhost:4242/remote.php/webdav/") requests: ()
09-13 12:27:04:910 [ info sync.httplogger ]:	"be5f664a-b37e-4f24-8fbb-549aaf77b4a2: Request: PROPFIND https://localhost:4242/remote.php/webdav/ Header: { Depth: 0, Original-Request-ID: c42ac82f-15e8-442b-afca-a252c4cc6265, Content-Length: 144, Authorization: Bearer [redacted], User-Agent: Mozilla/5.0 (Linux) mirall/2.10.1 (build 7187) (ownCloud, pop-5.19.0-76051900-generic ClientArchitecture: x86_64 OsArchitecture: x86_64), Accept: */*, Content-Type: text/xml; charset=utf-8, X-Request-ID: be5f664a-b37e-4f24-8fbb-549aaf77b4a2, } Data: [<?xml version=\"1.0\" encoding=\"utf-8\"?><d:propfind xmlns:d=\"DAV:\"><d:prop><d:quota-available-bytes/><d:quota-used-bytes/></d:prop>M</d:propfind>\n]"
09-13 12:27:04:910 [ debug sync.networkjob ]	[ OCC::AbstractNetworkJob::slotFinished ]:	Queuing:  QUrl("https://localhost:4242/remote.php/webdav/")  for retry
09-13 12:27:05:006 [ info sync.httplogger ]:	"be5f664a-b37e-4f24-8fbb-549aaf77b4a2: Response: PROPFIND 401 https://localhost:4242/remote.php/webdav/ Header: { Content-Length: 211, Content-Type: text/xml; charset=utf-8, Date: Tue, 13 Sep 2022 10:27:04 GMT, Www-Authenticate: Bearer realm=\"ocis.owncloud.test\", charset=\"UTF-8\", } Data: [<?xml version=\"1.0\" encoding=\"UTF-8\"?>\n<d:error xmlns:d=\"DAV\" xmlns:s=\"http://sabredav.org/ns\"><s:Exception>Sabre\\DAV\\Exception\\PermissionDenied</s:Exception><s:Message>Authentication error</s:Message></d:error>]"
09-13 12:27:05:006 [ debug sync.networkjob.jobqueue ]	[ OCC::JobQueue::retry ]:	Direct retry OCC::PropfindJob("https://localhost:4242/remote.php/webdav/", "c42ac82f-15e8-442b-afca-a252c4cc6265", "be5f664a-b37e-4f24-8fbb-549aaf77b4a2", "Host requires authentication")
09-13 12:27:05:006 [ info sync.networkjob ]:	Restarting "PROPFIND" QUrl("https://localhost:4242/remote.php/webdav/") for the 4 time
09-13 12:27:05:006 [ info sync.accessmanager ]:	6 "PROPFIND" "https://localhost:4242/remote.php/webdav/" has X-Request-ID "3dac4c95-3f39-4260-8d14-6888ac45cf22"
09-13 12:27:05:006 [ debug sync.cookiejar ]	[ OCC::CookieJar::cookiesForUrl ]:	QUrl("https://localhost:4242/remote.php/webdav/") requests: ()
09-13 12:27:05:006 [ info sync.httplogger ]:	"3dac4c95-3f39-4260-8d14-6888ac45cf22: Request: PROPFIND https://localhost:4242/remote.php/webdav/ Header: { Depth: 0, Original-Request-ID: c42ac82f-15e8-442b-afca-a252c4cc6265, Content-Length: 144, Authorization: Bearer [redacted], User-Agent: Mozilla/5.0 (Linux) mirall/2.10.1 (build 7187) (ownCloud, pop-5.19.0-76051900-generic ClientArchitecture: x86_64 OsArchitecture: x86_64), Accept: */*, Content-Type: text/xml; charset=utf-8, X-Request-ID: 3dac4c95-3f39-4260-8d14-6888ac45cf22, } Data: [<?xml version=\"1.0\" encoding=\"utf-8\"?><d:propfind xmlns:d=\"DAV:\"><d:prop><d:quota-available-bytes/><d:quota-used-bytes/></d:prop>M</d:propfind>\n]"
09-13 12:27:05:006 [ debug sync.networkjob ]	[ OCC::AbstractNetworkJob::slotFinished ]:	Queuing:  QUrl("https://localhost:4242/remote.php/webdav/")  for retry
09-13 12:27:05:113 [ info sync.httplogger ]:	"3dac4c95-3f39-4260-8d14-6888ac45cf22: Response: PROPFIND 401 https://localhost:4242/remote.php/webdav/ Header: { Content-Length: 211, Content-Type: text/xml; charset=utf-8, Date: Tue, 13 Sep 2022 10:27:05 GMT, Www-Authenticate: Bearer realm=\"ocis.owncloud.test\", charset=\"UTF-8\", } Data: [<?xml version=\"1.0\" encoding=\"UTF-8\"?>\n<d:error xmlns:d=\"DAV\" xmlns:s=\"http://sabredav.org/ns\"><s:Exception>Sabre\\DAV\\Exception\\PermissionDenied</s:Exception><s:Message>Authentication error</s:Message></d:error>]"
09-13 12:27:05:113 [ debug sync.networkjob.jobqueue ]	[ OCC::JobQueue::retry ]:	Direct retry OCC::PropfindJob("https://localhost:4242/remote.php/webdav/", "c42ac82f-15e8-442b-afca-a252c4cc6265", "3dac4c95-3f39-4260-8d14-6888ac45cf22", "Host requires authentication")
09-13 12:27:05:113 [ info sync.networkjob ]:	Restarting "PROPFIND" QUrl("https://localhost:4242/remote.php/webdav/") for the 5 time
09-13 12:27:05:114 [ info sync.accessmanager ]:	6 "PROPFIND" "https://localhost:4242/remote.php/webdav/" has X-Request-ID "c42e038f-a0d7-41b4-85b3-2403689bd671"
09-13 12:27:05:114 [ debug sync.cookiejar ]	[ OCC::CookieJar::cookiesForUrl ]:	QUrl("https://localhost:4242/remote.php/webdav/") requests: ()
09-13 12:27:05:114 [ info sync.httplogger ]:	"c42e038f-a0d7-41b4-85b3-2403689bd671: Request: PROPFIND https://localhost:4242/remote.php/webdav/ Header: { Depth: 0, Original-Request-ID: c42ac82f-15e8-442b-afca-a252c4cc6265, Content-Length: 144, Authorization: Bearer [redacted], User-Agent: Mozilla/5.0 (Linux) mirall/2.10.1 (build 7187) (ownCloud, pop-5.19.0-76051900-generic ClientArchitecture: x86_64 OsArchitecture: x86_64), Accept: */*, Content-Type: text/xml; charset=utf-8, X-Request-ID: c42e038f-a0d7-41b4-85b3-2403689bd671, } Data: [<?xml version=\"1.0\" encoding=\"utf-8\"?><d:propfind xmlns:d=\"DAV:\"><d:prop><d:quota-available-bytes/><d:quota-used-bytes/></d:prop>M</d:propfind>\n]"
09-13 12:27:05:114 [ debug sync.networkjob ]	[ OCC::AbstractNetworkJob::slotFinished ]:	Queuing:  QUrl("https://localhost:4242/remote.php/webdav/")  for retry
09-13 12:27:05:226 [ info sync.httplogger ]:	"c42e038f-a0d7-41b4-85b3-2403689bd671: Response: PROPFIND 401 https://localhost:4242/remote.php/webdav/ Header: { Content-Length: 211, Content-Type: text/xml; charset=utf-8, Date: Tue, 13 Sep 2022 10:27:05 GMT, Www-Authenticate: Bearer realm=\"ocis.owncloud.test\", charset=\"UTF-8\", } Data: [<?xml version=\"1.0\" encoding=\"UTF-8\"?>\n<d:error xmlns:d=\"DAV\" xmlns:s=\"http://sabredav.org/ns\"><s:Exception>Sabre\\DAV\\Exception\\PermissionDenied</s:Exception><s:Message>Authentication error</s:Message></d:error>]"
09-13 12:27:05:226 [ debug sync.networkjob ]	[ OCC::AbstractNetworkJob::needsRetry ]:	Not Retry too many retries 5 OCC::PropfindJob("https://localhost:4242/remote.php/webdav/", "c42ac82f-15e8-442b-afca-a252c4cc6265", "c42e038f-a0d7-41b4-85b3-2403689bd671", "Host requires authentication") QUrl("https://localhost:4242/remote.php/webdav/")
09-13 12:27:05:226 [ warning sync.networkjob ]:	OCC::PropfindJob("https://localhost:4242/remote.php/webdav/", "c42ac82f-15e8-442b-afca-a252c4cc6265", "c42e038f-a0d7-41b4-85b3-2403689bd671", "Host requires authentication") QNetworkReply::AuthenticationRequiredError "Host requires authentication" 401
09-13 12:27:05:226 [ info sync.networkjob.lscol ]:	LSCOL of QUrl("https://localhost:4242/remote.php/webdav/") FINISHED WITH STATUS "AuthenticationRequiredError Host requires authentication"
09-13 12:27:05:226 [ debug sync.networkjob ]	[ OCC::AbstractNetworkJob::slotFinished ]:	Network job finished OCC::PropfindJob("https://localhost:4242/remote.php/webdav/", "c42ac82f-15e8-442b-afca-a252c4cc6265", "c42e038f-a0d7-41b4-85b3-2403689bd671", "Host requires authentication")

Client version number

ownCloud Version 2.10.1 (build 7187) but also reproducible with the current testing client version.

Desktop environment (Linux only)

No response

Client package version and origin (Linux only)

No response

Installation path (Windows only)

No response

Server information

Current oCIS see description above

Additional context

No response

About this issue

  • Original URL
  • State: closed
  • Created 2 years ago
  • Comments: 36 (32 by maintainers)

Commits related to this issue

Most upvoted comments

Basically our problem is summarized in https://github.com/golang/go/issues/15527, which is also referenced in the underlying code:

https://github.com/golang/go/blob/d5de62df152baf4de6e9fe81933319b86fd95ae4/src/net/http/server.go#L1357-L1417

It can easily be triggered by a curl command:

curl -X POST -k -vv -H 'Expect:' -H 'Connection: keep-alive' --http1.1 -H 'Authorization: Bearer eyJhbGciOiJQUzI1NiIsImtpZCI6InByaXZhdGUta2V5IiwidHlwIjoiSldUIn0' --data-binary @/tmp/curl-body 'https://localhost:9200/dav/spaces/fooobar' 'https://localhost:9200/dav/spaces/bazfoo'

(where /tmp/curl-body is a big file).

@wkloucek Thank you for investigating! Very valuable insights!