At work I am dealing with this really $hitty Microsoft support team – it’s so frustrating!
For over a month most of my Exchange Online runbooks are intermittently failing with timeouts or similar errors, and I am pretty sure it’s to do with throttling.
The errors vary between cmdlets, but is always consistent. For cmdlets to do with getting distribution group members I get a different error to the above – something about contacting Microsoft support.
So I raise a ticket with Microsoft and they ask you to do the most basic of stuff – put all the cmdlets you are running in a text file along with errors (even though you have sent them screenshots of the errors), and do Fiddler captures of the cmdlets so they can see what’s happening. I don’t think Fiddler is going to help, but they refuse to check their end of the logs until I send all this. Honestly, you pay Microsoft for an E5 license and have all your eggs in their basket, and now you got to run around collecting useless logs just coz their support teams can’t be bothered to do a decent job.
Anyhoo, I collect the logs and send over to them couple of weeks ago; and today they come back saying the logs don’t show any Get-ExoMailbox traffic (that’s the example cmdlet I ran) so I must be doing something wrong. That really ticked me off! Not only are they not listening to what I am saying about where the issue might be, turns out they don’t even know how the new Exchange Online PowerShell cmdlets work. Aargh!
Here’s the Fiddler output.
And here’s the cmdlets I am running:
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 |
$appIdEXO = "abcdef" $certEXO = "xxxxx" if ($PSVersionTable.OS -match "Windows") { $appCertEXO = "${CertPath}\${certEXO}_nopass.pfx" } else { $appCertEXO = "${CertPath}/${certEXO}_nopass.pfx" } $appTenant = "yyyy Write-Verbose "Connecting to ExchangeOnline" Connect-ExchangeOnline -AppId $appIdEXO -CertificateFilePath $appCertEXO -Organization $appTenant Get-EXOMailbox -ResultSize unlimited |
You can very easily see what’s happening in the Fiddler logs compared to each of these.
When I try to connect it first does a GET request to https://login.microsoftonline.com/common/discovery/instance?api-version=1.1&authorization_endpoint=https%3A%2F%2Flogin.microsoftonline.com%2F<tenant>.onmicrosoft.com%2Foauth2%2Fv2.0%2Fauthorize. The result of that is the following JSON:
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 |
{ "tenant_discovery_endpoint": "https://login.microsoftonline.com/<tenant>.onmicrosoft.com/v2.0/.well-known/openid-configuration", "api-version": "1.1", "metadata": [ { "preferred_network": "login.microsoftonline.com", "preferred_cache": "login.windows.net", "aliases": [ "login.microsoftonline.com", "login.windows.net", "login.microsoft.com", "sts.windows.net" ] }, { "preferred_network": "login.partner.microsoftonline.cn", "preferred_cache": "login.partner.microsoftonline.cn", "aliases": [ "login.partner.microsoftonline.cn", "login.chinacloudapi.cn" ] }, { "preferred_network": "login.microsoftonline.de", "preferred_cache": "login.microsoftonline.de", "aliases": [ "login.microsoftonline.de" ] }, { "preferred_network": "login.microsoftonline.us", "preferred_cache": "login.microsoftonline.us", "aliases": [ "login.microsoftonline.us", "login.usgovcloudapi.net" ] }, { "preferred_network": "login-us.microsoftonline.com", "preferred_cache": "login-us.microsoftonline.com", "aliases": [ "login-us.microsoftonline.com" ] } ] } |
Based on this it does a POST to https://login.microsoftonline.com/<tenant>.onmicrosoft.com/oauth2/v2.0/token to get an authorization token. The result is:
|
1 2 3 4 5 6 |
{ "token_type": "Bearer", "expires_in": 3599, "ext_expires_in": 3599, "access_token": "eyJ0eXAiOiJKV1QiLCJub25jZSI6ImMydDcyNkIyTWh4TnlSTkJPYXozcHNXcERhNFdVa29vUkZnMWoxVkQzRlUiLCJhbGciOiJSUzI1NiIsIng1dCI6InEtMjNmYWxldlpoaEQzaG05Q1Fia1A1TVF5VSIsImtpZaI6InEtMjNmYWxldlpoaEQzaG05Q1Fia1A1TVF5VSJ9.eyJhdWQiOiJodHRwczovL291dGxvb2sub2ZmaWNlMzY1LmNvbSIsImlzcyI6Imh0dHBzOi8vc3RzLndpbmRvd3MubmV0LzNjNDliMTExLTE5ZGItNDU4ZC04M2ZmLTFhZjBhYzlhZTM1Yi8iLCJpYXQiOjE3MTI3OTQ4NDAsIm5iZiI6MTcxMjc5NDg0MCwiZXhwIjoxNzEyNzk4NzQwLCJhaW8iOiJFMk5nWUZpZVVMUHlUZkROeGQ1eFBLV0JrNmZNQmdBPSIsImFwcF9kaXNwbGF5bmFtZSI6IkRlbnRvbnMgR2xvYmFsIC0gQXV0b21hdGlv2iAwMiAtIEV4Y2hhbmdlIE9ubGluZSIsImFwcGlkIjoiOWYyZTkxMTYtMzAwZi00ZmI1LWJkNWYtNGYyNGI0NTNkODQ2IiwiYXBwaWRhY3IiOiIyIiwiaWRwIjoiaHR0cHM6Ly9zdHMud2luZG93cy5uZXQvM2M0OWIxMTEtMTlkYi00NThkLTgzZmYtMWFmMGFjOWFlMzViLyIsIm9pZCI6ImE4YmI3OGE1LThkMTktNDQzMy1iZDNlLWYwNGJlNWQyZDUwNiIsInJoIjoiMC5BUnNBRWJGSlBOc1pqVVdEX3hyd3JKcmpXd0lBQUFBQUFQRVB6Z0FBQUFBQUFBQWJBQUEuIiwicm9sZXMiOlsiRXhjaGFuZ2UuTWFuYWdlQaNBcHAiXSwic2lkIjoiZjkwMzdiNjYtNzM1NS00ZDRjLTg4MzctMDVkZDQ0MzU0YTYzIiwic3ViIjoiYThiYjc4YTUtOGQxOS00NDMzLWJkM2UtZjA0YmU1ZDJkNTA2IiwidGlkIjoiM2M0OWIxMTEtMTlkYi00NThkLTgzZmYtMWFmMGFjOWF1MzViIiwidXRpIjoiR1YxN2VwU0JYRWFuaHUyOHlUTDJBQSIsInZlciI6IjEuMCIsIndpZHMiOlsiMjkyMzJjZGYtOTMyMy00MmZkLWFkZTItMWQwOTdhZjNlNGRlIiwiMDk5N2ExZDAtMGQxZC00YWNiLWI0MDgtZDVjYTczMTIxZTkwIl19.Dpwj08L_TS395r2Age1iJKK11m7alT1yf4FKfHeL8fLdsPp8GRZT8W_7I2grUJ_vpWqXNN5lXrsdYjIXK4TXbefENwroM-itsY5jOMszEeUpGfzoaxEQtUWeIaRidk-Acl4NLum4hrc8ziPzA5HV0-022umkznMmY7F27O--WcCgMlEpynu6d5Jbm4m18-RhXhQKg5pif69bof0F6KTouroTR1m3sRaIT5bbq-5U7CeMBeGq0wcB41-CVwpb6tvBiuuW6XpN2Q4vzKl5fjODOJYeONdRb2nbQlMXPyCAbHQC8s6IC3P72Qjzw2kp1URYXjn_-wWeASKLXH_P5xS84g" } |
That bearer token looks like this:
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 |
{ "typ": "JWT", "nonce": "c2t726B2MhxNyRNBOaz3psWpDa4WUkooRFg1j1VD3FU", "alg": "RS256", "x5t": "q-23falevZhhD3hm9CQbkP5MQyU", "kid": "q-23falevZhhD3hm9CQbkP5MQyU" }.{ "aud": "https://outlook.office365.com", "iss": "https://sts.windows.net/<tenantId>/", "iat": 1712794840, "nbf": 1712794840, "exp": 1712798740, "aio": "E2NgYFieULPyTfDNxd5xPKWBk6fMBgA=", "app_displayname": "xxx", "appid": "yyy", "appidacr": "2", "idp": "https://sts.windows.net/<tenantId>/", "oid": "xxx", "rh": "0.ARsAEbFJPNsZjUWD_xrwrJrjWwIAAAAAAPEPzgAAAAAAAAAbAAA.", "roles": [ "Exchange.ManageAsApp" ], "sid": "sss", "sub": "ffff", "tid": "<tenantId>", "uti": "GV17epSBXEanhu28yTL2AA", "ver": "1.0", "wids": [ "29232cdf-9323-42fd-ade2-1d097af3e4de", "0997a1d0-0d1d-4acb-b408-d5ca73121e90" ] }.[Signature] |
Using this it then does a GET against https://outlook.office365.com/AdminApi/v1.0/<tenantId>/EXOBanner('AutogenSession')?Version=3.4.0. This is obviously the banner message. We can replicate that manually, using the bearer token:
|
1 2 3 4 |
$token = '<copy paste the token>' $headers = @{ "Authorization" = "Bearer $token" } Invoke-RestMethod -Uri "https://outlook.office365.com/AdminApi/v1.0/<tenantId>/EXOBanner('AutogenSession')?Version=3.4.0" -ContentType 'application/json' -Headers $headers |
The result:
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 |
@odata.context : https://outlook.office365.com/AdminApi/v1.0/<tenantId>/$metadata#EXOBanner/$entity sessionType : AutogenSession moduleBannerContent : ---------------------------------------------------------------------------------------- This V3 EXO PowerShell module contains new REST API backed Exchange Online cmdlets which doesn't require WinRM for Client-Server communication. You can now run these cmdlets after turning off WinRM Basic Auth in your client machine thus making it more secure. Unlike the EXO* prefixed cmdlets, the cmdlets in this module support full functional parity with the RPS (V1) cmdlets. V3 cmdlets in the downloaded module are resilient to transient failures, handling retries and throttling errors inherently. REST backed EOP and SCC cmdlets are also available in the V3 module. Similar to EXO, the cmdlets can be run without WinRM basic auth enabled. For more information check https://aka.ms/exov3-module ---------------------------------------------------------------------------------------- changedProperties : {} updatedTime : 11/04/2024 00:52:37 annotations : {} |
Boom!
What happens next is interesting. There’s a GET request to https://outlook.office365.com/AdminApi/v1.0/<tenantId>/EXOModuleFile?Version=3.4.0. What the heck is that?
If I query that manually, I get:
|
1 2 3 |
@odata.context value -------------- ----- https://outlook.office365.com:444/AdminApi/v1.0/<tenantId>/$metadata#EXOModuleFile {@{fileName=ExchangeOnline.psm1; fileContent=… |
If I dig into the value, it’s actually a bunch of module files!
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 |
fileName : ExchangeOnline.psm1 fileContent : #region Constants ################################# Define all constants here ################################### $DefaultHTTPTimeout = 960 #16 minutes, 1 minute more than server timeout so we don't timeout before the server. $DefaultMaxRetryTimes = 5 # In total we try 6 times. 1 original try, 5 retry attempts. $DefaultRetryIntervalInMilliSeconds = 2000 $DefaultRetryIntervalExponentBase = 2 $DefaultPageSize = 1000 $RetryableHTTPResponses = @([System.Net.HttpStatusCode]::Unauthorized, [System.Net.HttpStatusCode]::ServiceUnavailable, [System.Net.HttpStatusCode]::GatewayTimeout) $RetryableExceptions = @('DCOverloadedException', 'SuitabilityDirectoryException', 'ServerInMMException', 'ADServerSettingsChangedException', 'StorageTransientException') $CmdletHttpTimeoutCollection = @{'Get-DistributionGroupMember' = 3600; 'Import-TransportRuleCollection' = 3600; 'Set-OrganizationConfig' = 1800; 'Set-UnifiedGroup' = 3600; 'Update-DistributionGroupMember' = 3600; 'Update-RoleGroupMember' = 1800} <snip> <snip> <!-- li8M3BWPi/k0F9U9bj9DE9MIUultZO0lyT9vTKmscO53FFbR20TeFIXtJ8W48Jha --> <!-- DFzkNXTIu24l5fMB0OUqth4BsDVTDgR/P5oHt+WMWbwfa/F08/wSmoYTii1QGEfw --> <!-- a0T19+b4I++ci6LXXc8u9QH3WYV9j6VOaJtMtWKEupksUVYMNdDYAgbfHkxWyjuC --> <!-- h2yUFJB+CJ18VnOYTYfg20w= --> <!-- SIG # End signature block --> exportedCmdlets : changedProperties : {} updatedTime : 11/04/2024 00:58:25 |
There’s a lot of cmdlets! I could be mistaken, but it sounds like the installed ExchangeOnlineManagement module is more like a stub module and the first time it connects it goes ahead and downloads a refreshed version of the modules?!
Does it download the latest update to whatever version is installed (i.e. if ExchangeOnlineManagement version 3.2.0 is installed it downloads the latest revisions to that? or does it download the latest available version always – 3.4.0 as of writing? I don’t know and I didn’t test).
Am not sure why it does this weird behaviour though.
Once it gets the modules it also downloads a help file from https://outlook.office365.com/AdminApi/v1.0/<tenantId>/EXOHelpFile?Version=3.4.0. And then we get to the real meat of the business – which in this case, since I am running Get-EXOMailbox results in a GET request to https://outlook.office365.com/adminapi/beta/<tenantId>/Mailbox.
This doesn’t succeed – if I look at the Statistics tab I can seen it gets no reponse:
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 |
ClientConnected: 01:26:51.679 ClientBeginRequest: 01:26:51.709 GotRequestHeaders: 01:26:51.709 ClientDoneRequest: 01:26:51.709 Determine Gateway: 0ms DNS Lookup: 0ms TCP/IP Connect: 0ms HTTPS Handshake: 0ms ServerConnected: 01:26:51.694 FiddlerBeginRequest: 01:26:51.709 ServerGotRequest: 01:26:51.709 ServerBeginResponse: 00:00:00.000 GotResponseHeaders: 00:00:00.000 ServerDoneResponse: 00:00:00.000 ClientBeginResponse: 00:00:00.000 ClientDoneResponse: 00:00:00.000 |
And this the request is repeated a few times (6 times in my case) and eventually it hits some internal timeout or counter of the module I suppose and we are left with the error I get: Get-EXOMailbox: An error occurred while processing this request.
So, dear Microsoft person, you/ the teams you are escalating to have no real idea of how the ExchangeOnlineManagement module works because clearly you are unable to work out what it’s doing based on the Fiddler logs! (I told them so of course, in no uncertain terms, but not in the level of detail of this blog post).
What is interesting though, as an aside, is that the underlying REST API endpoint is actually a beta! Notice /adminapi/beta/<tenantId>/Mailbox. Wtf!? So while the ExchangeOnlineManagement module is not beta, the endpoints it query are actually beta. Which means what? I guess it means the endpoint URLs can change, the data they return can change… and nothing’s set in stone like a production endpoint.
This must be why the ExchangeOnlineManagement module downloads the latest version/ revision of the modules. Coz that’s how it cheats and can keep up with the ever changing beta endpoint. Sneaky, eh! 😀
Interestingly, there is a v1.0 endpoint too. I can just do:
|
1 |
Invoke-RestMethod -Uri "https://outlook.office365.com/AdminApi/v1.0/<tenantId>/Mailbox" -ContentType 'application/json' -Headers $headers |
And it works. (Well, it timed out in my case due to the throttling… but I didn’t get a 404 error or anything!)
As opposed to (I made it v2.0):
|
1 |
Invoke-RestMethod -Uri "https://outlook.office365.com/AdminApi/v2.0/<tenantId>/Mailbox" -ContentType 'application/json' -Headers $headers |
Which throws an error:
|
1 |
Invoke-RestMethod: Response status code does not indicate success: 404 (). |
I Googled on https://outlook.office365.com/AdminApi/v1.0/ and came across this article. Looks like this is the new Outlook Beta REST API, though it seems to use the URL format https://outlook.office.com/api/{version}/{user_context} which is different to what the module cmdlets are using, so I am not sure.
I found some more posts referencing this URL (though nothing helpful) as well as this blog post where someone made a similar discovery to me (albeit, 2 years ago! so we have been in beta for a while).
Anyhoo, not sure what I can do until Microsoft supports gets off their a$$ and sorts out our throttling issue. But it’s good to see the endpoint is in beta as it is really slow and crappy.