GitHub account unlinked from OSIO account #4754

ppitonak · 2019-02-08T08:09:23Z

Issue Overview

User's GitHub account get disconnected from his OpenShift.io account without explicitly clicking on disconnect account

Expected Behaviour

GitHub account stays connected to OSIO account as long as the user clicks on disconnect button or calls the API to remove the token

Current Behaviour

account disconnected four times in two months in our low-touch testing account

Steps To Reproduce

login
open settings page

Additional Information

account osio-ci-e2e-001
- connected on Dec 18, 14:12 UTC
- then Feb 7, 12:12 UTC
account osio-ci-e2e-002
- connected on Dec 18, 11:08 UTC
- then Dec 20, 12:25 UTC
- then Feb 7, 12:08 UTC
- then Feb 8, before 8:00 UTC (in less than 24 hours) - reconnected again
account osio-ci-e2e-004
- connected on Dec 18, 12:20 UTC
account osio-ci-e2e-006
- connected on Feb 7, 12:22 UTC
account osio-ci-e2e-007
- connected on Dec 20, 11:14 UTC
- then Feb 7, 12:23 UTC
- disconnected before Feb 8, 8:00 UTC (in less than 24 hours) - keeping disconnected for debugging

All of these account are conneced to @osiotestmachine. Notice that on disconnected in December but not in February, another one in February but not December, another in both Dec and Feb and the last one in Dec and twice in Feb. I don't see any pattern there.

related to #4743

ppitonak · 2019-02-11T13:44:18Z

@sbryzak could be this issue caused by fabric8-services/fabric8-auth@0afb1b2 ?

joshuawilson · 2019-02-11T15:37:43Z

Removing UI and adding Auth. Not sure how this is a UI bug.

alexeykazakov · 2019-02-11T17:14:01Z

could be this issue caused by fabric8-services/fabric8-auth@0afb1b2 ?

No it can't. That change is taking care of OSIO user tokens. Not GitHub tokens.
@ppitonak it would be very useful if you could check what HTTP requests are actually made during that flow. I suspect there is something wrong with the request from UI to auth.openshift.io/api/token?for=github (this is what UI is supposed to call when trying to obtain the github token for the user to check if the user has GitHub account linked) but it's hard to say without seeing that request.

joshuawilson · 2019-02-11T17:16:47Z

Why is this a SEV1?
Can you reproduce the effect?

alexeykazakov · 2019-02-11T17:20:01Z

I guess it's SEV1 because it's cumming from e2e failures.
I can't reproduce it manually.

vikram-raj · 2019-02-12T05:45:22Z

UI sending request to this https://forge.api.prod-preview.openshift.io/api/services/git/user endpoint. Its response is 404 not found when GitHub account is not connected. If connected its return 200 Ok with all user details and the array of user repositories and organizations.

alexeykazakov · 2019-02-12T07:38:00Z

I'm trying to find something useful in the logs but I don't think it's really a Sev-1 issue. As stated above it happened four times in two months for the e2e tests and we can't reproduce it manually.

ppitonak · 2019-02-12T09:01:28Z

@alexeykazakov I found the first job with unlinked account

test logs in and waits for dashboard to load http://artifacts.ci.centos.org/devtools/e2e/devtools-test-e2e-openshift.io-che-us-east-1b-released/30/01-01-afterEach.perf.log
test navigates to settings and then to features opt-in page http://artifacts.ci.centos.org/devtools/e2e/devtools-test-e2e-openshift.io-che-us-east-1b-released/30/02-01-afterEach.perf.log
1. notice that request 144 receives the response twice which indicate a bug somewhere, although the response is 200
2. request 150 ends with 401 Unauthorized
test creates a new space - nothing interesting here
test tries to create a new project in launcher http://artifacts.ci.centos.org/devtools/e2e/devtools-test-e2e-openshift.io-che-us-east-1b-released/30/03-02-afterEach.perf.log
1. request 178 to auth.openshift.io returns 200
2. request 220 to forge.api.openshift.io returns 500 (again twice)

alexeykazakov · 2019-02-12T17:31:43Z

Hm.. I don't see anything in our prod logs with req_id: "1000000314.150" at all.

alexeykazakov · 2019-02-12T17:41:11Z

@ppitonak for some reason I can't find anything in the prod logs with the req_id from the e2e logs. So, it's hard to say what's going on.
Could you modify the e2e tests so they log details of 401 errors? All headers and response body would help a lot.
The failed request is https://auth.openshift.io/api/token?force_pull=true&for=https://github.com with force_pull=true which forces Auth to call github to update the username. So, maybe github refuses that request because of exceeding api rate or something? Maybe our e2e tests are calling it too often or many times without proper delay or something like this. Hard to say without seeing details of that 401 response.

alexeykazakov · 2019-02-13T22:04:28Z

As stated above it happened four times in two months for the e2e tests and we can't reproduce it manually.

Changed from Sev-1 to Sev-2.

ppitonak · 2019-02-14T12:52:10Z

@alexeykazakov these are request ID numbers used internally by Chrome, not something OSIO-specific so you need to manually match it to errors in Kibana using timestamp.

Lucia will add logging response headers and body content in the case of 4xx or 5xx response.

ljelinkova · 2019-02-14T13:30:07Z

I looked into it and we already log the status code + status message. I do not think that there will be additional useful information.

This is example of such an output (it is an example of output, the error has nothing to do with this issue).

[14:03:41.039]   req_id:1000027443.141   [RESPONSE]   500   Internal Server Error   https://openshift.io/api/user/spaces
{
  "connectionId": 52,
  "connectionReused": true,
  "encodedDataLength": 183,
  "fromDiskCache": false,
  "fromServiceWorker": false,
  "headers": {
    "Content-Encoding": "gzip",
    "Content-Length": "148",
    "Content-Type": "application/vnd.api+json",
    "Date": "Thu, 14 Feb 2019 13:03:40 GMT",
    "Vary": "Accept-Encoding"
  },
  "headersText": "HTTP/1.1 500 Internal Server Error\r\nContent-Encoding: gzip\r\nContent-Type: application/vnd.api+json\r\nVary: Accept-Encoding\r\nDate: Thu, 14 Feb 2019 13:03:40 GMT\r\nContent-Length: 148\r\n\r\n",
  "mimeType": "application/vnd.api+json",
  "protocol": "http/1.1",
  "remoteIPAddress": "52.5.164.221",
  "remotePort": 443,
  "requestHeaders": {
    "Accept": "application/json, text/plain, */*",
    "Accept-Encoding": "gzip, deflate, br",
    "Accept-Language": "en-US,en;q=0.9",
    "Authorization": "Bearer XYZ
    "Connection": "keep-alive",
    "Cookie": "1c170d08514b975b4a928310c01901ad=af3338c21a703e55e6f5d14857e06a7c; rh_omni_tc=701f2000001Css0AAC; sat_ppv=53; dtm_prevURL=https%3A%2F%2Fopenshift.io%2F; ajs_user_id=null; ajs_group_id=null; ajs_anonymous_id=%229e0f4bce-4444-461c-9227-a985d8ac31bd%22; AMCVS_945D02BE532957400A490D4C%40AdobeOrg=1; sat_prevPage=OSIO%7Chomepage; s_cc=true; AMCV_945D02BE532957400A490D4C%40AdobeOrg=1406116232%7CMCIDTS%7C17942%7CMCMID%7C28787525591015777861401393381165715364%7CMCAAMLH-1550754199%7C7%7CMCAAMB-1550754199%%7CMCOPTOUT-1550156599s%7CNONE%7CMCAID%7CNONE%7CMCSYNCSOP%7C411-17949%7CvVersion%7C2.5.0; sat_prevExtCmp=701f2000001Css0AAC; wooTracker=HvFzPmSaYys7; rh_elqCustomerGUID=4b3d8eac-c479-4f5a-97b6-7d36a94b36f5; 1138c197bc94a32cc7fe2699b984fa72=ae1b62de48bbe95110d743362e41dd3f",
    "Host": "openshift.io",
    "Referer": "https://openshift.io/_home",
    "User-Agent": "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/71.0.3578.98 Safari/537.36"
  },
  "requestHeadersText": "GET /api/user/spaces HTTP/1.1\r\nHost: openshift.io\r\nConnection: keep-alive\r\nAccept: application/json, text/plain, */*\r\nAuthorization: Bearer 2ZuIf1S_Sw\r\nUser-Agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/71.0.3578.98 Safari/537.36\r\nReferer: https://openshift.io/_home\r\nAccept-Encoding: gzip, deflate, br\r\nAccept-Language: en-US,en;q=0.9\r\nCookie: 1c170d08514b975b4a928310c01901ad=af3338c21a703e55e6f5d14857e06a7c; rh_omni_tc=701f2000001Css0AAC; sat_ppv=53; dtm_prevURL=https%3A%2F%2Fopenshift.io%2F; ajs_user_id=null; ajs_group_id=null; ajs_anonymous_id=%229e0f4bce-4444-461c-9227-a985d8ac31bd%22; AMCVS_945D02BE532957400A490D4C%40AdobeOrg=1; sat_prevPage=OSIO%7Chomepage; s_cc=true; AMCV_945D02BE532957400A490D4C%40AdobeOrg=1406116232%7CMCIDTS%7C17942%7CMCMID%7C28787525591015777861401393381165715364%7CMCAAMLH-1550754199%7C7%7CMCAAMB-1550754199%7C6G1ynYcLPuiQxYZrsz_pkqfLG9yMXBpb2zX5dvJdYQJzPXImdj0y%7CMCOPTOUT-1550156599s%7CNONE%7CMCAID%7CNONE%7CMCSYNCSOP%7C411-17949%7CvVersion%7C2.5.0; sat_prevExtCmp=701f2000001Css0AAC; wooTracker=HvFzPmSaYys7; rh_elqCustomerGUID=4b3d8eac-c479-4f5a-97b6-7d36a94b36f5; 1138c197bc94a32cc7fe2699b984fa72=ae1b62de48bbe95110d743362e41dd3f\r\n",
  "securityDetails": {
    "certificateId": 0,
    "certificateTransparencyCompliance": "not-compliant",
    "cipher": "AES_128_GCM",
    "issuer": "DigiCert SHA2 High Assurance Server CA",
    "keyExchange": "ECDHE_RSA",
    "keyExchangeGroup": "P-256",
    "protocol": "TLS 1.2",
    "sanList": [
      "*.openshift.io",
      "openshift.io"
    ],
    "signedCertificateTimestampList": [],
    "subjectName": "*.openshift.io",
    "validFrom": 1491350400,
    "validTo": 1554897600
  },
  "securityState": "secure",
  "status": 500,
  "statusText": "Internal Server Error",
  "timing": {
    "connectEnd": -1,
    "connectStart": -1,
    "dnsEnd": -1,
    "dnsStart": -1,
    "proxyEnd": -1,
    "proxyStart": -1,
    "pushEnd": 0,
    "pushStart": 0,
    "receiveHeadersEnd": 264.777,
    "requestTime": 1330611.362277,
    "sendEnd": 0.859,
    "sendStart": 0.736,
    "sslEnd": -1,
    "sslStart": -1,
    "workerReady": -1,
    "workerStart": -1
  },
  "url": "https://openshift.io/api/user/spaces"
}

alexeykazakov · 2019-02-14T14:33:18Z

I’m more interested in 401 response from Auth.
Also response headers are important too because Auth using WWW-Authorize header to provide additional information in 401 errors.

ljelinkova · 2019-02-21T10:33:28Z

Pavol modified the logging so that also response headers are logged for 401 responses. However, I do not see anything interesting there.
http://artifacts.ci.centos.org/devtools/e2e/devtools-test-e2e-openshift.io-smoketest-us-east-2a-released/1628/03-02-afterEach.perf.log

[09:32:35.616]   req_id:1000000460.211   [RESPONSE]   401   Unauthorized   https://auth.openshift.io/api/token/audit?resource_id=a84de81a-d474-4ae2-a0f8-cb92b91700e3
request headers:
{
  "Accept": "application/json, text/plain, */*",
  "Accept-Encoding": "gzip, deflate, br",
  "Accept-Language": "en-US,en;q=0.9",
  "Connection": "keep-alive",
  "Content-Length": "0",
  "Content-Type": "application/json",
  "Host": "auth.openshift.io",
  "Origin": "https://openshift.io",
  "Referer": "https://openshift.io/osio-ci-e2e-007/e2e-0221-0931-4772",
  "User-Agent": "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/72.0.3626.109 Safari/537.36"
}
response headers:
{
  "Access-Control-Allow-Credentials": "true",
  "Access-Control-Allow-Origin": "https://openshift.io",
  "Access-Control-Max-Age": "600",
  "Content-Encoding": "gzip",
  "Content-Length": "145",
  "Content-Type": "application/vnd.api+json",
  "Date": "Thu, 21 Feb 2019 09:32:35 GMT",
  "Set-Cookie": "ebce143985a64abd1340268b36c4dd2e=e248bb43839e6d07a4d2221d2beae06e; path=/; HttpOnly; Secure",
  "Vary": "Origin"
}

ljelinkova · 2019-02-21T14:37:25Z

I found another disconnected account with this log message:

[13:58:38.068]   req_id:1000000458.158   [RESPONSE]   401   Unauthorized   https://auth.openshift.io/api/token?force_pull=true&for=https://github.com
request headers:
{
  "Accept": "application/json, text/plain, */*",
  "Accept-Encoding": "gzip, deflate, br",
  "Accept-Language": "en-US,en;q=0.9",
  "Authorization": "Bearer  <hidden>",
  "Connection": "keep-alive",
  "Content-Type": "application/json",
  "Host": "auth.openshift.io",
  "Origin": "https://openshift.io",
  "Referer": "https://openshift.io/osio-ci-e2e-002/_settings",
  "User-Agent": "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/72.0.3626.109 Safari/537.36",
  "X-Request-Id": "0b88bd20-5141-4e09-baf8-455b99532496"
}
response headers:
{
  "Access-Control-Allow-Credentials": "true",
  "Access-Control-Allow-Origin": "https://openshift.io",
  "Access-Control-Expose-Headers": "WWW-Authenticate",
  "Access-Control-Max-Age": "600",
  "Content-Encoding": "gzip",
  "Content-Length": "121",
  "Content-Type": "application/vnd.api+json",
  "Date": "Thu, 21 Feb 2019 13:58:38 GMT",
  "Set-Cookie": "ebce143985a64abd1340268b36c4dd2e=38230ab0126d2203ea12ba6c14170baa; path=/; HttpOnly; Secure",
  "Vary": "Origin",
  "Www-Authenticate": "LINK url=https://auth.openshift.io/api/token/link?for=https://github.com, description=\"github token is not valid or expired. Relink github account\""
}

alexeykazakov · 2019-02-21T14:50:26Z

"Www-Authenticate": "LINK url=https://auth.openshift.io/api/token/link?for=https://github.com, description="github token is not valid or expired. Relink github account""

This means that the token is present in auth but it's not accepted by GitHub as a valid token.

ljelinkova · 2019-02-21T14:53:18Z

Can you find the reason why it is not accepted?

alexeykazakov · 2019-02-21T17:54:00Z

I have an idea. We share the same github account among many test accounts, right? Every time one account authorizes in git (via osio) git generates a new token. Which automatically invalidates some old tokens for that git account (which might still be used by other osio test accounts).

alexeykazakov · 2019-02-21T17:55:32Z

There is nothing we can do in auth service side. It's a problem between e2e tests (the fact that they share the same github account) and GitHub limitations.

ppitonak · 2019-02-22T08:19:04Z

We share the same github account among many test accounts, right?

yes, we do

Every time one account authorizes in git (via osio) git generates a new token.

When does this happen in OSIO? Is it enough to open settings page?

alexeykazakov · 2019-02-22T08:32:53Z

No, it’s not enough to open settings. Have to click on refresh icon there. Or authorize github for another test account (which uses the same GitHub account). Or just generate a token in GitHub directly.

ppitonak · 2019-02-22T08:35:00Z

If two OSIO accounts are linked to the same GitHub account, they use two distinct GitHub tokens, don't they?

alexeykazakov · 2019-02-22T08:40:57Z

They do. But when GitHub generates a new token it invalidates some previously generated.

ppitonak added SEV2-high type/bug area/settings team/launcher area/launcher priority/P1 Critical area/e2e-tests team/ui SEV1-urgent and removed SEV2-high labels Feb 8, 2019

joshuawilson added area/auth team/auth and removed team/ui labels Feb 11, 2019

alexeykazakov added SEV2-high and removed SEV1-urgent labels Feb 13, 2019

ppitonak added the SEV1-urgent label Feb 20, 2019

ppitonak removed the SEV2-high label Feb 20, 2019

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

GitHub account unlinked from OSIO account #4754

GitHub account unlinked from OSIO account #4754

ppitonak commented Feb 8, 2019 •

edited

ppitonak commented Feb 11, 2019

joshuawilson commented Feb 11, 2019

alexeykazakov commented Feb 11, 2019

joshuawilson commented Feb 11, 2019

alexeykazakov commented Feb 11, 2019

vikram-raj commented Feb 12, 2019

alexeykazakov commented Feb 12, 2019

ppitonak commented Feb 12, 2019 •

edited

alexeykazakov commented Feb 12, 2019

alexeykazakov commented Feb 12, 2019 •

edited

alexeykazakov commented Feb 13, 2019

ppitonak commented Feb 14, 2019

ljelinkova commented Feb 14, 2019

alexeykazakov commented Feb 14, 2019

ljelinkova commented Feb 21, 2019

ljelinkova commented Feb 21, 2019

alexeykazakov commented Feb 21, 2019

ljelinkova commented Feb 21, 2019

alexeykazakov commented Feb 21, 2019

alexeykazakov commented Feb 21, 2019

ppitonak commented Feb 22, 2019

alexeykazakov commented Feb 22, 2019

ppitonak commented Feb 22, 2019

alexeykazakov commented Feb 22, 2019

GitHub account unlinked from OSIO account #4754

GitHub account unlinked from OSIO account #4754

Comments

ppitonak commented Feb 8, 2019 • edited

Issue Overview

Expected Behaviour

Current Behaviour

Steps To Reproduce

Additional Information

ppitonak commented Feb 11, 2019

joshuawilson commented Feb 11, 2019

alexeykazakov commented Feb 11, 2019

joshuawilson commented Feb 11, 2019

alexeykazakov commented Feb 11, 2019

vikram-raj commented Feb 12, 2019

alexeykazakov commented Feb 12, 2019

ppitonak commented Feb 12, 2019 • edited

alexeykazakov commented Feb 12, 2019

alexeykazakov commented Feb 12, 2019 • edited

alexeykazakov commented Feb 13, 2019

ppitonak commented Feb 14, 2019

ljelinkova commented Feb 14, 2019

alexeykazakov commented Feb 14, 2019

ljelinkova commented Feb 21, 2019

ljelinkova commented Feb 21, 2019

alexeykazakov commented Feb 21, 2019

ljelinkova commented Feb 21, 2019

alexeykazakov commented Feb 21, 2019

alexeykazakov commented Feb 21, 2019

ppitonak commented Feb 22, 2019

alexeykazakov commented Feb 22, 2019

ppitonak commented Feb 22, 2019

alexeykazakov commented Feb 22, 2019

ppitonak commented Feb 8, 2019 •

edited

ppitonak commented Feb 12, 2019 •

edited

alexeykazakov commented Feb 12, 2019 •

edited