Bug #1291
closedOAuthService: Facebook HTTPS "Cannot send after transport endpoint shutdown "
0%
Description
Hi,
Maybe this is not the right place but before I report this issue, I would like to thank the Emweb team for the wonderful Wt toolkit.
My users get this error while trying OAuth with Facebook:
"Sorry, could not login using your Facebook account."
"Facebook's identification server generated an unexpected response."
I couldn't find more details from the logs about what was wrong, but after a bit of debug I found that the error that triggers the issue is:
108 - Cannot send after transport endpoint shutdown
I'm a bit intrigued with this error because it started suddenly. My application and the examples used to work with Facebook OAuth2 in Wt 3.2.1.
I suspect the problem is external to Wt. Maybe something changed on Facebook side.
To debug I'm using the examples/feature/auth1 with Facebook configured.
This is my analysis of the error
-In OAuthProcess::handleToken(), the variable err is set, causing doParseTokenResponse(response) not to be called, resulting in an empty token.
-The attempt is not aborted on the 1st error, resulting In OAuthProcess::onOAuthDone() making a getIdentity(token_) with the empty token.
If I change the code to ignore error 108, after getting the Token, it seems to work as expected.
I know emweb plans to refine OAuth in a latter version of the toolkit, but if that is not a short term priority, I would like to suggest the following small improvements to error logging and handling, that would be useful to someone having the same or similar issues.
-Abort the Auth attempt after the first error and display a UI message
Log the socket error in OAuthProcess::handleToken (in my case, the error 108, the 1st error the one that caused things to go wrong)
-Log the OAuth error received in the JSON response in FacebookService::handleMe (the 2nd error, in my case it would tell me I was making a request without token)
I did a fresh Wt and OS install and it still happens.
These are the details of the systems where I observed that the Auth1 example with Facebook configured, fails:
Error: 108 - Cannot send after transport endpoint shutdown
Wt: 3.2.1 and git
OS: CentOS EL5 and EL6 (32 and 64 Bit)
boost: 1.41
compiler: g (GCC) 4.4.6 20110731
openssl: 1.0.0
glibc: 2.12 / glib2: 2.22
Please advise if there is a solution to my problem and if ignoring 108 is the right thing to do.
Thanks and regards,
Jorge
Updated by Jorge Paulo over 12 years ago
Just to clarify:
-Facebook responds to the HTTPS request with JSON containing the Token, but even so the error 108 is present.
-The variable that should hold the token is empty, because after the previous error the response is not parsed by the lib. (although it still tries to make a getIdentity).
Updated by Koen Deforche over 12 years ago
- Status changed from New to InProgress
- Assignee set to Koen Deforche
- Target version set to 3.2.2
Updated by Koen Deforche over 12 years ago
- Status changed from InProgress to Feedback
Hey,
Thanks for the detailed report. I believe that the proper solution would be to ignore errors that come from a shutdown of the socket after receiving the response body, in Http::Client. I'll commit this change and I would be interested in hearing if this solves the problem.
As to your other points, I've improved error logging and handling:
- logging of boost::asio error
- not proceeding to getIdentity() if there was an error obtaining the token
But I don't understand your last point: the OAuth error received in the JSON response in FacebookService::handleMe should be currently logged now ?
Regards,
koen
Updated by Jorge Paulo over 12 years ago
Hi,
my last point concerning FacebookService::handleMe was about the lack of logging of the error returned from Facebook.
Again, the cause of the problem was "err" being set to "108:Cannot send after transport endpoint shutdown".
The logging of the response was being bypassed because there was indeed an error in the socket, but as side effect it was hiding relevant information returned from Facebook in a different protocol layer.
if (!err) {
LOG_ERROR("user info request returned: " << response.status());
LOG_ERROR("with: " << response.body());
}
In my case it was this that was not being logged.
response.body():{""error"":{""message"":""An active access token must be used to query information about the current user."",""type"":""OAuthException"",""code"":2500}}
response.status(): 400\"
I think after the changes regarding error 108, this won't happen again.
I'm going to test the changes.
Thank you,
Jorge
Updated by Jorge Paulo over 12 years ago
Hi,
I tested the changes and confirm the problem is solved.
Regarding my note about logging the response content after a boost::asio error, it only makes sense to do it if there is the possibility that errors, other than 108, have the same odd behaviour: Asio error although a response with valid status and content was received. I don't have experience with asio, but to me it is seems very unlikely.
The response information would be convenient for application support, but not critical.
Thanks!
Jorge
Updated by Koen Deforche over 12 years ago
- Status changed from Feedback to Resolved
Hey,
I believe the socket error + correct contents isn't supposed to happen.
Regards,
koen
Updated by Koen Deforche over 12 years ago
- Status changed from Resolved to Closed
Released in Wt 3.2.2