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

Settings sync requiring login multiple times per day #186693

Closed
mendelgordon opened this issue Jun 30, 2023 · 53 comments
Closed

Settings sync requiring login multiple times per day #186693

mendelgordon opened this issue Jun 30, 2023 · 53 comments
Assignees
Labels
authentication Issues with the Authentication platform bug Issue identified by VS Code Team member as probable bug settings-sync
Milestone

Comments

@mendelgordon
Copy link

Type: Bug

This is the error I see in the settings sync log:
2023-06-28 18:35:06.329 [info] Auto Sync: Triggered by Interval
2023-06-28 18:35:06.331 [info] Sync started.
2023-06-28 18:35:28.626 [info] Request failed https://vscode-sync.trafficmanager.net/v1/manifest
2023-06-28 18:35:28.626 [error] RequestFailed (UserDataSyncError) syncResource:unknown operationId:unknown: Connection refused for the request 'https://vscode-sync.trafficmanager.net/v1/manifest'.
at e.UserDataSyncStoreService.v (/Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/code/node/sharedProcess/sharedProcessMain.js:81:148871)
at async e.UserDataSyncStoreService.manifest (/Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/code/node/sharedProcess/sharedProcessMain.js:81:146879)
at async e.UserDataSyncService.createSyncTask (/Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/code/node/sharedProcess/sharedProcessMain.js:81:120502)
at async r.C (/Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/code/node/sharedProcess/sharedProcessMain.js:81:110859)
at async r.z (/Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/code/node/sharedProcess/sharedProcessMain.js:81:110486)
2023-06-28 18:35:28.626 [error] RequestFailed (UserDataSyncError) syncResource:unknown operationId:unknown: Connection refused for the request 'https://vscode-sync.trafficmanager.net/v1/manifest'.
at e.UserDataSyncStoreService.v (/Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/code/node/sharedProcess/sharedProcessMain.js:81:148871)
at async e.UserDataSyncStoreService.manifest (/Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/code/node/sharedProcess/sharedProcessMain.js:81:146879)
at async e.UserDataSyncService.createSyncTask (/Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/code/node/sharedProcess/sharedProcessMain.js:81:120502)
at async r.C (/Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/code/node/sharedProcess/sharedProcessMain.js:81:110859)
at async r.z (/Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/code/node/sharedProcess/sharedProcessMain.js:81:110486)

Microsoft isn't set to be used as an auth provider for any of my extensions so I'm really not sure what could be causing this

VS Code version: Code 1.79.2 (695af09, 2023-06-14T08:58:33.551Z)
OS version: Darwin arm64 22.5.0
Modes:

System Info
Item Value
CPUs Apple M1 Pro (8 x 24)
GPU Status 2d_canvas: enabled
canvas_oop_rasterization: disabled_off
direct_rendering_display_compositor: disabled_off_ok
gpu_compositing: enabled
metal: disabled_off
multiple_raster_threads: enabled_on
opengl: enabled_on
rasterization: enabled
raw_draw: disabled_off_ok
video_decode: enabled
video_encode: enabled
vulkan: disabled_off
webgl: enabled
webgl2: enabled
webgpu: enabled
Load (avg) 2, 2, 2
Memory (System) 16.00GB (0.38GB free)
Process Argv --crash-reporter-id 7f812d7a-5465-45d4-9902-83edb02707b0
Screen Reader no
VM 0%
Extensions (15)
Extension Author (truncated) Version
vscode-eslint dba 2.4.2
gitlens eam 14.0.1
prettier-vscode esb 9.16.0
copilot-chat Git 0.2.1
copilot-nightly Git 1.93.218
vscode-github-actions git 0.25.8
vscode-language-babel mgm 0.0.39
remote-ssh ms- 0.102.0
remote-ssh-edit ms- 0.86.0
live-server ms- 0.4.8
remote-explorer ms- 0.4.0
vscode-xml red 0.25.0
intellicode-api-usage-examples Vis 0.2.7
vscodeintellicode Vis 1.2.30
vscode-webhint web 2.1.11
A/B Experiments
vsliv368:30146709
vsreu685:30147344
python383cf:30185419
vspor879:30202332
vspor708:30202333
vspor363:30204092
vstes627:30244334
vslsvsres303:30308271
vserr242cf:30382550
pythontb:30283811
vsjup518:30340749
pythonptprofiler:30281270
vshan820:30294714
vstes263:30335439
vscod805:30301674
binariesv615:30325510
bridge0708:30335490
bridge0723:30353136
vsaa593cf:30376535
pythonvs932:30410667
py29gd2263:30776702
vsclangdc:30486549
c4g48928:30535728
dsvsc012:30540252
pynewext54:30695312
azure-dev_surveyone:30548225
vscccc:30610679
3biah626:30602489
pyind779:30671433
f6dab269:30613381
pythonsymbol12:30671437
a9j8j154:30646983
showlangstatbar:30737416
vsctsb:30748421
pythonms35:30701012
03d35959:30757346
pythonfmttext:30731395
pythoncmvfstrcf:30756944
fixshowwlkth:30771522
showindicator:30766890
pythongtdpath:30769146
bgfeh915:30769767
pythonnosmt12:30779714
pythonidxpt:30772539
pythonnoceb:30776495

@sandy081
Copy link
Member

These logs are not talking about the login (authentication), can you please explain what you mean by multiple logins and after you login if settings sync works? When are you getting logged out?

@sandy081 sandy081 added the info-needed Issue requires more information from poster label Jun 30, 2023
@mendelgordon
Copy link
Author

Last night I stepped away from my pc with vscode still open and sync working, and this morning when I came back to it, it made me sign in to sync again - where can I get logs of the issue?

@sdsarun
Copy link

sdsarun commented Jun 30, 2023

I also have the same problem.

@fewwwww
Copy link

fewwwww commented Jun 30, 2023

Same issue.

@sandy081
Copy link
Member

sandy081 commented Jul 3, 2023

@mendelgordon Please share following logs

  • F1 > Open View... > Settings Sync
  • F1 > Open View... > Window

@sandy081
Copy link
Member

sandy081 commented Jul 3, 2023

@TylerLeonhardt Is this auth related?

@mendelgordon
Copy link
Author

settings sync log.txt
Line 7229 seems like the most recent time this issue occurred

window log.txt

@TylerLeonhardt
Copy link
Member

A few days ago there was an issue on the GitHub side that caused issues with Settings Sync. Are you still able to repro this today? If so... 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
  • To the right of Trace, click the double check mark button. ✔️ ✔️ (enables trace logging as the default)
  • 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:
    • GitHub Authentication Output channel
    • Log (Settings Sync) Output channel
    • Log (Main) Output channel
  • Open the Command Palette
  • Run the Developer: Set Log Level... command
  • To the right of Info, click the double check mark button. ✔️ ✔️ (to set the default back to info)

@mendelgordon
Copy link
Author

It most recently happened yesterday - if it happens again I'll enable the higher log level and wait for it to happen another time

@mendelgordon mendelgordon closed this as not planned Won't fix, can't repro, duplicate, stale Jul 3, 2023
@lifei
Copy link

lifei commented Jul 6, 2023

same issue. recently.

@mendelgordon
Copy link
Author

Happened again last night - I signed in with microsoft and turned on the higher log level, and when I came to my pc today it made me sign in to microsoft again
main.txt
microsoftauthentication.txt
settingssync.txt
window.txt

@mendelgordon mendelgordon reopened this Jul 7, 2023
@sandy081 sandy081 assigned Tyriar and unassigned sandy081 Jul 7, 2023
@sandy081 sandy081 removed the info-needed Issue requires more information from poster label Jul 7, 2023
@Tyriar Tyriar assigned TylerLeonhardt and unassigned Tyriar Jul 7, 2023
@Tyriar
Copy link
Member

Tyriar commented Jul 7, 2023

We've been making some changes to how credentials are stored recently so it's likely that.

@TylerLeonhardt
Copy link
Member

Your logs indicate that you have quite a few login sessions. Can you log out of your Microsoft:
image

and tell me if it says that you're still logged in after that?

@TylerLeonhardt TylerLeonhardt added the info-needed Issue requires more information from poster label Jul 7, 2023
@mendelgordon
Copy link
Author

I logged out of microsoft, and then it made me login to microsoft again to continue syncing my settings.

@TylerLeonhardt
Copy link
Member

So you signed out, and then saw that that account was no longer listed in the account menu, right? Can you share the Microsoft Auth & Window logs from this?

@mendelgordon
Copy link
Author

Correct.
Microsoft Auth:
2023-07-07 20:01:13.590 [info] Getting sessions for all scopes... 2023-07-07 20:01:13.591 [info] Got 1 sessions for all scopes... 2023-07-07 20:01:15.419 [info] Logging out of session 'f8cdef31-a31e-4b4a-93e4-5f571e91255a/1:live.com:0003000026538011/62afe373-40ac-476a-9612-d745c20929e4' 2023-07-07 20:01:15.420 [info] Sending change event for session that was removed with scopes: email offline_access openid profile 2023-07-07 20:01:15.420 [info] Logged out of session 'f8cdef31-a31e-4b4a-93e4-5f571e91255a/1:live.com:0003000026538011/62afe373-40ac-476a-9612-d745c20929e4' with scopes: email offline_access openid profile 2023-07-07 20:01:15.436 [info] Getting sessions for the following scopes: email offline_access openid profile 2023-07-07 20:01:15.436 [trace] No session found with idtoken scopes... Using fallback scope list of: email offline_access openid profile 2023-07-07 20:01:15.436 [info] Got 0 sessions for scopes: email offline_access openid profile 2023-07-07 20:01:15.436 [info] Getting sessions for the following scopes: email offline_access openid profile 2023-07-07 20:01:15.436 [trace] No session found with idtoken scopes... Using fallback scope list of: email offline_access openid profile 2023-07-07 20:01:15.436 [info] Got 0 sessions for scopes: email offline_access openid profile 2023-07-07 20:01:22.993 [info] Logging in for the following scopes: email offline_access openid profile 2023-07-07 20:01:26.912 [info] Exchanging login code for token for scopes: email offline_access openid profile 2023-07-07 20:01:27.230 [info] Exchanging login code for token (for scopes: email offline_access openid profile) succeeded! 2023-07-07 20:01:27.230 [info] Setting token for scopes: email offline_access openid profile 2023-07-07 20:01:27.230 [info] Login successful for scopes: email offline_access openid profile 2023-07-07 20:01:27.230 [info] Token available from cache (for scopes email offline_access openid profile), expires in 5090000 milliseconds 2023-07-07 20:01:27.247 [info] Getting sessions for the following scopes: email offline_access openid profile 2023-07-07 20:01:27.247 [info] Got 1 sessions for scopes: email offline_access openid profile 2023-07-07 20:01:27.247 [info] Token available from cache (for scopes email offline_access openid profile), expires in 5089983 milliseconds 2023-07-07 20:01:27.248 [info] Getting sessions for the following scopes: email offline_access openid profile 2023-07-07 20:01:27.248 [info] Got 1 sessions for scopes: email offline_access openid profile 2023-07-07 20:01:27.248 [info] Token available from cache (for scopes email offline_access openid profile), expires in 5089982 milliseconds 2023-07-07 20:01:28.846 [info] Stored token for scopes: email offline_access openid profile

Window:
2023-07-07 20:01:13.596 [trace] DialogService#confirm Sign out of 'mendelgordons@gmail.com'? 2023-07-07 20:01:15.420 [trace] [mainThreadSecretState] Deleting password for vscode.microsoft-authentication extension: f8cdef31-a31e-4b4a-93e4-5f571e91255a/1:live.com:0003000026538011/62afe373-40ac-476a-9612-d745c20929e4 2023-07-07 20:01:15.421 [trace] [secrets] deleting secret for key: secret://{"extensionId":"vscode.microsoft-authentication","key":"f8cdef31-a31e-4b4a-93e4-5f571e91255a/1:live.com:0003000026538011/62afe373-40ac-476a-9612-d745c20929e4"} 2023-07-07 20:01:15.422 [trace] [SecretStorageService] Skipping change event for secret: secret://{"extensionId":"vscode.microsoft-authentication","key":"f8cdef31-a31e-4b4a-93e4-5f571e91255a/1:live.com:0003000026538011/62afe373-40ac-476a-9612-d745c20929e4"} because it is paused 2023-07-07 20:01:15.422 [trace] [SecretStorageService] Skipping change event for secret: secret://{"extensionId":"vscode.microsoft-authentication","key":"f8cdef31-a31e-4b4a-93e4-5f571e91255a/1:live.com:0003000026538011/62afe373-40ac-476a-9612-d745c20929e4"} because it is paused 2023-07-07 20:01:15.423 [trace] [secrets] deleted secret for key: secret://{"extensionId":"vscode.microsoft-authentication","key":"f8cdef31-a31e-4b4a-93e4-5f571e91255a/1:live.com:0003000026538011/62afe373-40ac-476a-9612-d745c20929e4"} 2023-07-07 20:01:15.424 [trace] [mainThreadSecretState] Password deleted for: vscode.microsoft-authentication f8cdef31-a31e-4b4a-93e4-5f571e91255a/1:live.com:0003000026538011/62afe373-40ac-476a-9612-d745c20929e4 2023-07-07 20:01:15.424 [trace] [mainThreadSecretState] Setting password for vscode.microsoft-authentication extension: microsoft.login.keylist 2023-07-07 20:01:15.425 [trace] [secrets] encrypting secret for key: {"extensionId":"vscode.microsoft-authentication","key":"microsoft.login.keylist"} 2023-07-07 20:01:15.425 [info] Settings Sync: Reset current session 2023-07-07 20:01:15.426 [trace] Settings Sync: Getting accounts for github 2023-07-07 20:01:15.426 [trace] Settings Sync: Getting accounts for github 2023-07-07 20:01:15.435 [trace] Settings Sync: Updated accounts for github 2023-07-07 20:01:15.436 [trace] Settings Sync: Getting accounts for microsoft 2023-07-07 20:01:15.436 [trace] Settings Sync: Updated accounts for github 2023-07-07 20:01:15.436 [trace] Settings Sync: Getting accounts for microsoft 2023-07-07 20:01:15.437 [trace] Settings Sync: Updated accounts for microsoft 2023-07-07 20:01:15.437 [trace] [secrets] storing encrypted secret for key: secret://{"extensionId":"vscode.microsoft-authentication","key":"microsoft.login.keylist"} 2023-07-07 20:01:15.437 [trace] [SecretStorageService] Skipping change event for secret: secret://{"extensionId":"vscode.microsoft-authentication","key":"microsoft.login.keylist"} because it is paused 2023-07-07 20:01:15.438 [trace] [SecretStorageService] Skipping change event for secret: secret://{"extensionId":"vscode.microsoft-authentication","key":"microsoft.login.keylist"} because it is paused 2023-07-07 20:01:15.438 [trace] [secrets] stored encrypted secret for key: secret://{"extensionId":"vscode.microsoft-authentication","key":"microsoft.login.keylist"} 2023-07-07 20:01:15.438 [trace] [mainThreadSecretState] Password set for: vscode.microsoft-authentication microsoft.login.keylist 2023-07-07 20:01:15.438 [trace] Settings Sync: Updated accounts for microsoft 2023-07-07 20:01:15.439 [trace] Settings Sync: Account status changed from available to unavailable 2023-07-07 20:01:22.973 [trace] CommandService#executeCommand workbench.userData.actions.signin 2023-07-07 20:01:23.007 [trace] [editor auto save] triggering auto save with reason 4 2023-07-07 20:01:23.008 [trace] ChatService#onWillSaveState: Persisting 2 sessions 2023-07-07 20:01:23.008 [trace] ChatService#onWillSaveState: Persisting 112351 chars 2023-07-07 20:01:26.913 [trace] CommandService#executeCommand workbench.getCodeExchangeProxyEndpoints 2023-07-07 20:01:27.238 [trace] Settings Sync: Getting accounts for github 2023-07-07 20:01:27.238 [info] Settings Sync: Updated current session f8cdef31-a31e-4b4a-93e4-5f571e91255a/1:live.com:0003000026538011/47139558-f568-4512-bc8d-7a0ce54b032c 2023-07-07 20:01:27.240 [trace] Settings Sync: Getting accounts for github 2023-07-07 20:01:27.245 [trace] Settings Sync: Updated accounts for github 2023-07-07 20:01:27.246 [trace] Settings Sync: Getting accounts for microsoft 2023-07-07 20:01:27.247 [trace] Settings Sync: Updated accounts for github 2023-07-07 20:01:27.248 [trace] Settings Sync: Getting accounts for microsoft 2023-07-07 20:01:27.249 [trace] Settings Sync: Updated accounts for microsoft 2023-07-07 20:01:27.249 [trace] Settings Sync: Updating the token for the account mendelgordons@gmail.com 2023-07-07 20:01:27.249 [trace] Settings Sync: Token updated for the account mendelgordons@gmail.com 2023-07-07 20:01:27.253 [trace] Settings Sync: Updated accounts for microsoft 2023-07-07 20:01:27.253 [trace] Settings Sync: Updating the token for the account mendelgordons@gmail.com 2023-07-07 20:01:27.254 [trace] Settings Sync: Token updated for the account mendelgordons@gmail.com 2023-07-07 20:01:27.255 [trace] Settings Sync: Account status changed from unavailable to available 2023-07-07 20:01:28.846 [trace] [mainThreadSecretState] Setting password for vscode.microsoft-authentication extension: f8cdef31-a31e-4b4a-93e4-5f571e91255a/1:live.com:0003000026538011/47139558-f568-4512-bc8d-7a0ce54b032c 2023-07-07 20:01:28.846 [trace] [secrets] encrypting secret for key: {"extensionId":"vscode.microsoft-authentication","key":"f8cdef31-a31e-4b4a-93e4-5f571e91255a/1:live.com:0003000026538011/47139558-f568-4512-bc8d-7a0ce54b032c"} 2023-07-07 20:01:28.847 [trace] [mainThreadSecretState] Setting password for vscode.microsoft-authentication extension: microsoft.login.keylist 2023-07-07 20:01:28.847 [trace] [secrets] storing encrypted secret for key: secret://{"extensionId":"vscode.microsoft-authentication","key":"f8cdef31-a31e-4b4a-93e4-5f571e91255a/1:live.com:0003000026538011/47139558-f568-4512-bc8d-7a0ce54b032c"} 2023-07-07 20:01:28.848 [trace] [SecretStorageService] Skipping change event for secret: secret://{"extensionId":"vscode.microsoft-authentication","key":"f8cdef31-a31e-4b4a-93e4-5f571e91255a/1:live.com:0003000026538011/47139558-f568-4512-bc8d-7a0ce54b032c"} because it is paused 2023-07-07 20:01:28.848 [trace] [SecretStorageService] Skipping change event for secret: secret://{"extensionId":"vscode.microsoft-authentication","key":"f8cdef31-a31e-4b4a-93e4-5f571e91255a/1:live.com:0003000026538011/47139558-f568-4512-bc8d-7a0ce54b032c"} because it is paused 2023-07-07 20:01:28.848 [trace] [secrets] stored encrypted secret for key: secret://{"extensionId":"vscode.microsoft-authentication","key":"f8cdef31-a31e-4b4a-93e4-5f571e91255a/1:live.com:0003000026538011/47139558-f568-4512-bc8d-7a0ce54b032c"} 2023-07-07 20:01:28.848 [trace] [mainThreadSecretState] Password set for: vscode.microsoft-authentication f8cdef31-a31e-4b4a-93e4-5f571e91255a/1:live.com:0003000026538011/47139558-f568-4512-bc8d-7a0ce54b032c 2023-07-07 20:01:28.848 [trace] [secrets] encrypting secret for key: {"extensionId":"vscode.microsoft-authentication","key":"microsoft.login.keylist"} 2023-07-07 20:01:28.849 [trace] [secrets] storing encrypted secret for key: secret://{"extensionId":"vscode.microsoft-authentication","key":"microsoft.login.keylist"} 2023-07-07 20:01:28.849 [trace] [SecretStorageService] Skipping change event for secret: secret://{"extensionId":"vscode.microsoft-authentication","key":"microsoft.login.keylist"} because it is paused 2023-07-07 20:01:28.849 [trace] [SecretStorageService] Skipping change event for secret: secret://{"extensionId":"vscode.microsoft-authentication","key":"microsoft.login.keylist"} because it is paused 2023-07-07 20:01:28.849 [trace] [secrets] stored encrypted secret for key: secret://{"extensionId":"vscode.microsoft-authentication","key":"microsoft.login.keylist"} 2023-07-07 20:01:28.849 [trace] [mainThreadSecretState] Password set for: vscode.microsoft-authentication microsoft.login.keylist 2023-07-07 20:01:51.307 [trace] CommandService#executeCommand workbench.action.output.show.vscode.microsoft-authentication.Microsoft Authentication 2023-07-07 20:01:51.331 [trace] Stopped polling file:///Users/mendelgordon/Library/Application%20Support/Code/logs/20230706T163621/window6/renderer.log 2023-07-07 20:01:51.338 [trace] CommandService#executeCommand _setContext 2023-07-07 20:01:51.340 [trace] Started polling file:///Users/mendelgordon/Library/Application%20Support/Code/logs/20230706T163621/window6/exthost/vscode.microsoft-authentication/Microsoft%20Authentication.log 2023-07-07 20:01:51.345 [trace] CommandService#executeCommand _setContext 2023-07-07 20:01:56.998 [trace] KeybindingService#dispatch F1 [ Will dispatch command workbench.action.showCommands ] 2023-07-07 20:01:57.030 [trace] CommandService#executeCommand workbench.action.showCommands 2023-07-07 20:01:58.088 [trace] CommandService#executeCommand workbench.action.setLogLevel

@TylerLeonhardt
Copy link
Member

So at this point, are you are able to turn on Settings Sync? If that works, when you reload VS Code are you still logged in?

@mendelgordon
Copy link
Author

mendelgordon commented Jul 8, 2023 via email

@TylerLeonhardt
Copy link
Member

Ok. Thanks for confirming. I would like to see if you experience the same issue of a growing list of sessions again. If you hit this issue again, can you attach the logs again? We can leave this open.

@TylerLeonhardt TylerLeonhardt added the bug Issue identified by VS Code Team member as probable bug label Jul 8, 2023
@sandy081
Copy link
Member

I see you use this here but maybe there's another place a token gets saved?

@TylerLeonhardt Token is stored in the shared process where settings sync happens. Token is updated by the window (renderer), where I listen to the event you mentioned. I also re-request sessions when the existing token fails with 401. Since this happens on the window, do you think if there is a possibility that multiple windows are opened, and one of the windows is getting an invalid token from the auth extension ?

@TylerLeonhardt
Copy link
Member

@mendelgordon the next time this happens can you include:

  • Microsoft Authentication Output channel
  • Log (Settings Sync) Output channel
  • Log (Main) Output channel
  • Log (Window) Output channel

With these things, @sandy081 and I will sit down and follow the flow and see what is going wrong/add more logs to get to the bottom of this. Thank you so much for providing everything you have so far, it's been helpful!

@mendelgordon
Copy link
Author

@sandy081
Copy link
Member

sandy081 commented Sep 4, 2023

@mendelgordon Thanks for the logs.

@TylerLeonhardt Lets go through the logs together and diagnose the issue.

@TylerLeonhardt
Copy link
Member

TylerLeonhardt commented Sep 8, 2023

Monday's VS Code Insider build will have two things from my end:

  • a fix that prevents those huge chains of [info] Stored token for scopes: email offline_access openid profile and instead only stores secrets once (my hope is that this maybe fixes the issue)
  • a fix that makes sure tokens are fully refreshed before getting a session (my hope is that this maybe fixes the issue)
  • if not, I've also added a TON of new logging on the auth side to understand what's going on.

@sandy081 is also planning (if he hasn't done it yet) to add more logs on the Settings Sync side so we can fill in the gaps of our logs.

My recommendation for you @mendelgordon ... get VS Code Insiders if you don't have it already and use exclusively that to see if we can repro the issue. Make sure you have the TRACE log level enabled. That is super important for these logs I've added.

If you see it, please once again, send those 4 Output channels.

I really appreciate your patience here. This is a particularly pesky bug to track down...

@matthewpavkov
Copy link

I'm also seeing this same issue, I'll switch to the Insider build next week and monitor this thread. I'm sure mendelgordon will follow up, but if not, I can also provide the logging or otherwise confirm if the issue is resolved.

TylerLeonhardt added a commit that referenced this issue Sep 8, 2023
The idea here is... if a token is currently being refreshed, well then getting a token of those scopes should wait for that to finish.

Core has a really nice `SequencerByKey` for exactly this kind of thing, and so I've stolen that and started to organize the code with a `common` folder.

Oh, I also noticed we were sorting twice and fixed that to only sort once.

ref #186693
TylerLeonhardt added a commit that referenced this issue Sep 9, 2023
…#192638)

The idea here is... if a token is currently being refreshed, well then getting a token of those scopes should wait for that to finish.

Core has a really nice `SequencerByKey` for exactly this kind of thing, and so I've stolen that and started to organize the code with a `common` folder.

Oh, I also noticed we were sorting twice and fixed that to only sort once.

ref #186693
@mendelgordon
Copy link
Author

@matthewpavkov it’s better if you provide the logs, since I stopped using GitHub copilot, and that seemingly makes the issue happen less often.

@matthewpavkov
Copy link

@TylerLeonhardt I only have a few days of testing this, but so far the Insider build seems to work as expected.

I have two accounts I'm connected to, one for syncing my settings (Microsoft) and one for Copilot (GitHub). I have not had to log into Microsoft every day like I normally do. It's only been a few days, I will continue monitoring and report back regardless next week.

@mendelgordon FYI

@matthewpavkov
Copy link

@TylerLeonhardt Everything looks good still, this seems to be resolved now.

@TylerLeonhardt
Copy link
Member

@matthewpavkov glad to hear! @mendelgordon how's it going for you?

@mendelgordon
Copy link
Author

It's "only" signing me out approx. once a week, so I haven't bothered to get the logs - I still don't have copilot turned on so I'm not sure if that would make issues.

@TylerLeonhardt
Copy link
Member

Well, I'd love to figure out how to get it to not sign out at all 🙏 Copilot shouldn't affect this... but I'm curious if you do see a correlation these days.

@mendelgordon
Copy link
Author

Happened again but I'm not sure if I reenabled the trace level before or after it happened - when and why does the log level get reset to the default?
Does changing the log level reveal everything at that level in the log, so it's ok if you didn't have trace set at the time the issue occurred?
I'm also using the regular vscode, not insiders.
main.log
userDataSync.log
renderer.log
Microsoft Authentication.log

@TylerLeonhardt
Copy link
Member

@mendelgordon looks like the important trace logging isn't there. Did you grab today's VS Code stable release 1.83?

@TylerLeonhardt
Copy link
Member

when and why does the log level get reset to the default?
Does changing the log level reveal everything at that level in the log, so it's ok if you didn't have trace set at the time the issue occurred?

@sandy081 can you answer these? I think the 2nd question, the answer is "no", sadly.

@mendelgordon
Copy link
Author

Only got it after the issue occurred

@TylerLeonhardt
Copy link
Member

Ok yeah. 1.83 does have this stuff I mentioned here:
#186693 (comment)

so I am eager to hear your experience post-update.

@mendelgordon
Copy link
Author

I see in the update notes that there's a new option, Developer: Download Settings Sync Activity - is that something I should do the next time the issue occurs? Does that collect all of the logs needed, or would I still send the others as well?

@TylerLeonhardt
Copy link
Member

@sandy081 does that help us here at all?

@sandy081
Copy link
Member

No, as this does not capture login activity.

@mendelgordon
Copy link
Author

The issue went away after that update, and reactivating github copilot hasn't caused any issues here!

@github-actions github-actions bot locked and limited conversation to collaborators Jan 1, 2024
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 settings-sync
Projects
None yet
Development

No branches or pull requests

9 participants