microsoftgraph / msgraph-sdk-powershell

Powershell SDK for Microsoft Graph
https://www.powershellgallery.com/packages/Microsoft.Graph
Other
712 stars 172 forks source link

Get-MgSubscribedSku fails after successful Connect-MgGraph with Service Principal #2938

Closed AdamBlaumann closed 2 months ago

AdamBlaumann commented 2 months ago

Describe the bug

We have multiple scripts that use the MgGraph Powershell module to collect licensing information. The connection to Graph is successful, but if the script then calls "Get-MgSubscribedSku", it very often throws the error "An error occurred while sending the request." We also get an error for "Invoke-MgGraphRequest -Uri 'https://graph.microsoft.com/v1.0/subscribedSkus'", but with a clearer error message: "Unable to connect to the remote server".

On occasions the command works, then stops working again a few minutes later. The behaviour also seems to defer depending on which account is logged into the server from which the connection with the ServicePrincipal is made. (We are looking into the issue from the network side as well.)

The issue first appeared in late July, but we don't have an exact date. We did upgrade the SDK version from 2.18.0 to 2.20.0 at around that time, but reverting to 2.18.0 did not solve the issue, so this might be incidental.

Expected behavior

"Get-MgSubscribedSku" and "Invoke-MgGraphRequest -Uri 'https://graph.microsoft.com/v1.0/subscribedSkus'" should return the subscription information at every call.

How to reproduce

  1. Install the Graph PS module (v2.22.0)
  2. Establish an MS Graph connection using a service principal (PS commands are run by a specific local service account)
  3. Run "Get-MgSubscribedSku" and "Invoke-MgGraphRequest -Uri 'https://graph.microsoft.com/v1.0/subscribedSkus'"
  4. The command will fail for som periods of time, then work for again for a shorter period

SDK Version

2.22.0

Latest version known to work for scenario above?

No response

Known Workarounds

Re-running the command every now and then, until it workds

Debug output

Click to expand log ``` Debugpreference: Continue DEBUG: ClientCertificateCredential.GetToken invoked. Scopes: [ https://graph.microsoft.com/.default ] ParentRequestId: DEBUG: False MSAL 4.61.3.0 MSAL.Desktop 4.8 or later Windows Server 2019 Standard [2024-09-03 12:20:11Z - b30bb5ac-e1c7-4b34-be7a-16fcca1ac8aa] MSAL MSAL.Desktop with assembly version '4.61.3.0'. CorrelationId(b30bb5ac-e1c7-4b34-be7a-16fcca1ac8aa) DEBUG: False MSAL 4.61.3.0 MSAL.Desktop 4.8 or later Windows Server 2019 Standard [2024-09-03 12:20:11Z - b30bb5ac-e1c7-4b34-be7a-16fcca1ac8aa] === AcquireTokenForClientParameters === SendX5C: False ForceRefresh: False DEBUG: False MSAL 4.61.3.0 MSAL.Desktop 4.8 or later Windows Server 2019 Standard [2024-09-03 12:20:11Z - b30bb5ac-e1c7-4b34-be7a-16fcca1ac8aa] === Request Data === Authority Provided? - True Scopes - https://graph.microsoft.com/.default Extra Query Params Keys (space separated) - ApiId - AcquireTokenForClient IsConfidentialClient - True SendX5C - False LoginHint ? False IsBrokerConfigured - False HomeAccountId - False CorrelationId - b30bb5ac-e1c7-4b34-be7a-16fcca1ac8aa UserAssertion set: False LongRunningOboCacheKey set: False Region configured: DEBUG: False MSAL 4.61.3.0 MSAL.Desktop 4.8 or later Windows Server 2019 Standard [2024-09-03 12:20:11Z - b30bb5ac-e1c7-4b34-be7a-16fcca1ac8aa] === Token Acquisition (ClientCredentialRequest) started: Scopes: https://graph.microsoft.com/.default Authority Host: login.microsoftonline.com DEBUG: False MSAL 4.61.3.0 MSAL.Desktop 4.8 or later Windows Server 2019 Standard [2024-09-03 12:20:11Z - b30bb5ac-e1c7-4b34-be7a-16fcca1ac8aa] [Instance Discovery] Instance discovery is enabled and will be performed DEBUG: False MSAL 4.61.3.0 MSAL.Desktop 4.8 or later Windows Server 2019 Standard [2024-09-03 12:20:11Z - b30bb5ac-e1c7-4b34-be7a-16fcca1ac8aa] [Region discovery] Not using a regional authority. DEBUG: False MSAL 4.61.3.0 MSAL.Desktop 4.8 or later Windows Server 2019 Standard [2024-09-03 12:20:12Z - b30bb5ac-e1c7-4b34-be7a-16fcca1ac8aa] Fetching instance discovery from the network from host login.microsoftonline.com. DEBUG: Request [f8c54e6a-6cbc-48ad-9d88-24b554b4d580] GET https://login.microsoftonline.com/common/discovery/instance?api-version=1.1&authorization_endpoint=REDACTED x-client-SKU:REDACTED x-client-Ver:REDACTED x-client-OS:REDACTED client-request-id:REDACTED return-client-request-id:REDACTED x-app-name:REDACTED x-app-ver:REDACTED x-ms-client-request-id:f8c54e6a-6cbc-48ad-9d88-24b554b4d580 x-ms-return-client-request-id:true User-Agent:azsdk-net-Identity/1.11.4 (.NET Framework 4.8.4749.0; Microsoft Windows 10.0.17763 ) client assembly: Azure.Identity DEBUG: Response [f8c54e6a-6cbc-48ad-9d88-24b554b4d580] 200 OK (00.3s) Strict-Transport-Security:REDACTED X-Content-Type-Options:REDACTED Access-Control-Allow-Origin:REDACTED Access-Control-Allow-Methods:REDACTED client-request-id:REDACTED x-ms-request-id:b1456349-e63c-4772-b69a-051795c01200 x-ms-ests-server:REDACTED x-ms-srs:REDACTED X-XSS-Protection:REDACTED Cache-Control:max-age=86400, private Content-Type:application/json; charset=utf-8 P3P:REDACTED Set-Cookie:REDACTED Date:Tue, 03 Sep 2024 12:20:11 GMT Content-Length:980 DEBUG: False MSAL 4.61.3.0 MSAL.Desktop 4.8 or later Windows Server 2019 Standard [2024-09-03 12:20:12Z - b30bb5ac-e1c7-4b34-be7a-16fcca1ac8aa] Authority validation enabled? True. DEBUG: False MSAL 4.61.3.0 MSAL.Desktop 4.8 or later Windows Server 2019 Standard [2024-09-03 12:20:12Z - b30bb5ac-e1c7-4b34-be7a-16fcca1ac8aa] Authority validation - is known env? True. DEBUG: Request [45b6f383-ad77-4e93-a52d-5f15d4af07b2] POST https://login.microsoftonline.com/73994ef1-7e27-447e-9989-2b1e5b14a17c/oauth2/v2.0/token x-client-SKU:REDACTED x-client-Ver:REDACTED x-client-OS:REDACTED x-client-current-telemetry:REDACTED x-client-last-telemetry:REDACTED x-ms-lib-capability:REDACTED client-request-id:REDACTED return-client-request-id:REDACTED x-app-name:REDACTED x-app-ver:REDACTED Content-Type:application/x-www-form-urlencoded x-ms-client-request-id:45b6f383-ad77-4e93-a52d-5f15d4af07b2 x-ms-return-client-request-id:true User-Agent:azsdk-net-Identity/1.11.4 (.NET Framework 4.8.4749.0; Microsoft Windows 10.0.17763 ) client assembly: Azure.Identity DEBUG: Response [45b6f383-ad77-4e93-a52d-5f15d4af07b2] 200 OK (00.2s) Pragma:no-cache Strict-Transport-Security:REDACTED X-Content-Type-Options:REDACTED client-request-id:REDACTED x-ms-request-id:f434b334-bcc0-4d47-9f92-7b784b549a00 x-ms-ests-server:REDACTED x-ms-clitelem:REDACTED x-ms-srs:REDACTED X-XSS-Protection:REDACTED Cache-Control:no-store, no-cache Content-Type:application/json; charset=utf-8 Expires:-1 P3P:REDACTED Set-Cookie:REDACTED Date:Tue, 03 Sep 2024 12:20:12 GMT Content-Length:1756 DEBUG: False MSAL 4.61.3.0 MSAL.Desktop 4.8 or later Windows Server 2019 Standard [2024-09-03 12:20:12Z - b30bb5ac-e1c7-4b34-be7a-16fcca1ac8aa] ScopeSet was missing from the token response, so using developer provided scopes in the result. DEBUG: False MSAL 4.61.3.0 MSAL.Desktop 4.8 or later Windows Server 2019 Standard [2024-09-03 12:20:12Z - b30bb5ac-e1c7-4b34-be7a-16fcca1ac8aa] Checking client info returned from the server.. DEBUG: False MSAL 4.61.3.0 MSAL.Desktop 4.8 or later Windows Server 2019 Standard [2024-09-03 12:20:12Z - b30bb5ac-e1c7-4b34-be7a-16fcca1ac8aa] Saving token response to cache.. DEBUG: False MSAL 4.61.3.0 MSAL.Desktop 4.8 or later Windows Server 2019 Standard [2024-09-03 12:20:12Z - b30bb5ac-e1c7-4b34-be7a-16fcca1ac8aa] [SaveTokenResponseAsync] ID Token not present in response. DEBUG: False MSAL 4.61.3.0 MSAL.Desktop 4.8 or later Windows Server 2019 Standard [2024-09-03 12:20:12Z - b30bb5ac-e1c7-4b34-be7a-16fcca1ac8aa] Cannot determine home account ID - or id token or no client info and no subject DEBUG: False MSAL 4.61.3.0 MSAL.Desktop 4.8 or later Windows Server 2019 Standard [2024-09-03 12:20:12Z - b30bb5ac-e1c7-4b34-be7a-16fcca1ac8aa] [SaveTokenResponseAsync] Saving AT in cache and removing overlapping ATs... DEBUG: False MSAL 4.61.3.0 MSAL.Desktop 4.8 or later Windows Server 2019 Standard [2024-09-03 12:20:12Z - b30bb5ac-e1c7-4b34-be7a-16fcca1ac8aa] Looking for scopes for the authority in the cache which intersect with https://graph.microsoft.com/.default DEBUG: False MSAL 4.61.3.0 MSAL.Desktop 4.8 or later Windows Server 2019 Standard [2024-09-03 12:20:12Z - b30bb5ac-e1c7-4b34-be7a-16fcca1ac8aa] Intersecting scope entries count - 0 DEBUG: False MSAL 4.61.3.0 MSAL.Desktop 4.8 or later Windows Server 2019 Standard [2024-09-03 12:20:13Z - b30bb5ac-e1c7-4b34-be7a-16fcca1ac8aa] === Token Acquisition finished successfully: DEBUG: False MSAL 4.61.3.0 MSAL.Desktop 4.8 or later Windows Server 2019 Standard [2024-09-03 12:20:13Z - b30bb5ac-e1c7-4b34-be7a-16fcca1ac8aa] AT expiration time: 9/3/2024 1:20:11 PM +00:00, scopes: https://graph.microsoft.com/.default. source: IdentityProvider DEBUG: False MSAL 4.61.3.0 MSAL.Desktop 4.8 or later Windows Server 2019 Standard [2024-09-03 12:20:13Z - b30bb5ac-e1c7-4b34-be7a-16fcca1ac8aa] Fetched access token from host login.microsoftonline.com. DEBUG: ClientCertificateCredential.GetToken succeeded. Scopes: [ https://graph.microsoft.com/.default ] ParentRequestId: ExpiresOn: 2024-09-03T13:20:11.9791968+00:00 Connected to Graph PS>TerminatingError(Get-MgSubscribedSku_List): "The running command stopped because the preference variable "ErrorActionPreference" or common parameter is set to Stop: An error occurred while sending the request." Terminating error: Failed to collect licenses available in the tenant. Error message: An error occurred while sending the request. PS>$global:? True ```

Configuration

PSVersion 5.1.17763.6189 PSEdition Desktop PSCompatibleVersions {1.0, 2.0, 3.0, 4.0...} BuildVersion 10.0.17763.6189 CLRVersion 4.0.30319.42000 WSManStackVersion 3.0 PSRemotingProtocolVersion 2.3 SerializationVersion 1.1.0.1

OS: Windows Server 2019 Standard Version: 1809 Build: 17763.6189 Architecture: x64

Other information

No response

AdamBlaumann commented 2 months ago

After troubleshooting the issue further, we found this was caused by a network routing issue