vscode-azurefunctions icon indicating copy to clipboard operation
vscode-azurefunctions copied to clipboard

Azure VSCode extension continuously repeats GitHub authentication

Open Qythyx opened this issue 4 months ago • 10 comments

Note, this as a repost from the Azure Resource Groups project.

This is a bit of a complicated issue, so I'll try to explain it.

First, the symptom that I see is in VSCode, when I have the Azure Resources extension installed, it can get into a state where it continuously repeats GitHub authentication. Yes, I know Azure and GitHub are not directly related, but this is what I'm seeing. The messages are shown in the VSCode Output panel for GitHub Authentication, and they look like the following and are repeated continuously.

2025-08-19 16:54:18.347 [info] Getting sessions for all scopes...
2025-08-19 16:54:18.347 [info] Got 5 sessions for ...
2025-08-19 16:54:54.675 [info] Getting sessions for all scopes...
2025-08-19 16:54:54.678 [info] Got 5 sessions for ...
2025-08-19 16:54:54.683 [info] Getting sessions for read:user,repo,user:email,workflow...
2025-08-19 16:54:54.684 [info] Got 1 sessions for read:user,repo,user:email,workflow...

This is a problem because it ends up using the GitHub API, which can expire your rate limit. You can check the usage via a command like curl -H "Authorization: token <GITHUB_PERSONAL_TOKEN>" https://api.github.com/rate_limit. Which shows something like the following (I've excluded the uninteresting bits):

{
  "resources": {
    "core": {
      "limit": 5000,
      "used": 3376,
      "remaining": 1624,
      "reset": 1755591629
    },
    ⠇
    "code_scanning_upload": {
      "limit": 5000,
      "used": 3376,
      "remaining": 1624,
      "reset": 1755591629
    },
    ⠇
  },
  "rate": {
    "limit": 5000,
    "used": 3376,
    "remaining": 1624,
    "reset": 1755591629
  }
}

I've been able to temporarily solve this problem by clicking on the Accounts icon in the bottom-left in VSCode, going to my Microsoft account (the one I use for logging into Azure), and logging out. If I then go to the Azure Resources panel it says I need to Sign in to Azure. If I do that, it logs in successfully and the problem is no longer happening. But, the problem resurfaces at some time later. I'm not sure what causes it to start again.

I mentioned the Azure Resources extension as a problem, but I believe this may happen with any Azure extension, like Azure Functions, Azure Databases, etc.

I also don't know why these Azure extensions have interactions with GitHub authentication. One thing I did notice is that if I go to Account in VSCode, click on my Microsoft account, and then click on Manage Trusted Extensions then a list of trusted extensions is shown, one of which is GitHub Copilot Chat, so this implies at least some connection between this account an GitHub. See the screenshots below.

Image Image

Let me know if there is anything I can do to help investigate this problem more.

Qythyx avatar Aug 23 '25 06:08 Qythyx

This problem continues to regularly happen. I can temporarily solve it by signing out of my Microsoft account in VSCode and then signing back in. But inevitably the problem happens again within a few hours or so. I have not yet been able to figure out what causes it to start happening again.

A few more data points...

First, when the problem is occurring, retrieving Azure resource details in VSCode via the Azure extension is very slow. Refreshing resources takes quite a few minutes. When the problem is not happening it is almost instant.

Second, I've looked through all of the Azure related extension output logs and don't see anything in any of them. The only relevant logs is in GitHub Authentication showing the repeated messages mentioned above. If there is anywhere else I should look to try to diagnose this, please let me know.

Qythyx avatar Aug 25 '25 12:08 Qythyx

@Qythyx This seems super frustrating. Sorry that you're having to deal with it.

But why do you suspect it's the Azure Resources/Azure Functions extension that is making all these calls to the GitHub Authenticator? From everything you screengrabbed, I don't really see any output that indicates our extensions are making these requests.

Our extensions have exclusive output channels named after the extensions: Image

The logs that you posted seem like they're coming from a generic output channel?

Also that screen grab of the extensions that can access this account: is that for your Github account or your Microsoft account? Our extensions definitely access the Microsoft accounts, but should never try to access your Github account outside of very specific flows (like linking your Function app to a Github repository)

nturinski avatar Aug 25 '25 17:08 nturinski

@nturinski, that's a good question, and I can't be sure they are making the authentication requests, but they're definitely somehow involved. As I said, when the problem starts happening and I'm seeing a continuous stream of GitHub Authentication requests, I can immediately fix it by logging out of my Microsoft account, which is used by these Azure extensions. Also, when I log back in there is immediately 1 set of GH auth requests shown in the log (although they don't repeat infinitely...yet). So there is clearly some connection between these.

For the screenshots, there is more info below. It is interesting for the GH account it shows the Azure Functions extension does use it.

This is for my GitHub account:

Image

And here is what is shown for my Microsoft account:

Image

Qythyx avatar Aug 25 '25 23:08 Qythyx

@Qythyx have you tried disabling GitHub Copilot Chat? It seems like it used your Github account last.

nturinski avatar Aug 26 '25 17:08 nturinski

@nturinski, yes, I tried that yesterday at it seems to have helped, but I need to let in run longer to know for sure. Even with that, I still think there's something wrong with the VS Code Azure Resource extension. It gets into a state where refreshing the Azure Resources is extremely slow (takes more than 5 minutes). I'm able to temporarily fix that by logging out of my Microsoft account and then back in, afterwhich the resource refresh is almost instant. But inevitably the problem resurfaces again in the future.

I do find it interesting that this behavior did coincide with the GH Authentication issue originally mentioned. Something about the Azure Resource extension starts behaving badly and causes problems. So far I still haven't been able to find any logs that show anything helpful related to this.

Qythyx avatar Aug 28 '25 00:08 Qythyx

@nturinski, it seems that with either the Azure extensions disabled, or the GH Copilot Chat extension disabled then the problem stops occurring. But with both enabled the problem comes back, although I still cannot reproduce it on demand.

Qythyx avatar Sep 01 '25 09:09 Qythyx

This is interesting, I just noticed in the VSCode output logs for Azure Resource Groups if I show the debug level logs I get something like the following. This is happening at the same time that Azure Resources Extension is in a bad state such that it is very slow to show the list of resources (it basically never finishes refreshing). I don't understand everything in the logs, but the fact that they are repeating indefinitely is not a good sign. Also some of the auth: Got 1 tenants for account "[email protected]" in 2231ms messages show the time is multiple seconds, some exceeding 10 or 20 seconds.

2025-09-01 18:42:04.995 [debug] azure:core-rest-pipeline retryPolicy:info Retry 0: Received a response from request 3d34ddec-87c3-4985-9f52-9f6672054d70
2025-09-01 18:42:04.995 [debug] azure:core-rest-pipeline retryPolicy:info Retry 0: Processing 2 retry strategies.
2025-09-01 18:42:04.996 [debug] azure:core-rest-pipeline retryPolicy:info Retry 0: Processing retry strategy throttlingRetryStrategy.
2025-09-01 18:42:04.996 [debug] azure:core-rest-pipeline retryPolicy:info Retry 0: Skipped.
2025-09-01 18:42:04.996 [debug] azure:core-rest-pipeline retryPolicy:info Retry 0: Processing retry strategy exponentialRetryStrategy.
2025-09-01 18:42:04.996 [debug] azure:core-rest-pipeline retryPolicy:info Retry 0: Skipped.
2025-09-01 18:42:04.996 [debug] azure:core-rest-pipeline retryPolicy:info None of the retry strategies could work with the received response. Returning it.
2025-09-01 18:42:05.181 [debug] azure:core-rest-pipeline:info Response status code: 200
2025-09-01 18:42:05.181 [debug] azure:core-rest-pipeline:info Headers: {
  "cache-control": "no-cache",
  "pragma": "no-cache",
  "content-length": "302",
  "content-type": "application/json; charset=utf-8",
  "expires": "-1",
  "x-ms-ratelimit-remaining-tenant-reads": "249",
  "x-ms-request-id": "47ee2c16-6892-4a86-879c-15d4f27f1d63",
  "x-ms-correlation-request-id": "47ee2c16-6892-4a86-879c-15d4f27f1d63",
  "x-ms-routing-request-id": "JAPANWEST:20250901T094205Z:47ee2c16-6892-4a86-879c-15d4f27f1d63",
  "strict-transport-security": "max-age=31536000; includeSubDomains",
  "x-content-type-options": "nosniff",
  "x-cache": "CONFIG_NOCACHE",
  "x-msedge-ref": "Ref A: BDA1D3B079AF40559786F6575C700E6C Ref B: TYO01EDGE3605 Ref C: 2025-09-01T09:42:04Z",
  "date": "Mon, 01 Sep 2025 09:42:05 GMT",
  "connection": "close"
}
2025-09-01 18:42:05.181 [debug] azure:core-rest-pipeline retryPolicy:info Retry 0: Received a response from request e7f313a4-b454-43ab-8e39-c17ac868d891
2025-09-01 18:42:05.181 [debug] azure:core-rest-pipeline retryPolicy:info Retry 0: Processing 2 retry strategies.
2025-09-01 18:42:05.181 [debug] azure:core-rest-pipeline retryPolicy:info Retry 0: Processing retry strategy throttlingRetryStrategy.
2025-09-01 18:42:05.181 [debug] azure:core-rest-pipeline retryPolicy:info Retry 0: Skipped.
2025-09-01 18:42:05.181 [debug] azure:core-rest-pipeline retryPolicy:info Retry 0: Processing retry strategy exponentialRetryStrategy.
2025-09-01 18:42:05.181 [debug] azure:core-rest-pipeline retryPolicy:info Retry 0: Skipped.
2025-09-01 18:42:05.182 [debug] azure:core-rest-pipeline retryPolicy:info None of the retry strategies could work with the received response. Returning it.
2025-09-01 18:42:05.182 [debug] auth: Got 1 tenants for account "[email protected]" in 5662ms
2025-09-01 18:42:12.234 [debug] azure:core-rest-pipeline retryPolicy:info Retry 0: Attempting to send request b6f6394b-796f-4a7b-86dd-3f023714cafe
2025-09-01 18:42:12.234 [debug] azure:core-rest-pipeline:info Request: {
  "url": "https://management.azure.com/subscriptions?api-version=2022-12-01",
  "headers": {
    "accept": "application/json",
    "accept-encoding": "gzip,deflate",
    "user-agent": "azsdk-js-arm-resources-subscriptions/2.1.0 core-rest-pipeline/1.16.0 Node/22.17.0 OS/(arm64-Darwin-24.6.0)",
    "x-ms-client-request-id": "b6f6394b-796f-4a7b-86dd-3f023714cafe",
    "authorization": "REDACTED"
  },
  "method": "GET",
  "timeout": 0,
  "disableKeepAlive": false,
  "streamResponseStatusCodes": {},
  "withCredentials": false,
  "requestId": "b6f6394b-796f-4a7b-86dd-3f023714cafe",
  "allowInsecureConnection": false,
  "enableBrowserStreams": false
}
2025-09-01 18:42:12.337 [debug] azure:core-rest-pipeline:info Response status code: 200
2025-09-01 18:42:12.337 [debug] azure:core-rest-pipeline:info Headers: {
  "cache-control": "no-cache",
  "pragma": "no-cache",
  "content-length": "516",
  "content-type": "application/json; charset=utf-8",
  "expires": "-1",
  "x-ms-ratelimit-remaining-tenant-reads": "249",
  "x-ms-request-id": "94bd1400-a1cc-4c49-a4ae-1fe13ef4b4ee",
  "x-ms-correlation-request-id": "94bd1400-a1cc-4c49-a4ae-1fe13ef4b4ee",
  "x-ms-routing-request-id": "JAPANEAST:20250901T094212Z:94bd1400-a1cc-4c49-a4ae-1fe13ef4b4ee",
  "strict-transport-security": "max-age=31536000; includeSubDomains",
  "x-content-type-options": "nosniff",
  "x-cache": "CONFIG_NOCACHE",
  "x-msedge-ref": "Ref A: 360B74BB90B147E8ABC19383FA19408E Ref B: TYO01EDGE3817 Ref C: 2025-09-01T09:42:12Z",
  "date": "Mon, 01 Sep 2025 09:42:11 GMT",
  "connection": "close"
}
2025-09-01 18:42:12.337 [debug] azure:core-rest-pipeline retryPolicy:info Retry 0: Received a response from request b6f6394b-796f-4a7b-86dd-3f023714cafe
2025-09-01 18:42:12.337 [debug] azure:core-rest-pipeline retryPolicy:info Retry 0: Processing 2 retry strategies.
2025-09-01 18:42:12.337 [debug] azure:core-rest-pipeline retryPolicy:info Retry 0: Processing retry strategy throttlingRetryStrategy.
2025-09-01 18:42:12.337 [debug] azure:core-rest-pipeline retryPolicy:info Retry 0: Skipped.
2025-09-01 18:42:12.337 [debug] azure:core-rest-pipeline retryPolicy:info Retry 0: Processing retry strategy exponentialRetryStrategy.
2025-09-01 18:42:12.337 [debug] azure:core-rest-pipeline retryPolicy:info Retry 0: Skipped.
2025-09-01 18:42:12.338 [debug] azure:core-rest-pipeline retryPolicy:info None of the retry strategies could work with the received response. Returning it.
2025-09-01 18:42:12.338 [debug] auth: Got 1 subscriptions from 1 accounts in 25401ms
2025-09-01 18:42:15.604 [debug] auth: Loading subscriptions...
2025-09-01 18:42:17.022 [debug] azure:core-rest-pipeline retryPolicy:info Retry 0: Attempting to send request 8f179f27-8db5-483d-b5fb-1424d23d1b6f
2025-09-01 18:42:17.022 [debug] azure:core-rest-pipeline:info Request: {
  "url": "https://management.azure.com/tenants?api-version=2022-12-01",
  "headers": {
    "accept": "application/json",
    "accept-encoding": "gzip,deflate",
    "user-agent": "azsdk-js-arm-resources-subscriptions/2.1.0 core-rest-pipeline/1.16.0 Node/22.17.0 OS/(arm64-Darwin-24.6.0)",
    "x-ms-client-request-id": "8f179f27-8db5-483d-b5fb-1424d23d1b6f",
    "authorization": "REDACTED"
  },
  "method": "GET",
  "timeout": 0,
  "disableKeepAlive": false,
  "streamResponseStatusCodes": {},
  "withCredentials": false,
  "requestId": "8f179f27-8db5-483d-b5fb-1424d23d1b6f",
  "allowInsecureConnection": false,
  "enableBrowserStreams": false
}
2025-09-01 18:42:17.153 [debug] azure:core-rest-pipeline:info Response status code: 200
2025-09-01 18:42:17.153 [debug] azure:core-rest-pipeline:info Headers: {
  "cache-control": "no-cache",
  "pragma": "no-cache",
  "content-length": "302",
  "content-type": "application/json; charset=utf-8",
  "expires": "-1",
  "x-ms-ratelimit-remaining-tenant-reads": "249",
  "x-ms-request-id": "ecfe7176-2383-4c77-bd4a-b0bb4c703f39",
  "x-ms-correlation-request-id": "ecfe7176-2383-4c77-bd4a-b0bb4c703f39",
  "x-ms-routing-request-id": "JAPANWEST:20250901T094217Z:ecfe7176-2383-4c77-bd4a-b0bb4c703f39",
  "strict-transport-security": "max-age=31536000; includeSubDomains",
  "x-content-type-options": "nosniff",
  "x-cache": "CONFIG_NOCACHE",
  "x-msedge-ref": "Ref A: 5BF30A035D464C46BA83DD883EDB4924 Ref B: TYO01EDGE2707 Ref C: 2025-09-01T09:42:17Z",
  "date": "Mon, 01 Sep 2025 09:42:16 GMT",
  "connection": "close"
}
2025-09-01 18:42:17.153 [debug] azure:core-rest-pipeline retryPolicy:info Retry 0: Received a response from request 8f179f27-8db5-483d-b5fb-1424d23d1b6f
2025-09-01 18:42:17.153 [debug] azure:core-rest-pipeline retryPolicy:info Retry 0: Processing 2 retry strategies.
2025-09-01 18:42:17.153 [debug] azure:core-rest-pipeline retryPolicy:info Retry 0: Processing retry strategy throttlingRetryStrategy.
2025-09-01 18:42:17.153 [debug] azure:core-rest-pipeline retryPolicy:info Retry 0: Skipped.
2025-09-01 18:42:17.153 [debug] azure:core-rest-pipeline retryPolicy:info Retry 0: Processing retry strategy exponentialRetryStrategy.
2025-09-01 18:42:17.153 [debug] azure:core-rest-pipeline retryPolicy:info Retry 0: Skipped.
2025-09-01 18:42:17.153 [debug] azure:core-rest-pipeline retryPolicy:info None of the retry strategies could work with the received response. Returning it.
2025-09-01 18:42:17.153 [debug] auth: Got 1 tenants for account "[email protected]" in 2231ms
2025-09-01 18:42:21.118 [debug] azure:core-rest-pipeline retryPolicy:info Retry 0: Attempting to send request d72c4f56-86cb-485f-a764-fed36a26b69c
2025-09-01 18:42:21.118 [debug] azure:core-rest-pipeline:info Request: {
  "url": "https://management.azure.com/tenants?api-version=2022-12-01",
  "headers": {
    "accept": "application/json",
    "accept-encoding": "gzip,deflate",
    "user-agent": "azsdk-js-arm-resources-subscriptions/2.1.0 core-rest-pipeline/1.16.0 Node/22.17.0 OS/(arm64-Darwin-24.6.0)",
    "x-ms-client-request-id": "d72c4f56-86cb-485f-a764-fed36a26b69c",
    "authorization": "REDACTED"
  },
  "method": "GET",
  "timeout": 0,
  "disableKeepAlive": false,
  "streamResponseStatusCodes": {},
  "withCredentials": false,
  "requestId": "d72c4f56-86cb-485f-a764-fed36a26b69c",
  "allowInsecureConnection": false,
  "enableBrowserStreams": false
}
2025-09-01 18:42:21.273 [debug] azure:core-rest-pipeline:info Response status code: 200
2025-09-01 18:42:21.273 [debug] azure:core-rest-pipeline:info Headers: {
  "cache-control": "no-cache",
  "pragma": "no-cache",
  "content-length": "302",
  "content-type": "application/json; charset=utf-8",
  "expires": "-1",
  "x-ms-ratelimit-remaining-tenant-reads": "249",
  "x-ms-request-id": "4faa2c1b-c3c4-4911-b35b-cddebb615ae7",
  "x-ms-correlation-request-id": "4faa2c1b-c3c4-4911-b35b-cddebb615ae7",
  "x-ms-routing-request-id": "JAPANEAST:20250901T094221Z:4faa2c1b-c3c4-4911-b35b-cddebb615ae7",
  "strict-transport-security": "max-age=31536000; includeSubDomains",
  "x-content-type-options": "nosniff",
  "x-cache": "CONFIG_NOCACHE",
  "x-msedge-ref": "Ref A: 5BB55250DED1479EB15F976D0F9F76D5 Ref B: TYO01EDGE2217 Ref C: 2025-09-01T09:42:21Z",
  "date": "Mon, 01 Sep 2025 09:42:20 GMT",
  "connection": "close"
}
2025-09-01 18:42:21.273 [debug] azure:core-rest-pipeline retryPolicy:info Retry 0: Received a response from request d72c4f56-86cb-485f-a764-fed36a26b69c
2025-09-01 18:42:21.273 [debug] azure:core-rest-pipeline retryPolicy:info Retry 0: Processing 2 retry strategies.
2025-09-01 18:42:21.273 [debug] azure:core-rest-pipeline retryPolicy:info Retry 0: Processing retry strategy throttlingRetryStrategy.
2025-09-01 18:42:21.273 [debug] azure:core-rest-pipeline retryPolicy:info Retry 0: Skipped.
2025-09-01 18:42:21.273 [debug] azure:core-rest-pipeline retryPolicy:info Retry 0: Processing retry strategy exponentialRetryStrategy.
2025-09-01 18:42:21.273 [debug] azure:core-rest-pipeline retryPolicy:info Retry 0: Skipped.
2025-09-01 18:42:21.273 [debug] azure:core-rest-pipeline retryPolicy:info None of the retry strategies could work with the received response. Returning it.
2025-09-01 18:42:21.273 [debug] auth: Got 1 tenants for account "[email protected]" in 3822ms

Qythyx avatar Sep 01 '25 09:09 Qythyx

After some more investigation I found that when the Resources extension is in this bad state, even closing and reopening VSCode does not fix it. If I log out of my Microsoft account, however, then the problem stops, since it can't try to query the resources at all.

If I then log back into my Microsoft account the extension seems to work fine. Loading the resources is fast, and looking at the logs the timing shows responses in 100 to 300 ms. Much faster. I tried refreshing the resources multiple times and it was fine. I also tried quitting and restarting VSCode and it was still fine.

So, I still have no idea what puts it into this bad state. I'm still very suspicious that both the Azure authentication gets into a state where it repeats indefinitely and the GitHub Authentication does the same.

I'm going to try staying logged out of GitHub for a while and see if only using Azure still causes the problem.

Qythyx avatar Sep 01 '25 10:09 Qythyx

Thanks for this deep level of investigation. The core rest pipelines are what the Azure SDKs use to make any request to the Azure API and the specific API call that seems to be listed there is for GETing tenants.

I'm still not quite sure why this is happening or how I can reproduce it, but this is pointing us in the right direction.

Are you using VS Code Desktop or on the web? And are you using stable or insiders?

nturinski avatar Sep 04 '25 22:09 nturinski

I'm using Desktop and the stable version.

Qythyx avatar Sep 05 '25 00:09 Qythyx