upgrading to ubuntu 15.10 breaks google authentication
Closed, InvalidPublic
Actions

Assigned To

None

Authored By

	Adq
	Jan 26 2016, 11:58 AM

Description

I upgraded the phabricator machine to ubuntu 15.10. I did *not* upgrade phabricator or change its database. All attempts to authenticate with google authentication now fail with the attached log. (I can login to google ok, but then it fails inside phabricator somewhere). Existing logins are ok, this only happens if you logout and attempt to reauthenticate.

Ubuntu 15.10 is using php 5.6.11, previously ubuntu 15.04 was using php 5.6.4.

I'll keep investigating, but if you have any ideas, I'd appreciate it!

Jan 26 11:55:37 phabricator php5-fpm[1491]: ool www[1491]: [2016-01-26 11:55:37] EXCEPTION: (HTTPFutureHTTPResponseStatus) [HTTP/400] 
                                            {
                                              "error" : "invalid_grant",
                                              "error_description" : "Code was already redeemed."
                                            } at [<phutil>/src/future/http/BaseHTTPFuture.php:339]
Jan 26 11:55:37 phabricator php5-fpm[1491]: ool www[1491]: arcanist(head=master, ref.master=a03c6079bb71), phabricator(head=master, ref.master=d92f7a14739a), phutil(head=master, ref.master=59f5a8d2bb82), sprint(head=master, ref.master=3fbeaf53a042)
Jan 26 11:55:37 phabricator php5-fpm[1491]: ool www[1491]:   #0 <#2> BaseHTTPFuture::parseRawHTTPResponse(string) called at [<phutil>/src/future/http/HTTPSFuture.php:415]
Jan 26 11:55:37 phabricator php5-fpm[1491]: ool www[1491]:   #1 <#2> HTTPSFuture::isReady() called at [<phutil>/src/future/Future.php:37]
Jan 26 11:55:37 phabricator php5-fpm[1491]: ool www[1491]:   #2 <#2> Future::resolve() called at [<phutil>/src/future/http/BaseHTTPFuture.php:279]
Jan 26 11:55:37 phabricator php5-fpm[1491]: ool www[1491]:   #3 <#2> BaseHTTPFuture::resolvex() called at [<phutil>/src/auth/PhutilOAuthAuthAdapter.php:174]
Jan 26 11:55:37 phabricator php5-fpm[1491]: ool www[1491]:   #4 <#2> PhutilOAuthAuthAdapter::makeTokenRequest(array) called at [<phutil>/src/auth/PhutilOAuthAuthAdapter.php:161]
Jan 26 11:55:37 phabricator php5-fpm[1491]: ool www[1491]:   #5 <#2> PhutilOAuthAuthAdapter::loadAccessTokenData() called at [<phutil>/src/auth/PhutilOAuthAuthAdapter.php:122]
Jan 26 11:55:37 phabricator php5-fpm[1491]: ool www[1491]:   #6 <#2> PhutilOAuthAuthAdapter::getAccessTokenData(string) called at [<phutil>/src/auth/PhutilOAuthAuthAdapter.php:109]
Jan 26 11:55:37 phabricator php5-fpm[1491]: ool www[1491]:   #7 <#2> PhutilOAuthAuthAdapter::getAccessToken() called at [<phutil>/src/auth/PhutilGoogleAuthAdapter.php:98]
Jan 26 11:55:37 phabricator php5-fpm[1491]: ool www[1491]:   #8 <#2> PhutilGoogleAuthAdapter::loadOAuthAccountData() called at [<phutil>/src/auth/PhutilOAuthAuthAdapter.php:223]
Jan 26 11:55:37 phabricator php5-fpm[1491]: ool www[1491]:   #9 <#2> PhutilOAuthAuthAdapter::getOAuthAccountData(string, array) called at [<phutil>/src/auth/PhutilGoogleAuthAdapter.php:17]
Jan 26 11:55:37 phabricator php5-fpm[1491]: ool www[1491]:   #10 <#2> PhutilGoogleAuthAdapter::getAccountID() called at [<phabricator>/src/applications/auth/provider/PhabricatorOAuth2AuthProvider.php:83]
Jan 26 11:55:37 phabricator php5-fpm[1491]: ool www[1491]:   #11 <#2> PhabricatorOAuth2AuthProvider::processLoginRequest(PhabricatorAuthLoginController) called at [<phabricator>/src/applications/auth/controller/PhabricatorAuthLoginController.php:40]
Jan 26 11:55:37 phabricator php5-fpm[1491]: ool www[1491]:   #12 <#2> PhabricatorAuthLoginController::handleRequest(AphrontRequest) called at [<phabricator>/src/aphront/configuration/AphrontApplicationConfiguration.php:237]
Jan 26 11:55:37 phabricator php5-fpm[1491]: ool www[1491]:   #13 phlog(HTTPFutureHTTPResponseStatus) called at [<phabricator>/src/aphront/handler/PhabricatorDefaultRequestExceptionHandler.php:32]
Jan 26 11:55:37 phabricator php5-fpm[1491]: ool www[1491]:   #14 PhabricatorDefaultRequestExceptionHandler::handleRequestException(AphrontRequest, HTTPFutureHTTPResponseStatus) called at [<phabricator>/src/aphront/configuration/AphrontApplicationConfiguration.php:632]
Jan 26 11:55:37 phabricator php5-fpm[1491]: ool www[1491]:   #15 AphrontApplicationConfiguration::handleException(HTTPFutureHTTPResponseStatus) called at [<phabricator>/src/aphront/configuration/AphrontApplicationConfiguration.php:242]
Jan 26 11:55:37 phabricator php5-fpm[1491]: ool www[1491]:   #16 AphrontApplicationConfiguration::processRequest(AphrontRequest, PhutilDeferredLog, AphrontPHPHTTPSink, MultimeterControl) called at [<phabricator>/src/aphront/configuration/AphrontApplicationConfiguration.php:149]
Jan 26 11:55:37 phabricator php5-fpm[1491]: ool www[1491]:   #17 AphrontApplicationConfiguration::runHTTPRequest(AphrontPHPHTTPSink) called at [<phabricator>/webroot/index.php:17]

Related Objects

Mentioned Here: rPHU59f5a8d2bb82: Add scroll wrapper for big tables
rPd92f7a14739a: Add CSS to wrap long tables in a scrollable area
rARCa03c6079bb71: Make "arc land" great again

Event Timeline

Also just seen this:

[HTTP/400]
{

"error" : "invalid_request",
"error_description" : "Invalid grant_type: authorization_code7a0n"

}

Looks like random crap on the end of the grant_type ??

Here's another...

[HTTP/400]
{

"error" : "invalid_request",
"error_description" : "Invalid grant_type: authorization_codele%2Flogin%Q"

}

Looking further, google auth works up until this URL is requested in my browser: https://phabricator.tvsquared.com/auth/login/google:google.com/?state=STATE&code=CODE

Internally on the server, I can see it successfully requests an id_token using my configured creds.

It then requests: https://www.googleapis.com/plus/v1/people/me?access_token=ACCESSTOKEN
Google rejects this request with a 400 bad request error saying:
<p><b>400.</b> <ins>That’s an error.</ins>
<p>Your client has issued a malformed or illegal request. <ins>That’s all we know.</ins>

However, if I cut and paste the unmodified googleplus profile url into my browser, it works fine! its just the call to it from within phabricator that fails.

Has something changed in php in ubuntu 15.10?

OK, dug in some more... I've eventually managed to get it sort of working. in src/future/http/HTTPSFuture.php, you have this code:

      if (strlen($this->rawBody)) {
<SNIP>
      } else {
        $data = $this->formatRequestDataForCURL();
        curl_setopt($curl, CURLOPT_POSTFIELDS, $data);
      }

I found that if I change this to:

      if (strlen($this->rawBody)) {
<SNIP>
      } else {
        $data = $this->formatRequestDataForCURL();
        if (strlen($data)) {
            curl_setopt($curl, CURLOPT_POSTFIELDS, $data);
        }
      }

Then the failing call to the google+ api starts working again, and authentication mostly works.

Its a little flakey, as sometimes it still fails with the above error messages with random strings appended to 'authorization_code'. Retrying a few times succeeds. Really strange; I've checked for updates in ubuntu in case of a php/curl bug, but there's nothing so far.

This points to some change in the guts of CURL in 15.10?
ubuntu 15.10:
ii curl 7.43.0-1ubuntu2 amd64 command line tool for transferring data with URL syntax
ii libcurl3:amd64 7.43.0-1ubuntu2 amd64 easy-to-use client-side URL transfer library (OpenSSL flavour)
ii libcurl3-gnutls:amd64 7.43.0-1ubuntu2 amd64 easy-to-use client-side URL transfer library (GnuTLS flavour)
ii php5-curl 5.6.11+dfsg-1ubuntu3.1 amd64 CURL module for php5

ubuntu 15.04:
ii curl 7.38.0-3ubuntu2.2 amd64 command line tool for transferring data with URL syntax
ii libcurl3:amd64 7.38.0-3ubuntu2.2 amd64 easy-to-use client-side URL transfer library (OpenSSL flavour)
ii libcurl3-gnutls:amd64 7.38.0-3ubuntu2.2 amd64 easy-to-use client-side URL transfer library (GnuTLS flavour)
ii libcurl4-gnutls-dev:amd64 7.38.0-3ubuntu2.2 amd64 development files and documentation for libcurl (GnuTLS flavour)
ii php5-curl 5.6.4+dfsg-4ubuntu6.4 amd64 CURL module for php5

avivey updated the task description. (Show Details)Jan 26 2016, 6:18 PM

chad added a project: Auth.Jan 26 2016, 6:25 PM

freeman-endlessm added a subscriber: freeman-endlessm.Feb 10 2016, 1:06 AM

This effects me too, I'm on a freshly installed Ubuntu 15.10 server. On master:

[Wed Feb 10 01:25:11.179370 2016] [:error] [pid 638] [client IP_ADDRESS:1039] [2016-02-10 01:25:11] EXCEPTION: (HTTPFutureHTTPResponseStatus) [HTTP/400] \n<!DOCTYPE html>\n<html lang=en>\n  <meta charset=utf-8>\n  <meta name=viewport content="initial-scale=1, minimum-scale=1, width=device-width">\n  <title>Error 400 (Bad Request)!!1</title>\n  <style>\n    *{margin:0;padding:0}html,code{font:15px/22px arial,sans-serif}html{background:#fff;color:#222;padding:15px}body{margin:7% auto 0;max-width:390px;min-height:180px;padding:30px 0 15px}* > body{background:url(//www.google.com/images/errors/robot.png) 100% 5px no-repeat;padding-right:205px}p{margin:11px 0 22px;overf... at [<phutil>/src/future/http/BaseHTTPFuture.php:339]
[Wed Feb 10 01:25:11.179833 2016] [:error] [pid 638] [client IP_ADDRESS:1039] arcanist(head=master, ref.master=57f6fb59d739), phabricator(head=master, ref.master=aa6c99384879, custom=1), phutil(head=master, ref.master=f43291e99d36)
[Wed Feb 10 01:25:11.179902 2016] [:error] [pid 638] [client IP_ADDRESS:1039]   #0 <#2> BaseHTTPFuture::parseRawHTTPResponse(string) called at [<phutil>/src/future/http/HTTPSFuture.php:415]
[Wed Feb 10 01:25:11.179947 2016] [:error] [pid 638] [client IP_ADDRESS:1039]   #1 <#2> HTTPSFuture::isReady() called at [<phutil>/src/future/Future.php:37]
[Wed Feb 10 01:25:11.179974 2016] [:error] [pid 638] [client IP_ADDRESS:1039]   #2 <#2> Future::resolve() called at [<phutil>/src/auth/PhutilGoogleAuthAdapter.php:112]
[Wed Feb 10 01:25:11.179996 2016] [:error] [pid 638] [client IP_ADDRESS:1039]   #3 <#2> PhutilGoogleAuthAdapter::loadOAuthAccountData() called at [<phutil>/src/auth/PhutilOAuthAuthAdapter.php:223]
[Wed Feb 10 01:25:11.180017 2016] [:error] [pid 638] [client IP_ADDRESS:1039]   #4 <#2> PhutilOAuthAuthAdapter::getOAuthAccountData(string, array) called at [<phutil>/src/auth/PhutilGoogleAuthAdapter.php:17]
[Wed Feb 10 01:25:11.180052 2016] [:error] [pid 638] [client IP_ADDRESS:1039]   #5 <#2> PhutilGoogleAuthAdapter::getAccountID() called at [<phabricator>/src/applications/auth/provider/PhabricatorOAuth2AuthProvider.php:83]
[Wed Feb 10 01:25:11.180077 2016] [:error] [pid 638] [client IP_ADDRESS:1039]   #6 <#2> PhabricatorOAuth2AuthProvider::processLoginRequest(PhabricatorAuthLoginController) called at [<phabricator>/src/applications/auth/controller/PhabricatorAuthLoginController.php:40]
[Wed Feb 10 01:25:11.180099 2016] [:error] [pid 638] [client IP_ADDRESS:1039]   #7 <#2> PhabricatorAuthLoginController::handleRequest(AphrontRequest) called at [<phabricator>/src/aphront/configuration/AphrontApplicationConfiguration.php:237]
[Wed Feb 10 01:25:11.180120 2016] [:error] [pid 638] [client IP_ADDRESS:1039]   #8 phlog(HTTPFutureHTTPResponseStatus) called at [<phabricator>/src/aphront/handler/PhabricatorDefaultRequestExceptionHandler.php:32]
[Wed Feb 10 01:25:11.180140 2016] [:error] [pid 638] [client IP_ADDRESS:1039]   #9 PhabricatorDefaultRequestExceptionHandler::handleRequestException(AphrontRequest, HTTPFutureHTTPResponseStatus) called at [<phabricator>/src/aphront/configuration/AphrontApplicationConfiguration.php:632]
[Wed Feb 10 01:25:11.180191 2016] [:error] [pid 638] [client IP_ADDRESS:1039]   #10 AphrontApplicationConfiguration::handleException(HTTPFutureHTTPResponseStatus) called at [<phabricator>/src/aphront/configuration/AphrontApplicationConfiguration.php:242]
[Wed Feb 10 01:25:11.180215 2016] [:error] [pid 638] [client IP_ADDRESS:1039]   #11 AphrontApplicationConfiguration::processRequest(AphrontRequest, PhutilDeferredLog, AphrontPHPHTTPSink, MultimeterControl) called at [<phabricator>/src/aphront/configuration/AphrontApplicationConfiguration.php:149]
[Wed Feb 10 01:25:11.180262 2016] [:error] [pid 638] [client IP_ADDRESS:1039]   #12 AphrontApplicationConfiguration::runHTTPRequest(AphrontPHPHTTPSink) called at [<phabricator>/webroot/index.php:17]

Rebuilding machine image for app server on 15.04 fixes the issue. (dabase server and data unchanged.)

ide added a subscriber: ide.Mar 23 2016, 4:18 AM

also affected by this, same report/errormessage.

Support for Ubuntu 15.10 ended on 2016-07-28.
Did this problem also happen with any later, still supported Ubuntu version (like 16.04) or can this task be closed as obsolete?

Presuming something fixed this.

iiam

upgrading to ubuntu 15.10 breaks google authenticationClosed, InvalidPublicActions

Description

Related Objects

Event Timeline

upgrading to ubuntu 15.10 breaks google authentication
Closed, InvalidPublic
Actions