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.

Sign up for GitHub

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

Jump to bottom

Sync settings are invalid after opening a new instance #160500

Closed
buzzers opened this issue Sep 9, 2022 · 11 comments
Closed

Sync settings are invalid after opening a new instance #160500

buzzers opened this issue Sep 9, 2022 · 11 comments
Assignees
@TylerLeonhardt @sandy081
Labels
authentication Issues with the Authentication platform bug Issue identified by VS Code Team member as probable bug upstream-issue-linked This is an upstream issue that has been reported upstream

Comments

@buzzers
Copy link

buzzers commented Sep 9, 2022 •
edited

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

  • VS Code Version: 1.71.0 (user setup)
  • Commit: 784b017
  • DateTime: 2022-09-01T07:36:10.600Z
  • Electron: 19.0.12
  • Chromium: 102.0.5005.167
  • Node.js: 16.14.2
  • V8: 10.2.154.15-electron.0
  • OS Version: Windows_NT x64 10.0.19044
  • Sandbox: No

Steps to Reproduce:

  1. Open VS Code, and then see log in Log (Sync Settings)
[2022-09-09 17:20:49.750] [settingssync] [info] Using settings sync service https://vscode-sync.trafficmanager.net/
[2022-09-09 17:20:49.750] [settingssync] [info] Auto Sync is enabled.
[2022-09-09 17:20:49.750] [settingssync] [info] Auto Sync: Suspended until auth token is available.
  1. Login account, and then see log in Log (Sync Settings)
[2022-09-09 17:21:03.540] [settingssync] [info] Auto Sync: Started
[2022-09-09 17:21:03.541] [settingssync] [info] Auto Sync: Triggered by Interval
  1. Open another VS Code instance, and then see log in Log (Sync Settings)
[2022-09-09 17:21:11.419] [settingssync] [info] Auto Sync: Suspended until auth token is available.
[2022-09-09 17:21:11.419] [settingssync] [info] Auto sync: Cancelled sync that is in progress
[2022-09-09 17:21:11.420] [settingssync] [info] Auto Sync: Stopped

ps: See log after a few minutes

[2022-09-09 17:24:44.986] [settingssync] [info] Request failed https://vscode-sync.trafficmanager.net/v1/resource/machines/latest
[2022-09-09 17:24:44.986] [settingssync] [error] RequestFailed (UserDataSyncError) syncResource:unknown operationId:unknown: Connection refused for the request 'https://vscode-sync.trafficmanager.net/v1/resource/machines/latest'.
    at R.request (vscode-file://vscode-app/c:/Users/liuha/AppData/Local/Programs/Microsoft%20VS%20Code/resources/app/out/vs/code/electron-browser/sharedProcess/sharedProcessMain.js:83:146108)
    at async R.readResource (vscode-file://vscode-app/c:/Users/liuha/AppData/Local/Programs/Microsoft%20VS%20Code/resources/app/out/vs/code/electron-browser/sharedProcess/sharedProcessMain.js:83:142525)
    at async tt.readMachinesData (vscode-file://vscode-app/c:/Users/liuha/AppData/Local/Programs/Microsoft%20VS%20Code/resources/app/out/vs/code/electron-browser/sharedProcess/sharedProcessMain.js:83:104478)
    at async tt.getMachines (vscode-file://vscode-app/c:/Users/liuha/AppData/Local/Programs/Microsoft%20VS%20Code/resources/app/out/vs/code/electron-browser/sharedProcess/sharedProcessMain.js:83:103085)
    at async r.doSync (vscode-file://vscode-app/c:/Users/liuha/AppData/Local/Programs/Microsoft%20VS%20Code/resources/app/out/vs/code/electron-browser/sharedProcess/sharedProcessMain.js:83:116833)

ps2: Restarting VS Code also causes sync to pause
@sandy081
Copy link
Member

sandy081 commented Sep 12, 2022 •
edited

Restarting VS Code also causes sync to pause

Do you see any badges on the account icon or settings gear icon asking you to sign in to sync ?

Can you also please provide screenshots of what you see?

@sandy081 sandy081 added the info-needed Issue requires more information from poster label Sep 12, 2022
@buzzers
Copy link
Author

buzzers commented Sep 13, 2022

  1. When I open VSCode it prompts to log in
    image

  2. After logging in, the badge is no longer displayed and the prompt sync is turned on. But the log shows that the sync is stopped.
    image

  3. After restarting, it prompts me again that I need to log in.
    image

@sandy081

@sandy081
Copy link
Member

Seems like authentication issue.

@TylerLeonhardt Can you please help here to diagnose the issue

@TylerLeonhardt
Copy link
Member

Can you follow these steps so that we can get more information on what's going on?

  • 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 or GitHub Authentication Output channel
    • Log (Settings Sync) Output channel
    • Log (Window) Output channel

@buzzers
Copy link
Author

buzzers commented Sep 15, 2022

@TylerLeonhardt

Microsoft Authentication

[Info  - 15:22:59.197] Reading sessions from secret storage...
[Error  - 15:22:59.250] Key was not found in SecretStorage.
[Info  - 15:22:59.250] Got 0 stored sessions
[Info  - 15:22:59.254] Getting sessions for the following scopes: email offline_access openid profile
[Trace  - 15:22:59.254] No session found with idtoken scopes... Using fallback scope list of: email offline_access openid profile
[Info  - 15:22:59.254] Got 0 sessions for scopes: email offline_access openid profile
[Info  - 15:23:23.111] Getting sessions for all scopes...
[Info  - 15:23:23.111] Got 0 sessions for all scopes...
[Info  - 15:23:24.170] Getting sessions for the following scopes: email offline_access openid profile
[Trace  - 15:23:24.170] No session found with idtoken scopes... Using fallback scope list of: email offline_access openid profile
[Info  - 15:23:24.170] Got 0 sessions for scopes: email offline_access openid profile
[Info  - 15:23:25.408] Logging in for the following scopes: email offline_access openid profile
[Info  - 15:23:29.768] Exchanging login code for token for scopes: email offline_access openid profile
[Info  - 15:23:30.820] Exchanging login code for token (for scopes: email offline_access openid profile) succeeded!
[Info  - 15:23:30.820] Setting token for scopes: email offline_access openid profile
[Info  - 15:23:30.820] Login successful for scopes: email offline_access openid profile
[Info  - 15:23:30.820] Token available from cache (for scopes email offline_access openid profile), expires in 4052000 milliseconds
[Info  - 15:23:30.831] Getting sessions for the following scopes: email offline_access openid profile
[Info  - 15:23:30.831] Got 1 sessions for scopes: email offline_access openid profile
[Info  - 15:23:30.831] Token available from cache (for scopes email offline_access openid profile), expires in 4051989 milliseconds
[Info  - 15:23:30.831] Getting sessions for the following scopes: email offline_access openid profile
[Info  - 15:23:30.831] Got 1 sessions for scopes: email offline_access openid profile
[Info  - 15:23:30.831] Token available from cache (for scopes email offline_access openid profile), expires in 4051989 milliseconds
[Error  - 15:23:31.491] Error: �ڴ���Դ���㣬�޷����������

Log (Window)

[2022-09-15 23:23:09.106] [renderer1] [trace] CommandService#executeCommand workbench.output.action.switchBetweenOutputs
[2022-09-15 23:23:09.109] [renderer1] [trace] Stopped polling file:///c%3A/Users/*****/AppData/Roaming/Code/logs/20220915T232258/userDataSync.log
[2022-09-15 23:23:09.114] [renderer1] [trace] Started polling file:///c%3A/Users/*****/AppData/Roaming/Code/logs/20220915T232258/exthost1/output_logging_20220915T232259/1-Microsoft%20Authentication.log
[2022-09-15 23:23:12.368] [renderer1] [trace] CommandService#executeCommand workbench.output.action.switchBetweenOutputs
[2022-09-15 23:23:12.372] [renderer1] [trace] Stopped polling file:///c%3A/Users/*****/AppData/Roaming/Code/logs/20220915T232258/exthost1/output_logging_20220915T232259/1-Microsoft%20Authentication.log
[2022-09-15 23:23:12.377] [renderer1] [trace] Started polling file:///c%3A/Users/*****/AppData/Roaming/Code/logs/20220915T232258/renderer1.log
[2022-09-15 23:23:22.029] [renderer1] [trace] CommandService#executeCommand workbench.output.action.switchBetweenOutputs
[2022-09-15 23:23:22.032] [renderer1] [trace] Stopped polling file:///c%3A/Users/*****/AppData/Roaming/Code/logs/20220915T232258/renderer1.log
[2022-09-15 23:23:22.038] [renderer1] [trace] Started polling file:///c%3A/Users/*****/AppData/Roaming/Code/logs/20220915T232258/exthost1/output_logging_20220915T232259/1-Microsoft%20Authentication.log
[2022-09-15 23:23:24.168] [renderer1] [trace] CommandService#executeCommand workbench.userData.actions.signin
[2022-09-15 23:23:24.168] [renderer1] [trace] Settings Sync: Getting accounts for microsoft
[2022-09-15 23:23:24.179] [renderer1] [trace] Settings Sync: Updated accounts for microsoft
[2022-09-15 23:23:24.179] [renderer1] [trace] Settings Sync: Getting accounts for github
[2022-09-15 23:23:24.185] [renderer1] [trace] Settings Sync: Updated accounts for github
[2022-09-15 23:23:29.771] [renderer1] [trace] CommandService#executeCommand workbench.getCodeExchangeProxyEndpoints
[2022-09-15 23:23:30.830] [renderer1] [trace] Settings Sync: Getting accounts for microsoft
[2022-09-15 23:23:30.830] [renderer1] [info] Settings Sync: Updated current session f8cdef31-a31e-4b4a-93e4-5f571e91255a/1:live.com:0003000026FC45F7/f9746ed9-0eec-430f-9fee-51f43dca90c4
[2022-09-15 23:23:30.831] [renderer1] [trace] Settings Sync: Getting accounts for microsoft
[2022-09-15 23:23:30.832] [renderer1] [trace] Settings Sync: Updated accounts for microsoft
[2022-09-15 23:23:30.832] [renderer1] [trace] Settings Sync: Getting accounts for github
[2022-09-15 23:23:30.833] [renderer1] [trace] Settings Sync: Updated accounts for microsoft
[2022-09-15 23:23:30.833] [renderer1] [trace] Settings Sync: Getting accounts for github
[2022-09-15 23:23:30.833] [renderer1] [trace] Settings Sync: Updated accounts for github
[2022-09-15 23:23:30.833] [renderer1] [trace] Settings Sync: Updating the token for the account *********@outlook.com
[2022-09-15 23:23:30.834] [renderer1] [trace] Settings Sync: Token updated for the account *********@outlook.com
[2022-09-15 23:23:30.834] [renderer1] [trace] Settings Sync: Updated accounts for github
[2022-09-15 23:23:30.834] [renderer1] [trace] Settings Sync: Updating the token for the account *********@outlook.com
[2022-09-15 23:23:30.834] [renderer1] [trace] Settings Sync: Token updated for the account *********@outlook.com
[2022-09-15 23:23:30.837] [renderer1] [trace] Settings Sync: Account status changed from unavailable to available
[2022-09-15 23:23:32.658] [renderer1] [trace] [text file model] resolve() - enter vscode-userdata:/c%3A/Users/*****/AppData/Roaming/Code/User/settings.json
[2022-09-15 23:23:32.659] [renderer1] [trace] [text file model] resolveFromFile() vscode-userdata:/c%3A/Users/*****/AppData/Roaming/Code/User/settings.json
[2022-09-15 23:23:32.662] [renderer1] [trace] [text file model] resolveFromContent() - enter vscode-userdata:/c%3A/Users/*****/AppData/Roaming/Code/User/settings.json
[2022-09-15 23:23:32.662] [renderer1] [trace] [text file model] doCreateTextModel() vscode-userdata:/c%3A/Users/*****/AppData/Roaming/Code/User/settings.json
[2022-09-15 23:23:32.663] [renderer1] [trace] onWillActivateByEvent:  onLanguage:jsonc
[2022-09-15 23:23:32.666] [renderer1] [trace] [text file model] dispose() vscode-userdata:/c%3A/Users/*****/AppData/Roaming/Code/User/settings.json
[2022-09-15 23:23:32.666] [renderer1] [trace] [backup tracker] discarding backup vscode-userdata:/c%3A/Users/*****/AppData/Roaming/Code/User/settings.json 
[2022-09-15 23:23:32.681] [renderer1] [trace] [text file model] resolve() - enter vscode-userdata:/c%3A/Users/*****/AppData/Roaming/Code/User/keybindings.json
[2022-09-15 23:23:32.681] [renderer1] [trace] [text file model] resolveFromFile() vscode-userdata:/c%3A/Users/*****/AppData/Roaming/Code/User/keybindings.json
[2022-09-15 23:23:32.682] [renderer1] [trace] [text file model] dispose() vscode-userdata:/c%3A/Users/*****/AppData/Roaming/Code/User/keybindings.json
[2022-09-15 23:23:32.682] [renderer1] [trace] [backup tracker] discarding backup vscode-userdata:/c%3A/Users/*****/AppData/Roaming/Code/User/keybindings.json 
[2022-09-15 23:23:55.421] [renderer1] [trace] KeybindingService#dispatch Ctrl+A editor.action.selectAll
[2022-09-15 23:23:55.421] [renderer1] [trace] CommandService#executeCommand editor.action.selectAll
[2022-09-15 23:23:55.421] [renderer1] [trace] Executing Command 'editor.action.selectAll' which has 4 bound.
[2022-09-15 23:23:55.421] [renderer1] [trace] Command 'editor.action.selectAll' was handled by 'code-editor'.
[2022-09-15 23:23:55.665] [renderer1] [trace] KeybindingService#dispatch Ctrl+C editor.action.clipboardCopyAction
[2022-09-15 23:23:55.665] [renderer1] [trace] CommandService#executeCommand editor.action.clipboardCopyAction
[2022-09-15 23:23:55.665] [renderer1] [trace] Executing Command 'editor.action.clipboardCopyAction' which has 6 bound.
[2022-09-15 23:23:55.666] [renderer1] [trace] Command 'editor.action.clipboardCopyAction' was handled by 'code-editor'.
[2022-09-15 23:24:05.896] [renderer1] [trace] CommandService#executeCommand workbench.output.action.switchBetweenOutputs
[2022-09-15 23:24:05.900] [renderer1] [trace] Stopped polling file:///c%3A/Users/*****/AppData/Roaming/Code/logs/20220915T232258/exthost1/output_logging_20220915T232259/1-Microsoft%20Authentication.log
[2022-09-15 23:24:05.909] [renderer1] [trace] Started polling file:///c%3A/Users/*****/AppData/Roaming/Code/logs/20220915T232258/renderer1.log

Log (Settings Sync)

[2022-09-15 23:22:59.031] [settingssync] [info] Using settings sync service https://vscode-sync.trafficmanager.net/
[2022-09-15 23:22:59.031] [settingssync] [info] Auto Sync is enabled.
[2022-09-15 23:22:59.031] [settingssync] [info] Auto Sync: Suspended until auth token is available.
[2022-09-15 23:23:30.835] [settingssync] [info] Auto Sync: Started
[2022-09-15 23:23:30.836] [settingssync] [info] Auto Sync: Triggered by Interval
[2022-09-15 23:23:30.836] [settingssync] [trace] Sending request to server {"url":"https://vscode-sync.trafficmanager.net/v1/manifest","type":"GET","headers":{"X-Execution-Id":"","Content-Type":"application/json","X-Client-Name":"code","X-Client-Version":"1.71.1","X-Client-Commit":"","X-Account-Type":"microsoft","X-Machine-Session-Id":"","X-User-Session-Id":""}}
[2022-09-15 23:23:32.200] [settingssync] [trace] Request succeeded {"url":"https://vscode-sync.trafficmanager.net/v1/manifest","status":200,"execution-id":""}
[2022-09-15 23:23:32.204] [settingssync] [trace] Sending request to server {"url":"https://vscode-sync.trafficmanager.net/v1/resource/machines/latest","type":"GET","headers":{"Cache-Control":"no-cache","X-Client-Name":"code","X-Client-Version":"1.71.1","X-Client-Commit":"","X-Account-Type":"microsoft","X-Machine-Session-Id":"","X-User-Session-Id":""}}
[2022-09-15 23:23:32.654] [settingssync] [trace] Request succeeded {"url":"https://vscode-sync.trafficmanager.net/v1/resource/machines/latest","status":200}
[2022-09-15 23:23:32.655] [settingssync] [trace] Sync started.
[2022-09-15 23:23:32.655] [settingssync] [trace] Settings: Started synchronizing settings...
[2022-09-15 23:23:32.676] [settingssync] [trace] Settings: Merging remote settings with local settings...
[2022-09-15 23:23:32.676] [settingssync] [info] Settings: No changes found during synchronizing settings.
[2022-09-15 23:23:32.678] [settingssync] [trace] Settings: Finished synchronizing settings.
[2022-09-15 23:23:32.678] [settingssync] [trace] Keybindings: Started synchronizing keybindings...
[2022-09-15 23:23:32.683] [settingssync] [info] Keybindings: No changes found during synchronizing keybindings.
[2022-09-15 23:23:32.684] [settingssync] [trace] Keybindings: Finished synchronizing keybindings.
[2022-09-15 23:23:32.684] [settingssync] [trace] Snippets: Started synchronizing snippets...
[2022-09-15 23:23:32.686] [settingssync] [trace] Snippets: Remote snippets does not exist. Synchronizing snippets for the first time.
[2022-09-15 23:23:32.687] [settingssync] [info] Snippets: No changes found during synchronizing snippets.
[2022-09-15 23:23:32.687] [settingssync] [trace] Snippets: Finished synchronizing snippets.
[2022-09-15 23:23:32.687] [settingssync] [trace] Tasks: Started synchronizing tasks...
[2022-09-15 23:23:32.689] [settingssync] [info] Tasks: No changes found during synchronizing tasks.
[2022-09-15 23:23:32.691] [settingssync] [trace] Tasks: Finished synchronizing tasks.
[2022-09-15 23:23:32.691] [settingssync] [trace] GlobalState: Started synchronizing globalstate...
[2022-09-15 23:23:32.693] [settingssync] [debug] GlobalStateSync#getLocalArgvContent {"$mid":1,"path":"/C:/Users/*****/.vscode/argv.json","scheme":"file"}
[2022-09-15 23:23:32.696] [settingssync] [debug] GlobalStateSync#getLocalArgvContent - Resolved {"$mid":1,"fsPath":"c:\\Users\\*****\\.vscode\\argv.json","_sep":1,"path":"/C:/Users/*****/.vscode/argv.json","scheme":"file"}
[2022-09-15 23:23:32.696] [settingssync] [trace] GlobalState: Merging remote ui state with local ui state...
[2022-09-15 23:23:32.703] [settingssync] [trace] GlobalState: Updating remote ui state...
[2022-09-15 23:23:32.703] [settingssync] [trace] Sending request to server {"url":"https://vscode-sync.trafficmanager.net/v1/resource/globalState","type":"POST","headers":{"X-Execution-Id":"","Content-Type":"text/plain","If-Match":"df6827a9-3f52-4eb6-8ab3-b13987c861bb","X-Client-Name":"code","X-Client-Version":"1.71.1","X-Client-Commit":"","X-Account-Type":"microsoft","X-Machine-Session-Id":"","X-User-Session-Id":""}}
[2022-09-15 23:23:33.092] [settingssync] [trace] Request succeeded {"url":"https://vscode-sync.trafficmanager.net/v1/resource/globalState","status":200,"execution-id":""}
[2022-09-15 23:23:33.092] [settingssync] [info] GlobalState: Updated remote ui state
[2022-09-15 23:23:33.092] [settingssync] [trace] GlobalState: Updating last synchronized ui state...
[2022-09-15 23:23:33.096] [settingssync] [info] GlobalState: Updated last synchronized ui state
[2022-09-15 23:23:33.098] [settingssync] [trace] GlobalState: Finished synchronizing globalstate.
[2022-09-15 23:23:33.098] [settingssync] [trace] Extensions: Started synchronizing extensions...
[2022-09-15 23:23:33.163] [settingssync] [trace] Extensions: Merging remote extensions with local extensions...
[2022-09-15 23:23:33.163] [settingssync] [info] Extensions: No changes found during synchronizing extensions.
[2022-09-15 23:23:33.164] [settingssync] [trace] Extensions: Finished synchronizing extensions.
[2022-09-15 23:23:33.165] [settingssync] [info] Sync done. Took 510ms
[2022-09-15 23:23:51.210] [settingssync] [trace] activity sources windowFocus
[2022-09-15 23:23:51.210] [settingssync] [info] Auto Sync: Triggered by Activity
[2022-09-15 23:23:51.210] [settingssync] [trace] Sending request to server {"url":"https://vscode-sync.trafficmanager.net/v1/manifest","type":"GET","headers":{"X-Execution-Id":"","Content-Type":"application/json","If-None-Match":"","X-Client-Name":"code","X-Client-Version":"1.71.1","X-Client-Commit":"","X-Account-Type":"microsoft","X-Machine-Session-Id":"","X-User-Session-Id":""}}
[2022-09-15 23:23:51.495] [settingssync] [trace] Request succeeded {"url":"https://vscode-sync.trafficmanager.net/v1/manifest","status":200,"execution-id":""}
[2022-09-15 23:23:51.495] [settingssync] [trace] Sync started.
[2022-09-15 23:23:51.496] [settingssync] [trace] Settings: Started synchronizing settings...
[2022-09-15 23:23:51.499] [settingssync] [trace] Settings: Merging remote settings with local settings...
[2022-09-15 23:23:51.499] [settingssync] [info] Settings: No changes found during synchronizing settings.
[2022-09-15 23:23:51.501] [settingssync] [trace] Settings: Finished synchronizing settings.
[2022-09-15 23:23:51.501] [settingssync] [trace] Keybindings: Started synchronizing keybindings...
[2022-09-15 23:23:51.503] [settingssync] [info] Keybindings: No changes found during synchronizing keybindings.
[2022-09-15 23:23:51.504] [settingssync] [trace] Keybindings: Finished synchronizing keybindings.
[2022-09-15 23:23:51.504] [settingssync] [trace] Snippets: Started synchronizing snippets...
[2022-09-15 23:23:51.506] [settingssync] [trace] Snippets: Remote snippets does not exist. Synchronizing snippets for the first time.
[2022-09-15 23:23:51.506] [settingssync] [info] Snippets: No changes found during synchronizing snippets.
[2022-09-15 23:23:51.507] [settingssync] [trace] Snippets: Finished synchronizing snippets.
[2022-09-15 23:23:51.507] [settingssync] [trace] Tasks: Started synchronizing tasks...
[2022-09-15 23:23:51.509] [settingssync] [info] Tasks: No changes found during synchronizing tasks.
[2022-09-15 23:23:51.510] [settingssync] [trace] Tasks: Finished synchronizing tasks.
[2022-09-15 23:23:51.510] [settingssync] [trace] GlobalState: Started synchronizing globalstate...
[2022-09-15 23:23:51.511] [settingssync] [debug] GlobalStateSync#getLocalArgvContent {"$mid":1,"fsPath":"c:\\Users\\*****\\.vscode\\argv.json","_sep":1,"path":"/C:/Users/*****/.vscode/argv.json","scheme":"file"}
[2022-09-15 23:23:51.513] [settingssync] [debug] GlobalStateSync#getLocalArgvContent - Resolved {"$mid":1,"fsPath":"c:\\Users\\*****\\.vscode\\argv.json","_sep":1,"path":"/C:/Users/*****/.vscode/argv.json","scheme":"file"}
[2022-09-15 23:23:51.513] [settingssync] [trace] GlobalState: Merging remote ui state with local ui state...
[2022-09-15 23:23:51.513] [settingssync] [info] GlobalState: No changes found during synchronizing ui state.
[2022-09-15 23:23:51.513] [settingssync] [trace] GlobalState: Finished synchronizing globalstate.
[2022-09-15 23:23:51.514] [settingssync] [trace] Extensions: Started synchronizing extensions...
[2022-09-15 23:23:51.565] [settingssync] [trace] Extensions: Merging remote extensions with local extensions...
[2022-09-15 23:23:51.565] [settingssync] [info] Extensions: No changes found during synchronizing extensions.
[2022-09-15 23:23:51.568] [settingssync] [trace] Extensions: Finished synchronizing extensions.
[2022-09-15 23:23:51.568] [settingssync] [info] Sync done. Took 72ms
[2022-09-15 23:23:57.862] [settingssync] [debug] Auto Sync: Skipped. Limited to once per 10 seconds.
[2022-09-15 23:24:05.860] [settingssync] [trace] activity sources windowFocus
[2022-09-15 23:24:05.860] [settingssync] [info] Auto Sync: Triggered by Activity
[2022-09-15 23:24:05.860] [settingssync] [trace] Sending request to server {"url":"https://vscode-sync.trafficmanager.net/v1/manifest","type":"GET","headers":{"X-Execution-Id":"","Content-Type":"application/json","If-None-Match":"","X-Client-Name":"code","X-Client-Version":"1.71.1","X-Client-Commit":"","X-Account-Type":"microsoft","X-Machine-Session-Id":"","X-User-Session-Id":""}}
[2022-09-15 23:24:06.080] [settingssync] [trace] Request succeeded {"url":"https://vscode-sync.trafficmanager.net/v1/manifest","status":304,"execution-id":""}
[2022-09-15 23:24:06.080] [settingssync] [trace] Sync started.
[2022-09-15 23:24:06.080] [settingssync] [trace] Settings: Started synchronizing settings...
[2022-09-15 23:24:06.086] [settingssync] [trace] Settings: Merging remote settings with local settings...
[2022-09-15 23:24:06.086] [settingssync] [info] Settings: No changes found during synchronizing settings.
[2022-09-15 23:24:06.088] [settingssync] [trace] Settings: Finished synchronizing settings.
[2022-09-15 23:24:06.088] [settingssync] [trace] Keybindings: Started synchronizing keybindings...
[2022-09-15 23:24:06.090] [settingssync] [info] Keybindings: No changes found during synchronizing keybindings.
[2022-09-15 23:24:06.091] [settingssync] [trace] Keybindings: Finished synchronizing keybindings.
[2022-09-15 23:24:06.091] [settingssync] [trace] Snippets: Started synchronizing snippets...
[2022-09-15 23:24:06.093] [settingssync] [trace] Snippets: Remote snippets does not exist. Synchronizing snippets for the first time.
[2022-09-15 23:24:06.093] [settingssync] [info] Snippets: No changes found during synchronizing snippets.
[2022-09-15 23:24:06.094] [settingssync] [trace] Snippets: Finished synchronizing snippets.
[2022-09-15 23:24:06.094] [settingssync] [trace] Tasks: Started synchronizing tasks...
[2022-09-15 23:24:06.096] [settingssync] [info] Tasks: No changes found during synchronizing tasks.
[2022-09-15 23:24:06.097] [settingssync] [trace] Tasks: Finished synchronizing tasks.
[2022-09-15 23:24:06.097] [settingssync] [trace] GlobalState: Started synchronizing globalstate...
[2022-09-15 23:24:06.099] [settingssync] [debug] GlobalStateSync#getLocalArgvContent {"$mid":1,"fsPath":"c:\\Users\\*****\\.vscode\\argv.json","_sep":1,"path":"/C:/Users/*****/.vscode/argv.json","scheme":"file"}
[2022-09-15 23:24:06.100] [settingssync] [debug] GlobalStateSync#getLocalArgvContent - Resolved {"$mid":1,"fsPath":"c:\\Users\\*****\\.vscode\\argv.json","_sep":1,"path":"/C:/Users/*****/.vscode/argv.json","scheme":"file"}
[2022-09-15 23:24:06.100] [settingssync] [trace] GlobalState: Merging remote ui state with local ui state...
[2022-09-15 23:24:06.100] [settingssync] [info] GlobalState: No changes found during synchronizing ui state.
[2022-09-15 23:24:06.101] [settingssync] [trace] GlobalState: Finished synchronizing globalstate.
[2022-09-15 23:24:06.101] [settingssync] [trace] Extensions: Started synchronizing extensions...
[2022-09-15 23:24:06.152] [settingssync] [trace] Extensions: Merging remote extensions with local extensions...
[2022-09-15 23:24:06.152] [settingssync] [info] Extensions: No changes found during synchronizing extensions.
[2022-09-15 23:24:06.153] [settingssync] [trace] Extensions: Finished synchronizing extensions.
[2022-09-15 23:24:06.153] [settingssync] [info] Sync done. Took 73ms
[2022-09-15 23:24:12.841] [settingssync] [debug] Auto Sync: Skipped. Limited to once per 10 seconds.

@TylerLeonhardt
Copy link
Member

[Error - 15:23:31.491] Error: �ڴ���Դ���㣬�޷����������

well this is interesting... Can you try in the Insiders version of VS Code and tell me if you see the same?

https://code.visualstudio.com/insiders

@buzzers
Copy link
Author

buzzers commented Sep 30, 2022

@TylerLeonhardt

Microsoft Authentication

[2022-09-30 11:20:16.086] [Microsoft Authentication] [info] Reading sessions from secret storage...
[2022-09-30 11:20:16.087] [Microsoft Authentication] [info] Got 0 stored sessions
[2022-09-30 11:20:16.087] [Microsoft Authentication] [info] Getting sessions for the following scopes: email offline_access openid profile
[2022-09-30 11:20:16.087] [Microsoft Authentication] [info] Got 0 sessions for scopes: email offline_access openid profile
[2022-09-30 11:21:16.681] [Microsoft Authentication] [info] Getting sessions for all scopes...
[2022-09-30 11:21:16.681] [Microsoft Authentication] [info] Got 0 sessions for all scopes...
[2022-09-30 11:21:30.620] [Microsoft Authentication] [info] Getting sessions for the following scopes: email offline_access openid profile
[2022-09-30 11:21:30.620] [Microsoft Authentication] [trace] No session found with idtoken scopes... Using fallback scope list of: email offline_access openid profile
[2022-09-30 11:21:30.620] [Microsoft Authentication] [info] Got 0 sessions for scopes: email offline_access openid profile
[2022-09-30 11:21:32.147] [Microsoft Authentication] [info] Logging in for the following scopes: email offline_access openid profile
[2022-09-30 11:21:37.715] [Microsoft Authentication] [info] Exchanging login code for token for scopes: email offline_access openid profile
[2022-09-30 11:21:38.661] [Microsoft Authentication] [info] Exchanging login code for token (for scopes: email offline_access openid profile) succeeded!
[2022-09-30 11:21:38.661] [Microsoft Authentication] [info] Setting token for scopes: email offline_access openid profile
[2022-09-30 11:21:38.661] [Microsoft Authentication] [info] Login successful for scopes: email offline_access openid profile
[2022-09-30 11:21:38.661] [Microsoft Authentication] [info] Token available from cache (for scopes email offline_access openid profile), expires in 3739000 milliseconds
[2022-09-30 11:21:38.662] [Microsoft Authentication] [info] Getting sessions for the following scopes: email offline_access openid profile
[2022-09-30 11:21:38.662] [Microsoft Authentication] [info] Got 1 sessions for scopes: email offline_access openid profile
[2022-09-30 11:21:38.662] [Microsoft Authentication] [info] Token available from cache (for scopes email offline_access openid profile), expires in 3738999 milliseconds
[2022-09-30 11:21:38.662] [Microsoft Authentication] [info] Getting sessions for the following scopes: email offline_access openid profile
[2022-09-30 11:21:38.662] [Microsoft Authentication] [info] Got 1 sessions for scopes: email offline_access openid profile
[2022-09-30 11:21:38.662] [Microsoft Authentication] [info] Token available from cache (for scopes email offline_access openid profile), expires in 3738998 milliseconds
[2022-09-30 11:21:38.918] [Microsoft Authentication] [error] ["Error: �ڴ���Դ���㣬�޷����������\r",""]
[2022-09-30 11:21:51.337] [Microsoft Authentication] [info] Getting sessions for all scopes...
[2022-09-30 11:21:51.337] [Microsoft Authentication] [info] Got 1 sessions for all scopes...

No change in output.

@TylerLeonhardt
Copy link
Member

Let's see if this is a keytar issue then... first log in in vscode (even though it fails)

if you have nodejs installed, you can run this simple one-liner to see if the problem is how your keychain is setup:

npx @emacs-grammarly/keytar-cli find-creds -s vscodevscode.github-authentication

or if you're on Insiders:

npx @emacs-grammarly/keytar-cli find-creds -s vscode-insidersvscode.github-authentication

This is using the following open source package: https://github.com/emacs-grammarly/keytar-cli

What you should get is something like this:

[
  {
    account: 'github.auth',
    password: '....... longggg string ......'
  }
]

NOTE: on macOS I got a system prompt to allow this process to access the keychain... that may or may not be the case for you

Additionally, we can see if we can properly set passwords:

npx @emacs-grammarly/keytar-cli set-pass testingvscode testingvscode testingvscode

and then

npx @emacs-grammarly/keytar-cli find-creds -s testingvscode

should give us that newly created password.

@buzzers
Copy link
Author

buzzers commented Oct 15, 2022

@TylerLeonhardt
image

I get an error that seems to be the same as vscode's log output.

@TylerLeonhardt
Copy link
Member

Ok. This means it's an issue with keytar that we depend on.

Let me get an issue going over there and hopefully that team will be able to help more.

@TylerLeonhardt TylerLeonhardt mentioned this issue Oct 16, 2022
Open
@TylerLeonhardt TylerLeonhardt added upstream-issue-linked This is an upstream issue that has been reported upstream bug Issue identified by VS Code Team member as probable bug authentication Issues with the Authentication platform and removed info-needed Issue requires more information from poster labels Oct 16, 2022
@TylerLeonhardt
Copy link
Member

Upstream: atom/node-keytar#472

@TylerLeonhardt TylerLeonhardt added this to the Backlog milestone Oct 16, 2022
@buzzers buzzers closed this as completed Oct 22, 2022
@TylerLeonhardt TylerLeonhardt removed this from the Backlog milestone Oct 23, 2022
@github-actions github-actions bot locked and limited conversation to collaborators Dec 6, 2022
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees

@TylerLeonhardt TylerLeonhardt

@sandy081 sandy081

Labels
authentication Issues with the Authentication platform bug Issue identified by VS Code Team member as probable bug upstream-issue-linked This is an upstream issue that has been reported upstream
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@TylerLeonhardt @buzzers @sandy081