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

winget list running slow possible issue with "Opened SQLite Index with version" #4901

Open
marekciel opened this issue Oct 24, 2024 · 2 comments
Labels
Area-Performance Issue related to CPU or memory performance Command-List Issue related to WinGet List Issue-Bug It either shouldn't be doing this or needs an investigation.

Comments

@marekciel
Copy link

marekciel commented Oct 24, 2024

Brief description of your issue

winget list is runing very slow on the newly installed machine. It was working correctly but after couple of reboots winget stoped responding.

I can also see the same slownes behavior when ussing import and upgrade commands (although I have only tried on thoes)

Steps to reproduce

winget list

Expected behavior

To finish get list in a matter of seconds.

Actual behavior

When trying to list packages it take for ever to do so.

2024-10-24 15:05:24.362 [CORE] Package: Microsoft.DesktopAppInstaller v1.23.1911.0
2024-10-24 15:05:24.362 [CORE] IsCOMCall:0; Caller: winget-cli
2024-10-24 15:05:24.369 [CLI ] WinGet invoked with arguments: 'list' '--verbose-logs'
2024-10-24 15:05:24.369 [CLI ] Found subcommand: list
2024-10-24 15:05:24.371 [CLI ] Leaf command to execute: root:list
2024-10-24 15:05:24.372 [CORE] Setting action: Get, Type: Secure, Name: admin_settings
2024-10-24 15:05:24.372 [CORE] Admin settings was not found
2024-10-24 15:05:24.372 [CORE] Setting action: Get, Type: Secure, Name: admin_settings
2024-10-24 15:05:24.372 [CORE] Admin settings was not found
2024-10-24 15:05:24.372 [CLI ] Executing command: list
2024-10-24 15:05:24.372 [REPO] Additional sources GP is not enabled.
2024-10-24 15:05:24.372 [CORE] Setting action: Get, Type: Secure, Name: user_sources
2024-10-24 15:05:24.372 [CORE] Setting action: Get, Type: Secure, Name: admin_settings
2024-10-24 15:05:24.372 [CORE] Admin settings was not found
2024-10-24 15:05:24.373 [CORE] Adding chain to pinning configuration [Microsoft Store Source]:
DigiCert Global Root G3 : PublicKey
  Microsoft Azure ECC TLS Issuing CA 04 : Subject | Issuer
    sfdataservice.microsoft.com : Subject | Issuer
2024-10-24 15:05:24.373 [CORE] Adding chain to pinning configuration [Microsoft Store Source]:
DigiCert Global Root G3 : PublicKey
  Microsoft Azure ECC TLS Issuing CA 04 : Subject | Issuer
    sfdataservice.microsoft.com : Subject | Issuer
2024-10-24 15:05:24.378 [CORE] Setting action: Get, Type: Standard, Name: sources_metadata
2024-10-24 15:05:24.378 [YAML] Detected UTF-8
2024-10-24 15:05:24.378 [REPO] GetCurrentSourceRefs: Source named 'microsoft.builtin.desktop.frameworks' from origin Default is hidden and is dropped.
2024-10-24 15:05:24.378 [REPO] Default source requested, multiple sources available, adding all to source references.
2024-10-24 15:05:24.378 [REPO] Adding to source references msstore
2024-10-24 15:05:24.379 [CORE] Setting action: Get, Type: Secure, Name: admin_settings
2024-10-24 15:05:24.379 [CORE] Admin settings was not found
2024-10-24 15:05:24.379 [CORE] Default proxy is not set
2024-10-24 15:05:24.379 [REPO] REST HTTP Client helper does not use proxy
2024-10-24 15:05:24.379 [REPO] Adding to source references winget
2024-10-24 15:05:24.379 [CLI ] Created authentication arguments. Mode: silentPreferred, Account: 
2024-10-24 15:05:24.388 [CORE] Examining extension: PFN = Microsoft.Winget.Source_8wekyb3d8bbwe, ID = IndexDB
2024-10-24 15:05:24.388 [CORE] Found matching extension.
2024-10-24 15:05:24.391 [REPO] Source `winget` after auto update time [15 mins]; it has been at least 19 mins
2024-10-24 15:05:24.396 [CORE] Examining extension: PFN = Microsoft.Winget.Source_8wekyb3d8bbwe, ID = IndexDB
2024-10-24 15:05:24.396 [CORE] Found matching extension.
2024-10-24 15:05:24.398 [CORE] Retrieving headers from url: https://cdn.winget.microsoft.com/cache/source2.msix
2024-10-24 15:05:24.834 [REPO] Header indicates version is: 2024.1024.1221.1
2024-10-24 15:05:24.834 [REPO] Remote source data (2024.1024.1221.1) was not newer than existing (2024.1024.1221.1), no update needed
2024-10-24 15:05:24.834 [REPO] Additional sources GP is not enabled.
2024-10-24 15:05:24.834 [CORE] Setting action: Get, Type: Secure, Name: user_sources
2024-10-24 15:05:24.834 [CORE] Setting action: Get, Type: Secure, Name: admin_settings
2024-10-24 15:05:24.834 [CORE] Admin settings was not found
2024-10-24 15:05:24.834 [CORE] Adding chain to pinning configuration [Microsoft Store Source]:
DigiCert Global Root G3 : PublicKey
  Microsoft Azure ECC TLS Issuing CA 04 : Subject | Issuer
    sfdataservice.microsoft.com : Subject | Issuer
2024-10-24 15:05:24.834 [CORE] Adding chain to pinning configuration [Microsoft Store Source]:
DigiCert Global Root G3 : PublicKey
  Microsoft Azure ECC TLS Issuing CA 04 : Subject | Issuer
    sfdataservice.microsoft.com : Subject | Issuer
2024-10-24 15:05:24.835 [CORE] Setting action: Get, Type: Standard, Name: sources_metadata
2024-10-24 15:05:24.835 [YAML] Detected UTF-8
2024-10-24 15:05:24.835 [CORE] Setting action: Set, Type: Standard, Name: sources_metadata
2024-10-24 15:05:24.835 [REPO] Multiple sources available, creating aggregated source.
2024-10-24 15:05:24.835 [REPO] Adding to aggregated source: msstore
2024-10-24 15:05:24.835 [REPO] User agent caller found: winget-cli
2024-10-24 15:05:24.835 [REPO] Sending http GET request to: https://storeedgefd.dsx.mp.microsoft.com/v9.0/information
2024-10-24 15:05:24.837 [REPO] Http GET request details:
GET / HTTP/1.1

Content-Type: application/json

User-Agent: winget-cli WindowsPackageManager/1.8.1911 DesktopAppInstaller/Microsoft.DesktopAppInstaller v1.23.1911.0




2024-10-24 15:05:25.359 [REPO] Response status: 200
2024-10-24 15:05:25.359 [REPO] Response details:
HTTP/1.1 200 OK

Cache-Control: max-age=0, no-cache, no-store

Connection: keep-alive

Content-Length: 861

Content-Type: application/json; charset=utf-8

Date: Thu, 24 Oct 2024 13:05:25 GMT

Expires: Thu, 24 Oct 2024 13:05:25 GMT

MS-CV: o9JImZEujU2dDq/e.0

Pragma: no-cache

Server: Microsoft-HTTPAPI/2.0

X-OSG-Served-By: Torus-WESTEUROPE_Legacy000M54_1.0.0.0

X-Segment-On: true



{"$type":"Microsoft.Marketplace.Storefront.StoreEdgeFD.BusinessLogic.Response.PackageMetadata.PackageMetadataResponse, StoreEdgeFD","Data":{"$type":"Microsoft.Marketplace.Storefront.StoreEdgeFD.BusinessLogic.Response.PackageMetadata.PackageMetadataData, StoreEdgeFD","SourceIdentifier":"StoreEdgeFD","SourceAgreements":{"$type":"Microsoft.Marketplace.Storefront.StoreEdgeFD.BusinessLogic.Response.PackageMetadata.SourceAgreements, StoreEdgeFD","AgreementsIdentifier":"StoreEdgeFD","Agreements":[{"$type":"Microsoft.Marketplace.Storefront.StoreEdgeFD.BusinessLogic.Response.PackageManifest.AgreementDetail, StoreEdgeFD","AgreementLabel":"Terms of Transaction","AgreementUrl":"https://aka.ms/microsoft-store-terms-of-transaction"}]},"ServerSupportedVersions":["1.0.0","1.1.0","1.6.0"],"RequiredQueryParameters":["market"],"RequiredPackageMatchFields":["market"]}}
2024-10-24 15:05:25.359 [REPO] Authentication node not found. Assuming authentication type none.
2024-10-24 15:05:25.359 [REPO] User agent caller found: winget-cli
2024-10-24 15:05:25.359 [REPO] Sending http GET request to: https://storeedgefd.dsx.mp.microsoft.com/v9.0/information
2024-10-24 15:05:25.359 [REPO] Http GET request details:
GET / HTTP/1.1

Content-Type: application/json

User-Agent: winget-cli WindowsPackageManager/1.8.1911 DesktopAppInstaller/Microsoft.DesktopAppInstaller v1.23.1911.0




2024-10-24 15:05:25.436 [REPO] Response status: 200
2024-10-24 15:05:25.437 [REPO] Response details:
HTTP/1.1 200 OK

Cache-Control: max-age=0, no-cache, no-store

Connection: keep-alive

Content-Length: 861

Content-Type: application/json; charset=utf-8

Date: Thu, 24 Oct 2024 13:05:25 GMT

Expires: Thu, 24 Oct 2024 13:05:25 GMT

MS-CV: o9JImZEujU2dDq/e.0

Pragma: no-cache

Server: Microsoft-HTTPAPI/2.0

X-OSG-Served-By: Torus-WESTEUROPE_Legacy000M54_1.0.0.0

X-Segment-On: true



{"$type":"Microsoft.Marketplace.Storefront.StoreEdgeFD.BusinessLogic.Response.PackageMetadata.PackageMetadataResponse, StoreEdgeFD","Data":{"$type":"Microsoft.Marketplace.Storefront.StoreEdgeFD.BusinessLogic.Response.PackageMetadata.PackageMetadataData, StoreEdgeFD","SourceIdentifier":"StoreEdgeFD","SourceAgreements":{"$type":"Microsoft.Marketplace.Storefront.StoreEdgeFD.BusinessLogic.Response.PackageMetadata.SourceAgreements, StoreEdgeFD","AgreementsIdentifier":"StoreEdgeFD","Agreements":[{"$type":"Microsoft.Marketplace.Storefront.StoreEdgeFD.BusinessLogic.Response.PackageManifest.AgreementDetail, StoreEdgeFD","AgreementLabel":"Terms of Transaction","AgreementUrl":"https://aka.ms/microsoft-store-terms-of-transaction"}]},"ServerSupportedVersions":["1.0.0","1.1.0","1.6.0"],"RequiredQueryParameters":["market"],"RequiredPackageMatchFields":["market"]}}
2024-10-24 15:05:25.437 [REPO] Authentication node not found. Assuming authentication type none.
2024-10-24 15:05:25.437 [REPO] Adding to aggregated source: winget
2024-10-24 15:05:25.468 [CORE] Examining extension: PFN = Microsoft.Winget.Source_8wekyb3d8bbwe, ID = IndexDB
2024-10-24 15:05:25.469 [CORE] Found matching extension.
2024-10-24 15:05:25.510 [REPO] Opening database for ImmutableRead at 'C:\Program Files\WindowsApps\Microsoft.Winget.Source_2024.1024.1221.1_neutral__8wekyb3d8bbwe\Public\index.db'
2024-10-24 15:05:25.511 [REPO] Opened SQLite Index with version [2.0], last write [2024-10-24 13:20:25.000]
2024-10-24 15:06:38.795 [CLI ] Checking Source agreements for source: msstore
2024-10-24 15:06:38.796 [REPO] Additional sources GP is not enabled.
2024-10-24 15:06:38.796 [CORE] Setting action: Get, Type: Secure, Name: user_sources
2024-10-24 15:06:38.796 [CORE] Setting action: Get, Type: Secure, Name: admin_settings
2024-10-24 15:06:38.796 [CORE] Admin settings was not found
2024-10-24 15:06:38.796 [CORE] Adding chain to pinning configuration [Microsoft Store Source]:

It looks like every time it tries to Opened SQLite Index with version it takes a minute to move on. This happens everytime this is needed:

2024-10-24 15:05:25.511 [REPO] Opened SQLite Index with version [2.0], last write [2024-10-24 13:20:25.000]
2024-10-24 15:06:38.795 [CLI ] Checking Source agreements for source: msstore

2024-10-24 15:07:17.190 [REPO] Opened SQLite Index with version [1.7], last write [2024-10-24 13:20:04.000]
2024-10-24 15:07:53.886 [REPO] Performing search: Query:[none] Include:ProductCode='27a75bf3-be48-5c35-934f-8491cf108abe'

2024-10-24 15:07:53.895 [REPO] Opened SQLite Index with version [1.7], last write [2024-10-24 15:01:54.000]
2024-10-24 15:08:29.451 [REPO] Performing search: Query:[none] Include:ProductCode='27a75bf3-be48-5c35-934f-8491cf108abe'[Exact] Include:NormalizedNameAndPublisher='drawio'+'jgraph'[Exact]

Environment

Windows Package Manager v1.8.1911
Copyright (c) Microsoft Corporation. All rights reserved.

Windows: Windows.Desktop v10.0.22631.4317
System Architecture: X64
Package: Microsoft.DesktopAppInstaller v1.23.1911.0

Winget Directories

Logs %LOCALAPPDATA%\Packages\Microsoft.DesktopAppInstaller_8wekyb3d8bbwe\LocalState\DiagOutputDir
User Settings %LOCALAPPDATA%\Packages\Microsoft.DesktopAppInstaller_8wekyb3d8bbwe\LocalState\settings.json
Portable Links Directory (User) %LOCALAPPDATA%\Microsoft\WinGet\Links
Portable Links Directory (Machine) C:\Program Files\WinGet\Links
Portable Package Root (User) %LOCALAPPDATA%\Microsoft\WinGet\Packages
Portable Package Root C:\Program Files\WinGet\Packages
Portable Package Root (x86) C:\Program Files (x86)\WinGet\Packages
Installer Downloads %USERPROFILE%\Downloads

Links

Privacy Statement https://aka.ms/winget-privacy
License Agreement https://aka.ms/winget-license
Third Party Notices https://aka.ms/winget-3rdPartyNotice
Homepage https://aka.ms/winget
Windows Store Terms https://www.microsoft.com/en-us/storedocs/terms-of-sale

Admin Setting State

LocalManifestFiles Disabled
BypassCertificatePinningForMicrosoftStore Disabled
InstallerHashOverride Disabled
LocalArchiveMalwareScanOverride Disabled
ProxyCommandLineOptions Disabled
DefaultProxy Disabled

Copy link

We've found some similar issues:

If any of the above are duplicates, please consider closing this issue out and adding additional context in the original issue.

Note: You can give me feedback by 👍 or 👎 this comment.

@microsoft-github-policy-service microsoft-github-policy-service bot added the Needs-Triage Issue need to be triaged label Oct 24, 2024
@denelon denelon added Issue-Bug It either shouldn't be doing this or needs an investigation. Area-Performance Issue related to CPU or memory performance Command-List Issue related to WinGet List and removed Needs-Triage Issue need to be triaged labels Oct 24, 2024
@yangskyboxlabs
Copy link

yangskyboxlabs commented Dec 10, 2024

Was seeing the same behaviour, but only on my primary machine. After chatting with a colleague about it, who was not having issues, I decided to purge all WinGet cache files and now performance is back to what is expected.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Area-Performance Issue related to CPU or memory performance Command-List Issue related to WinGet List Issue-Bug It either shouldn't be doing this or needs an investigation.
Projects
None yet
Development

No branches or pull requests

3 participants