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

Setting Sync: failed because of Unauthorized (401) #133201

Closed
carlocardella opened this issue Sep 15, 2021 · 60 comments
Closed

Setting Sync: failed because of Unauthorized (401) #133201

carlocardella opened this issue Sep 15, 2021 · 60 comments
Assignees
Labels
authentication Issues with the Authentication platform bug Issue identified by VS Code Team member as probable bug candidate Issue identified as probable candidate for fixing in the next release verified Verification succeeded

Comments

@carlocardella
Copy link
Member

Does this issue occur when all extensions are disabled?: Yes

  • VS Code Version:
Version: 1.60.1 (user setup)
Commit: 83bd43bc519d15e50c4272c6cf5c1479df196a4d
Date: 2021-09-10T17:07:10.714Z
Electron: 13.1.8
Chrome: 91.0.4472.164
Node.js: 14.16.0
V8: 9.1.269.39-electron.0
OS: Windows_NT x64 10.0.22000

Steps to Reproduce:

  1. Enable Settings Sync (with a Microsoft account, @live.com in case it matter)
  2. Wait 15-20 minutes, sync will eventually stop with an Unauthorized error

I can reproduce this problem on three different machines, both with the latest Stable and Insiders. The problem started last month for me but we were just a few days away from the August release so I decided to wait and see if the problem went away with the new version (it happened in the past). It didn't.

Setting Sync Log:

[2021-09-14 18:14:00.571] [settingssync] [info] Auto Sync: Triggered by Interval
[2021-09-14 18:14:00.870] [settingssync] [info] Settings: No changes found during synchronizing settings.
[2021-09-14 18:14:00.884] [settingssync] [info] Keybindings: No changes found during synchronizing keybindings.
[2021-09-14 18:14:00.899] [settingssync] [info] Snippets: No changes found during synchronizing snippets.
[2021-09-14 18:14:01.175] [settingssync] [info] GlobalState: No changes found during synchronizing ui state.
[2021-09-14 18:14:01.417] [settingssync] [info] Extensions: No changes found during synchronizing extensions.
[2021-09-14 18:14:01.421] [settingssync] [info] Sync done. Took 679ms
[2021-09-14 18:19:01.439] [settingssync] [info] Auto Sync: Triggered by Interval
[2021-09-14 18:19:01.707] [settingssync] [info] Settings: No changes found during synchronizing settings.
[2021-09-14 18:19:01.749] [settingssync] [info] Keybindings: No changes found during synchronizing keybindings.
[2021-09-14 18:19:01.765] [settingssync] [info] Snippets: No changes found during synchronizing snippets.
[2021-09-14 18:19:02.031] [settingssync] [info] GlobalState: No changes found during synchronizing ui state.
[2021-09-14 18:19:02.277] [settingssync] [info] Extensions: No changes found during synchronizing extensions.
[2021-09-14 18:19:02.278] [settingssync] [info] Sync done. Took 688ms
[2021-09-14 18:24:02.283] [settingssync] [info] Auto Sync: Triggered by Interval
[2021-09-14 18:24:02.567] [settingssync] [info] Settings: No changes found during synchronizing settings.
[2021-09-14 18:24:02.583] [settingssync] [info] Keybindings: No changes found during synchronizing keybindings.
[2021-09-14 18:24:02.602] [settingssync] [info] Snippets: No changes found during synchronizing snippets.
[2021-09-14 18:24:02.897] [settingssync] [info] GlobalState: No changes found during synchronizing ui state.
[2021-09-14 18:24:03.125] [settingssync] [info] Extensions: No changes found during synchronizing extensions.
[2021-09-14 18:24:03.126] [settingssync] [info] Sync done. Took 698ms
[2021-09-14 18:29:03.136] [settingssync] [info] Auto Sync: Triggered by Interval
[2021-09-14 18:29:03.426] [settingssync] [info] Settings: No changes found during synchronizing settings.
[2021-09-14 18:29:03.442] [settingssync] [info] Keybindings: No changes found during synchronizing keybindings.
[2021-09-14 18:29:03.456] [settingssync] [info] Snippets: No changes found during synchronizing snippets.
[2021-09-14 18:29:03.720] [settingssync] [info] GlobalState: No changes found during synchronizing ui state.
[2021-09-14 18:29:03.959] [settingssync] [info] Extensions: No changes found during synchronizing extensions.
[2021-09-14 18:29:03.965] [settingssync] [info] Sync done. Took 654ms
[2021-09-14 18:34:03.973] [settingssync] [info] Auto Sync: Triggered by Interval
[2021-09-14 18:34:04.120] [settingssync] [info] Request failed {"url":"https://vscode-sync.trafficmanager.net/v1/manifest","status":401,"execution-id":"3a1b0766-8591-4179-ab40-e37a58352793"}
[2021-09-14 18:34:04.120] [settingssync] [info] Auto Sync: Suspended until auth token is available.
[2021-09-14 18:34:04.120] [settingssync] [info] Auto sync: Cancelled sync that is in progress
[2021-09-14 18:34:04.120] [settingssync] [info] Auto Sync: Stopped
[2021-09-14 18:34:04.121] [settingssync] [error] Unauthorized (UserDataSyncError) syncResource:unknown operationId:unknown: Request 'https://vscode-sync.trafficmanager.net/v1/manifest' failed because of Unauthorized (401).
    at S.request (vscode-file://vscode-app/c:/Users/carloc/AppData/Local/Programs/Microsoft%20VS%20Code/resources/app/out/vs/code/electron-browser/sharedProcess/sharedProcessMain.js:58:171737)
    at async S.manifest (vscode-file://vscode-app/c:/Users/carloc/AppData/Local/Programs/Microsoft%20VS%20Code/resources/app/out/vs/code/electron-browser/sharedProcess/sharedProcessMain.js:58:168934)
    at async o.createSyncTask (vscode-file://vscode-app/c:/Users/carloc/AppData/Local/Programs/Microsoft%20VS%20Code/resources/app/out/vs/code/electron-browser/sharedProcess/sharedProcessMain.js:58:140173)
    at async u.doSync (vscode-file://vscode-app/c:/Users/carloc/AppData/Local/Programs/Microsoft%20VS%20Code/resources/app/out/vs/code/electron-browser/sharedProcess/sharedProcessMain.js:58:134594)
[2021-09-14 18:34:04.148] [settingssync] [info] Auto Sync: Started
[2021-09-14 18:34:04.149] [settingssync] [info] Auto Sync: Triggered by Interval
[2021-09-14 18:34:04.176] [settingssync] [info] Request failed {"url":"https://vscode-sync.trafficmanager.net/v1/manifest","status":401,"execution-id":"4ceacf3f-3468-47d1-a83a-910db1f0a0e9"}
[2021-09-14 18:34:04.176] [settingssync] [info] Auto Sync: Suspended until auth token is available.
[2021-09-14 18:34:04.176] [settingssync] [info] Auto sync: Cancelled sync that is in progress
[2021-09-14 18:34:04.176] [settingssync] [info] Auto Sync: Stopped
[2021-09-14 18:34:04.177] [settingssync] [error] Unauthorized (UserDataSyncError) syncResource:unknown operationId:unknown: Request 'https://vscode-sync.trafficmanager.net/v1/manifest' failed because of Unauthorized (401).
    at S.request (vscode-file://vscode-app/c:/Users/carloc/AppData/Local/Programs/Microsoft%20VS%20Code/resources/app/out/vs/code/electron-browser/sharedProcess/sharedProcessMain.js:58:171737)
    at async S.manifest (vscode-file://vscode-app/c:/Users/carloc/AppData/Local/Programs/Microsoft%20VS%20Code/resources/app/out/vs/code/electron-browser/sharedProcess/sharedProcessMain.js:58:168934)
    at async o.createSyncTask (vscode-file://vscode-app/c:/Users/carloc/AppData/Local/Programs/Microsoft%20VS%20Code/resources/app/out/vs/code/electron-browser/sharedProcess/sharedProcessMain.js:58:140173)
    at async u.doSync (vscode-file://vscode-app/c:/Users/carloc/AppData/Local/Programs/Microsoft%20VS%20Code/resources/app/out/vs/code/electron-browser/sharedProcess/sharedProcessMain.js:58:134594)

Things I tried (all with no luck):

  1. Logged off from the Microsoft account I use for sync
  2. Turn off Settings Sync on all my machines and VSCode instances
  3. Clear data in Cloud

One additional pointer: I sync both Stable and Insiders on the Stable channel.
I remember at least one occurrence in the past where the two versions could not be sync'ed in the same channel because of some temporary incompatibility, is this still the case?

@TylerLeonhardt
Copy link
Member

Can you provide the contents of the Microsoft Authentication output pane:
image

And also anything that shows up in Dev Tools:

  • ctrl + shift + P
  • "Dev Tools"

@carlocardella
Copy link
Member Author

Sure.

Microsoft Authentication pane:

[...]
[Info  - 12:18:04.814] Token available from cache, expires in 4947995 milliseconds
[Info  - 12:18:04.814] Token available from cache, expires in 2041716 milliseconds
[Info  - 12:18:04.824] Token available from cache, expires in 2041706 milliseconds
[Info  - 12:51:36.516] Refreshing token...
[Error  - 12:51:38.244] Unexpected token � in JSON at position 0
[Info  - 12:51:38.244] Failed to fetch token claims from access_token. Attempting to parse id_token instead
[Info  - 12:51:38.244] Token refresh success
[Info  - 12:51:38.247] Token available from cache, expires in 2934562 milliseconds
[Info  - 12:51:38.247] Token available from cache, expires in 4206997 milliseconds
[Info  - 12:51:38.250] Token available from cache, expires in 4206994 milliseconds
[Info  - 13:40:02.799] Refreshing token...
[Info  - 13:40:03.39] Token refresh success
[Info  - 13:40:03.43] Token available from cache, expires in 3849996 milliseconds
[Info  - 13:40:03.43] Token available from cache, expires in 1302201 milliseconds
[Info  - 13:40:03.46] Token available from cache, expires in 1302198 milliseconds
[Info  - 14:01:15.230] Refreshing token...
[Error  - 14:01:16.546] Unexpected token � in JSON at position 0
[Info  - 14:01:16.546] Failed to fetch token claims from access_token. Attempting to parse id_token instead
[Info  - 14:01:16.546] Token refresh success
[Info  - 14:01:16.552] Token available from cache, expires in 2576487 milliseconds
[Info  - 14:01:16.552] Token available from cache, expires in 3783994 milliseconds
[Info  - 14:01:16.559] Token available from cache, expires in 3783987 milliseconds

I do not see anything unusual in the Dev Console but I'll post the output after the next repro

@carlocardella
Copy link
Member Author

Just got a new repro.

[Info  - 14:44:32.763] Token available from cache, expires in 3650015 milliseconds
[Info  - 14:44:32.763] Token available from cache, expires in 1187783 milliseconds
[Info  - 14:44:35.821] Token available from cache, expires in 3646957 milliseconds
[Info  - 14:44:35.821] Token available from cache, expires in 1184725 milliseconds
[Info  - 14:44:37.854] Token available from cache, expires in 3644924 milliseconds
[Info  - 14:44:37.854] Token available from cache, expires in 1182692 milliseconds
[Info  - 15:03:50.540] Refreshing token...
[Error  - 15:03:51.972] Unexpected token � in JSON at position 0
[Info  - 15:03:51.972] Failed to fetch token claims from access_token. Attempting to parse id_token instead
[Info  - 15:03:51.972] Token refresh success
[Info  - 15:03:51.976] Token available from cache, expires in 2490802 milliseconds
[Info  - 15:03:51.976] Token available from cache, expires in 4490996 milliseconds
[Info  - 15:03:51.984] Token available from cache, expires in 4490988 milliseconds
[Info  - 15:10:46.820] Token available from cache, expires in 2075958 milliseconds
[Info  - 15:10:46.820] Token available from cache, expires in 4076152 milliseconds
[Info  - 15:43:54.491] Token available from cache, expires in 88287 milliseconds
[Info  - 15:43:54.491] Token available from cache, expires in 2088481 milliseconds
[Info  - 15:43:54.519] Token available from cache, expires in 88259 milliseconds
[Info  - 15:43:54.519] Token available from cache, expires in 2088453 milliseconds <== the error happened here, nothing in the log after this line

Dev Console content:
vscode-app-1631807142289.zip

@TylerLeonhardt TylerLeonhardt added authentication Issues with the Authentication platform bug Issue identified by VS Code Team member as probable bug labels Sep 16, 2021
@carlocardella
Copy link
Member Author

Quick update: I have used "Clear Data in Cloud" one more time and apparently sync is stable now, it has been running for over 30 minutes which is much longer than it used to

@carlocardella
Copy link
Member Author

carlocardella commented Sep 17, 2021

I spoke too soon 😒
Sync failed on one (only one, so far) of the Insiders instances with the same Unautheorized error:

[2021-09-16 17:14:42.815] [settingssync] [info] Keybindings: No changes found during synchronizing keybindings.
[2021-09-16 17:14:42.829] [settingssync] [info] Snippets: No changes found during synchronizing snippets.
[2021-09-16 17:14:43.095] [settingssync] [info] GlobalState: No changes found during synchronizing ui state.
[2021-09-16 17:14:43.277] [settingssync] [info] Extensions: No changes found during synchronizing extensions.
[2021-09-16 17:14:43.277] [settingssync] [info] Sync done. Took 544ms
[2021-09-16 17:19:43.292] [settingssync] [info] Auto Sync: Triggered by Interval
[2021-09-16 17:19:43.504] [settingssync] [info] Settings: No changes found during synchronizing settings.
[2021-09-16 17:19:43.511] [settingssync] [info] Keybindings: No changes found during synchronizing keybindings.
[2021-09-16 17:19:43.526] [settingssync] [info] Snippets: No changes found during synchronizing snippets.
[2021-09-16 17:19:43.775] [settingssync] [info] GlobalState: No changes found during synchronizing ui state.
[2021-09-16 17:19:44.196] [settingssync] [info] Extensions: No changes found during synchronizing extensions.
[2021-09-16 17:19:44.196] [settingssync] [info] Sync done. Took 779ms
[2021-09-16 17:24:44.205] [settingssync] [info] Auto Sync: Triggered by Interval
[2021-09-16 17:24:44.433] [settingssync] [info] Settings: No changes found during synchronizing settings.
[2021-09-16 17:24:44.448] [settingssync] [info] Keybindings: No changes found during synchronizing keybindings.
[2021-09-16 17:24:44.465] [settingssync] [info] Snippets: No changes found during synchronizing snippets.
[2021-09-16 17:24:44.831] [settingssync] [info] GlobalState: Updated global state ["workbench.activity.pinnedViewlets2"]
[2021-09-16 17:24:44.831] [settingssync] [info] GlobalState: Updated local ui state
[2021-09-16 17:24:44.834] [settingssync] [info] GlobalState: Updated last synchronized ui state
[2021-09-16 17:24:45.290] [settingssync] [info] Extensions: No changes found during synchronizing extensions.
[2021-09-16 17:24:45.291] [settingssync] [info] Sync done. Took 945ms
[2021-09-16 17:29:45.305] [settingssync] [info] Auto Sync: Triggered by Interval
[2021-09-16 17:29:45.466] [settingssync] [info] Request failed {"url":"https://vscode-sync.trafficmanager.net/v1/manifest","status":401,"execution-id":"0371de49-22de-4240-beaa-696bf9826d01"}
[2021-09-16 17:29:45.466] [settingssync] [info] Auto Sync: Suspended until auth token is available.
[2021-09-16 17:29:45.466] [settingssync] [info] Auto sync: Cancelled sync that is in progress
[2021-09-16 17:29:45.466] [settingssync] [info] Auto Sync: Stopped
[2021-09-16 17:29:45.466] [settingssync] [error] Unauthorized (UserDataSyncError) syncResource:unknown operationId:unknown: Request 'https://vscode-sync.trafficmanager.net/v1/manifest' failed because of Unauthorized (401).
    at p.request (vscode-file://vscode-app/c:/Users/carloc/AppData/Local/Programs/Microsoft%20VS%20Code%20Insiders/resources/app/out/vs/code/electron-browser/sharedProcess/sharedProcessMain.js:58:172186)
    at async p.manifest (vscode-file://vscode-app/c:/Users/carloc/AppData/Local/Programs/Microsoft%20VS%20Code%20Insiders/resources/app/out/vs/code/electron-browser/sharedProcess/sharedProcessMain.js:58:169383)
    at async o.createSyncTask (vscode-file://vscode-app/c:/Users/carloc/AppData/Local/Programs/Microsoft%20VS%20Code%20Insiders/resources/app/out/vs/code/electron-browser/sharedProcess/sharedProcessMain.js:58:140642)
    at async c.doSync (vscode-file://vscode-app/c:/Users/carloc/AppData/Local/Progra
[vscode-app-1631838932742.zip](https://github.com/microsoft/vscode/files/718
[vscode-app-1631838932742.zip](https://github.com/microsoft/vscode/files/7181690/vscode-app-1631838932742.zip)
[vscode-app-1631838932742.zip](https://github.com/microsoft/v
[vscode-app-1631838932742.zip](https://github.com/microsoft/vscode/files/7181698/vscode-app-1631838932742.zip)
scode/files/7181696/vscode-app-1631838932742.zip)

[vscode-app-1631838932742.zip](https://github.com/microsoft/vscode/files/7181686/vscode-app-1631838932742.zip)
1685/vscode-app-1631838932742.zip)
ms/Microsoft%20VS%20Code%20Insiders/resources/app/out/vs/code/electron-browser/sharedProcess/sharedProcessMain.js:58:135066)
[2021-09-16 17:29:45.492] [settingssync] [info] Auto Sync: Started
[2021-09-16 17:29:45.492] [settingssync] [info] Auto Sync: Triggered by Interval
[2021-09-16 17:29:45.519] [settingssync] [info] Request failed {"url":"https://vscode-sync.trafficmanager.net/v1/manifest","status":401,"execution-id":"09392d1e-4e82-4f1b-a333-fc3056aeaca9"}
[2021-09-16 17:29:45.519] [settingssync] [info] Auto Sync: Suspended until auth token is available.
[2021-09-16 17:29:45.519] [settingssync] [info] Auto sync: Cancelled sync that is in progress
[2021-09-16 17:29:45.520] [settingssync] [info] Auto Sync: Stopped
[2021-09-16 17:29:45.520] [settingssync] [error] Unauthorized (UserDataSyncError) 
[vscode-app-1631838932742.zip](https://github.com/microsoft/vscode/files/7181695/vscode-app-1631838932742.zip)
syncRes
[vscode-app-1631838932742.zip](https://github.com/microsoft/vscode/files/7181692/vscode-app-1631838932742.zip)
ource:unknown operationId:unknown: Request 'https://vscode-sync.trafficmanager.net/v1/manifest' failed because of Unauthorized (401).
    at p.request (vscode-file://vscode-app/c:/Users/carloc/AppData/Local/Programs/Microsoft%20VS%20Code%20Insiders/resources/app/out/vs/code/electron-browser/sharedProcess/sharedProcessMain.js:58:172186)
    at async p.manifest (vscode-file://vscode-app/c:/Users/carloc/AppData/Local/Programs/Microsoft%20VS%20Code%20Insiders/resources/app/out/vs/code/electron-browser/sharedProcess/sharedProcessMain.js:58:169383)
    at async o.createSyncTask (vscode-file://vscode-app/c:/Users/carloc/AppData/Local/Programs/Microsoft%20VS%20Code%20Insiders/resources/app/out/vs/code/electron-browser/sharedProcess/sharedProcessMain.js:58:140642)
    at async c.doSync (vscode-file://vscode-app/c:/Users/carloc/AppData/Local/Programs/Microsoft%20VS%20Code%20Insiders/resources/app/out/vs/code/electron-browser/sharedProcess/sharedProcessMain.js:58:135066)

Anyway this time there is no json error in the Authentication output:

[Info  - 00:18:17.369] Token refresh success
[Info  - 00:18:17.370] Token available from cache, expires in 3598894 milliseconds
[Info  - 00:18:17.370] Token available from cache, expires in 36000 milliseconds
[Info  - 00:18:17.370] Token available from cache, expires in 3598999 milliseconds
[Info  - 00:18:17.370] Token available from cache, expires in 2568318 milliseconds
[Info  - 00:18:17.370] Token available from cache, expires in 3090988 milliseconds
[Info  - 00:18:17.370] Token available from cache, expires in 1015073 milliseconds
[Info  - 00:18:17.373] Token available from cache, expires in 3090985 milliseconds
[Info  - 00:18:23.382] Refreshing token...
[Info  - 00:18:23.663] Token refresh success
[Info  - 00:18:23.665] Token available from cache, expires in 3592599 milliseconds
[Info  - 00:18:23.665] Token available from cache, expires in 4135998 milliseconds
[Info  - 00:18:23.665] Token available from cache, expires in 3592704 milliseconds
[Info  - 00:18:23.665] Token available from cache, expires in 2562023 milliseconds
[Info  - 00:18:23.665] Token available from cache, expires in 3084693 milliseconds
[Info  - 00:18:23.665] Token available from cache, expires in 1008778 milliseconds
[Info  - 00:18:23.668] Token available from cache, expires in 3084690 milliseconds
[Info  - 00:29:45.489] Token available from cache, expires in 2910775 milliseconds
[Info  - 00:29:45.489] Token available from cache, expires in 3454174 milliseconds
[Info  - 00:29:45.489] Token available from cache, expires in 2910880 milliseconds
[Info  - 00:29:45.489] Token available from cache, expires in 1880199 milliseconds
[Info  - 00:29:45.489] Token available from cache, expires in 2402869 milliseconds
[Info  - 00:29:45.489] Token available from cache, expires in 326954 milliseconds
[Info  - 00:29:45.520] Token available from cache, expires in 2910744 milliseconds
[Info  - 00:29:45.520] Token available from cache, expires in 3454143 milliseconds
[Info  - 00:29:45.520] Token available from cache, expires in 2910849 milliseconds
[Info  - 00:29:45.520] Token available from cache, expires in 1880168 milliseconds
[Info  - 00:29:45.520] Token available from cache, expires in 2402838 milliseconds
[Info  - 00:29:45.520] Token available from cache, expires in 326923 milliseconds

This is the full Dev Tools console output from this Iniders instance:
vscode-app-1631838932742.zip

@carlocardella
Copy link
Member Author

While I do still see the error Invalid token in JSON in Insiders, sync seems to be more stable (it as not crashed in a while).
The crash remains with the latest Stable

@TylerLeonhardt
Copy link
Member

Thanks for providing all this useful data @carlocardella I will try to investigate as much as I can this week.

@mtayler
Copy link

mtayler commented Sep 29, 2021

I have also been experiencing this same issue with similar logs, using an @microsoft.com account.

@TylerLeonhardt TylerLeonhardt modified the milestones: Backlog, October 2021 Oct 4, 2021
@carlocardella
Copy link
Member Author

Stable 1.61 is, well... stable... I do still see the invalid token in json error but at least the sync is not crashing anymore, on any of my machines and vscode versions

@laurinkeithdavis
Copy link

I am still having machines fail with this:

Version: 1.61.2 (system setup)
Commit: 6cba118
Date: 2021-10-19T14:57:20.575Z
Electron: 13.5.1
Chrome: 91.0.4472.164
Node.js: 14.16.0
V8: 9.1.269.39-electron.0
OS: Windows_NT x64 10.0.17763

I was able to fix one by signing in to LiveShare instead.

@laurinkeithdavis
Copy link

Finally found this:
image

Had to do it twice before it worked (first time, did not sign me out). Now, it's working (for how long, I have no idea).

@scott-burgess
Copy link

Had to do it twice before it worked (first time, did not sign me out). Now, it's working (for how long, I have no idea).

For me, signing out and in didn't resolve this issue either - I still get this:
[2021-10-25 13:37:14.888] [settingssync] [error] Unauthorized (UserDataSyncError) syncResource:unknown operationId:unknown: Request 'https://vscode-sync.trafficmanager.net/v1/manifest' failed because of Unauthorized (401).

@TylerLeonhardt
Copy link
Member

I've added a ton more logging on the Microsoft Auth side in that☝️ commit and I did move a few other things around... let's see how it goes for you all. Please try out Insiders tomorrow.

If you still see the issue, please add the Microsoft Authentication Output channel here.

Here's where it is for your reference:
image

@carlocardella
Copy link
Member Author

carlocardella commented Oct 27, 2021

Looks like Stable has regressed on all my machines, the behavior and logs looks the same as what I previously shared above.
Insiders is still running smoothly (for now)

@TylerLeonhardt
Copy link
Member

We'll have a new stable next week so we'll be able to really test things out then.

@miguelsolorio
Copy link
Contributor

miguelsolorio commented Oct 28, 2021

Adding logs from today's Insiders, though I am using the Stable settings sync service:

[Info  - 19:51:35.471] Getting sessions for all scopes...
[Info  - 19:51:35.471] Token available from cache (for scopes https://management.core.windows.net/.default offline_access), expires in 2373190 milliseconds
[Info  - 19:51:35.471] Got 1 sessions for all scopes...
[Info  - 19:51:41.291] Getting sessions for all scopes...
[Info  - 19:51:41.291] Token available from cache (for scopes https://management.core.windows.net/.default offline_access), expires in 2367370 milliseconds
[Info  - 19:51:41.292] Got 1 sessions for all scopes...
[Info  - 19:51:41.492] Getting sessions for all scopes...
[Info  - 19:51:41.492] Token available from cache (for scopes https://management.core.windows.net/.default offline_access), expires in 2367169 milliseconds
[Info  - 19:51:41.495] Got 1 sessions for all scopes...
[Info  - 19:51:41.553] Getting sessions for all scopes...
[Info  - 19:51:41.553] Token available from cache (for scopes https://management.core.windows.net/.default offline_access), expires in 2367108 milliseconds
[Info  - 19:51:41.553] Got 1 sessions for all scopes...
[Info  - 19:51:41.702] Getting sessions for all scopes...
[Info  - 19:51:41.702] Token available from cache (for scopes https://management.core.windows.net/.default offline_access), expires in 2366959 milliseconds
[Info  - 19:51:41.703] Got 1 sessions for all scopes...

and settings sync logs:

[2021-10-28 13:11:51.936] [settingssync] [info] Request failed {"url":"https://vscode-sync.trafficmanager.net/v1/manifest","status":401,"execution-id":"f22f0035-6ea0-49c9-b659-6d2e5fc40b68"}

@carlocardella
Copy link
Member Author

carlocardella commented Nov 10, 2021

Just got another error, this is the Settings Sync with log level as trace:

[2021-11-10 09:42:17.121] [settingssync] [info] Sync done. Took 1644ms
[2021-11-10 09:43:33.960] [settingssync] [trace] activity sources windowFocus
[2021-11-10 09:43:33.960] [settingssync] [info] Auto Sync: Triggered by Activity
[2021-11-10 09:43:33.961] [settingssync] [trace] Sending request to server {"url":"https://vscode-sync.trafficmanager.net/v1/manifest","type":"GET","headers":{"X-Execution-Id":"e248defe-a670-4845-a9db-505653d82545","Content-Type":"application/json","If-None-Match":"W/\"171-qh5Ul7c3SZE7Hh71SMWFzaXN46k\"","X-Client-Name":"code-insiders","X-Client-Version":"1.63.0-insider","X-Client-Commit":"bef4dba21f68bbdb8d9f08fe04b2e1858597722b","X-Account-Type":"microsoft","X-Machine-Session-Id":"53269ec8-db53-44ca-8ffa-8992a13ea56b","X-User-Session-Id":"4d7117a7-8763-4605-97ef-3cfd22ba0a6b"}}
[2021-11-10 09:43:34.002] [settingssync] [trace] Request succeeded {"url":"https://vscode-sync.trafficmanager.net/v1/manifest","status":304,"execution-id":"e248defe-a670-4845-a9db-505653d82545"}
[2021-11-10 09:43:34.002] [settingssync] [trace] Sync started.
[2021-11-10 09:43:34.003] [settingssync] [trace] Settings: Started synchronizing settings...
[2021-11-10 09:43:34.193] [settingssync] [trace] Settings: Merging remote settings with local settings...
[2021-11-10 09:43:34.193] [settingssync] [info] Settings: No changes found during synchronizing settings.
[2021-11-10 09:43:34.195] [settingssync] [trace] Settings: Finished synchronizing settings.
[2021-11-10 09:43:34.195] [settingssync] [trace] Keybindings: Started synchronizing keybindings...
[2021-11-10 09:43:34.202] [settingssync] [trace] Keybindings: Merging remote keybindings with local keybindings...
[2021-11-10 09:43:34.216] [settingssync] [info] Keybindings: No changes found during synchronizing keybindings.
[2021-11-10 09:43:34.218] [settingssync] [trace] Keybindings: Finished synchronizing keybindings.
[2021-11-10 09:43:34.219] [settingssync] [trace] Snippets: Started synchronizing snippets...
[2021-11-10 09:43:34.229] [settingssync] [trace] Snippets: Merging remote snippets with local snippets...
[2021-11-10 09:43:34.229] [settingssync] [info] Snippets: No changes found during synchronizing snippets.
[2021-11-10 09:43:34.233] [settingssync] [trace] Snippets: Finished synchronizing snippets.
[2021-11-10 09:43:34.234] [settingssync] [trace] GlobalState: Started synchronizing globalstate...
[2021-11-10 09:43:34.237] [settingssync] [debug] GlobalStateSync#getLocalArgvContent {"$mid":1,"fsPath":"c:\\Users\\carloc\\.vscode-insiders\\argv.json","_sep":1,"path":"/C:/Users/carloc/.vscode-insiders/argv.json","scheme":"file"}
[2021-11-10 09:43:34.830] [settingssync] [debug] GlobalStateSync#getLocalArgvContent - Resolved {"$mid":1,"fsPath":"c:\\Users\\carloc\\.vscode-insiders\\argv.json","_sep":1,"path":"/C:/Users/carloc/.vscode-insiders/argv.json","scheme":"file"}
[2021-11-10 09:43:34.830] [settingssync] [trace] GlobalState: Merging remote ui state with local ui state...
[2021-11-10 09:43:34.830] [settingssync] [info] GlobalState: No changes found during synchronizing ui state.
[2021-11-10 09:43:34.849] [settingssync] [trace] GlobalState: Finished synchronizing globalstate.
[2021-11-10 09:43:34.850] [settingssync] [trace] Extensions: Started synchronizing extensions...
[2021-11-10 09:43:35.100] [settingssync] [trace] Extensions: Merging remote extensions with local extensions...
[2021-11-10 09:43:35.100] [settingssync] [info] Extensions: No changes found during synchronizing extensions.
[2021-11-10 09:43:35.101] [settingssync] [trace] Extensions: Finished synchronizing extensions.
[2021-11-10 09:43:35.101] [settingssync] [info] Sync done. Took 1099ms
[2021-11-10 09:48:35.124] [settingssync] [info] Auto Sync: Triggered by Interval
[2021-11-10 09:48:35.125] [settingssync] [trace] Sending request to server {"url":"https://vscode-sync.trafficmanager.net/v1/manifest","type":"GET","headers":{"X-Execution-Id":"10d9a636-c2f8-46d3-9f06-a7bd8247fde5","Content-Type":"application/json","If-None-Match":"W/\"171-qh5Ul7c3SZE7Hh71SMWFzaXN46k\"","X-Client-Name":"code-insiders","X-Client-Version":"1.63.0-insider","X-Client-Commit":"bef4dba21f68bbdb8d9f08fe04b2e1858597722b","X-Account-Type":"microsoft","X-Machine-Session-Id":"53269ec8-db53-44ca-8ffa-8992a13ea56b","X-User-Session-Id":"4d7117a7-8763-4605-97ef-3cfd22ba0a6b"}}
[2021-11-10 09:48:35.201] [settingssync] [trace] Request succeeded {"url":"https://vscode-sync.trafficmanager.net/v1/manifest","status":304,"execution-id":"10d9a636-c2f8-46d3-9f06-a7bd8247fde5"}
[2021-11-10 09:48:35.202] [settingssync] [trace] Sync started.
[2021-11-10 09:48:35.203] [settingssync] [trace] Settings: Started synchronizing settings...
[2021-11-10 09:48:35.384] [settingssync] [trace] Settings: Merging remote settings with local settings...
[2021-11-10 09:48:35.384] [settingssync] [info] Settings: No changes found during synchronizing settings.
[2021-11-10 09:48:35.387] [settingssync] [trace] Settings: Finished synchronizing settings.
[2021-11-10 09:48:35.387] [settingssync] [trace] Keybindings: Started synchronizing keybindings...
[2021-11-10 09:48:35.399] [settingssync] [trace] Keybindings: Merging remote keybindings with local keybindings...
[2021-11-10 09:48:35.413] [settingssync] [info] Keybindings: No changes found during synchronizing keybindings.
[2021-11-10 09:48:35.415] [settingssync] [trace] Keybindings: Finished synchronizing keybindings.
[2021-11-10 09:48:35.415] [settingssync] [trace] Snippets: Started synchronizing snippets...
[2021-11-10 09:48:35.431] [settingssync] [trace] Snippets: Merging remote snippets with local snippets...
[2021-11-10 09:48:35.431] [settingssync] [info] Snippets: No changes found during synchronizing snippets.
[2021-11-10 09:48:35.437] [settingssync] [trace] Snippets: Finished synchronizing snippets.
[2021-11-10 09:48:35.437] [settingssync] [trace] GlobalState: Started synchronizing globalstate...
[2021-11-10 09:48:35.441] [settingssync] [debug] GlobalStateSync#getLocalArgvContent {"$mid":1,"fsPath":"c:\\Users\\carloc\\.vscode-insiders\\argv.json","_sep":1,"path":"/C:/Users/carloc/.vscode-insiders/argv.json","scheme":"file"}
[2021-11-10 09:48:36.036] [settingssync] [debug] GlobalStateSync#getLocalArgvContent - Resolved {"$mid":1,"fsPath":"c:\\Users\\carloc\\.vscode-insiders\\argv.json","_sep":1,"path":"/C:/Users/carloc/.vscode-insiders/argv.json","scheme":"file"}
[2021-11-10 09:48:36.036] [settingssync] [trace] GlobalState: Merging remote ui state with local ui state...
[2021-11-10 09:48:36.037] [settingssync] [info] GlobalState: No changes found during synchronizing ui state.
[2021-11-10 09:48:36.037] [settingssync] [trace] GlobalState: Finished synchronizing globalstate.
[2021-11-10 09:48:36.037] [settingssync] [trace] Extensions: Started synchronizing extensions...
[2021-11-10 09:48:36.278] [settingssync] [trace] Extensions: Merging remote extensions with local extensions...
[2021-11-10 09:48:36.278] [settingssync] [info] Extensions: No changes found during synchronizing extensions.
[2021-11-10 09:48:36.278] [settingssync] [trace] Extensions: Finished synchronizing extensions.
[2021-11-10 09:48:36.279] [settingssync] [info] Sync done. Took 1077ms
[2021-11-10 09:49:43.518] [settingssync] [trace] activity sources windowFocus
[2021-11-10 09:49:43.519] [settingssync] [info] Auto Sync: Triggered by Activity
[2021-11-10 09:49:43.519] [settingssync] [trace] Sending request to server {"url":"https://vscode-sync.trafficmanager.net/v1/manifest","type":"GET","headers":{"X-Execution-Id":"c53406f7-6d53-4827-bd84-b448a2d0ddf3","Content-Type":"application/json","If-None-Match":"W/\"171-qh5Ul7c3SZE7Hh71SMWFzaXN46k\"","X-Client-Name":"code-insiders","X-Client-Version":"1.63.0-insider","X-Client-Commit":"bef4dba21f68bbdb8d9f08fe04b2e1858597722b","X-Account-Type":"microsoft","X-Machine-Session-Id":"53269ec8-db53-44ca-8ffa-8992a13ea56b","X-User-Session-Id":"4d7117a7-8763-4605-97ef-3cfd22ba0a6b"}}
[2021-11-10 09:49:43.558] [settingssync] [trace] Request succeeded {"url":"https://vscode-sync.trafficmanager.net/v1/manifest","status":304,"execution-id":"c53406f7-6d53-4827-bd84-b448a2d0ddf3"}
[2021-11-10 09:49:43.559] [settingssync] [trace] Sync started.
[2021-11-10 09:49:43.559] [settingssync] [trace] Settings: Started synchronizing settings...
[2021-11-10 09:49:43.736] [settingssync] [trace] Settings: Merging remote settings with local settings...
[2021-11-10 09:49:43.736] [settingssync] [info] Settings: No changes found during synchronizing settings.
[2021-11-10 09:49:43.737] [settingssync] [trace] Settings: Finished synchronizing settings.
[2021-11-10 09:49:43.737] [settingssync] [trace] Keybindings: Started synchronizing keybindings...
[2021-11-10 09:49:43.745] [settingssync] [trace] Keybindings: Merging remote keybindings with local keybindings...
[2021-11-10 09:49:43.752] [settingssync] [info] Keybindings: No changes found during synchronizing keybindings.
[2021-11-10 09:49:43.754] [settingssync] [trace] Keybindings: Finished synchronizing keybindings.
[2021-11-10 09:49:43.754] [settingssync] [trace] Snippets: Started synchronizing snippets...
[2021-11-10 09:49:43.765] [settingssync] [trace] Snippets: Merging remote snippets with local snippets...
[2021-11-10 09:49:43.765] [settingssync] [info] Snippets: No changes found during synchronizing snippets.
[2021-11-10 09:49:43.770] [settingssync] [trace] Snippets: Finished synchronizing snippets.
[2021-11-10 09:49:43.770] [settingssync] [trace] GlobalState: Started synchronizing globalstate...
[2021-11-10 09:49:43.776] [settingssync] [debug] GlobalStateSync#getLocalArgvContent {"$mid":1,"fsPath":"c:\\Users\\carloc\\.vscode-insiders\\argv.json","_sep":1,"path":"/C:/Users/carloc/.vscode-insiders/argv.json","scheme":"file"}
[2021-11-10 09:49:44.411] [settingssync] [debug] GlobalStateSync#getLocalArgvContent - Resolved {"$mid":1,"fsPath":"c:\\Users\\carloc\\.vscode-insiders\\argv.json","_sep":1,"path":"/C:/Users/carloc/.vscode-insiders/argv.json","scheme":"file"}
[2021-11-10 09:49:44.411] [settingssync] [trace] GlobalState: Merging remote ui state with local ui state...
[2021-11-10 09:49:44.412] [settingssync] [info] GlobalState: No changes found during synchronizing ui state.
[2021-11-10 09:49:44.418] [settingssync] [trace] GlobalState: Finished synchronizing globalstate.
[2021-11-10 09:49:44.418] [settingssync] [trace] Extensions: Started synchronizing extensions...
[2021-11-10 09:49:44.668] [settingssync] [trace] Extensions: Merging remote extensions with local extensions...
[2021-11-10 09:49:44.668] [settingssync] [info] Extensions: No changes found during synchronizing extensions.
[2021-11-10 09:49:44.669] [settingssync] [trace] Extensions: Finished synchronizing extensions.
[2021-11-10 09:49:44.669] [settingssync] [info] Sync done. Took 1110ms
[2021-11-10 09:49:45.874] [settingssync] [debug] Auto Sync: Skipped. Limited to once per 10 seconds.
[2021-11-10 09:54:44.693] [settingssync] [info] Auto Sync: Triggered by Interval
[2021-11-10 09:54:44.694] [settingssync] [trace] Sending request to server {"url":"https://vscode-sync.trafficmanager.net/v1/manifest","type":"GET","headers":{"X-Execution-Id":"c9eba858-a19a-43af-82cd-ff786f728df0","Content-Type":"application/json","If-None-Match":"W/\"171-qh5Ul7c3SZE7Hh71SMWFzaXN46k\"","X-Client-Name":"code-insiders","X-Client-Version":"1.63.0-insider","X-Client-Commit":"bef4dba21f68bbdb8d9f08fe04b2e1858597722b","X-Account-Type":"microsoft","X-Machine-Session-Id":"53269ec8-db53-44ca-8ffa-8992a13ea56b","X-User-Session-Id":"4d7117a7-8763-4605-97ef-3cfd22ba0a6b"}}
[2021-11-10 09:54:44.787] [settingssync] [info] Request failed {"url":"https://vscode-sync.trafficmanager.net/v1/manifest","status":401,"execution-id":"c9eba858-a19a-43af-82cd-ff786f728df0"}
[2021-11-10 09:54:44.788] [settingssync] [info] Settings Sync auth token failed microsoft false
[2021-11-10 09:54:44.788] [settingssync] [info] Auto Sync: Suspended until auth token is available.
[2021-11-10 09:54:44.788] [settingssync] [info] Auto sync: Cancelled sync that is in progress
[2021-11-10 09:54:44.788] [settingssync] [info] Auto Sync: Stopped
[2021-11-10 09:54:44.789] [settingssync] [error] Unauthorized (UserDataSyncError) syncResource:unknown operationId:unknown: Request 'https://vscode-sync.trafficmanager.net/v1/manifest' failed because of Unauthorized (401).
    at b.request (vscode-file://vscode-app/c:/Users/carloc/AppData/Local/Programs/Microsoft%20VS%20Code%20Insiders/resources/app/out/vs/code/electron-browser/sharedProcess/sharedProcessMain.js:76:179023)
    at async b.manifest (vscode-file://vscode-app/c:/Users/carloc/AppData/Local/Programs/Microsoft%20VS%20Code%20Insiders/resources/app/out/vs/code/electron-browser/sharedProcess/sharedProcessMain.js:76:176220)
    at async l.createSyncTask (vscode-file://vscode-app/c:/Users/carloc/AppData/Local/Programs/Microsoft%20VS%20Code%20Insiders/resources/app/out/vs/code/electron-browser/sharedProcess/sharedProcessMain.js:76:147087)
    at async a.doSync (vscode-file://vscode-app/c:/Users/carloc/AppData/Local/Programs/Microsoft%20VS%20Code%20Insiders/resources/app/out/vs/code/electron-browser/sharedProcess/sharedProcessMain.js:76:141474)
[2021-11-10 09:54:44.848] [settingssync] [info] Auto Sync: Started
[2021-11-10 09:54:44.849] [settingssync] [info] Auto Sync: Triggered by Interval
[2021-11-10 09:54:44.849] [settingssync] [trace] Sending request to server {"url":"https://vscode-sync.trafficmanager.net/v1/manifest","type":"GET","headers":{"X-Execution-Id":"05e98fc1-cc6b-4c0b-9034-6ecd6c171c33","Content-Type":"application/json","X-Client-Name":"code-insiders","X-Client-Version":"1.63.0-insider","X-Client-Commit":"bef4dba21f68bbdb8d9f08fe04b2e1858597722b","X-Account-Type":"microsoft","X-Machine-Session-Id":"53269ec8-db53-44ca-8ffa-8992a13ea56b","X-User-Session-Id":"4d7117a7-8763-4605-97ef-3cfd22ba0a6b"}}
[2021-11-10 09:54:44.867] [settingssync] [info] Request failed {"url":"https://vscode-sync.trafficmanager.net/v1/manifest","status":401,"execution-id":"05e98fc1-cc6b-4c0b-9034-6ecd6c171c33"}
[2021-11-10 09:54:44.867] [settingssync] [info] Settings Sync auth token failed microsoft true
[2021-11-10 09:54:44.868] [settingssync] [info] Auto Sync: Suspended until auth token is available.
[2021-11-10 09:54:44.868] [settingssync] [info] Auto sync: Cancelled sync that is in progress
[2021-11-10 09:54:44.868] [settingssync] [info] Auto Sync: Stopped
[2021-11-10 09:54:44.868] [settingssync] [error] Unauthorized (UserDataSyncError) syncResource:unknown operationId:unknown: Request 'https://vscode-sync.trafficmanager.net/v1/manifest' failed because of Unauthorized (401).
    at b.request (vscode-file://vscode-app/c:/Users/carloc/AppData/Local/Programs/Microsoft%20VS%20Code%20Insiders/resources/app/out/vs/code/electron-browser/sharedProcess/sharedProcessMain.js:76:179023)
    at async b.manifest (vscode-file://vscode-app/c:/Users/carloc/AppData/Local/Programs/Microsoft%20VS%20Code%20Insiders/resources/app/out/vs/code/electron-browser/sharedProcess/sharedProcessMain.js:76:176220)
    at async l.createSyncTask (vscode-file://vscode-app/c:/Users/carloc/AppData/Local/Programs/Microsoft%20VS%20Code%20Insiders/resources/app/out/vs/code/electron-browser/sharedProcess/sharedProcessMain.js:76:147087)
    at async a.doSync (vscode-file://vscode-app/c:/Users/carloc/AppData/Local/Programs/Microsoft%20VS%20Code%20Insiders/resources/app/out/vs/code/electron-browser/sharedProcess/sharedProcessMain.js:76:141474)
[2021-11-10 09:54:45.147] [settingssync] [trace] GlobalState: Checking for local changes...
[2021-11-10 09:54:45.156] [settingssync] [debug] GlobalStateSync#getLocalArgvContent {"$mid":1,"fsPath":"c:\\Users\\carloc\\.vscode-insiders\\argv.json","_sep":1,"path":"/C:/Users/carloc/.vscode-insiders/argv.json","scheme":"file"}
[2021-11-10 09:54:45.805] [settingssync] [debug] GlobalStateSync#getLocalArgvContent - Resolved {"$mid":1,"fsPath":"c:\\Users\\carloc\\.vscode-insiders\\argv.json","_sep":1,"path":"/C:/Users/carloc/.vscode-insiders/argv.json","scheme":"file"}
[2021-11-10 09:54:45.805] [settingssync] [trace] GlobalState: Merging remote ui state with local ui state...

The account picker is identical as my prevoius screenshot.

Microsoft Authentication log

[Info  - 16:47:26.844] Got 1 sessions for all scopes...
[Info  - 16:50:50.709] Getting sessions for openid,profile,email,offline_access...
[Info  - 16:50:50.709] Got 1 sessions for email,offline_access,openid,profile...
[Info  - 16:50:50.709] Token available from cache (for scopes email offline_access openid profile), expires in 778917 milliseconds
[Info  - 16:50:52.783] Getting sessions for openid,profile,email,offline_access...
[Info  - 16:50:52.783] Got 1 sessions for email,offline_access,openid,profile...
[Info  - 16:50:52.783] Token available from cache (for scopes email offline_access openid profile), expires in 776843 milliseconds
[Info  - 16:50:53.15] Getting sessions for openid,profile,email,offline_access...
[Info  - 16:50:53.15] Got 1 sessions for email,offline_access,openid,profile...
[Info  - 16:50:53.15] Token available from cache (for scopes email offline_access openid profile), expires in 776611 milliseconds
[Info  - 16:50:56.162] Getting sessions for all scopes...
[Info  - 16:50:56.162] Token available from cache (for scopes email offline_access openid profile), expires in 773464 milliseconds
[Info  - 16:50:56.162] Got 1 sessions for all scopes...
[Info  - 16:50:59.6] Getting sessions for openid,profile,email,offline_access...
[Info  - 16:50:59.6] Got 1 sessions for email,offline_access,openid,profile...
[Info  - 16:50:59.6] Token available from cache (for scopes email offline_access openid profile), expires in 770620 milliseconds
[Info  - 16:51:00.859] Getting sessions for openid,profile,email,offline_access...
[Info  - 16:51:00.859] Got 1 sessions for email,offline_access,openid,profile...
[Info  - 16:51:00.859] Token available from cache (for scopes email offline_access openid profile), expires in 768767 milliseconds
[Info  - 16:51:00.908] Getting sessions for openid,profile,email,offline_access...
[Info  - 16:51:00.908] Got 1 sessions for email,offline_access,openid,profile...
[Info  - 16:51:00.908] Token available from cache (for scopes email offline_access openid profile), expires in 768718 milliseconds
[Info  - 16:51:05.156] Getting sessions for all scopes...
[Info  - 16:51:05.156] Token available from cache (for scopes email offline_access openid profile), expires in 764470 milliseconds
[Info  - 16:51:05.157] Got 1 sessions for all scopes...
[Info  - 16:51:10.127] Logging out of session 'f8cdef31-a31e-4b4a-93e4-5f571e91255a/1:live.com:0003BFFD88C26EAA/c0a8d0a3-3fe0-45e7-be5e-7407f36153c5'
[Info  - 16:51:10.136] Getting sessions for openid,profile,email,offline_access...
[Info  - 16:51:10.136] Got 0 sessions for email,offline_access,openid,profile...
[Info  - 16:51:12.605] Getting sessions for all scopes...
[Info  - 16:51:12.605] Got 0 sessions for all scopes...
[Info  - 16:51:14.348] Getting sessions for openid,profile,email,offline_access...
[Info  - 16:51:14.349] Got 0 sessions for email,offline_access,openid,profile...
[Info  - 16:51:16.581] Logging in for the following scopes: email offline_access openid profile
[Info  - 16:51:29.205] Exchanging login code for token for scopes: email offline_access openid profile
[Info  - 16:51:29.711] Exchanging login code for token (for scopes: email offline_access openid profile) succeeded!
[Info  - 16:51:29.711] Setting token for scopes: email offline_access openid profile
[Info  - 16:51:29.727] Login successful for scopes: email offline_access openid profile
[Info  - 16:51:29.727] Token available from cache (for scopes email offline_access openid profile), expires in 4920984 milliseconds
[Info  - 16:51:29.734] Getting sessions for openid,profile,email,offline_access...
[Info  - 16:51:29.734] Got 1 sessions for email,offline_access,openid,profile...
[Info  - 16:51:29.734] Token available from cache (for scopes email offline_access openid profile), expires in 4920977 milliseconds
[Info  - 16:51:29.734] Getting sessions for openid,profile,email,offline_access...
[Info  - 16:51:29.734] Got 1 sessions for email,offline_access,openid,profile...
[Info  - 16:51:29.734] Token available from cache (for scopes email offline_access openid profile), expires in 4920977 milliseconds
[Info  - 16:51:39.264] Getting sessions for all scopes...
[Info  - 16:51:39.264] Token available from cache (for scopes email offline_access openid profile), expires in 4911447 milliseconds
[Info  - 16:51:39.264] Got 1 sessions for all scopes...
[Info  - 17:54:44.841] Getting sessions for openid,profile,email,offline_access...
[Info  - 17:54:44.841] Got 1 sessions for email,offline_access,openid,profile...
[Info  - 17:54:44.841] Token available from cache (for scopes email offline_access openid profile), expires in 1125870 milliseconds
[Info  - 17:54:44.878] Getting sessions for openid,profile,email,offline_access...
[Info  - 17:54:44.878] Got 1 sessions for email,offline_access,openid,profile...
[Info  - 17:54:44.878] Token available from cache (for scopes email offline_access openid profile), expires in 1125833 milliseconds
[Info  - 18:13:00.713] Refreshing token for scopes: email offline_access openid profile
[Info  - 18:13:01.282] Setting token for scopes: email offline_access openid profile
[Info  - 18:13:01.328] Token refresh success for scopes: email offline_access openid profile
[Info  - 18:13:01.328] Triggering change session event...
[Info  - 18:13:01.331] Getting sessions for openid,profile,email,offline_access...
[Info  - 18:13:01.331] Got 1 sessions for email,offline_access,openid,profile...
[Info  - 18:13:01.331] Token available from cache (for scopes email offline_access openid profile), expires in 3881951 milliseconds
[Info  - 18:30:13.21] Getting sessions for all scopes...
[Info  - 18:30:13.21] Token available from cache (for scopes email offline_access openid profile), expires in 2850261 milliseconds
[Info  - 18:30:13.21] Got 1 sessions for all scopes...

@carlocardella
Copy link
Member Author

Version: 1.63.0-insider (user setup)
Commit: c1096372119bcf83b9bd8ccee96dcf266f35de76
Date: 2021-11-11T13:18:41.690Z
Electron: 13.5.2
Chromium: 91.0.4472.164
Node.js: 14.16.0
V8: 9.1.269.39-electron.0
OS: Windows_NT x64 10.0.22000

20211111.zip

@TylerLeonhardt
Copy link
Member

I'm able to repro this and I'm filling the codebase with log statements since attaching a debugger doesn't work in this instance.

It just takes over an hour to get a repro... figure out I'm missing X log statement... then rerun the whole experiment.

I am actively working on this - just want you all to know.

@rdepew
Copy link

rdepew commented Nov 11, 2021

Watching.

For business reasons, I'm not using the Insider versions, but I'm looking forward to this being fixed. Thanks to @TylerLeonhardt and @sandy081 for working on it.

@TylerLeonhardt
Copy link
Member

TylerLeonhardt commented Nov 11, 2021

Here are some fun learnings...

This value comes from a cracked open JWT used in the Microsoft Authentication extension

exp: 1636664095

This value comes from the response of the API call that gave me said JWT

expires_in: 4209

exp is a unix time in seconds… the Date.now() at the time was 1636660150974 in ms.

1636664095 * 1000 - 1636660150974 = 3944026ms / 1000 / 60 = 65.73min

expires_in is simply in seconds…

4209/60 = 70.15min

So if the docs say:

exp int, a Unix timestamp The “exp” (expiration time) claim identifies the expiration time on or after which the JWT must not be accepted for processing. It’s important to note that a resource may reject the token before this time as well, such as when a change in authentication is required or a token revocation has been detected.

and

expires_in How long the access token is valid (in seconds).

Who is right? 🙃

We currently refresh at a rate of 30 seconds before expires_in which in the example above... would mean that the token is technically expired for a solid 4 and a half minutes before we refresh...

I talked to @connor4312 about this and he says:

For consuming things like this I always use expires_in and refresh when it reaches something like 2/3rd's of the lifetime. If the consuming code is running on users' devices there's no guarantee their time is accurate. Or if I need to use a timestamp I can convert it to an "expires in" by looking at the Date header of the API response (which is pretty common and usually returned from most servers)

In our case, we don't need to use a timestamp so the "refresh every 2/3rds of expires_in" is a reasonable approach. This is what I'm gonna run with.

So at the end of the day, a simple 1 line change of expiresIn * 2/3 replacing expiresIn - 30... I've been running it for a few hours and haven't seen any issues yet... let's see how you all fare.

The commit:
f8b1720

@carlocardella
Copy link
Member Author

Today's Insiders has been running smoothly with Settings Sync enabled for over four hour, it never lasted this long without errors. Looks very promising

@TylerLeonhardt TylerLeonhardt added the candidate Issue identified as probable candidate for fixing in the next release label Nov 12, 2021
@TylerLeonhardt
Copy link
Member

Marked as a candidate so that the change can be included in a 1.62.3 (if we do one)

@Kytech
Copy link

Kytech commented Nov 14, 2021

Also been having the issue on the latest stable release as of the date of this comment. It's been happening on both a personal Microsoft Account and a work Microsoft Account (attached to Active Directory). My logging output looks the same as what everyone else has posted. Since there's a fix in the works, I'll try insiders and see if that fixes the issue for me. If that doesn't fix it, I'll pull together some logs and leave a comment here.

@TylerLeonhardt
Copy link
Member

fixed in #137083 . Will be included in 1.62.3 coming later this week.

@TylerLeonhardt
Copy link
Member

verification steps:

  • Turn on Settings sync
  • Use a Microsoft account (work or personal shouldn't matter)
  • Wait 3 hours

You should not be logged out of Settings Sync

@sandy081 sandy081 added the verified Verification succeeded label Nov 18, 2021
@Jimbo99
Copy link

Jimbo99 commented Nov 19, 2021

It might be something my end but this had been working fine for me for months (no need to login every few hours). Then I had this problem a few times each day for the past week or so. I updated VSCode yesterday to the latest (non-Insider) v1.62.3 and still getting the same issue.

In the log below I needed to sign in again at 17:22. Two instances of VSCode were open during all of this time.

Version: 1.62.3 (system setup)
Commit: ccbaa2d
Date: 2021-11-17T08:11:14.551Z
Electron: 13.5.2
Chrome: 91.0.4472.164
Node.js: 14.16.0
V8: 9.1.269.39-electron.0
OS: Windows_NT x64 10.0.19042

[2021-11-19 15:53:05.143] [settingssync] [info] Using settings sync service https://vscode-sync.trafficmanager.net/
[2021-11-19 15:53:05.143] [settingssync] [info] Auto Sync is enabled.
[2021-11-19 15:53:05.143] [settingssync] [info] Auto Sync: Suspended until auth token is available.
[2021-11-19 15:53:06.403] [settingssync] [info] Auto Sync: Started
[2021-11-19 15:53:06.403] [settingssync] [info] Auto Sync: Triggered by Interval
[2021-11-19 15:53:07.053] [settingssync] [info] Settings: No changes found during synchronizing settings.
[2021-11-19 15:53:07.062] [settingssync] [info] Keybindings: No changes found during synchronizing keybindings.
[2021-11-19 15:53:07.065] [settingssync] [info] Snippets: No changes found during synchronizing snippets.
[2021-11-19 15:53:07.636] [settingssync] [info] GlobalState: Updated remote ui state
[2021-11-19 15:53:07.640] [settingssync] [info] GlobalState: Updated last synchronized ui state
[2021-11-19 15:53:07.713] [settingssync] [info] Extensions: No changes found during synchronizing extensions.
[2021-11-19 15:53:07.713] [settingssync] [info] Sync done. Took 688ms
[2021-11-19 15:53:08.956] [settingssync] [info] Auto Sync: Triggered by Activity
[2021-11-19 15:53:09.058] [settingssync] [info] Settings: No changes found during synchronizing settings.
[2021-11-19 15:53:09.059] [settingssync] [info] Keybindings: No changes found during synchronizing keybindings.
[2021-11-19 15:53:09.062] [settingssync] [info] Snippets: No changes found during synchronizing snippets.
[2021-11-19 15:53:09.069] [settingssync] [info] GlobalState: No changes found during synchronizing ui state.
[2021-11-19 15:53:09.122] [settingssync] [info] Extensions: No changes found during synchronizing extensions.
[2021-11-19 15:53:09.122] [settingssync] [info] Sync done. Took 82ms
[2021-11-19 15:53:13.042] [settingssync] [info] Auto Sync: Suspended until auth token is available.
[2021-11-19 15:53:13.042] [settingssync] [info] Auto Sync: Stopped
[2021-11-19 17:22:00.407] [settingssync] [info] Auto Sync: Started
[2021-11-19 17:22:00.408] [settingssync] [info] Auto Sync: Triggered by Interval
[2021-11-19 17:22:00.801] [settingssync] [info] Settings: No changes found during synchronizing settings.
[2021-11-19 17:22:00.803] [settingssync] [info] Keybindings: No changes found during synchronizing keybindings.
[2021-11-19 17:22:00.810] [settingssync] [info] Snippets: No changes found during synchronizing snippets.
[2021-11-19 17:22:01.298] [settingssync] [info] GlobalState: Updated remote ui state
[2021-11-19 17:22:01.302] [settingssync] [info] GlobalState: Updated last synchronized ui state
[2021-11-19 17:22:01.384] [settingssync] [info] Extensions: No changes found during synchronizing extensions.
[2021-11-19 17:22:01.384] [settingssync] [info] Sync done. Took 610ms
[2021-11-19 17:22:28.826] [settingssync] [info] Auto Sync: Triggered by Activity
[2021-11-19 17:22:28.923] [settingssync] [info] Settings: No changes found during synchronizing settings.
[2021-11-19 17:22:28.924] [settingssync] [info] Keybindings: No changes found during synchronizing keybindings.
[2021-11-19 17:22:28.927] [settingssync] [info] Snippets: No changes found during synchronizing snippets.
[2021-11-19 17:22:28.937] [settingssync] [info] GlobalState: No changes found during synchronizing ui state.
[2021-11-19 17:22:28.997] [settingssync] [info] Extensions: No changes found during synchronizing extensions.
[2021-11-19 17:22:29.000] [settingssync] [info] Sync done. Took 94ms

@TylerLeonhardt
Copy link
Member

@Jimbo99 I don't think this is related but I'm not sure. Can you open a new issue (since this one is way to long)? And also attach the following:

  • Open the Command Palette
  • Run the Developer: Set Log Level... command
  • Choose Trace
  • Wait for the issue to happen...
  • Open the Output pane (ctrl+shift+u I think on Windows)
  • drop in this issue he contents of the following:
    • Microsoft Authentication Output channel
    • Log (Settings Sync) Output channel
    • Log (Window) Output channel

@Jimbo99
Copy link

Jimbo99 commented Nov 19, 2021

Thanks Tyler. Will do!

@Twoleeland
Copy link

Twoleeland commented Nov 30, 2021

I ran the command Developer: Set Log Level..., choosed Trace and then logged in to my Microsoft account to synchronize the settings and to enable Live Share feature.

The problem still exists with the "Unexpected token in JSON at position 0."
when using your Microsoft account.

Microsoft Authentication Output:
[Info - 15:58:48.628] Reading sessions from keychain...
[Info - 15:58:49.930] Got stored sessions!
[Trace - 15:58:49.930] Read the following session from the keychain with the following scopes: email offline_access openid profile
[Info - 15:58:49.930] Refreshing token for scopes: email offline_access openid profile
[Trace - 15:58:49.931] Read the following session from the keychain with the following scopes: 9bd5ab7f-4031-4045-ace9-6bebbad202f6/all email offline_access openid
[Info - 15:58:49.931] Refreshing token for scopes: 9bd5ab7f-4031-4045-ace9-6bebbad202f6/all email offline_access openid
[Info - 15:58:56.291] Token refresh success for scopes: email offline_access openid profile
[Error - 15:58:56.294] Unexpected token � in JSON at position 0
[Info - 15:58:56.295] Failed to fetch token claims from access_token. Attempting to parse id_token instead
[Info - 15:58:56.295] Token refresh success for scopes: 9bd5ab7f-4031-4045-ace9-6bebbad202f6/all email offline_access openid
[Info - 15:58:58.849] Getting sessions for all scopes...
[Info - 15:58:58.850] Token available from cache (for scopes email offline_access openid profile), expires in 4266438 milliseconds
[Info - 15:58:58.850] Token available from cache (for scopes 9bd5ab7f-4031-4045-ace9-6bebbad202f6/all email offline_access openid), expires in 3991445 milliseconds
[Info - 15:58:59.277] Got 2 sessions for all scopes...
[Error - 15:59:01.519] Getting token failed: Error: Decryption failed
[Error - 15:59:01.519] Getting token failed: Error: Decryption failed
[Info - 15:59:01.565] No stored keychain data, clearing local data
[Info - 15:59:02.332] Getting sessions for all scopes...
[Info - 15:59:02.333] Got 0 sessions for all scopes...
[Info - 16:00:52.364] Getting sessions for all scopes...
[Info - 16:00:52.364] Got 0 sessions for all scopes...
[Info - 16:00:53.436] Getting sessions for all scopes...
[Info - 16:00:53.436] Got 0 sessions for all scopes...
[Info - 16:00:55.160] Logging in for the following scopes: email offline_access openid profile
[Info - 16:00:59.808] Exchanging login code for token for scopes: email offline_access openid profile
[Info - 16:01:00.188] Exchanging login code for token (for scopes: email offline_access openid profile) succeeded!
[Info - 16:01:00.190] Login successful for scopes: email offline_access openid profile
[Info - 16:01:00.190] Token available from cache (for scopes email offline_access openid profile), expires in 4234999 milliseconds
[Info - 16:01:00.196] Getting sessions for all scopes...
[Info - 16:01:00.196] Token available from cache (for scopes email offline_access openid profile), expires in 4234993 milliseconds
[Info - 16:01:00.196] Getting sessions for all scopes...
[Info - 16:01:00.196] Token available from cache (for scopes email offline_access openid profile), expires in 4234993 milliseconds
[Info - 16:01:00.197] Got 1 sessions for all scopes...
[Info - 16:01:00.197] Got 1 sessions for all scopes...
[Info - 16:01:00.207] Getting sessions for 9bd5ab7f-4031-4045-ace9-6bebbad202f6/all,email,offline_access,openid...
[Info - 16:01:00.207] Got 0 sessions for 9bd5ab7f-4031-4045-ace9-6bebbad202f6/all,email,offline_access,openid...
[Info - 16:01:30.648] Getting sessions for all scopes...
[Info - 16:01:30.648] Token available from cache (for scopes email offline_access openid profile), expires in 4204541 milliseconds
[Info - 16:01:30.649] Got 1 sessions for all scopes...
[Info - 16:01:33.10] Logging in for the following scopes: 9bd5ab7f-4031-4045-ace9-6bebbad202f6/all email offline_access openid
[Info - 16:01:37.234] Exchanging login code for token for scopes: 9bd5ab7f-4031-4045-ace9-6bebbad202f6/all email offline_access openid
[Info - 16:01:37.704] Exchanging login code for token (for scopes: 9bd5ab7f-4031-4045-ace9-6bebbad202f6/all email offline_access openid) succeeded!
[Error - 16:01:37.704] Unexpected token � in JSON at position 0
[Info - 16:01:37.704] Failed to fetch token claims from access_token. Attempting to parse id_token instead
[Info - 16:01:37.705] Login successful for scopes: 9bd5ab7f-4031-4045-ace9-6bebbad202f6/all email offline_access openid
[Info - 16:01:37.705] Token available from cache (for scopes 9bd5ab7f-4031-4045-ace9-6bebbad202f6/all email offline_access openid), expires in 4340999 milliseconds
[Info - 16:01:37.717] Getting sessions for all scopes...
[Info - 16:01:37.717] Token available from cache (for scopes email offline_access openid profile), expires in 4197472 milliseconds
[Info - 16:01:37.717] Token available from cache (for scopes 9bd5ab7f-4031-4045-ace9-6bebbad202f6/all email offline_access openid), expires in 4340987 milliseconds
[Info - 16:01:37.718] Got 2 sessions for all scopes...
[Info - 16:01:37.795] Getting sessions for 9bd5ab7f-4031-4045-ace9-6bebbad202f6/all,email,offline_access,openid...
[Info - 16:01:37.795] Got 1 sessions for 9bd5ab7f-4031-4045-ace9-6bebbad202f6/all,email,offline_access,openid...
[Info - 16:01:37.795] Token available from cache (for scopes 9bd5ab7f-4031-4045-ace9-6bebbad202f6/all email offline_access openid), expires in 4340909 milliseconds

@TylerLeonhardt
Copy link
Member

@Twoleeland

The problem still exists with the "Unexpected token in JSON at position 0."
when using your Microsoft account

This is expected and this error is caught and handled. Look at the next log statements:

[Error - 15:58:56.294] Unexpected token � in JSON at position 0
[Info - 15:58:56.295] Failed to fetch token claims from access_token. Attempting to parse id_token instead
[Info - 15:58:56.295] Token refresh success for scopes: 9bd5ab7f-4031-4045-ace9-6bebbad202f6/all email offline_access openid

Are you seeing the 401 that this error talks about in the latest version of VS Code?

@wasker
Copy link

wasker commented Dec 9, 2021

I'm seeing some weird behavior in this area after upgrading to v1.63 and relying on Save functionality of HyperV to stop/restore VM where VSCode is.

Since the upgrade - first Save/Restore got me back into the original bug's state. I re-logged in, then saved VM again - and this morning (PST) I'm completely logged out from all accounts.

This pattern of usage was regular for me before 1.63 and so far all interim fixes were indeed fixing the issue.

[Info - 23:41:39.153] Reading sessions from keychain...
[Info - 23:41:39.508] Got stored sessions!
[Trace - 23:41:39.508] Read the following session from the keychain with the following scopes: email offline_access openid profile
[Info - 23:41:39.508] Refreshing token for scopes: email offline_access openid profile
[Info - 23:41:40.947] Setting token for scopes: email offline_access openid profile
[Trace - 23:41:40.947] storing data into keychain...
[Info - 23:41:41.3] Token refresh success for scopes: email offline_access openid profile
[Info - 23:41:41.8] Getting sessions for openid,profile,email,offline_access...
[Info - 23:41:41.8] Got 1 sessions for email,offline_access,openid,profile...
[Info - 23:41:41.8] Token available from cache (for scopes email offline_access openid profile), expires in 4612939 milliseconds
[Info - 00:32:56.282] Refreshing token for scopes: email offline_access openid profile
[Info - 00:32:56.720] Setting token for scopes: email offline_access openid profile
[Trace - 00:32:56.720] storing data into keychain...
[Info - 00:32:56.763] Token refresh success for scopes: email offline_access openid profile
[Info - 00:32:56.763] Triggering change session event...
[Info - 00:32:56.781] Getting sessions for openid,profile,email,offline_access...
[Info - 00:32:56.781] Got 1 sessions for email,offline_access,openid,profile...
[Info - 00:32:56.781] Token available from cache (for scopes email offline_access openid profile), expires in 5258939 milliseconds
[Info - 01:31:22.732] Refreshing token for scopes: email offline_access openid profile
[Info - 01:31:23.484] Setting token for scopes: email offline_access openid profile
[Trace - 01:31:23.484] storing data into keychain...
[Info - 01:31:23.514] Token refresh success for scopes: email offline_access openid profile
[Info - 01:31:23.514] Triggering change session event...
[Info - 01:31:23.523] Getting sessions for openid,profile,email,offline_access...
[Info - 01:31:23.523] Got 1 sessions for email,offline_access,openid,profile...
[Info - 01:31:23.523] Token available from cache (for scopes email offline_access openid profile), expires in 4751961 milliseconds
[Info - 02:35:30.587] Getting sessions for openid,profile,email,offline_access...
[Info - 02:35:30.587] Got 1 sessions for email,offline_access,openid,profile...
[Info - 02:35:30.587] Token available from cache (for scopes email offline_access openid profile), expires in 904897 milliseconds
[Info - 02:35:30.631] Getting sessions for openid,profile,email,offline_access...
[Info - 02:35:30.631] Got 1 sessions for email,offline_access,openid,profile...
[Info - 02:35:30.631] Token available from cache (for scopes email offline_access openid profile), expires in 904853 milliseconds
[Info - 02:36:06.286] Getting sessions for openid,profile,email,offline_access...
[Info - 02:36:06.286] Got 1 sessions for email,offline_access,openid,profile...
[Info - 02:36:06.286] Token available from cache (for scopes email offline_access openid profile), expires in 869198 milliseconds
[Info - 02:36:08.638] Getting sessions for openid,profile,email,offline_access...
[Info - 02:36:08.638] Got 1 sessions for email,offline_access,openid,profile...
[Info - 02:36:08.638] Token available from cache (for scopes email offline_access openid profile), expires in 866846 milliseconds
[Info - 02:36:08.711] Getting sessions for openid,profile,email,offline_access...
[Info - 02:36:08.711] Got 1 sessions for email,offline_access,openid,profile...
[Info - 02:36:08.711] Token available from cache (for scopes email offline_access openid profile), expires in 866773 milliseconds
[Info - 02:36:30.915] Getting sessions for openid,profile,email,offline_access...
[Info - 02:36:30.915] Got 1 sessions for email,offline_access,openid,profile...
[Info - 02:36:30.915] Token available from cache (for scopes email offline_access openid profile), expires in 844569 milliseconds
[Info - 02:36:33.553] Logging in for the following scopes: email offline_access openid profile
[Info - 02:36:52.482] Exchanging login code for token for scopes: email offline_access openid profile
[Info - 02:36:52.732] Exchanging login code for token (for scopes: email offline_access openid profile) succeeded!
[Info - 02:36:52.732] Setting token for scopes: email offline_access openid profile
[Trace - 02:36:52.732] storing data into keychain...
[Info - 02:36:52.813] Login successful for scopes: email offline_access openid profile
[Info - 02:36:52.813] Token available from cache (for scopes email offline_access openid profile), expires in 4351919 milliseconds
[Info - 02:36:52.820] Getting sessions for openid,profile,email,offline_access...
[Info - 02:36:52.820] Got 2 sessions for email,offline_access,openid,profile...
[Info - 02:36:52.820] Token available from cache (for scopes email offline_access openid profile), expires in 822664 milliseconds
[Info - 02:36:52.820] Token available from cache (for scopes email offline_access openid profile), expires in 4351912 milliseconds
[Info - 02:36:52.820] Getting sessions for openid,profile,email,offline_access...
[Info - 02:36:52.820] Got 2 sessions for email,offline_access,openid,profile...
[Info - 02:36:52.820] Token available from cache (for scopes email offline_access openid profile), expires in 822664 milliseconds
[Info - 02:36:52.820] Token available from cache (for scopes email offline_access openid profile), expires in 4351912 milliseconds
[Info - 18:10:21.52] Getting sessions for openid,profile,email,offline_access...
[Info - 18:10:21.52] Got 2 sessions for email,offline_access,openid,profile...
[Info - 18:10:21.52] Token expired or unavailable (for scopes email offline_access openid profile), trying refresh
[Info - 18:10:21.52] Refreshing token for scopes: email offline_access openid profile
[Info - 18:10:21.52] Token expired or unavailable (for scopes email offline_access openid profile), trying refresh
[Info - 18:10:21.52] Refreshing token for scopes: email offline_access openid profile
[Info - 18:10:21.413] Setting token for scopes: email offline_access openid profile
[Trace - 18:10:21.413] storing data into keychain...
[Info - 18:10:21.418] Setting token for scopes: email offline_access openid profile
[Trace - 18:10:21.418] storing data into keychain...
[Info - 18:10:21.447] Token refresh success for scopes: email offline_access openid profile
[Error - 18:10:21.460] Getting token failed: Error: Decryption failed
[Info - 18:10:21.460] No stored keychain data, clearing local data
[Info - 18:10:21.460] Sending change event with 0 added and 2 removed
[Info - 18:10:21.464] Token refresh success for scopes: email offline_access openid profile
[Info - 18:10:21.466] Getting sessions for openid,profile,email,offline_access...
[Info - 18:10:21.466] Got 0 sessions for email,offline_access,openid,profile...
[Error - 18:10:21.479] Getting token failed: Error: Decryption failed
[Info - 18:20:13.468] Getting sessions for all scopes...
[Info - 18:20:13.468] Got 0 sessions for all scopes...
[Info - 18:20:15.351] Getting sessions for openid,profile,email,offline_access...
[Info - 18:20:15.351] Got 0 sessions for email,offline_access,openid,profile...
[Info - 18:20:17.163] Logging in for the following scopes: email offline_access openid profile
[Info - 18:20:22.157] Exchanging login code for token for scopes: email offline_access openid profile
[Info - 18:20:22.636] Exchanging login code for token (for scopes: email offline_access openid profile) succeeded!
[Info - 18:20:22.636] Setting token for scopes: email offline_access openid profile
[Trace - 18:20:22.636] storing data into keychain...
[Info - 18:20:22.742] Login successful for scopes: email offline_access openid profile
[Info - 18:20:22.742] Token available from cache (for scopes email offline_access openid profile), expires in 4911894 milliseconds
[Info - 18:20:22.747] Getting sessions for openid,profile,email,offline_access...
[Info - 18:20:22.747] Got 1 sessions for email,offline_access,openid,profile...
[Info - 18:20:22.747] Token available from cache (for scopes email offline_access openid profile), expires in 4911889 milliseconds
[Info - 18:20:22.747] Getting sessions for openid,profile,email,offline_access...
[Info - 18:20:22.747] Got 1 sessions for email,offline_access,openid,profile...
[Info - 18:20:22.747] Token available from cache (for scopes email offline_access openid profile), expires in 4911889 milliseconds

@Twoleeland
Copy link

@TylerLeonhardt
I must apologize because I misunderstood the intent of the thread. Sorry for that!

My problem, although not related to this problem, is confusing after some tests:

  1. At home: signing in to Microsoft (= MS) account for syncing settings, no problems at all. 👌
  2. At work: I get the errors as posted above and have to sign in to MS account every time I open VSCode.
    -> really weird, because other apps or services have no such problems using MS account.

Conclusion:
Finally, switched to GitHub account for syncing settings. And now, I have no problems any more, whether I'm at work or at home or somewhere else. 😉

@github-actions github-actions bot locked and limited conversation to collaborators Dec 30, 2021
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
authentication Issues with the Authentication platform bug Issue identified by VS Code Team member as probable bug candidate Issue identified as probable candidate for fixing in the next release verified Verification succeeded
Projects
None yet
Development

No branches or pull requests