Settings sync requiring login multiple times per day

[mendelgordon]

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 (695af097c7bd098fbf017ce3ac85e09bbc5dda06, 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]

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?

[mendelgordon]

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]

I also have the same problem.

[fewwwww]

Same issue.

[sandy081]

@mendelgordon Please share following logs

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

[sandy081]

@TylerLeonhardt Is this auth related?

[mendelgordon]

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

window log.txt

[TylerLeonhardt]

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]

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

[lifei]

same issue. recently.

[mendelgordon]

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

[Tyriar]

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

[TylerLeonhardt]

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

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

[mendelgordon]

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

[TylerLeonhardt]

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]

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 '[email protected]'? 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 [email protected] 2023-07-07 20:01:27.249 [trace] Settings Sync: Token updated for the account [email protected] 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 [email protected] 2023-07-07 20:01:27.254 [trace] Settings Sync: Token updated for the account [email protected] 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]

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]

Yes and yes

[TylerLeonhardt]

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.

[mendelgordon]

Should I use the trace log level?

[TylerLeonhardt]

Yes please! No harm in not.

[mendelgordon]

Happened again microsoft-authentication.log settings-sync.log

[rschuetzler]

Happening to me as well. On the Insiders build on a mac, and I get the "sign in to enable sync" about once per day.

My userDataSync.log file:

2023-07-19 15:00:37.857 [info] Using settings sync service https://vscode-sync.trafficmanager.net/
2023-07-19 15:00:37.857 [info] Auto Sync is enabled.
2023-07-19 15:00:37.857 [info] Auto Sync: Suspended until auth token is available.
2023-07-19 15:00:38.132 [info] Deleting non existing profile from backup /Users/ryan/Library/Application Support/Code - Insiders/User/sync/extensions
2023-07-19 15:00:38.159 [info] Deleting non existing profile from backup /Users/ryan/Library/Application Support/Code - Insiders/User/sync/globalState
2023-07-19 15:00:38.172 [info] Deleting non existing profile from backup /Users/ryan/Library/Application Support/Code - Insiders/User/sync/keybindings
2023-07-19 15:00:38.175 [info] Deleting non existing profile from backup /Users/ryan/Library/Application Support/Code - Insiders/User/sync/profiles
2023-07-19 15:00:38.189 [info] Deleting non existing profile from backup /Users/ryan/Library/Application Support/Code - Insiders/User/sync/settings
2023-07-19 15:00:38.208 [info] Deleting non existing profile from backup /Users/ryan/Library/Application Support/Code - Insiders/User/sync/snippets
2023-07-19 15:00:38.210 [info] Deleting non existing profile from backup /Users/ryan/Library/Application Support/Code - Insiders/User/sync/tasks
2023-07-19 15:00:44.712 [info] Auto Sync: Triggered by Interval
2023-07-19 15:00:44.712 [info] Sync started.
2023-07-19 15:00:44.982 [info] Settings: Last sync resource does not exist locally.
2023-07-19 15:00:45.112 [info] Settings: No changes found during synchronizing settings.
2023-07-19 15:00:45.113 [info] Keybindings: Last sync resource does not exist locally.
2023-07-19 15:00:45.173 [info] Keybindings: No changes found during synchronizing keybindings.
2023-07-19 15:00:45.173 [info] Snippets: Last sync resource does not exist locally.
2023-07-19 15:00:45.234 [info] Snippets: No changes found during synchronizing snippets.
2023-07-19 15:00:45.235 [info] Tasks: Last sync resource does not exist locally.
2023-07-19 15:00:45.288 [info] Tasks: No changes found during synchronizing tasks.
2023-07-19 15:00:45.289 [info] GlobalState: Last sync resource does not exist locally.
2023-07-19 15:00:45.589 [info] GlobalState: Updated remote ui state. Updated: cpp.1.lastSessionDate,cpp.1.sessionCount,java.2.lastSessionDate,java.2.sessionCount,typescript.1.lastSessionDate,typescript.1.sessionCount,csharp.1.lastSessionDate,csharp.1.sessionCount,commandPalette.mru.cache,commandPalette.mru.counter.
2023-07-19 15:00:45.616 [info] GlobalState: Updated last synchronized ui state
2023-07-19 15:00:45.641 [info] Extensions: Last sync resource does not exist locally.
2023-07-19 15:00:45.942 [info] Extensions: Updated remote extensions. Updated: ["a bunch of extensions"].
2023-07-19 15:00:45.947 [info] Extensions: Updated last synchronized extensions.
2023-07-19 15:00:45.948 [info] Profiles: Last sync resource does not exist locally.
2023-07-19 15:00:46.003 [info] Profiles: No changes found during synchronizing profiles.
2023-07-19 15:00:46.004 [info] Sync done. Took 1291ms
2023-07-19 15:00:50.193 [info] Auto Sync: Triggered by Activity
2023-07-19 15:00:50.193 [info] Sync started.
2023-07-19 15:00:50.256 [info] Settings: No changes found during synchronizing settings.
2023-07-19 15:00:50.257 [info] Keybindings: No changes found during synchronizing keybindings.
2023-07-19 15:00:50.259 [info] Snippets: No changes found during synchronizing snippets.
2023-07-19 15:00:50.261 [info] Tasks: No changes found during synchronizing tasks.
2023-07-19 15:00:50.263 [info] GlobalState: No changes found during synchronizing ui state.
2023-07-19 15:00:50.484 [info] Extensions: Updated remote extensions. Updated: ["a bunch of extensions"].
2023-07-19 15:00:50.492 [info] Extensions: Updated last synchronized extensions.
2023-07-19 15:00:50.494 [info] Profiles: No changes found during synchronizing profiles.
2023-07-19 15:00:50.495 [info] Sync done. Took 303ms

[TylerLeonhardt]

@sandy081 I notice that we log the status of the call to the settings sync server:

2023-07-14 02:09:50.772 [info] Request failed {"url":"https://vscode-sync.trafficmanager.net/v1/manifest","status":401,"execution-id":"foo","operation-id":"bar"}

but we don't return the actual 401 payload which would tell us why the 401 occurred. Do you think you could add some logging where this gets called to log the text payload along with the 401?

[sandy081]

Can you please try following and let me know if the information is captured here:

• Enable log level to trace - F1 > Developer: Set Log Level... > Trace
• Looks for the requests in the Network log - F1 > Open View... > Network

[mendelgordon]

I wonder if this is triggered by github copilot settingssync.txt networkrequests.txt

[rschuetzler]

Happened again this morning and I caught the 401 in the logs. I don't see Network as an option when I try to open view.

userDataSync.log:

2023-07-26 11:55:54.899 [info] Auto Sync: Triggered by Interval
2023-07-26 11:55:54.899 [info] Sync started.
2023-07-26 11:55:55.572 [info] Request failed {"url":"https://vscode-sync.trafficmanager.net/v1/manifest","status":401,"execution-id":"7b554cdb-ae83-4238-81f9-cdad78c791b7","operation-id":"c622e56d98f1451db86096433d9caa9c"}
2023-07-26 11:55:55.572 [info] Settings Sync auth token failed microsoft false Unauthorized
2023-07-26 11:55:55.572 [info] Auto Sync: Suspended until auth token is available.
2023-07-26 11:55:55.572 [info] Auto sync: Cancelled sync that is in progress
2023-07-26 11:55:55.572 [info] Auto Sync: Stopped
2023-07-26 11:55:55.572 [error] Unauthorized (UserDataSyncError) syncResource:unknown operationId:c622e56d98f1451db86096433d9caa9c: GET request 'https://vscode-sync.trafficmanager.net/v1/manifest' failed because of Unauthorized (401).
    at f.v (/Applications/Visual Studio Code - Insiders.app/Contents/Resources/app/out/vs/code/node/sharedProcess/sharedProcessMain.js:91:126689)
    at async f.manifest (/Applications/Visual Studio Code - Insiders.app/Contents/Resources/app/out/vs/code/node/sharedProcess/sharedProcessMain.js:91:124343)
    at async i.createSyncTask (/Applications/Visual Studio Code - Insiders.app/Contents/Resources/app/out/vs/code/node/sharedProcess/sharedProcessMain.js:91:99785)
    at async o.C (/Applications/Visual Studio Code - Insiders.app/Contents/Resources/app/out/vs/code/node/sharedProcess/sharedProcessMain.js:91:90981)
    at async o.z (/Applications/Visual Studio Code - Insiders.app/Contents/Resources/app/out/vs/code/node/sharedProcess/sharedProcessMain.js:91:90621)
2023-07-26 11:55:57.173 [info] Auto Sync: Triggered by Interval
2023-07-26 11:55:57.174 [info] Sync started.
2023-07-26 11:55:57.253 [info] Request failed {"url":"https://vscode-sync.trafficmanager.net/v1/manifest","status":401,"execution-id":"5464811b-b5d9-4931-b35f-81dfbf857804","operation-id":"3840426b06424e1d9f1da578e4a646cb"}
2023-07-26 11:55:57.254 [info] Settings Sync auth token failed microsoft true Unauthorized
2023-07-26 11:55:57.254 [info] Auto Sync: Suspended until auth token is available.
2023-07-26 11:55:57.255 [info] Auto sync: Cancelled sync that is in progress
2023-07-26 11:55:57.256 [info] Auto Sync: Stopped
2023-07-26 11:55:57.256 [error] Unauthorized (UserDataSyncError) syncResource:unknown operationId:3840426b06424e1d9f1da578e4a646cb: GET request 'https://vscode-sync.trafficmanager.net/v1/manifest' failed because of Unauthorized (401).
    at f.v (/Applications/Visual Studio Code - Insiders.app/Contents/Resources/app/out/vs/code/node/sharedProcess/sharedProcessMain.js:91:126689)
    at async f.manifest (/Applications/Visual Studio Code - Insiders.app/Contents/Resources/app/out/vs/code/node/sharedProcess/sharedProcessMain.js:91:124343)
    at async i.createSyncTask (/Applications/Visual Studio Code - Insiders.app/Contents/Resources/app/out/vs/code/node/sharedProcess/sharedProcessMain.js:91:99785)
    at async o.C (/Applications/Visual Studio Code - Insiders.app/Contents/Resources/app/out/vs/code/node/sharedProcess/sharedProcessMain.js:91:90981)
    at async o.z (/Applications/Visual Studio Code - Insiders.app/Contents/Resources/app/out/vs/code/node/sharedProcess/sharedProcessMain.js:91:90621)

telemetry.log:

2023-07-25 16:37:25.963 [info] Below are logs for every telemetry event sent from VS Code once the log level is set to trace.
2023-07-25 16:37:25.963 [info] ===========================================================

[TylerLeonhardt]

@sandy081 added some additional important logging in https://github.com/microsoft/vscode/pull/188935 that should be available with the insiders version today... or wait a few days for the next stable likely out next Thursday.

With this logging, sharing the Settings Sync output channel would be super helpful!

[mendelgordon]

I installed the insiders version and didn't have the issue there at all - now that the logging was added to the stable build I switched back to that and had the issue again today. Please see the attached log. settingssync.txt

[rschuetzler]

New userDataSync.log:

2023-08-04 18:50:37.875 [info] Auto Sync: Triggered by Interval
2023-08-04 18:50:37.877 [info] Sync started.
2023-08-04 18:50:38.294 [info] Request failed {"url":"https://vscode-sync.trafficmanager.net/v1/manifest","status":401,"execution-id":"371a9de9-0074-4fa6-b5af-7aa79f8f690a","operation-id":"ceb10c5a48b84d0382527b0cbc23d39a"} Failed to verify user: jwt expired
2023-08-04 18:50:38.295 [info] Settings Sync auth token failed microsoft false Unauthorized
2023-08-04 18:50:38.295 [info] Auto Sync: Suspended until auth token is available.
2023-08-04 18:50:38.296 [info] Auto sync: Cancelled sync that is in progress
2023-08-04 18:50:38.296 [info] Auto Sync: Stopped
2023-08-04 18:50:38.296 [error] Unauthorized (UserDataSyncError) syncResource:unknown operationId:ceb10c5a48b84d0382527b0cbc23d39a: GET request 'https://vscode-sync.trafficmanager.net/v1/manifest' failed because of Unauthorized (401).
    at f.v (/Applications/Visual Studio Code - Insiders.app/Contents/Resources/app/out/vs/code/node/sharedProcess/sharedProcessMain.js:91:126683)
    at async f.manifest (/Applications/Visual Studio Code - Insiders.app/Contents/Resources/app/out/vs/code/node/sharedProcess/sharedProcessMain.js:91:124335)
    at async i.createSyncTask (/Applications/Visual Studio Code - Insiders.app/Contents/Resources/app/out/vs/code/node/sharedProcess/sharedProcessMain.js:91:99765)
    at async o.C (/Applications/Visual Studio Code - Insiders.app/Contents/Resources/app/out/vs/code/node/sharedProcess/sharedProcessMain.js:91:90961)
    at async o.z (/Applications/Visual Studio Code - Insiders.app/Contents/Resources/app/out/vs/code/node/sharedProcess/sharedProcessMain.js:91:90601)