Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Use the "s:message" from erroneous requests on their "Issue" column #6459

Closed
SamuAlfageme opened this issue Apr 17, 2018 · 14 comments
Closed
Assignees
Labels
Milestone

Comments

@SamuAlfageme
Copy link
Contributor

SamuAlfageme commented Apr 17, 2018

I was just testing the fix in owncloud/core#29794 (comment) and realized we could rethink the way client/server errors get displayed:

screen shot 2018-04-17 at 09 29 48

The "Issue" on the "Not Synced" tab reads as follows:

Server replied "403 Forbidden" to "GET https://alfageme.solidgear.prv/remote.php/dav/files/admin/mr-nobody-yify-english.srt"

Which does not contain the actual reasons for the issue. On the body of the response we have more info of the actual problem:

<?xml version="1.0" encoding="utf-8"?>
<d:error xmlns:d="DAV:" xmlns:s="http://sabredav.org/ns">
  <s:exception>Sabre\DAV\Exception\Forbidden</s:exception>
  <s:message>Encryption not ready: Private Key missing for user: please try to log-out and log-in again</s:message>
</d:error>

Replacing the full WebDAV path that failed (not that useful since the user already has this info in the "File" entry) by the s:message on the reply would be more useful and somehow user-friendly.

Of course, if said response does not contain such s:message, we can use the old logic as fallback.

@ogoffart
Copy link
Contributor

Normally this was already supposed to be the case. AbstractNetworkJob::errorStringParsingBody is supposed to extrace the Message.
So this is not working as expected.

@SamuAlfageme
Copy link
Contributor Author

@ogoffart can't see this working on latest nightly, might be missing something 😕

With the steps from my original #6459 (comment) (the one for fetching files with oauth2 + user-key encryption enabled owncloud/oauth2#105) I'm still seeing the long "issue" text.

@guruz guruz removed the ReadyToTest QA, please validate the fix/enhancement label Apr 25, 2018
@SamuAlfageme
Copy link
Contributor Author

Seen w/ files firewall as well - in that case; there's a bogus timer as well:

Server replied "403 Forbidden" to "GET https://alfageme/remote.php/dav/files/admin/Documents/Example.odt" (skipped due to earlier error, trying again in 9 second(s))

i.e. does not update reactively.

@guruz guruz added this to the 2.5.0 milestone May 30, 2018
@guruz
Copy link
Contributor

guruz commented May 30, 2018

blue-ticket, moved into milestone

ogoffart added a commit that referenced this issue May 30, 2018
We want to keep the body so we can get the message from it
(Issue #6459)

TestDownload::testErrorMessage did not fail because the FakeErrorReply
did not emit readyRead and did not implement bytesAvailable.
ogoffart added a commit that referenced this issue May 31, 2018
We want to keep the body so we can get the message from it
(Issue #6459)

TestDownload::testErrorMessage did not fail because the FakeErrorReply
did not emit readyRead and did not implement bytesAvailable.
ogoffart added a commit that referenced this issue Jun 1, 2018
We want to keep the body so we can get the message from it
(Issue #6459)

TestDownload::testErrorMessage did not fail because the FakeErrorReply
did not emit readyRead and did not implement bytesAvailable.
@ogoffart ogoffart added the ReadyToTest QA, please validate the fix/enhancement label Jun 4, 2018
@SamuAlfageme
Copy link
Contributor Author

Still reproducing in today's daily build w/ the files firewall 403 s:message:

screenshot 2018-06-06 10 54 12

@SamuAlfageme SamuAlfageme removed the ReadyToTest QA, please validate the fix/enhancement label Jun 6, 2018
@ogoffart
Copy link
Contributor

ogoffart commented Jun 7, 2018

Strange, this works for me with the file firewall on linux.
Can you paste the log? Does the error show there or not at all?

@SamuAlfageme
Copy link
Contributor Author

@ogoffart from 2.5.0alpha1 :

06-07 09:41:33:688 [ warning sync.networkjob ]:	QNetworkReply::NetworkError(ContentAccessDenied) "Server replied \"403 Forbidden\" to \"GET https://alfageme:9643/remote.php/dav/files/admin/Documents/Example.odt\"" QVariant(int, 403)
06-07 09:41:33:689 [ warning sync.propagator ]:	Probably firewall error:  403 , blacklisting up to 1h only
06-07 09:41:33:690 [ info sync.database ]:	Setting blacklist entry for  "Documents/Example.odt" 1 "Server replied \"403 Forbidden\" to \"GET https://alfageme:9643/remote.php/dav/files/admin/Documents/Example.odt\"" 1528357293 25 1528268975 "0576cdaed4f873bfe2ac32834cde5b25" "" 0
06-07 09:41:33:691 [ warning sync.propagator ]:	Could not complete propagation of "Documents/Example.odt" by OCC::PropagateDownloadFile(0x7fea13521100) with status 2 and error: "Server replied \"403 Forbidden\" to \"GET https://alfageme:9643/remote.php/dav/files/admin/Documents/Example.odt\""
06-07 09:41:33:752 [ info gui.account.manager ]:	Saving account "https://alfageme:9643"
06-07 09:41:33:753 [ info gui.account.manager ]:	Saving  1  unknown certs.
06-07 09:41:33:753 [ info gui.account.manager ]:	Saving cookies. "/Users/salfageme/Library/Preferences/ownCloud/cookies0.db"
06-07 09:41:33:757 [ info gui.account.manager ]:	Saved account settings, status: QSettings::Status(NoError)
06-07 09:41:33:758 [ info sync.account ]:	"SSL-Errors happened for url  \"https://alfageme:9643/remote.php/dav/files/admin/Photos/Squirrel.jpg\" \tError in  QSslCertificate(\"3\", \"0d:7e:4a:60:66:d1\", \"3vFoJ/z2G9t+WuPI9UGaqQ==\", (\"mitmproxy\"), (\"mitmproxy\"), QMap(), QDateTime(2017-01-03 08:54:47.000 UTC Qt::TimeSpec(UTC)), QDateTime(2020-01-05 08:54:47.000 UTC Qt::TimeSpec(UTC))) : \"The root certificate of the certificate chain is self-signed, and untrusted\" ( \"The root certificate of the certificate chain is self-signed, and untrusted\" ) \n " Certs are known and trusted! This is not an actual error.
06-07 09:41:34:013 [ warning sync.networkjob ]:	QNetworkReply::NetworkError(ContentAccessDenied) "Server replied \"403 Forbidden\" to \"GET https://alfageme:9643/remote.php/dav/files/admin/Photos/Paris.jpg\"" QVariant(int, 403)
06-07 09:41:34:015 [ warning sync.propagator ]:	Probably firewall error:  403 , blacklisting up to 1h only
06-07 09:41:34:016 [ info sync.database ]:	Setting blacklist entry for  "Photos/Paris.jpg" 1 "Server replied \"403 Forbidden\" to \"GET https://alfageme:9643/remote.php/dav/files/admin/Photos/Paris.jpg\"" 1528357294 25 1528268975 "3ffd639284a71e4dba6c7333b858a747" "" 0
06-07 09:41:34:016 [ warning sync.propagator ]:	Could not complete propagation of "Photos/Paris.jpg" by OCC::PropagateDownloadFile(0x7fea11980ec0) with status 2 and error: "Server replied \"403 Forbidden\" to \"GET https://alfageme:9643/remote.php/dav/files/admin/Photos/Paris.jpg\""
06-07 09:41:34:028 [ info sync.propagator ]:	Starting INSTRUCTION_NEW propagation of "ownCloud Manual.pdf" by OCC::PropagateDownloadFile(0x7fea11d7fe60)
06-07 09:41:34:029 [ warning sync.propagator ]:	No valid fileinfo
06-07 09:41:34:030 [ info sync.accessmanager ]:	2 "" "https://alfageme:9643/remote.php/dav/files/admin/ownCloud Manual.pdf" has X-Request-ID "c0228666-edbd-489a-9b81-b15222873f90"
06-07 09:41:34:031 [ info sync.networkjob ]:	OCC::GETFileJob created for "https://alfageme" + "/ownCloud Manual.pdf" "OCC::PropagateDownloadFile"
06-07 09:41:34:210 [ warning sync.networkjob ]:	QNetworkReply::NetworkError(ContentAccessDenied) "Server replied \"403 Forbidden\" to \"GET https://alfageme:9643/remote.php/dav/files/admin/Photos/San Francisco.jpg\"" QVariant(int, 403)
06-07 09:41:34:211 [ warning sync.propagator ]:	Probably firewall error:  403 , blacklisting up to 1h only
06-07 09:41:34:211 [ info sync.database ]:	Setting blacklist entry for  "Photos/San Francisco.jpg" 1 "Server replied \"403 Forbidden\" to \"GET https://alfageme:9643/remote.php/dav/files/admin/Photos/San Francisco.jpg\"" 1528357294 25 1528268975 "ae124405fe0bf1c2e79c40747158a017" "" 0
06-07 09:41:34:212 [ warning sync.propagator ]:	Could not complete propagation of "Photos/San Francisco.jpg" by OCC::PropagateDownloadFile(0x7fea11d84250) with status 2 and error: "Server replied \"403 Forbidden\" to \"GET https://alfageme:9643/remote.php/dav/files/admin/Photos/San Francisco.jpg\""
06-07 09:41:34:357 [ warning sync.networkjob ]:	QNetworkReply::NetworkError(ContentAccessDenied) "Server replied \"403 Forbidden\" to \"GET https://alfageme:9643/remote.php/dav/files/admin/Photos/Squirrel.jpg\"" QVariant(int, 403)
06-07 09:41:34:358 [ warning sync.propagator ]:	Probably firewall error:  403 , blacklisting up to 1h only
06-07 09:41:34:359 [ info sync.database ]:	Setting blacklist entry for  "Photos/Squirrel.jpg" 1 "Server replied \"403 Forbidden\" to \"GET https://alfageme:9643/remote.php/dav/files/admin/Photos/Squirrel.jpg\"" 1528357294 25 1528268975 "bc90defaeb830d3f53c8c618596c9c6c" "" 0
06-07 09:41:34:359 [ warning sync.propagator ]:	Could not complete propagation of "Photos/Squirrel.jpg" by OCC::PropagateDownloadFile(0x7fea11c97a60) with status 2 and error: "Server replied \"403 Forbidden\" to \"GET https://alfageme:9643/remote.php/dav/files/admin/Photos/Squirrel.jpg\""
06-07 09:41:34:464 [ warning sync.networkjob ]:	QNetworkReply::NetworkError(ContentAccessDenied) "Server replied \"403 Forbidden\" to \"GET https://alfageme:9643/remote.php/dav/files/admin/ownCloud Manual.pdf\"" QVariant(int, 403)
06-07 09:41:34:465 [ warning sync.propagator ]:	Probably firewall error:  403 , blacklisting up to 1h only
06-07 09:41:34:465 [ info sync.database ]:	Setting blacklist entry for  "ownCloud Manual.pdf" 1 "Server replied \"403 Forbidden\" to \"GET https://alfageme:9643/remote.php/dav/files/admin/ownCloud Manual.pdf\"" 1528357294 25 1528268975 "6db6243091f7683fec1d38687a45f66d" "" 0
06-07 09:41:34:465 [ warning sync.propagator ]:	Could not complete propagation of "ownCloud Manual.pdf" by OCC::PropagateDownloadFile(0x7fea11d7fe60) with status 2 and error: "Server replied \"403 Forbidden\" to \"GET https://alfageme:9643/remote.php/dav/files/admin/ownCloud Manual.pdf\""
06-07 09:41:34:478 [ info sync.database ]:	Closing DB "/Users/salfageme/ownCloud13/._sync_34336c1fcdf8.db"

@ogoffart
Copy link
Contributor

ogoffart commented Jun 7, 2018

Ah, the patch was not in the alpha.

@SamuAlfageme
Copy link
Contributor Author

@ogoffart with 2.6.0-daily20180607 (build 9936) I don't even get my folder sync connections to green status:

screenshot 2018-06-07 10 47 47

For some reason it also displays a bogus progress value (i.e. 2KB) and creates hidden zero-byte file ".Squirrel.jpg.~468f1778" on disk.

06-07 10:47:20:679 [ info gui.folder ]:	#### Propagation start ####################################################
06-07 10:47:20:681 [ info gui.application ]:	Sync state changed for folder  "https://alfageme:9643/remote.php/dav/files/admin/" :  "Sync Running"
06-07 10:47:20:708 [ info sync.propagator ]:	Starting INSTRUCTION_NEW propagation of "Documents" by OCC::PropagateLocalMkdir(0x7fc1f33dc760)
06-07 10:47:20:708 [ warning sync.propagator ]:	No valid fileinfo
06-07 10:47:20:709 [ info sync.database ]:	Updating file record for path: "Documents" inode: 8601639427 modtime: 1528268975 type: 2 etag: "_invalid_" fileId: "00000015ocqhnivq31kx" remotePerm: "DNVCKR" fileSize: 0 checksum: ""
06-07 10:47:20:709 [ info sync.propagator ]:	Completed propagation of "Documents" by OCC::PropagateLocalMkdir(0x7fc1f33dc760) with status 4
06-07 10:47:20:748 [ info sync.propagator ]:	Starting INSTRUCTION_NEW propagation of "Documents/Example.odt" by OCC::PropagateDownloadFile(0x7fc1f34c78a0)
06-07 10:47:20:749 [ warning sync.propagator ]:	No valid fileinfo
06-07 10:47:20:750 [ info sync.accessmanager ]:	2 "" "https://alfageme:9643/remote.php/dav/files/admin/Documents/Example.odt" has X-Request-ID "773069c1-3c57-4d5a-a36d-2b4cb94408de"
06-07 10:47:20:751 [ info sync.networkjob ]:	OCC::GETFileJob created for "https://alfageme" + "/Documents/Example.odt" "OCC::PropagateDownloadFile"
06-07 10:47:20:752 [ info sync.propagator ]:	Starting INSTRUCTION_NEW propagation of "Photos" by OCC::PropagateLocalMkdir(0x7fc1f4334910)
06-07 10:47:20:752 [ warning sync.propagator ]:	No valid fileinfo
06-07 10:47:20:753 [ info sync.database ]:	Updating file record for path: "Photos" inode: 8601639429 modtime: 1528268975 type: 2 etag: "_invalid_" fileId: "00000010ocqhnivq31kx" remotePerm: "DNVCKR" fileSize: 0 checksum: ""
06-07 10:47:20:754 [ info sync.propagator ]:	Completed propagation of "Photos" by OCC::PropagateLocalMkdir(0x7fc1f4334910) with status 4
06-07 10:47:20:786 [ info sync.propagator ]:	Starting INSTRUCTION_NEW propagation of "Photos/Paris.jpg" by OCC::PropagateDownloadFile(0x7fc1f34cbbd0)
06-07 10:47:20:787 [ warning sync.propagator ]:	No valid fileinfo
06-07 10:47:20:788 [ info sync.accessmanager ]:	2 "" "https://alfageme:9643/remote.php/dav/files/admin/Photos/Paris.jpg" has X-Request-ID "887d75bd-71d4-4e49-af61-bafab1dc9ee7"
06-07 10:47:20:789 [ info sync.networkjob ]:	OCC::GETFileJob created for "https://alfageme" + "/Photos/Paris.jpg" "OCC::PropagateDownloadFile"
06-07 10:47:20:790 [ info sync.propagator ]:	Starting INSTRUCTION_NEW propagation of "Photos/San Francisco.jpg" by OCC::PropagateDownloadFile(0x7fc1f34633d0)
06-07 10:47:20:790 [ warning sync.propagator ]:	No valid fileinfo
06-07 10:47:20:792 [ info sync.accessmanager ]:	2 "" "https://alfageme:9643/remote.php/dav/files/admin/Photos/San Francisco.jpg" has X-Request-ID "c2eaae50-04a7-45d9-a7f1-db60163a3fa9"
06-07 10:47:20:793 [ info sync.networkjob ]:	OCC::GETFileJob created for "https://alfageme" + "/Photos/San Francisco.jpg" "OCC::PropagateDownloadFile"
06-07 10:47:20:794 [ info sync.propagator ]:	Starting INSTRUCTION_NEW propagation of "Photos/Squirrel.jpg" by OCC::PropagateDownloadFile(0x7fc1f34d2020)
06-07 10:47:20:794 [ warning sync.propagator ]:	No valid fileinfo
06-07 10:47:20:796 [ info sync.accessmanager ]:	2 "" "https://alfageme:9643/remote.php/dav/files/admin/Photos/Squirrel.jpg" has X-Request-ID "74180f78-5387-4a00-a665-ea8ed1956c14"
06-07 10:47:20:797 [ info sync.networkjob ]:	OCC::GETFileJob created for "https://alfageme" + "/Photos/Squirrel.jpg" "OCC::PropagateDownloadFile"
06-07 10:47:20:800 [ info gui.account.manager ]:	Saving account "https://alfageme:9643"
06-07 10:47:20:801 [ info gui.account.manager ]:	Saving  1  unknown certs.
06-07 10:47:20:802 [ info gui.account.manager ]:	Saving cookies. "/Users/salfageme/Library/Preferences/ownCloud/cookies0.db"
06-07 10:47:20:805 [ info gui.account.manager ]:	Saved account settings, status: QSettings::Status(NoError)
06-07 10:47:20:806 [ info sync.account ]:	"SSL-Errors happened for url  \"https://alfageme:9643/remote.php/dav/files/admin/Photos/Paris.jpg\" \tError in  QSslCertificate(\"3\", \"b8:50:4d:ef:ce:42:ea:27\", \"9uLKbBPMTip/Emw8nWejcQ==\", (\"ownCloud GmbH\"), (\"ownCloud GmbH\"), QMap(), QDateTime(2018-06-06 07:07:02.000 UTC Qt::TimeSpec(UTC)), QDateTime(2023-06-05 07:07:02.000 UTC Qt::TimeSpec(UTC))) : \"The host name did not match any of the valid hosts for this certificate\" ( \"The host name did not match any of the valid hosts for this certificate\" ) \n " Certs are known and trusted! This is not an actual error.
06-07 10:47:20:860 [ info gui.account.manager ]:	Saving account "https://alfageme:9643"
06-07 10:47:20:861 [ info gui.account.manager ]:	Saving  1  unknown certs.
06-07 10:47:20:862 [ info gui.account.manager ]:	Saving cookies. "/Users/salfageme/Library/Preferences/ownCloud/cookies0.db"
06-07 10:47:20:865 [ info gui.account.manager ]:	Saved account settings, status: QSettings::Status(NoError)
06-07 10:47:20:866 [ info sync.account ]:	"SSL-Errors happened for url  \"https://alfageme:9643/remote.php/dav/files/admin/Photos/San Francisco.jpg\" \tError in  QSslCertificate(\"3\", \"b8:50:4d:ef:ce:42:ea:27\", \"9uLKbBPMTip/Emw8nWejcQ==\", (\"ownCloud GmbH\"), (\"ownCloud GmbH\"), QMap(), QDateTime(2018-06-06 07:07:02.000 UTC Qt::TimeSpec(UTC)), QDateTime(2023-06-05 07:07:02.000 UTC Qt::TimeSpec(UTC))) : \"The host name did not match any of the valid hosts for this certificate\" ( \"The host name did not match any of the valid hosts for this certificate\" ) \n " Certs are known and trusted! This is not an actual error.
06-07 10:47:20:898 [ info gui.account.manager ]:	Saving account "https://alfageme:9643"
06-07 10:47:20:899 [ info gui.account.manager ]:	Saving  1  unknown certs.
06-07 10:47:20:900 [ info gui.account.manager ]:	Saving cookies. "/Users/salfageme/Library/Preferences/ownCloud/cookies0.db"
06-07 10:47:20:903 [ info gui.account.manager ]:	Saved account settings, status: QSettings::Status(NoError)
06-07 10:47:20:904 [ info sync.account ]:	"SSL-Errors happened for url  \"https://alfageme:9643/remote.php/dav/files/admin/Photos/Squirrel.jpg\" \tError in  QSslCertificate(\"3\", \"b8:50:4d:ef:ce:42:ea:27\", \"9uLKbBPMTip/Emw8nWejcQ==\", (\"ownCloud GmbH\"), (\"ownCloud GmbH\"), QMap(), QDateTime(2018-06-06 07:07:02.000 UTC Qt::TimeSpec(UTC)), QDateTime(2023-06-05 07:07:02.000 UTC Qt::TimeSpec(UTC))) : \"The host name did not match any of the valid hosts for this certificate\" ( \"The host name did not match any of the valid hosts for this certificate\" ) \n " Certs are known and trusted! This is not an actual error.
06-07 10:47:21:034 [ warning sync.networkjob ]:	QNetworkReply::NetworkError(ContentAccessDenied) "Server replied \"403 Forbidden\" to \"GET https://alfageme:9643/remote.php/dav/files/admin/Documents/Example.odt\"" QVariant(int, 403)
06-07 10:47:21:159 [ warning sync.networkjob ]:	QNetworkReply::NetworkError(ContentAccessDenied) "Server replied \"403 Forbidden\" to \"GET https://alfageme:9643/remote.php/dav/files/admin/Photos/Paris.jpg\"" QVariant(int, 403)
06-07 10:47:21:280 [ warning sync.networkjob ]:	QNetworkReply::NetworkError(ContentAccessDenied) "Server replied \"403 Forbidden\" to \"GET https://alfageme:9643/remote.php/dav/files/admin/Photos/Squirrel.jpg\"" QVariant(int, 403)
06-07 10:47:21:405 [ warning sync.networkjob ]:	QNetworkReply::NetworkError(ContentAccessDenied) "Server replied \"403 Forbidden\" to \"GET https://alfageme:9643/remote.php/dav/files/admin/Photos/San Francisco.jpg\"" QVariant(int, 403)

@guruz
Copy link
Contributor

guruz commented Jun 11, 2018

403 Forbidden

So you are saying the sync looks like it continues even though there is errors?
(i dont know if we ignore 403 and continue syncing..)
How does it look like after some time?

CC @ckamm for blacklist stuff

@SamuAlfageme
Copy link
Contributor Author

It actually never starts - not sure how 2.5alpha1 and master diverged re. this.

Also I remember @ckamm and I discussed the 0B .~XXXXXXX files created on 403 some time ago. can't find the issue tho.

Disclaimer: the firewall reproducer might not be the best.

@ckamm
Copy link
Contributor

ckamm commented Jun 12, 2018

Blacklist: If the correct error message is shown to the user the first time, the same message will also be shown on subsequent runs when the file is ignored. So blacklisting isn't supposed to affect which error is shown - except that the message will only be updated if there is an actual synchronization attempt for the item.

@ckamm
Copy link
Contributor

ckamm commented Jun 13, 2018

@SamuAlfageme I see the same odd gui state that you show in your screenshot on the 2.5 branch (white text "preparing to sync" that doesn't go away) - let's cover that in a different ticket though: #6581

The download temporaries I'd not worry about. They exist because there's a download error and should go away when it is resolved.

@ogoffart ogoffart added the ReadyToTest QA, please validate the fix/enhancement label Jun 29, 2018
@ogoffart
Copy link
Contributor

I have tested that again, and i see the message properly.

@guruz guruz closed this as completed Jun 29, 2018
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

4 participants