AzureStorageExplorer icon indicating copy to clipboard operation
AzureStorageExplorer copied to clipboard

CPU usage hits 100% for long periods, performance drops to a crawl

Open natemcintosh opened this issue 1 year ago • 29 comments

Preflight Checklist

Storage Explorer Version

1.36.2

Regression From

No response

Architecture

x64

Storage Explorer Build Number

20241029.2

Platform

Linux (snap)

OS Version

Ubuntu 22.04.5 LTS x86_64

Bug Description

A few seconds after opening the app, it regularly slows to a crawl. Upon checking htop, it says that it's using 100% CPU. Each button click takes about 20s to complete, and the state to update.

Leaving it running in the background for an hour or so, it seems to get over the 100% CPU usage, and is perfectly usable.

Steps to Reproduce

  1. Launch Storage Explorer

Actual Experience

A few seconds after opening the app, it regularly slows to a crawl. Upon checking htop, it says that it's using 100% CPU. Each button click takes about 20s to complete, and the state to update.

Leaving it running in the background for an hour or so, it seems to get over the 100% CPU usage, and is perfectly usable.

Expected Experience

The app doesn't use 100% CPU and process interactions at a crawl.

Additional Context

No response

natemcintosh avatar Nov 01 '24 18:11 natemcintosh

@natemcintosh How long does it take for the app to launch and load all of its components? Do you have any tabs being restored when you launch? Do you have many storage resources being loaded?

Can you share your app logs from the time the app launches to the time CPU usage goes down to normal levels?

craxal avatar Nov 01 '24 21:11 craxal

Hi @craxal, thanks for getting back to me.

  1. How long does it take for the app to launch and load all of its components? On the occasion it doesn't start running at 100% CPU from the get-go, it usually takes ~20s to fully start up and load components. In the more common case where it does hit 100% CPU immediately after starting up, it regularly take over 2 mins or more.
  2. Do you have any tabs being restored when you launch? No, I almost always close out my tab. At most, there's one tab open to a storage container.
  3. Do you have many storage resources being loaded? It looks like I'm part of 12 Storage Accounts. One has >100 blob containers, but the rest mostly have <10.
  4. Can you share your app logs from the time the app launches to the time CPU usage goes down to normal levels? I've set the log level to Trace. It seems to be behaving well today, so the logs may not be of interest. As soon as I start experiencing it again I will share the logs. Are there any logs in particular you'd like to see? I see a number in the log folder for a given startup.

natemcintosh avatar Nov 04 '24 16:11 natemcintosh

@natemcintosh Nothing specific comes to mind. When the CPU activity starts to spike, take note of what you have in the Explorer tree, what tabs you have open, and what activities are currently running. Also see if you can pinpoint which process or processes are taking so much CPU power. Storage Explorer manages a lot of child processes, so if we can narrow down which processes are problematic, that can help. If you can get the PIDs, we can cross reference that with the log files, which contain the PIDs of the processes they are logs for.

craxal avatar Nov 04 '24 17:11 craxal

Hi @craxal,

It happened when I started it up this morning.

  • In the Explorer tree, I have 3 quick access storage containers, two accounts (neither of which are expanded downwards).
  • No tabs are open on startup.
  • What do you mean by activities?
  • The process name is /snap/storage-explorer/65/StorageExplorerExe --no-sandbox, PID is 7318. I've included a screenshot of the htop print out.
  • It took just under 30 mins for the issue to resolve, and behavior to go back to normal.
  • I have saved all the logs. Some of them have some slightly sensitive information, so I would prefer not to post them all here. Which ones would be most useful to see?

Image

natemcintosh avatar Nov 06 '24 15:11 natemcintosh

@natemcintosh

What do you mean by activities?

There's a panel at the bottom of the app titled "Activities". That was in case the slow down occurred when performing certain operations. But since it happens at startup, we probably don't need to worry about that.

I have saved all the logs. Some of them have some slightly sensitive information, so I would prefer not to post them all here. Which ones would be most useful to see?

If the process with PID 7318 is the problematic one, we'll want to look at the log file that contains 7318 in its name. What sensitive information are you concerned about? Perhaps file paths? We automatically redact any credentials that may appear. If you don't want to share here, you can also send a copy to sehelp at microsoft dot com.

One thing that might help is to make sure your system is up to date. We had another Linux issue that seemed to go away after their snap components were updated.

craxal avatar Nov 06 '24 17:11 craxal

Hi @craxal

Grepping through the logs, it looks like 7318 only shows up in the main log. I'll paste its contents at the bottom.

I'll perform a sudo apt update && sudo apt full-upgrade -y, and then a sudo snap refresh storage-explorer. I usually perform the apt update ... at least once a week. I have also tried uninstalling and then re-installing storage explorer (via snap), which did not resolve the issue.

[2024-11-06T13:33:18.111Z] (main:7318) <NONE> Log level: trace
[2024-11-06T13:33:18.111Z] (main:7318) <INFO> Startup app state:  {
    lastWindowState: {
      rect: { x: 462, y: 236, width: 1000, height: 768 },
      maximized: true
    },
    disableGpu: false,
    dialogAutoResponse: {}
  }
[2024-11-06T13:33:24.768Z] (main:7318) <INFO> No proxy environment variables exist on startup
[2024-11-06T13:33:24.769Z] (main:7318) <INFO> Applying proxy configuration
[2024-11-06T13:33:24.769Z] (main:7318) <INFO> Proxy configuration source set to: none
[2024-11-06T13:33:24.769Z] (main:7318) <INFO> Proxy configuration set to: undefined
[2024-11-06T13:33:24.771Z] (main:7318) <INFO> Initializing user accounts manager account store...
[2024-11-06T13:33:24.774Z] (main:7318) <VERB> Loading 'StorageExplorer.Resources'
[2024-11-06T13:33:24.774Z] (main:7318) <VERB> Loaded 'StorageExplorer.Resources' via function
[2024-11-06T13:33:24.775Z] (main:7318) <VERB> Loading 'UserConfiguration'
[2024-11-06T13:33:24.775Z] (main:7318) <VERB> Loaded 'UserConfiguration' via function
[2024-11-06T13:33:24.776Z] (main:7318) <DBUG> Resolved resource module './resources/Activities': '/snap/storage-explorer/65/resources/app/resources/Activities.json'
[2024-11-06T13:33:24.776Z] (main:7318) <DBUG> Resolved resource module './resources/Azure': '/snap/storage-explorer/65/resources/app/resources/Azure.json'
[2024-11-06T13:33:24.776Z] (main:7318) <DBUG> Resolved resource module './resources/Dialogs': '/snap/storage-explorer/65/resources/app/resources/Dialogs.json'
[2024-11-06T13:33:24.776Z] (main:7318) <DBUG> Resolved resource module './resources/ExtensionManager': '/snap/storage-explorer/65/resources/app/resources/ExtensionManager.json'
[2024-11-06T13:33:24.776Z] (main:7318) <DBUG> Resolved resource module './resources/Host': '/snap/storage-explorer/65/resources/app/resources/Host.json'
[2024-11-06T13:33:24.776Z] (main:7318) <DBUG> Resolved resource module './resources/Shell': '/snap/storage-explorer/65/resources/app/resources/Shell.json'
[2024-11-06T13:33:25.013Z] (main:7318) <DBUG> Provider proxy to Electron renderer created
[2024-11-06T13:33:25.812Z] (main:7318) <VERB> Loading 'Environment.Dialogs'
[2024-11-06T13:33:25.813Z] (main:7318) <VERB> Loaded 'Environment.Dialogs' via function
[2024-11-06T13:33:25.844Z] (main:7318) <VERB> app-launch-complete [
    {
      name: 'Shell',
      source: { module: '' },
      operations: [ 'Shell.shellInfo' ]
    },
    {
      name: 'VerticalToolbarProvider',
      source: { module: '' },
      operations: [
        'StorageExplorer.VerticalToolbar.registerButtons',
        'StorageExplorer.VerticalToolbar.openOrExecuteButton'
      ]
    },
    {
      name: 'StorageExplorer.PanelManager',
      source: { module: '' },
      operations: [
        'StorageExplorer.PanelManager.registerPanels',
        'StorageExplorer.PanelManager.openPanel',
        'StorageExplorer.PanelManager.updatePanel',
        'StorageExplorer.PanelManager.showPanel',
        'StorageExplorer.PanelManager.closePanel',
        'StorageExplorer.PanelManager.openPanelDevTools',
        'StorageExplorer.PanelManager.getRegisteredPanels',
        'StorageExplorer.PanelManager.getPanelProps'
      ]
    },
    {
      name: 'StorageExplorer.MenuManager',
      source: { module: '' },
      operations: [
        'StorageExplorer.MenuManager.registerMenuItem',
        'StorageExplorer.MenuManager.reloadMenus'
      ]
    },
    {
      name: 'SslCertificateManagerProvider',
      source: { module: '' },
      operations: [ 'SslCertificateManager.getSslSettings' ]
    },
    {
      name: 'Environment.Editors',
      source: { module: '' },
      operations: [
        'Environment.Theming.onThemeChanged',
        'Environment.Zoom.onZoomChanged'
      ]
    },
    {
      name: 'Activities.Response',
      source: { module: '' },
      operations: [ 'Activities.handleError' ]
    },
    {
      name: 'NotificationBarProvider',
      source: { module: '' },
      operations: [
        'StorageExplorer.NotificationBar.showSingleLink',
        'StorageExplorer.NotificationBar.ShowMultiLink',
        'StorageExplorer.NotificationBar.show'
      ]
    },
    {
      name: 'MenuManagerProvider',
      source: { module: '' },
      operations: [ 'MenuManager.showMenu' ]
    },
    {
      name: 'WatchFileProvider',
      source: { module: '' },
      operations: [
        'StorageExplorer.Blob.Files.WatchFileChangeAzCopy',
        'StorageExplorer.FileShare.Files.WatchFileChangeAzCopy'
      ]
    },
    {
      name: 'StorageApiSettingManagerProvider',
      source: { module: '' },
      operations: [
        'StorageApiSettingManager.getStorageApiSetting',
        'StorageApiSettingManager.getAzureStackApiVersion',
        'StorageApiSettingManager.isTargetingAzureStack',
        'StorageApiSettingManager.peekAzureStackApiVersion'
      ]
    },
    {
      name: 'ConfidentialPersistentStorage',
      source: { module: '' },
      operations: [
        'PersistentStorage.Confidential.getItem',
        'PersistentStorage.Confidential.setItem',
        'PersistentStorage.Confidential.delItemKey'
      ]
    },
    {
      name: 'PersistentStorage',
      source: { module: '' },
      operations: [
        'PersistentStorage.Local.getItem',
        'PersistentStorage.Local.setItem',
        'PersistentStorage.Local.delItemKey',
        'PersistentStorage.Session.getItem',
        'PersistentStorage.Session.setItem',
        'PersistentStorage.Session.delItemKey'
      ]
    },
    {
      name: 'PersistentStorage.CustomConnections',
      source: { module: '' },
      operations: [
        'PersistentStorage.CustomConnections.getCustomConnections',
        'PersistentStorage.CustomConnections.getAllCustomConnections',
        'PersistentStorage.CustomConnections.addCustomConnection',
        'PersistentStorage.CustomConnections.deleteCustomConnection',
        'PersistentStorage.CustomConnections.renameCustomConnection'
      ]
    },
    {
      name: 'Azure.ConnectProvider',
      source: { module: '' },
      operations: [
        'Azure.Connect.openConnect2Dialog',
        'Azure.Connect.copyCodeAndOpenUrl',
        'Azure.Connect.openAzureAdADeepLinkDialog'
      ]
    },
    {
      name: 'StorageExplorer.AppReset',
      source: { module: '' },
      operations: [
        'StorageExplorer.AppReset.registerForReset',
        'StorageExplorer.AppReset.resetWithUI'
      ]
    },
    {
      name: 'StorageExplorer.NodeProducerProvider',
      source: { module: '' },
      operations: [
        'NodeProducers.registerProducers',
        'NodeProducers.getBoundArguments',
        'NodeProducers.getChildren',
        'NodeProducers.getSearchTypes',
        'NodeProducers.getDependentNodeTypes',
        'NodeProducers.getNodeTypes'
      ]
    },
    {
      name: 'DaytonaTabMessenger',
      source: { module: '' },
      operations: [ 'DaytonaTabMessenger.broadcastEvent' ]
    },
    {
      name: 'Testing.Errors.InProc',
      source: { module: '' },
      operations: [
        'Testing.Errors.InProc.throwPrimitive',
        'Testing.Errors.InProc.throwString',
        'Testing.Errors.InProc.throwObject',
        'Testing.Errors.InProc.throwError',
        'Testing.Errors.InProc.throwSystemError'
      ]
    }
  ]
[2024-11-06T13:33:25.853Z] (main:7318) <WARN> An implementation of 'Environment.Theming.onThemeChanged' has already been registered by another provider, this most recent implementation will be ignored unless 'Environment.Theming.onThemeChanged is used as an event'.
[2024-11-06T13:33:25.853Z] (main:7318) <WARN> An implementation of 'Environment.Zoom.onZoomChanged' has already been registered by another provider, this most recent implementation will be ignored unless 'Environment.Zoom.onZoomChanged is used as an event'.
[2024-11-06T13:33:25.855Z] (main:7318) <DBUG> Constructed NodeProcessProviderProxy for provider 'Testing.Errors.ChildProc'
[2024-11-06T13:33:25.855Z] (main:7318) <INFO> Initializing extension manager...
[2024-11-06T13:33:25.855Z] (main:7318) <DBUG> Looking for extensions to open or debug.
[2024-11-06T13:33:25.855Z] (main:7318) <INFO> Done looking for extensions to open or debug.
[2024-11-06T13:33:25.856Z] (main:7318) <VERB> Getting all installed exensions results: Installed IDs: [] All: [] Non-corrrupted: []
[2024-11-06T13:33:25.991Z] (main:7318) <INFO> Loading 17 extensions
[2024-11-06T13:33:25.991Z] (main:7318) <DBUG> Loading extensions: [
    {
      id: 'app',
      displayName: undefined,
      version: '1.36.2',
      intVersion: undefined,
      publisher: undefined,
      description: undefined,
      logoPath: '',
      feedbackUrl: undefined,
      currentPath: '/snap/storage-explorer/65/resources/app',
      enabled: true,
      compatible: true,
      updateAvailable: false,
      needsRestart: false,
      isDebug: false
    },
    {
      id: 'account-panel',
      displayName: undefined,
      version: '5.4.0',
      intVersion: undefined,
      publisher: undefined,
      description: '',
      logoPath: '',
      feedbackUrl: undefined,
      currentPath: '/snap/storage-explorer/65/resources/app/node_modules/@storage-explorer/account-panel',
      enabled: true,
      compatible: true,
      updateAvailable: false,
      needsRestart: false,
      isDebug: false
    },
    {
      id: 'activity-log',
      displayName: undefined,
      version: '1.1.0',
      intVersion: undefined,
      publisher: undefined,
      description: 'A Storage Explorer extension providing activity log functionality',
      logoPath: '',
      feedbackUrl: undefined,
      currentPath: '/snap/storage-explorer/65/resources/app/node_modules/@storage-explorer/activity-log',
      enabled: true,
      compatible: true,
      updateAvailable: false,
      needsRestart: false,
      isDebug: false
    },
    {
      id: 'adls2-extension',
      displayName: undefined,
      version: '1.9.7',
      intVersion: undefined,
      publisher: undefined,
      description: 'A temporary Storage Explorer extension adding support for ADLS Gen 2 resources.',
      logoPath: '',
      feedbackUrl: undefined,
      currentPath: '/snap/storage-explorer/65/resources/app/node_modules/@storage-explorer/adls2-extension',
      enabled: true,
      compatible: true,
      updateAvailable: false,
      needsRestart: false,
      isDebug: false
    },
    {
      id: 'azcopy-extension',
      displayName: undefined,
      version: '1.7.3',
      intVersion: undefined,
      publisher: undefined,
      description: '',
      logoPath: '',
      feedbackUrl: undefined,
      currentPath: '/snap/storage-explorer/65/resources/app/node_modules/@storage-explorer/azcopy-extension',
      enabled: true,
      compatible: true,
      updateAvailable: false,
      needsRestart: false,
      isDebug: false
    },
    {
      id: 'blob-extension',
      displayName: undefined,
      version: '1.14.2',
      intVersion: undefined,
      publisher: undefined,
      description: 'A Storage Explorer extension adding support for Azure Blob Storage.',
      logoPath: '',
      feedbackUrl: undefined,
      currentPath: '/snap/storage-explorer/65/resources/app/node_modules/@storage-explorer/blob-extension',
      enabled: true,
      compatible: true,
      updateAvailable: false,
      needsRestart: false,
      isDebug: false
    },
    {
      id: 'configuration-panel',
      displayName: undefined,
      version: '1.2.0',
      intVersion: undefined,
      publisher: undefined,
      description: 'A Storage Explorer extension that defines the settings panel UI elements',
      logoPath: '',
      feedbackUrl: undefined,
      currentPath: '/snap/storage-explorer/65/resources/app/node_modules/@storage-explorer/configuration-panel',
      enabled: true,
      compatible: true,
      updateAvailable: false,
      needsRestart: false,
      isDebug: false
    },
    {
      id: 'explorer-panel',
      displayName: 'Explorer Panel',
      version: '1.3.12',
      intVersion: undefined,
      publisher: undefined,
      description: '',
      logoPath: '',
      feedbackUrl: undefined,
      currentPath: '/snap/storage-explorer/65/resources/app/node_modules/@storage-explorer/explorer-panel',
      enabled: true,
      compatible: true,
      updateAvailable: false,
      needsRestart: false,
      isDebug: false
    },
    {
      id: 'file-extension',
      displayName: undefined,
      version: '1.8.6-rc.1',
      intVersion: undefined,
      publisher: undefined,
      description: '',
      logoPath: '',
      feedbackUrl: undefined,
      currentPath: '/snap/storage-explorer/65/resources/app/node_modules/@storage-explorer/file-extension',
      enabled: true,
      compatible: true,
      updateAvailable: false,
      needsRestart: false,
      isDebug: false
    },
    {
      id: 'file-preview',
      displayName: undefined,
      version: '0.6.19',
      intVersion: undefined,
      publisher: undefined,
      description: 'An extension that supports previewing blob data in Storage Explorer',
      logoPath: '',
      feedbackUrl: undefined,
      currentPath: '/snap/storage-explorer/65/resources/app/node_modules/@storage-explorer/file-preview',
      enabled: true,
      compatible: true,
      updateAvailable: false,
      needsRestart: false,
      isDebug: false
    },
    {
      id: 'managed-disks-extension',
      displayName: undefined,
      version: '1.7.5',
      intVersion: undefined,
      publisher: undefined,
      description: '',
      logoPath: '',
      feedbackUrl: undefined,
      currentPath: '/snap/storage-explorer/65/resources/app/node_modules/@storage-explorer/managed-disks-extension',
      enabled: true,
      compatible: true,
      updateAvailable: false,
      needsRestart: false,
      isDebug: false
    },
    {
      id: 'markdown-panel',
      displayName: undefined,
      version: '1.1.1',
      intVersion: undefined,
      publisher: undefined,
      description: '',
      logoPath: '',
      feedbackUrl: undefined,
      currentPath: '/snap/storage-explorer/65/resources/app/node_modules/@storage-explorer/markdown-panel',
      enabled: true,
      compatible: true,
      updateAvailable: false,
      needsRestart: false,
      isDebug: false
    },
    {
      id: 'queue-extension',
      displayName: undefined,
      version: '1.5.2',
      intVersion: undefined,
      publisher: undefined,
      description: '',
      logoPath: '',
      feedbackUrl: undefined,
      currentPath: '/snap/storage-explorer/65/resources/app/node_modules/@storage-explorer/queue-extension',
      enabled: true,
      compatible: true,
      updateAvailable: false,
      needsRestart: false,
      isDebug: false
    },
    {
      id: 'start-panel',
      displayName: undefined,
      version: '1.0.9',
      intVersion: undefined,
      publisher: undefined,
      description: '',
      logoPath: '',
      feedbackUrl: undefined,
      currentPath: '/snap/storage-explorer/65/resources/app/node_modules/@storage-explorer/start-panel',
      enabled: true,
      compatible: true,
      updateAvailable: false,
      needsRestart: false,
      isDebug: false
    },
    {
      id: 'storage-account-extension',
      displayName: undefined,
      version: '3.2.7',
      intVersion: undefined,
      publisher: undefined,
      description: '',
      logoPath: '',
      feedbackUrl: undefined,
      currentPath: '/snap/storage-explorer/65/resources/app/node_modules/@storage-explorer/storage-account-extension',
      enabled: true,
      compatible: true,
      updateAvailable: false,
      needsRestart: false,
      isDebug: false
    },
    {
      id: 'table-extension',
      displayName: undefined,
      version: '1.4.1',
      intVersion: undefined,
      publisher: undefined,
      description: '',
      logoPath: '',
      feedbackUrl: undefined,
      currentPath: '/snap/storage-explorer/65/resources/app/node_modules/@storage-explorer/table-extension',
      enabled: true,
      compatible: true,
      updateAvailable: false,
      needsRestart: false,
      isDebug: false
    },
    {
      id: 'icon-explorer',
      displayName: undefined,
      version: '1.0.1',
      intVersion: undefined,
      publisher: undefined,
      description: '',
      logoPath: '',
      feedbackUrl: undefined,
      currentPath: '/snap/storage-explorer/65/resources/app/node_modules/@storage-explorer/icon-explorer',
      enabled: true,
      compatible: true,
      updateAvailable: false,
      needsRestart: false,
      isDebug: false
    }
  ]
[2024-11-06T13:33:25.998Z] (main:7318) <VERB> Loading 'StorageExplorer.Icons'
[2024-11-06T13:33:26.000Z] (main:7318) <VERB> Loaded 'StorageExplorer.Icons' via function
[2024-11-06T13:33:26.000Z] (main:7318) <DBUG> Constructed NodeProcessProviderProxy for provider '@storage-explorer/table-extension'
[2024-11-06T13:33:26.001Z] (main:7318) <VERB> Loading 'WorkerManagerProvider'
[2024-11-06T13:33:26.002Z] (main:7318) <DBUG> Constructed NodeProcessProviderProxy for provider 'JobHandlerProvider_quick_0'
[2024-11-06T13:33:26.002Z] (main:7318) <DBUG> Constructed NodeProcessProviderProxy for provider 'JobHandlerProvider_quick_1'
[2024-11-06T13:33:26.002Z] (main:7318) <DBUG> Constructed NodeProcessProviderProxy for provider 'JobHandlerProvider_quick_2'
[2024-11-06T13:33:26.002Z] (main:7318) <DBUG> Constructed NodeProcessProviderProxy for provider 'JobHandlerProvider_quick_3'
[2024-11-06T13:33:26.002Z] (main:7318) <DBUG> Constructed NodeProcessProviderProxy for provider 'JobHandlerProvider_quick_4'
[2024-11-06T13:33:26.002Z] (main:7318) <DBUG> Constructed NodeProcessProviderProxy for provider 'JobHandlerProvider_large_0'
[2024-11-06T13:33:26.002Z] (main:7318) <DBUG> Constructed NodeProcessProviderProxy for provider 'JobHandlerProvider_azcopy-copy_0'
[2024-11-06T13:33:26.002Z] (main:7318) <DBUG> Constructed NodeProcessProviderProxy for provider 'JobHandlerProvider_networkRequestHeavy_0'
[2024-11-06T13:33:26.002Z] (main:7318) <DBUG> Constructed NodeProcessProviderProxy for provider 'JobHandlerProvider_networkRequestHeavy_1'
[2024-11-06T13:33:26.002Z] (main:7318) <VERB> Loaded 'WorkerManagerProvider' via function
[2024-11-06T13:33:26.002Z] (main:7318) <VERB> Loading 'AppConfiguration'
[2024-11-06T13:33:26.007Z] (main:7318) <VERB> Loaded 'AppConfiguration' via function
[2024-11-06T13:33:26.008Z] (main:7318) <VERB> Loading 'Environment.ThemingProvider'
[2024-11-06T13:33:26.008Z] (main:7318) <VERB> Loaded 'Environment.ThemingProvider' via function
[2024-11-06T13:33:26.112Z] (main:7318) <DBUG> Constructed NodeProcessProviderProxy for provider '@storage-explorer/storage-account-extension'
[2024-11-06T13:33:26.116Z] (main:7318) <VERB> app-startup-complete
[2024-11-06T13:33:26.122Z] (main:7318) <DBUG> Constructed NodeProcessProviderProxy for provider '@storage-explorer/start-panel'
[2024-11-06T13:33:26.122Z] (main:7318) <DBUG> Constructed NodeProcessProviderProxy for provider '@storage-explorer/queue-extension'
[2024-11-06T13:33:26.124Z] (main:7318) <DBUG> Constructed NodeProcessProviderProxy for provider '@storage-explorer/markdown-panel'
[2024-11-06T13:33:26.126Z] (main:7318) <DBUG> Constructed NodeProcessProviderProxy for provider '@storage-explorer/managed-disks-extension'
[2024-11-06T13:33:26.127Z] (main:7318) <DBUG> Constructed NodeProcessProviderProxy for provider '@storage-explorer/file-preview'
[2024-11-06T13:33:26.128Z] (main:7318) <DBUG> Constructed NodeProcessProviderProxy for provider '@storage-explorer/file-extension'
[2024-11-06T13:33:26.138Z] (main:7318) <DBUG> Resolved resource module './resources/ExplorerPanel': '/snap/storage-explorer/65/resources/app/node_modules/@storage-explorer/explorer-panel/resources/ExplorerPanel.json'
[2024-11-06T13:33:26.143Z] (main:7318) <DBUG> Constructed NodeProcessProviderProxy for provider '@storage-explorer/configuration-panel'
[2024-11-06T13:33:26.146Z] (main:7318) <DBUG> Constructed NodeProcessProviderProxy for provider '@storage-explorer/blob-extension'
[2024-11-06T13:33:26.147Z] (main:7318) <DBUG> Constructed NodeProcessProviderProxy for provider '@storage-explorer/azcopy-extension'
[2024-11-06T13:33:26.147Z] (main:7318) <DBUG> Constructed NodeProcessProviderProxy for provider '@storage-explorer/adls2-extension'
[2024-11-06T13:33:26.147Z] (main:7318) <DBUG> Constructed NodeProcessProviderProxy for provider '@storage-explorer/activity-log'
[2024-11-06T13:33:26.166Z] (main:7318) <DBUG> Resolved resource module './resources/AccountPanel': '/snap/storage-explorer/65/resources/app/node_modules/@storage-explorer/account-panel/resources/AccountPanel.json'
[2024-11-06T13:33:26.170Z] (main:7318) <DBUG> Resource namespace 'Activities' was preloaded.
[2024-11-06T13:33:26.170Z] (main:7318) <DBUG> Resource namespace 'Azure.Resources' was preloaded.
[2024-11-06T13:33:26.170Z] (main:7318) <DBUG> Resource namespace 'Dialogs' was preloaded.
[2024-11-06T13:33:26.170Z] (main:7318) <DBUG> Resource namespace 'ExtensionManager' was preloaded.
[2024-11-06T13:33:26.170Z] (main:7318) <DBUG> Resource namespace 'CloudExplorer.Resources' was preloaded.
[2024-11-06T13:33:26.170Z] (main:7318) <DBUG> Resource namespace 'Shell' was preloaded.
[2024-11-06T13:33:26.170Z] (main:7318) <INFO> Extensions loaded
[2024-11-06T13:33:26.179Z] (main:7318) <VERB> Loading 'NetProvider'
[2024-11-06T13:33:26.180Z] (main:7318) <VERB> Loading 'ProxyProvider'
[2024-11-06T13:33:26.180Z] (main:7318) <VERB> Loaded 'ProxyProvider' via function
[2024-11-06T13:33:26.181Z] (main:7318) <VERB> Loaded 'NetProvider' via function
[2024-11-06T13:33:26.181Z] (main:7318) <DBUG> Launching Node process for provider '@storage-explorer/adls2-extension'
[2024-11-06T13:33:26.181Z] (main:7318) <DBUG> Launching Node process for provider '@storage-explorer/blob-extension'
[2024-11-06T13:33:26.181Z] (main:7318) <DBUG> Launching Node process for provider '@storage-explorer/file-extension'
[2024-11-06T13:33:26.181Z] (main:7318) <DBUG> Launching Node process for provider '@storage-explorer/queue-extension'
[2024-11-06T13:33:26.181Z] (main:7318) <DBUG> Launching Node process for provider '@storage-explorer/storage-account-extension'
[2024-11-06T13:33:26.181Z] (main:7318) <DBUG> Launching Node process for provider '@storage-explorer/table-extension'
[2024-11-06T13:33:26.182Z] (main:7318) <VERB> Getting all installed exensions results: Installed IDs: [] All: [] Non-corrrupted: []
[2024-11-06T13:33:26.182Z] (main:7318) <VERB> Loading 'Telemetry'
[2024-11-06T13:33:26.533Z] (main:7318) <VERB> Loaded 'Telemetry' via function
[2024-11-06T13:33:26.569Z] (main:7318) <VERB> Loading 'ShellProvider'
[2024-11-06T13:33:26.596Z] (main:7318) <VERB> Loaded 'ShellProvider' via function
[2024-11-06T13:33:26.596Z] (main:7318) <VERB> Loading 'StorageExplorer.Updates'
[2024-11-06T13:33:26.603Z] (main:7318) <VERB> Loaded 'StorageExplorer.Updates' via function
[2024-11-06T13:33:26.605Z] (main:7318) <VERB> Loading 'AzureSubscriptions'
[2024-11-06T13:33:26.609Z] (main:7318) <VERB> Loaded 'AzureSubscriptions' via function
[2024-11-06T13:33:26.609Z] (main:7318) <VERB> Loading 'AutoSet'
[2024-11-06T13:33:26.610Z] (main:7318) <VERB> Loaded 'AutoSet' via function
[2024-11-06T13:33:26.610Z] (main:7318) <DBUG> Using ssl settings {"sslCertsDir":"/home/ute2/snap/storage-explorer/65/.config/StorageExplorer/certs/","ignoreCerts":false} for provider '@storage-explorer/adls2-extension'
[2024-11-06T13:33:26.610Z] (main:7318) <DBUG> Starting node process for provider '@storage-explorer/adls2-extension'
[2024-11-06T13:33:26.620Z] (main:7318) <DBUG> Launched Node process 7590 for module 'NodeProcessHostProxy'
[2024-11-06T13:33:26.621Z] (main:7318) <DBUG> Using ssl settings {"sslCertsDir":"/home/ute2/snap/storage-explorer/65/.config/StorageExplorer/certs/","ignoreCerts":false} for provider '@storage-explorer/blob-extension'
[2024-11-06T13:33:26.621Z] (main:7318) <DBUG> Starting node process for provider '@storage-explorer/blob-extension'
[2024-11-06T13:33:26.631Z] (main:7318) <DBUG> Launched Node process 7591 for module 'NodeProcessHostProxy'
[2024-11-06T13:33:26.632Z] (main:7318) <DBUG> Using ssl settings {"sslCertsDir":"/home/ute2/snap/storage-explorer/65/.config/StorageExplorer/certs/","ignoreCerts":false} for provider '@storage-explorer/file-extension'
[2024-11-06T13:33:26.632Z] (main:7318) <DBUG> Starting node process for provider '@storage-explorer/file-extension'
[2024-11-06T13:33:26.644Z] (main:7318) <DBUG> Launched Node process 7592 for module 'NodeProcessHostProxy'
[2024-11-06T13:33:26.644Z] (main:7318) <DBUG> Using ssl settings {"sslCertsDir":"/home/ute2/snap/storage-explorer/65/.config/StorageExplorer/certs/","ignoreCerts":false} for provider '@storage-explorer/queue-extension'
[2024-11-06T13:33:26.644Z] (main:7318) <DBUG> Starting node process for provider '@storage-explorer/queue-extension'
[2024-11-06T13:33:26.667Z] (main:7318) <DBUG> Launched Node process 7593 for module 'NodeProcessHostProxy'
[2024-11-06T13:33:26.667Z] (main:7318) <DBUG> Using ssl settings {"sslCertsDir":"/home/ute2/snap/storage-explorer/65/.config/StorageExplorer/certs/","ignoreCerts":false} for provider '@storage-explorer/storage-account-extension'
[2024-11-06T13:33:26.668Z] (main:7318) <DBUG> Starting node process for provider '@storage-explorer/storage-account-extension'
[2024-11-06T13:33:26.704Z] (main:7318) <DBUG> Launched Node process 7612 for module 'NodeProcessHostProxy'
[2024-11-06T13:33:26.706Z] (main:7318) <DBUG> Using ssl settings {"sslCertsDir":"/home/ute2/snap/storage-explorer/65/.config/StorageExplorer/certs/","ignoreCerts":false} for provider '@storage-explorer/table-extension'
[2024-11-06T13:33:26.706Z] (main:7318) <DBUG> Starting node process for provider '@storage-explorer/table-extension'
[2024-11-06T13:33:26.747Z] (main:7318) <DBUG> Launched Node process 7616 for module 'NodeProcessHostProxy'
[2024-11-06T13:33:26.908Z] (main:7318) <DBUG> Node process 7592 ack received for module 'NodeProcessHostProxy'
[2024-11-06T13:33:26.908Z] (main:7318) <DBUG> Started node process 7592 for provider '@storage-explorer/file-extension'
[2024-11-06T13:33:26.908Z] (main:7318) <DBUG> Launched Node process 7592 for provider '@storage-explorer/file-extension'
[2024-11-06T13:33:26.923Z] (main:7318) <DBUG> Node process 7590 ack received for module 'NodeProcessHostProxy'
[2024-11-06T13:33:26.923Z] (main:7318) <DBUG> Started node process 7590 for provider '@storage-explorer/adls2-extension'
[2024-11-06T13:33:26.923Z] (main:7318) <DBUG> Launched Node process 7590 for provider '@storage-explorer/adls2-extension'
[2024-11-06T13:33:27.055Z] (main:7318) <DBUG> Node process 7591 ack received for module 'NodeProcessHostProxy'
[2024-11-06T13:33:27.056Z] (main:7318) <DBUG> Started node process 7591 for provider '@storage-explorer/blob-extension'
[2024-11-06T13:33:27.056Z] (main:7318) <DBUG> Launched Node process 7591 for provider '@storage-explorer/blob-extension'
[2024-11-06T13:33:27.125Z] (main:7318) <DBUG> Sending auto-set telemetry: {}
[2024-11-06T13:33:29.328Z] (main:7318) <DBUG> Node process 7593 ack received for module 'NodeProcessHostProxy'
[2024-11-06T13:33:29.328Z] (main:7318) <DBUG> Started node process 7593 for provider '@storage-explorer/queue-extension'
[2024-11-06T13:33:29.328Z] (main:7318) <DBUG> Launched Node process 7593 for provider '@storage-explorer/queue-extension'
[2024-11-06T13:33:29.334Z] (main:7318) <DBUG> Node process 7616 ack received for module 'NodeProcessHostProxy'
[2024-11-06T13:33:29.334Z] (main:7318) <DBUG> Started node process 7616 for provider '@storage-explorer/table-extension'
[2024-11-06T13:33:29.334Z] (main:7318) <DBUG> Launched Node process 7616 for provider '@storage-explorer/table-extension'
[2024-11-06T13:33:29.334Z] (main:7318) <DBUG> Node process 7612 ack received for module 'NodeProcessHostProxy'
[2024-11-06T13:33:29.335Z] (main:7318) <DBUG> Started node process 7612 for provider '@storage-explorer/storage-account-extension'
[2024-11-06T13:33:29.335Z] (main:7318) <DBUG> Launched Node process 7612 for provider '@storage-explorer/storage-account-extension'
[2024-11-06T13:33:35.543Z] (main:7318) <INFO> SubscriptionCache found V2 cache, using it.
[2024-11-06T13:33:35.543Z] (main:7318) <VERB> Loading 'Azure.UserAccounts'
[2024-11-06T13:33:35.543Z] (main:7318) <VERB> Loaded 'Azure.UserAccounts' via function
[2024-11-06T13:33:37.556Z] (main:7318) <DBUG> Resolved resource module 'resources/ActivityLog': '/snap/storage-explorer/65/resources/app/node_modules/@storage-explorer/activity-log/resources/ActivityLog.json'
[2024-11-06T13:33:43.582Z] (main:7318) <DBUG> IdentityUserAccountsManager._initAccountStore took 18812ms, retries remaining: 5
[2024-11-06T13:33:43.582Z] (main:7318) <INFO> Initializing user accounts manager error store...
[2024-11-06T13:33:47.597Z] (main:7318) <DBUG> Resolved resource module './resources/StorageAccountProducer': '/snap/storage-explorer/65/resources/app/node_modules/@storage-explorer/storage-account-extension/resources/StorageAccountProducer.json'
[2024-11-06T13:33:47.599Z] (main:7318) <DBUG> Resolved resource module 'resources/BlobNodeProducer': '/snap/storage-explorer/65/resources/app/node_modules/@storage-explorer/blob-extension/resources/BlobNodeProducer.json'
[2024-11-06T13:33:47.599Z] (main:7318) <DBUG> Resolved resource module 'resources/FileShareProducers': '/snap/storage-explorer/65/resources/app/node_modules/@storage-explorer/file-extension/resources/FileShareProducers.json'
[2024-11-06T13:33:47.600Z] (main:7318) <DBUG> Resolved resource module 'resources/Queues': '/snap/storage-explorer/65/resources/app/node_modules/@storage-explorer/queue-extension/resources/Queues.json'
[2024-11-06T13:33:47.601Z] (main:7318) <DBUG> Resolved resource module 'resources/TableNodes': '/snap/storage-explorer/65/resources/app/node_modules/@storage-explorer/table-extension/resources/TableNodes.json'
[2024-11-06T13:33:47.601Z] (main:7318) <DBUG> Resolved resource module './resources/DiskNodeProducer': '/snap/storage-explorer/65/resources/app/node_modules/@storage-explorer/managed-disks-extension/resources/DiskNodeProducer.json'
[2024-11-06T13:33:47.605Z] (main:7318) <VERB> Loading 'StorageExplorer.TopLevelNodes'
[2024-11-06T13:33:47.609Z] (main:7318) <VERB> Loaded 'StorageExplorer.TopLevelNodes' via function
[2024-11-06T13:33:47.610Z] (main:7318) <INFO> AzureSubscriptionsManager checking for new accounts...
[2024-11-06T13:33:53.679Z] (main:7318) <DBUG> IdentityUserAccountsManager._initErrorStore took 10097ms
[2024-11-06T13:33:53.679Z] (main:7318) <INFO> Initializing user accounts manager AAD providers...
[2024-11-06T13:33:59.708Z] (main:7318) <DBUG> IdentityUserAccountsManager._initAadProviders took 6029ms
[2024-11-06T13:34:19.812Z] (main:7318) <VERB> Loading 'ConfidentialStorage'
[2024-11-06T13:34:19.812Z] (main:7318) <VERB> Loaded 'ConfidentialStorage' via function
[2024-11-06T13:34:23.823Z] (main:7318) <DBUG> Resolved resource module './resources/StorageAccountActions': '/snap/storage-explorer/65/resources/app/node_modules/@storage-explorer/storage-account-extension/resources/StorageAccountActions.json'
[2024-11-06T13:34:23.823Z] (main:7318) <DBUG> Resolved resource module './resources/StorageAccountActions': '/snap/storage-explorer/65/resources/app/node_modules/@storage-explorer/storage-account-extension/resources/StorageAccountActions.json'
[2024-11-06T13:34:23.823Z] (main:7318) <DBUG> Resolved resource module './resources/StorageAccountActions': '/snap/storage-explorer/65/resources/app/node_modules/@storage-explorer/storage-account-extension/resources/StorageAccountActions.json'
[2024-11-06T13:34:27.831Z] (main:7318) <DBUG> Resolved resource module 'resources/BlobActions': '/snap/storage-explorer/65/resources/app/node_modules/@storage-explorer/blob-extension/resources/BlobActions.json'
[2024-11-06T13:34:27.831Z] (main:7318) <DBUG> Resolved resource module 'resources/BlobContainerActions': '/snap/storage-explorer/65/resources/app/node_modules/@storage-explorer/blob-extension/resources/BlobContainerActions.json'
[2024-11-06T13:34:27.832Z] (main:7318) <DBUG> Resolved resource module 'resources/BlobServiceActions': '/snap/storage-explorer/65/resources/app/node_modules/@storage-explorer/blob-extension/resources/BlobServiceActions.json'
[2024-11-06T13:34:31.844Z] (main:7318) <DBUG> Launching Node process for provider '@storage-explorer/managed-disks-extension'
[2024-11-06T13:34:31.844Z] (main:7318) <DBUG> Using ssl settings {"sslCertsDir":"/home/ute2/snap/storage-explorer/65/.config/StorageExplorer/certs/","ignoreCerts":false} for provider '@storage-explorer/managed-disks-extension'
[2024-11-06T13:34:31.845Z] (main:7318) <DBUG> Starting node process for provider '@storage-explorer/managed-disks-extension'
[2024-11-06T13:34:31.852Z] (main:7318) <DBUG> Launched Node process 7929 for module 'NodeProcessHostProxy'
[2024-11-06T13:34:33.859Z] (main:7318) <DBUG> Node process 7929 ack received for module 'NodeProcessHostProxy'
[2024-11-06T13:34:33.859Z] (main:7318) <DBUG> Started node process 7929 for provider '@storage-explorer/managed-disks-extension'
[2024-11-06T13:34:33.859Z] (main:7318) <DBUG> Launched Node process 7929 for provider '@storage-explorer/managed-disks-extension'
[2024-11-06T13:34:37.871Z] (main:7318) <DBUG> Resolved resource module './resources/ManagedDisks': '/snap/storage-explorer/65/resources/app/node_modules/@storage-explorer/managed-disks-extension/resources/ManagedDisks.json'
[2024-11-06T13:34:51.918Z] (main:7318) <VERB> Acquiring token for account 7f72b3b6-e71d-4edd-a801-c72c59b0749d.48aa478c-32b6-4e41-babc-cc13a9c9b986:666446FFA39D8AF9E3F8ADB1ACD75DE573935F2F62E51D8AFD6362BDDCA142C3, tenant 48aa478c-32b6-4e41-babc-cc13a9c9b986, resource https://management.core.windows.net/
[2024-11-06T13:34:53.921Z] (main:7318) <VERB> Acquiring token for account 7f72b3b6-e71d-4edd-a801-c72c59b0749d.48aa478c-32b6-4e41-babc-cc13a9c9b986:666446FFA39D8AF9E3F8ADB1ACD75DE573935F2F62E51D8AFD6362BDDCA142C3, tenant 48aa478c-32b6-4e41-babc-cc13a9c9b986, resource https://management.core.windows.net/
[2024-11-06T13:34:57.933Z] (main:7318) <VERB> Acquiring token for account 7f72b3b6-e71d-4edd-a801-c72c59b0749d.48aa478c-32b6-4e41-babc-cc13a9c9b986:666446FFA39D8AF9E3F8ADB1ACD75DE573935F2F62E51D8AFD6362BDDCA142C3, tenant 48aa478c-32b6-4e41-babc-cc13a9c9b986, resource https://management.core.windows.net/
[2024-11-06T13:34:59.936Z] (main:7318) <VERB> Acquiring token for account 7f72b3b6-e71d-4edd-a801-c72c59b0749d.48aa478c-32b6-4e41-babc-cc13a9c9b986:666446FFA39D8AF9E3F8ADB1ACD75DE573935F2F62E51D8AFD6362BDDCA142C3, tenant 48aa478c-32b6-4e41-babc-cc13a9c9b986, resource https://management.core.windows.net/
[2024-11-06T13:35:01.944Z] (main:7318) <VERB> Successfully acquired token account 7f72b3b6-e71d-4edd-a801-c72c59b0749d.48aa478c-32b6-4e41-babc-cc13a9c9b986:666446FFA39D8AF9E3F8ADB1ACD75DE573935F2F62E51D8AFD6362BDDCA142C3, tenant 48aa478c-32b6-4e41-babc-cc13a9c9b986, resource https://management.core.windows.net/
[2024-11-06T13:35:01.945Z] (main:7318) <VERB> Successfully acquired token account 7f72b3b6-e71d-4edd-a801-c72c59b0749d.48aa478c-32b6-4e41-babc-cc13a9c9b986:666446FFA39D8AF9E3F8ADB1ACD75DE573935F2F62E51D8AFD6362BDDCA142C3, tenant 48aa478c-32b6-4e41-babc-cc13a9c9b986, resource https://management.core.windows.net/
[2024-11-06T13:35:03.949Z] (main:7318) <VERB> Successfully acquired token account 7f72b3b6-e71d-4edd-a801-c72c59b0749d.48aa478c-32b6-4e41-babc-cc13a9c9b986:666446FFA39D8AF9E3F8ADB1ACD75DE573935F2F62E51D8AFD6362BDDCA142C3, tenant 48aa478c-32b6-4e41-babc-cc13a9c9b986, resource https://management.core.windows.net/
[2024-11-06T13:35:03.950Z] (main:7318) <VERB> Successfully acquired token account 7f72b3b6-e71d-4edd-a801-c72c59b0749d.48aa478c-32b6-4e41-babc-cc13a9c9b986:666446FFA39D8AF9E3F8ADB1ACD75DE573935F2F62E51D8AFD6362BDDCA142C3, tenant 48aa478c-32b6-4e41-babc-cc13a9c9b986, resource https://management.core.windows.net/
[2024-11-06T13:35:13.978Z] (main:7318) <VERB> Unable to acquire token, tenant https://management.core.windows.net/ is filtered out
[2024-11-06T13:35:13.979Z] (main:7318) <VERB> Unable to acquire token, tenant https://management.core.windows.net/ is filtered out
[2024-11-06T13:37:28.273Z] (main:7318) <VERB> Acquiring token for account 7f72b3b6-e71d-4edd-a801-c72c59b0749d.48aa478c-32b6-4e41-babc-cc13a9c9b986:666446FFA39D8AF9E3F8ADB1ACD75DE573935F2F62E51D8AFD6362BDDCA142C3, tenant 48aa478c-32b6-4e41-babc-cc13a9c9b986, resource https://management.core.windows.net/
[2024-11-06T13:37:28.275Z] (main:7318) <VERB> Acquiring token for account 7f72b3b6-e71d-4edd-a801-c72c59b0749d.48aa478c-32b6-4e41-babc-cc13a9c9b986:666446FFA39D8AF9E3F8ADB1ACD75DE573935F2F62E51D8AFD6362BDDCA142C3, tenant 48aa478c-32b6-4e41-babc-cc13a9c9b986, resource https://management.core.windows.net/
[2024-11-06T13:37:32.287Z] (main:7318) <VERB> Successfully acquired token account 7f72b3b6-e71d-4edd-a801-c72c59b0749d.48aa478c-32b6-4e41-babc-cc13a9c9b986:666446FFA39D8AF9E3F8ADB1ACD75DE573935F2F62E51D8AFD6362BDDCA142C3, tenant 48aa478c-32b6-4e41-babc-cc13a9c9b986, resource https://management.core.windows.net/
[2024-11-06T13:37:32.290Z] (main:7318) <VERB> Acquiring token for account 7f72b3b6-e71d-4edd-a801-c72c59b0749d.48aa478c-32b6-4e41-babc-cc13a9c9b986:666446FFA39D8AF9E3F8ADB1ACD75DE573935F2F62E51D8AFD6362BDDCA142C3, tenant 48aa478c-32b6-4e41-babc-cc13a9c9b986, resource https://management.core.windows.net/
[2024-11-06T13:37:34.292Z] (main:7318) <VERB> Acquiring token for account 7f72b3b6-e71d-4edd-a801-c72c59b0749d.48aa478c-32b6-4e41-babc-cc13a9c9b986:666446FFA39D8AF9E3F8ADB1ACD75DE573935F2F62E51D8AFD6362BDDCA142C3, tenant 48aa478c-32b6-4e41-babc-cc13a9c9b986, resource https://management.core.windows.net/
[2024-11-06T13:37:34.294Z] (main:7318) <VERB> Successfully acquired token account 7f72b3b6-e71d-4edd-a801-c72c59b0749d.48aa478c-32b6-4e41-babc-cc13a9c9b986:666446FFA39D8AF9E3F8ADB1ACD75DE573935F2F62E51D8AFD6362BDDCA142C3, tenant 48aa478c-32b6-4e41-babc-cc13a9c9b986, resource https://management.core.windows.net/
[2024-11-06T13:37:40.316Z] (main:7318) <VERB> Successfully acquired token account 7f72b3b6-e71d-4edd-a801-c72c59b0749d.48aa478c-32b6-4e41-babc-cc13a9c9b986:666446FFA39D8AF9E3F8ADB1ACD75DE573935F2F62E51D8AFD6362BDDCA142C3, tenant 48aa478c-32b6-4e41-babc-cc13a9c9b986, resource https://management.core.windows.net/
[2024-11-06T13:37:40.320Z] (main:7318) <VERB> Successfully acquired token account 7f72b3b6-e71d-4edd-a801-c72c59b0749d.48aa478c-32b6-4e41-babc-cc13a9c9b986:666446FFA39D8AF9E3F8ADB1ACD75DE573935F2F62E51D8AFD6362BDDCA142C3, tenant 48aa478c-32b6-4e41-babc-cc13a9c9b986, resource https://management.core.windows.net/
[2024-11-06T13:37:52.355Z] (main:7318) <VERB> Unable to acquire token, tenant https://management.core.windows.net/ is filtered out
[2024-11-06T13:48:39.634Z] (main:7318) <DBUG> Resolved resource module 'resources/BlobEditor': '/snap/storage-explorer/65/resources/app/node_modules/@storage-explorer/blob-extension/resources/BlobEditor.json'
[2024-11-06T13:49:17.731Z] (main:7318) <INFO> Initialized ConfidentialStorageManager.
[2024-11-06T13:59:39.377Z] (main:7318) <DBUG> Launching Node process for provider '@storage-explorer/azcopy-extension'
[2024-11-06T13:59:39.377Z] (main:7318) <DBUG> Using ssl settings {"sslCertsDir":"/home/ute2/snap/storage-explorer/65/.config/StorageExplorer/certs/","ignoreCerts":false} for provider '@storage-explorer/azcopy-extension'
[2024-11-06T13:59:39.377Z] (main:7318) <DBUG> Starting node process for provider '@storage-explorer/azcopy-extension'
[2024-11-06T13:59:39.386Z] (main:7318) <DBUG> Launched Node process 9789 for module 'NodeProcessHostProxy'
[2024-11-06T13:59:39.508Z] (main:7318) <DBUG> Node process 9789 ack received for module 'NodeProcessHostProxy'
[2024-11-06T13:59:39.509Z] (main:7318) <DBUG> Started node process 9789 for provider '@storage-explorer/azcopy-extension'
[2024-11-06T13:59:39.509Z] (main:7318) <DBUG> Launched Node process 9789 for provider '@storage-explorer/azcopy-extension'
[2024-11-06T13:59:39.555Z] (main:7318) <DBUG> Resolved resource module 'resources/AzCopy': '/snap/storage-explorer/65/resources/app/node_modules/@storage-explorer/azcopy-extension/resources/AzCopy.json'
[2024-11-06T13:59:39.556Z] (main:7318) <VERB> Loading 'JobQueueProvider'
[2024-11-06T13:59:39.556Z] (main:7318) <VERB> Loaded 'JobQueueProvider' via function
[2024-11-06T13:59:39.557Z] (main:7318) <DBUG> Initialization complete.
[2024-11-06T13:59:39.557Z] (main:7318) <DBUG> Resolved resource module './resources/Copy': '/snap/storage-explorer/65/resources/app/node_modules/@storage-explorer/azcopy-extension/resources/Copy.json'
[2024-11-06T13:59:39.557Z] (main:7318) <DBUG> Resolved resource module './resources/Delete': '/snap/storage-explorer/65/resources/app/node_modules/@storage-explorer/azcopy-extension/resources/Delete.json'
[2024-11-06T13:59:39.564Z] (main:7318) <DBUG> Launching Node process for provider '@storage-explorer/activity-log'
[2024-11-06T13:59:39.565Z] (main:7318) <DBUG> Using ssl settings {"sslCertsDir":"/home/ute2/snap/storage-explorer/65/.config/StorageExplorer/certs/","ignoreCerts":false} for provider '@storage-explorer/activity-log'
[2024-11-06T13:59:39.565Z] (main:7318) <DBUG> Starting node process for provider '@storage-explorer/activity-log'
[2024-11-06T13:59:39.573Z] (main:7318) <DBUG> Launched Node process 9801 for module 'NodeProcessHostProxy'
[2024-11-06T13:59:39.698Z] (main:7318) <DBUG> Node process 9801 ack received for module 'NodeProcessHostProxy'
[2024-11-06T13:59:39.698Z] (main:7318) <DBUG> Started node process 9801 for provider '@storage-explorer/activity-log'
[2024-11-06T13:59:39.698Z] (main:7318) <DBUG> Launched Node process 9801 for provider '@storage-explorer/activity-log'
[2024-11-06T13:59:39.712Z] (main:7318) <DBUG> Launching Node process for provider 'JobHandlerProvider_azcopy-copy_0'
[2024-11-06T13:59:39.713Z] (main:7318) <DBUG> Using ssl settings {"sslCertsDir":"/home/ute2/snap/storage-explorer/65/.config/StorageExplorer/certs/","ignoreCerts":false} for provider 'JobHandlerProvider_azcopy-copy_0'
[2024-11-06T13:59:39.713Z] (main:7318) <DBUG> Starting node process for provider 'JobHandlerProvider_azcopy-copy_0'
[2024-11-06T13:59:39.722Z] (main:7318) <DBUG> Launched Node process 9813 for module 'NodeProcessHostProxy'
[2024-11-06T13:59:39.844Z] (main:7318) <DBUG> Node process 9813 ack received for module 'NodeProcessHostProxy'
[2024-11-06T13:59:39.844Z] (main:7318) <DBUG> Started node process 9813 for provider 'JobHandlerProvider_azcopy-copy_0'
[2024-11-06T13:59:39.844Z] (main:7318) <DBUG> Launched Node process 9813 for provider 'JobHandlerProvider_azcopy-copy_0'
[2024-11-06T13:59:45.948Z] (main:7318) <VERB> Loading 'FileSystemProvider'
[2024-11-06T13:59:45.949Z] (main:7318) <VERB> Loaded 'FileSystemProvider' via function

natemcintosh avatar Nov 06 '24 21:11 natemcintosh

The logs indeed indicate there's a hefty span of time (approximately 25 minutes) Storage Explorer is expending to get started. Most things look fine, like extensions, provider processes, and string resources. The biggest gaps seem to occur while the identity client library is retrieving tenant information. Can you share your authentication logs as well?

You might also try signing out to see if Storage Explorer loads any faster and CPU usages goes down quicker. If that's the case, try signing back in and relaunching. If slow down persists, you might try playing around with the tenants/subscriptions you have filtered or unfiltered.

craxal avatar Nov 06 '24 21:11 craxal

Looking through the logs, I don't see any with a title relating to authentication, and grepping for "auth" in the logs folder didn't reveal anything. Is that a log that has to be specifically turned on?

natemcintosh avatar Nov 12 '24 21:11 natemcintosh

@natemcintosh https://learn.microsoft.com/troubleshoot/azure/azure-storage/blobs/alerts/storage-explorer-troubleshooting?tabs=Windows#authentication-logs

craxal avatar Nov 13 '24 00:11 craxal

Thanks, have set it up to record auth logs. I also down-selected what should be shown to just a single account.

Have not had any issues yet today, but will post auth logs if I run into the issue again.

natemcintosh avatar Nov 13 '24 16:11 natemcintosh

The issue popped up again today. I verified in the GUI settings that Verbose Authentication Logging had been previously enabled. I looked for ~/.ServiceHub/ on my Linux machine, but it did not exist. Could that be due to being installed via snap?

natemcintosh avatar Dec 10 '24 15:12 natemcintosh

@natemcintosh I think you want to look for ~/snap/storage-explorer/current/.ServiceHub, because snaps are sandboxed.

craxal avatar Dec 10 '24 17:12 craxal

@natemcintosh Have you been running into this problem lately? Does it still occur on 1.37.0?

craxal avatar Jan 16 '25 18:01 craxal

Hi @craxal, I have not seen the behavior in 1.37.0 yet. Will update here if I do run into it.

natemcintosh avatar Jan 16 '25 19:01 natemcintosh

If you encounter more performance issues, leave a comment, and we can reopen.

craxal avatar Mar 10 '25 17:03 craxal

Hi @craxal, sorry I forgot to come back to this even though I have still been experiencing this behavior. Looking in the ~/snap/storage-explorer/current/.ServiceHub folder, I see several hundred logs. Should I be looking at the one with ...IdentityStorageService... in the name? I can also send them to you if needed.

The most recent logs in the folder are:

│ 186 │ a8c8a5b2-AadAccountProviderService-17426-vix1uwjq-1.log         │ file │ 234.5 kB │ 2 days ago  │
│ 187 │ a8c8a5b2-ErrorStorageService-17426-n4xh5mlq-1.log               │ file │  59.1 kB │ 2 days ago  │
│ 188 │ a8c8a5b2-AadAccountProviderService-17426-hswwzfob-1.log         │ file │   4.6 kB │ 2 days ago  │
│ 189 │ a8c8a5b2-AadAccountProviderService-17426-j23zrfom-1.log         │ file │   4.6 kB │ 2 days ago  │
│ 190 │ a8c8a5b2-AadAccountProviderService-17426-sc53xijg-1.log         │ file │   4.6 kB │ 2 days ago  │
│ 191 │ a8c8a5b2-AssemblyLoadContext-dotnet-FB9BE8-17426-m1dcqor0-1.log │ file │ 162.0 kB │ 2 days ago  │
│ 192 │ a8c8a5b2-dotnet-17426-4ggnaxi4-1.log                            │ file │  18.0 kB │ 2 days ago  │
│ 193 │ a8c8a5b2-hubController-17016-ccze453a-1.log                     │ file │  28.3 kB │ 2 days ago  │
│ 194 │ cf2b9acb-StorageServiceNodeClient-18295-1.log                   │ file │    217 B │ 5 hours ago │
│ 195 │ cf2b9acb-ServiceDiscoveryManager-18619-24lcjkwx-1.log           │ file │    115 B │ 5 hours ago │
│ 196 │ cf2b9acb-dotnet-18872-18619-0nq01tl1-1.log                      │ file │    551 B │ 5 hours ago │
│ 197 │ StaticNetworkClientFactory-18872-szhadnfk-1.log                 │ file │    391 B │ 5 hours ago │
│ 198 │ StorageServiceSingleton-18872-o2eheez5-1.log                    │ file │    917 B │ 5 hours ago │
│ 199 │ StorageServiceSingleton-18872-d1x5dy1q-1.log                    │ file │   1.0 kB │ 5 hours ago │
│ 200 │ StorageServiceSingleton-18872-y0hjq240-1.log                    │ file │    801 B │ 5 hours ago │
│ 201 │ StorageServiceSingleton-18872-nx5h0a1q-1.log                    │ file │   1.1 kB │ 5 hours ago │
│ 202 │ cf2b9acb-hubController-18619-qjw5i0gz-1.log                     │ file │  24.8 kB │ 5 hours ago │
│ 203 │ StaticNetworkClientFactory-18872-5twvhjqf-1.log                 │ file │    391 B │ 5 hours ago │
│ 204 │ StaticNetworkClientFactory-18872-p4multlg-1.log                 │ file │    391 B │ 5 hours ago │
│ 205 │ cf2b9acb-hubLookup-18295-1.log                                  │ file │   3.1 kB │ 5 hours ago │
│ 206 │ StaticNetworkClientFactory-18872-21sypsih-1.log                 │ file │    391 B │ 5 hours ago │
│ 207 │ cf2b9acb-dotnet-18872-hl45pzop-1.log                            │ file │  15.4 kB │ 5 hours ago │
│ 208 │ StaticNetworkClientFactory-18872-gppxuyjt-1.log                 │ file │    391 B │ 5 hours ago │
│ 209 │ StaticNetworkClientFactory-18872-vgv1cu4l-1.log                 │ file │    391 B │ 5 hours ago │
│ 210 │ StaticNetworkClientFactory-18872-xtobz2xo-1.log                 │ file │    391 B │ 5 hours ago │
│ 211 │ StaticNetworkClientFactory-18872-2s5hg5qm-1.log                 │ file │    391 B │ 5 hours ago │
│ 212 │ StaticNetworkClientFactory-18872-5wfejeyw-1.log                 │ file │    391 B │ 5 hours ago │
│ 213 │ StaticNetworkClientFactory-18872-bqazxmye-1.log                 │ file │    391 B │ 5 hours ago │
│ 214 │ StaticNetworkClientFactory-18872-qdt1ts30-1.log                 │ file │    391 B │ 5 hours ago │
│ 215 │ cf2b9acb-AadAccountProviderService-18872-i2fmzqff-1.log         │ file │   3.7 kB │ 5 hours ago │
│ 216 │ cf2b9acb-AadAccountProviderService-18872-q0cmnwt1-1.log         │ file │   4.0 kB │ 5 hours ago │
│ 217 │ cf2b9acb-AadAccountProviderService-18872-sllihxe3-1.log         │ file │   3.8 kB │ 5 hours ago │
│ 218 │ cf2b9acb-AadAccountProviderService-18872-xr4dykrw-1.log         │ file │   3.8 kB │ 5 hours ago │
│ 219 │ StaticNetworkClientFactory-18872-kkkk1krg-1.log                 │ file │   1.5 kB │ 5 hours ago │
│ 220 │ StaticNetworkClientFactory-18872-ehhvd0yg-1.log                 │ file │    391 B │ 5 hours ago │
│ 221 │ StaticNetworkClientFactory-18872-gkhlmaj0-1.log                 │ file │    391 B │ 5 hours ago │
│ 222 │ StorageUtilitiesSingleton-18872-buz1ytaq-1.log                  │ file │  11.1 kB │ 5 hours ago │
│ 223 │ cf2b9acb-AadAccountProviderService-18872-2holyp5x-1.log         │ file │  72.0 kB │ 5 hours ago │
│ 224 │ cf2b9acb-AssemblyLoadContext-dotnet-934827-18872-wlc24ock-1.log │ file │ 137.7 kB │ 5 hours ago │
│ 225 │ cf2b9acb-AadAccountProviderNodeClient-18295-1.log               │ file │   3.3 kB │ 5 hours ago │
│ 226 │ ErrorStorageServiceSingleton-18872-1woyrqzd-1.log               │ file │   2.4 kB │ 5 hours ago │
│ 227 │ cf2b9acb-ErrorStorageService-18872-fh3pgts5-1.log               │ file │   1.6 kB │ 5 hours ago │
│ 228 │ cf2b9acb-IdentityStorageService-18872-eva5d3pg-1.log            │ file │ 556.4 kB │ 5 hours ago │
├─────┼─────────────────────────────────────────────────────────────────┼──────┼──────────┼─────────────┤
│   # │                              name                               │ type │   size   │  modified   │
╰─────┴─────────────────────────────────────────────────────────────────┴──────┴──────────┴─────────────╯

natemcintosh avatar Mar 10 '25 19:03 natemcintosh

The largest files are likely to contain more useful information, but it wouldn't hurt to look through them all. If you can share those with us, that would also be helpful.

craxal avatar Mar 10 '25 20:03 craxal

@craxal what is the best way to get you the files? Paste the contents here? Is there anything in them I should worry about in terms of my organization's credentials?

natemcintosh avatar Mar 11 '25 14:03 natemcintosh

@natemcintosh Log files are scrubbed for sensitive data, so you should be able to a .zip file here safely here (you can scan the files yourself to verify). Alternatively, you can send it to sehelp AT microsoft dot com.

craxal avatar Mar 11 '25 18:03 craxal

If I'd like to send it to sehelp AT microsoft dot com, do I need to do anything to ensure it gets to you?

natemcintosh avatar Mar 11 '25 18:03 natemcintosh

@natemcintosh No, that's all you need to do.

craxal avatar Mar 11 '25 20:03 craxal

Just sent

natemcintosh avatar Mar 12 '25 15:03 natemcintosh

We've received your logs. Unfortunately, I didn't see anything terribly illuminating. Timestamps only seem to span about 2 minutes.

Looking more closely at your app logs from earlier, I notice that there appears to be several attempts to obtain auth tokens for the same tenant/resource. I also see a few entries mentioning that certain tenants are filtered out.

Perhaps we can try something to help narrow down the problems. If the slow down happens pretty consistently, try the following:

  1. Create some SAS or key-based attachments to resources you often work with (no auth-based attachments for now).
  2. Sign out and close Storage Explorer.
  3. Launch Storage Explorer again. Don't sign in. See if the slow down occurs. Share your app logs. If the slow down occurs again, try resetting auth (Help > Reset), closing Storage Explorer, and launching again.

craxal avatar Mar 12 '25 17:03 craxal

Oh dear, it sounds like I might have sent the logs from a run with no issues. Can I try again next time it happens?

natemcintosh avatar Mar 12 '25 18:03 natemcintosh

@natemcintosh Sure! And if it happens again, feel free to try the steps I provided. If anything sign-in-related is causing you problems, and not signing in resolves the performance issue, that will help us narrow down the problem area.

craxal avatar Mar 12 '25 18:03 craxal

hi @craxal, I have tried signing out, closing, and restarting, but received the same slow down. I gathered up my logs from both before and after signing out, and sent them to the email you gave above.

Next up, trying to reset the auth and see what happens.

natemcintosh avatar Apr 28 '25 18:04 natemcintosh

I've fully reset my application, and am now accessing my resources via a connection string to the storage account. So far so good. Will update if issues arise.

natemcintosh avatar Apr 28 '25 19:04 natemcintosh

No, after restarting my VM, the issue is still occurring

natemcintosh avatar Apr 28 '25 20:04 natemcintosh

@natemcintosh Does not signing in resolve your performance issues? Or does the app still take up time with CPU at 100%?

craxal avatar May 07 '25 16:05 craxal