Azure / AzureStack-Tools

Scripts and tools that help customers use Azure and Azure Stack
MIT License
240 stars 263 forks source link

FIXED: Az Registration script RegisterWithAzure.psm1 throwing -- InvalidRegistrationToken : The registration token is malformed. #597

Open tysonflint opened 3 years ago

tysonflint commented 3 years ago

I have deployed ASDK version 1.2008.0.59. The installation was successful. I am now trying to register the ASDK under one of my subscription's tenant. The resource group "azurestack" is successfully created in 'westcentralus' by the registration script, as I can see it show up in the Azure portal.
I've been deleting this resource group each time I reattempt the ASDK registration command.

I'm performing an AzureCloud deployment (not ADFS). I'm running it under the context of the global admin account of the tenant.

Here's my PowerShell version that I'm running:

$PSVersionTable.PSVersion
Major  Minor  Build  Revision
5      1      17763  10184

I'm running the "Az" branch of the AzureStack-Tools on GitHub: https://github.com/Azure/AzureStack-Tools/archive/az.zip

Here is what I'm using for the ASDK registration (with xxx in replacing sensitive info).

Connect-AzAccount -EnvironmentName "AzureCloud"
Register-AzResourceProvider -ProviderNamespace Microsoft.AzureStack
Get-AzSubscription -SubscriptionID "xxxxxxxx-xxxx-xxxx-xxxe-xxxxxxxxxxxx" -TenantId "xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx" | Set-AzContext
Register-AzResourceProvider -ProviderNamespace Microsoft.AzureStack
Import-Module C:\AzureStack-Tools-az\Registration\RegisterWithAzure.psm1
$CloudAdminCred = Get-Credential -UserName AZURESTACK\CloudAdmin -Message "Enter the credentials to access the privileged endpoint."
$RegistrationName = "TysonAsdkRegistration"
Set-AzsRegistration `
-PrivilegedEndpointCredential $CloudAdminCred `
-PrivilegedEndpoint AzS-ERCS01 `
-BillingModel Development `
-RegistrationName $RegistrationName `
-UsageReportingEnabled:$true

I am getting following error right after the resource group is created:

2021-02-26.00-35-06: InvalidRegistrationToken : The registration token is malformed.
2021-02-26.00-35-07: at New-RegistrationResource, C:\AzureStack-Tools-az\Registration\RegisterWithAzure.psm1: line 1386
at Set-AzsRegistration, C:\AzureStack-Tools-az\Registration\RegisterWithAzure.psm1: line 427
at <ScriptBlock>, <No file>: line 1

Line 1386 of RegisterWithAzure.psm1

    $registrationResource = New-AzResource @resourceCreationParams -Force
    Fails with message:
    InvalidRegistrationToken : The registration token is malformed.

It is called from:

Line 426 of RegisterWithAzure.psm1

New-RegistrationResource -ResourceGroupName $ResourceGroupName -ResourceGroupLocation $ResourceGroupLocation -RegistrationToken $RegistrationToken -RegistrationName $RegistrationName

The values of the variables in the above line look correct with the exception of the $RegistrationToken, which does not end in a double equal sign as I would expect.

I successfully registered my ASDK using this same tenant last year. I blew that ASDK install away to upgrade to 1.2008.0.59. I deleted the old resource group in Azure before attempting this registration. The only thing that might be different this time is that I'm using the newer Az modules, rather than the older AzureRM modules.

Here is the LOG, with my sensitive info XXX'ed out.

Do you have any ideas to try troubleshooting the validity of the $RegistrationToken.
Shouldn't a valid token end in "==", rather than just a single "=" ?

As a troubleshooting step, I also tried this:

Enter-PSSession -ComputerName AzS-ERCS01 -ConfigurationName PrivilegedEndpoint
New-RegistrationToken -BillingModel 'Development' -MarketplaceSyndicationEnabled:$true -UsageReportingEnabled:$true -AgreementNumber "" -MsAssetTag "" -TokenVersion "4.0"

The token returned by "New-RegistrationToken" on AzS-ERCS01 appears the same as the one returned by the RegisterWithAzure.psm1 script. Both tokens are 4096 chars long and end in a single "=".

I'm thinking the issue must be in one of three areas:

  1. There's an issue with the parameters that RegisterWithAzure.psm1 is sending over to "New-RegistrationToken" on AzS-ERCS01.
  2. The "New-RegistrationToken" on AzS-ERCS01 is generating an invalid token.
  3. Some external issue is causing this problem, like my Azure subscription or tenant in Azure. I haven't made any changes to my Azure subscriptions or tenants since I successfully registered an earlier version of the ASDK earlier last year.

I have not yet tried the AzureRM modules yet, as it appears those will be retired soon.

Thank you in advance for your ideas in troubleshooting!

==================================================================================

2021-02-26.00-30-06: *********************** Begin log: Set-AzsRegistration ***********************

2021-02-26.00-30-12: Gathering info from current Azure Powershell context...
2021-02-26.00-30-12: Current Azure Context: 
 {
    "Account":  {
                    "Id":  "tysonflint@xxxxxxxxxx.com",
                    "Type":  "User",
                    "Tenants":  [
                                    "xxxxxxxx-xxx-xxxx-xxx-xxxxxxxxxxx"
                                ],
                    "AccessToken":  null,
                    "Credential":  null,
                    "TenantMap":  {

                                  },
                    "CertificateThumbprint":  null,
                    "ExtendedProperties":  {
                                               "Subscriptions":  "xxxxxxxx-xxxxx-xxxx-xxx-xxxxxxxxxxxx,xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx",
                                               "Tenants":  "xxxxxxx-xxxx-xxx-xxxx-xxxxxxxxxxxx"
                                           }
                },
    "Tenant":  {
                   "Id":  "xxxxxxxx-xxxx-xxx-xxxx-xxxxxxxxxxxx",
                   "TenantId":  "xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx",
                   "ExtendedProperties":  {

                                          }
               },
    "Environment":  {
                        "Name":  "AzureCloud",
                        "EnableAdfsAuthentication":  false,
                        "OnPremise":  false,
                        "ActiveDirectoryServiceEndpointResourceId":  "https://management.core.windows.net/",
                        "AdTenant":  "Common",
                        "GalleryUrl":  "https://gallery.azure.com/",
                        "ManagementPortalUrl":  "https://go.microsoft.com/fwlink/?LinkId=254433",
                        "ServiceManagementUrl":  "https://management.core.windows.net/",
                        "PublishSettingsFileUrl":  "https://go.microsoft.com/fwlink/?LinkID=301775",
                        "ResourceManagerUrl":  "https://management.azure.com/",
                        "SqlDatabaseDnsSuffix":  ".database.windows.net",
                        "StorageEndpointSuffix":  "core.windows.net",
                        "ActiveDirectoryAuthority":  "https://login.microsoftonline.com/",
                        "GraphUrl":  "https://graph.windows.net/",
                        "GraphEndpointResourceId":  "https://graph.windows.net/",
                        "TrafficManagerDnsSuffix":  "trafficmanager.net",
                        "AzureKeyVaultDnsSuffix":  "vault.azure.net",
                        "DataLakeEndpointResourceId":  "https://datalake.azure.net/",
                        "AzureDataLakeStoreFileSystemEndpointSuffix":  "azuredatalakestore.net",
                        "AzureDataLakeAnalyticsCatalogAndJobEndpointSuffix":  "azuredatalakeanalytics.net",
                        "AzureKeyVaultServiceEndpointResourceId":  "https://vault.azure.net",
                        "AzureOperationalInsightsEndpointResourceId":  "https://api.loganalytics.io",
                        "AzureOperationalInsightsEndpoint":  "https://api.loganalytics.io/v1",
                        "AzureAnalysisServicesEndpointSuffix":  "asazure.windows.net",
                        "AnalysisServicesEndpointResourceId":  "https://region.asazure.windows.net",
                        "AzureAttestationServiceEndpointSuffix":  "attest.azure.net",
                        "AzureAttestationServiceEndpointResourceId":  "https://attest.azure.net",
                        "VersionProfiles":  [

                                            ],
                        "ExtendedProperties":  {
                                                   "OperationalInsightsEndpoint":  "https://api.loganalytics.io/v1",
                                                   "OperationalInsightsEndpointResourceId":  "https://api.loganalytics.io",
                                                   "AzureAnalysisServicesEndpointSuffix":  "asazure.windows.net",
                                                   "AnalysisServicesEndpointResourceId":  "https://region.asazure.windows.net",
                                                   "AzureAttestationServiceEndpointSuffix":  "attest.azure.net",
                                                   "AzureAttestationServiceEndpointResourceId":  "https://attest.azure.net"
                                               },
                        "BatchEndpointResourceId":  "https://batch.core.windows.net/"
                    },
    "Subscription":  {
                         "Id":  "xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx",
                         "Name":  "Pay-As-You-Go",
                         "State":  "Enabled",
                         "SubscriptionId":  "xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx",
                         "TenantId":  "xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx",
                         "CurrentStorageAccountName":  null,
                         "ExtendedProperties":  {
                                                    "Account":  "tysonflint@xxxxxxxxxxxxxx.com",
                                                    "Tenants":  "xxxxxxxx-xxx-xxxx-xxxx-xxxxxxxxxxxx",
                                                    "Environment":  "AzureCloud"
                                                },
                         "CurrentStorageAccount":  null
                     }
}
2021-02-26.00-30-12: Initializing session with privileged endpoint: AzS-ERCS01. Attempt 0 of 3
2021-02-26.00-30-35: Connection to AzS-ERCS01 successful
2021-02-26.00-30-35: Verifying stamp version.
2021-02-26.00-30-45: Running registration actions on build 1.2008.0.59. Cloud Id: xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx, Deployment Id: xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx
2021-02-26.00-30-46: Creating Azure Active Directory service principal in tenant 'xxxxxxxx-xxxx-xxx-xxxx-xxxxxxxxxxxx' Attempt 0 of 3
2021-02-26.00-33-58: Service principal created and Azure bridge configured. ObjectId: xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxx
2021-02-26.00-33-58: Get-RegistrationToken parameters: {
    "AgreementNumber":  "",
    "MarketplaceSyndicationEnabled":  {
                                          "IsPresent":  true
                                      },
    "MsAssetTag":  "",
    "TokenVersion":  "4.0",
    "UsageReportingEnabled":  {
                                  "IsPresent":  true
                              },
    "BillingModel":  "Development"
}
2021-02-26.00-33-58: Creating registration token. Attempt 0 of 3
2021-02-26.00-34-28: Registration token created.
2021-02-26.00-34-28: Creating registration resource at ResourceGroupLocation: westcentralus
2021-02-26.00-34-28: Registering Azure Stack resource provider.
2021-02-26.00-34-30: Resource provider registered.
2021-02-26.00-34-30: Resource creation params: {
    "ResourceType":  "Microsoft.AzureStack/registrations",
    "ResourceName":  "TysonAsdkRegistration",
    "Properties":  {
                       "registrationToken":  "eyJBZ3Jxxxx <There are 4096 bytes in this string, the ending does not end in a double equals sign like it has in the past.> xxxXX0="
                   },
    "ResourceGroupName":  "azurestack",
    "ApiVersion":  "2017-06-01",
    "Location":  "Global"
}
2021-02-26.00-34-31: Creating resource group 'azurestack' in location westcentralus.
2021-02-26.00-34-32: Creating registration resource...
2021-02-26.00-34-33: *** WARNING ***
2021-02-26.00-34-33: Creation of Azure resource failed:
InvalidRegistrationToken : The registration token is malformed.
2021-02-26.00-34-33: *** End WARNING ***
2021-02-26.00-34-33: Waiting 10 seconds and trying again...
2021-02-26.00-34-43: Creating registration resource...
2021-02-26.00-34-45: *** WARNING ***
2021-02-26.00-34-45: Creation of Azure resource failed:
InvalidRegistrationToken : The registration token is malformed.
2021-02-26.00-34-45: *** End WARNING ***
2021-02-26.00-34-45: Waiting 10 seconds and trying again...
2021-02-26.00-34-55: Creating registration resource...
2021-02-26.00-34-56: *** WARNING ***
2021-02-26.00-34-56: Creation of Azure resource failed:
InvalidRegistrationToken : The registration token is malformed.
2021-02-26.00-34-56: *** End WARNING ***
2021-02-26.00-34-56: Waiting 10 seconds and trying again...
2021-02-26.00-35-06: ************************ Error ************************
2021-02-26.00-35-06: InvalidRegistrationToken : The registration token is malformed.
2021-02-26.00-35-07: at New-RegistrationResource, C:\AzureStack-Tools-az\Registration\RegisterWithAzure.psm1: line 1386
at Set-AzsRegistration, C:\AzureStack-Tools-az\Registration\RegisterWithAzure.psm1: line 427
at <ScriptBlock>, <No file>: line 1
2021-02-26.00-35-07: *********************** Ending registration action during New-RegistrationResource ***********************

2021-02-26.00-35-07: Logs can be found at: C:\MASLogs\Registration\AzureStack.Activation.Set-AzsRegistration-2021-02-26.log  and  \\AzS-ERCS01\c$\maslogs 

2021-02-26.00-35-07: Removing any existing PSSession...
tysonflint commented 3 years ago

I have worked through this issue and have successfully registered my ASDK. The issue was a Win32_PhysicalMemory WMI query incorrectly returning the number of slots of RAM (returning 21 slots instead of 32, and returning 32 MB per slot, rather than 32GB per slot. It is almost like the WMI query was returning the total RAM across all CPU sockets for each slot. For example, my MB has 4 CPUs, of 8 slots each, each with 8GB of RAM, but the WMI query would report something like all slot1 memory across all CPU sockets, returning slot1=32MB, slot2=32MB, [...] up to 21 times (rather than the expected 32 times). Ideally, if done correctly, it would have reported on a per slot per socket basis, and returned 8GB 32 times (once per physical slot per physical CPU socket). Since the WMI query was also returning number of bytes, incorrectly by a factor of 1000, I was considering the bad workaround of dividing by 1MB rather than 1GB, but found a better solution.

Both of these two WMI issues (number of slots, and MB instead of GB) were worked around by not using the WMI query and using the "CsTotalPhysicalMemory" property of "get-computerinfo", which is shown further below.

In summary, this is the file with the line of text responsible for the issue: \\AzS-ERCS01\c$\Program Files\WindowsPowerShell\Modules\Microsoft.AzureStack.Activation\Microsoft.Azurestack.Activation.psm1

This is the line responsible for the issue: TotalMemoryInGB = ((Get-WmiObject -Class Win32_PhysicalMemory -Namespace "root\CIMV2" -ComputerName $hostName | Microsoft.PowerShell.Utility\Measure-Object -Property Capacity -Sum).Sum/1GB)

It can be fixed by replacing it with: TotalMemoryInGB = [math]::round($(get-computerinfo).CsTotalPhysicalMemory/1GB)

Below are the details on how I figured it out.

============================================================================

I opened a remote PowerShell session to AzS-ERCS01: Enter-PSSession -ComputerName AzS-ERCS01 -ConfigurationName PrivilegedEndpoint

I entered the following command to AS-ERCS01 , which was being used in C:\AzureStack-Tools-az\Registration\RegisterWithAzure.psm1

New-RegistrationToken -BillingModel 'Development' -MarketplaceSyndicationEnabled:$true -UsageReportingEnabled:$true -AgreementNumber "" -MsAssetTag "" -TokenVersion "4.0"

This gave me the same registration token that was in the output of the registration script, to use for troubleshooting. While still in the AzS-ERCS01 remote session, I entered the following:

get-command New-RegistrationToken

Which returned:

CommandType     Name                                               Version    Source
-----------     ----                                               -------    ------
Function        New-RegistrationToken                              0.0        Microsoft.Azurestack.Activation

I then knew to look into a module called "Microsoft.Azurestack.Activation" to see how the registration token was being formed.

I found the module responsible for the token here: \\AzS-ERCS01\c$\Program Files\WindowsPowerShell\Modules\Microsoft.AzureStack.Activation\Microsoft.Azurestack.Activation.psm1

The code responsible for creating forming the token is in between lines 272 and go to 290.

        $registration = @{
            BillingModel         = $BillingModel
            AgreementNumber      = $AgreementNumber
            MarketplaceSyndicationEnabled    = $MarketplaceSyndicationEnabled.ToBool()
            UsageReportingEnabled            = $UsageReportingEnabled.ToBool()
            ObjectId             = $stampInfo.ObjectId
            CloudId              = $stampInfo.CloudId
            Issuer               = $stampInfo.Issuer
            RegionNames          = $stampInfo.RegionNames
            HardwareInfo         = $stampInfo.HardwareInfo
            StampVersion         = $stampInfo.StampVersion
            Version              = $TokenVersion
            MsAssetTag           = $MsAssetTag
        } | ConvertTo-Json -Compress -Depth 4

        Write-Log "Creating registration token: $registration"

        $buffer = [System.Text.Encoding]::UTF8.GetBytes($registration)
        $registrationToken = [Convert]::ToBase64String($buffer)

I pasted my registration token (the output of the New-RegistrationToken command above) into a variable called $registrationtoken. I then converted the string to a byte array:

$registrationTokenAsByteArray = [Convert]::FromBase64String(I $registrationTokenString)

Then from the byte array to a string: $originalRegistration = [System.Text.Encoding]::UTF8.GetString($bufferOfUtf8ByteArray)

I was then left with about a 3000 character single line of text that was human readable but all squished onto a single line. I pasted it into Notepad++ and reformatted into something more friendly using the "Hex Editor" plugin, by searching for a the hex value of a comma (2c), and replacing with a comma followed by carriage return line feed (2c 0d 0a). I then tabbed out the sections based on curly braces and separated the sections with carriage returns.

I did this again for my registration token that I had recorded from a prior successful ASDK registration from last year on build 1.1910.0.58 and compared it to the 1.2008.0.59 token. I used ComareIt to compare the two human readable registration arrays. In CompareIt I shifted a few blocks of text around in order to bring the two registration arrays in synch and found the following changes between build 1910 and 2008.

New values in registration array compared between build 1910 and 2008:

"Version":"4.0" (was "Version":"2.0" in ASDK build 1910)
"MsAssetTag":"" (didn't exist in build 1910)
"Model":"H8QM3" (my motherboard model, didn't exist in 1910)
"SerialNumber":"1234567890" (my motherboard serial number, didn't exist in 1910)
"TotalMemoryInGB":0.65625 (the total RAM of my ASDK host, which didn't exist in 1910).

Seeing the "TotalMemoryInGB" value of 0.65625 GB did not make sense to me, since my ASDK host has 256GB installed. I found that $stampInfo.HardwareInfo was being generated from a function in Microsoft.Azurestack.Activation.psm1 called GetHardwareInfo(), by the following line:

TotalMemoryInGB = ((Get-WmiObject -Class Win32_PhysicalMemory -Namespace "root\CIMV2" -ComputerName $hostName | Microsoft.PowerShell.Utility\Measure-Object -Property Capacity -Sum).Sum/1GB)

This line looked like it might be suspect, so I ran the following WMI query:

Get-WmiObject -Class Win32_PhysicalMemory -Namespace "root\CIMV2" | %{$_.Capacity}

It returned the following, incorrectly saying that I have 21 slots of 32MB sticks.

33554432 33554432 33554432 33554432 33554432 33554432 33554432 33554432 33554432 33554432 33554432 33554432 33554432 33554432 33554432 33554432 33554432 33554432 33554432 33554432 33554432

Summing them together: (Get-WmiObject -Class Win32_PhysicalMemory -Namespace "root\CIMV2" | %{$_.Capacity} | measure-object -sum).sum Returns: 704643072 (about 700MB)

Dividing by 1GB: (Get-WmiObject -Class Win32_PhysicalMemory -Namespace "root\CIMV2" | %{$_.Capacity} | measure-object -sum).sum / 1GB Returns: 0.65625 (just over half a GB)

My ASDK host actually has 4 sockets of AMD Opteron 8439 hexa-core CPUs (4x6 = 24 total cores), each CPU has 8 RAM slots fully populated with 8GB sticks (4x8x8 = 256GB total). The WMI query is at fault, saying that it has just over half a GB of RAM.

The WMI query should have returned 8589934592 (8GB sticks) and returned it 32 times (rather than 21), as the motherboard has 32 memory slots that are fully populated. The sum of which should have been 274877906944 (256GB).

I commented out the line with the faulty WMI query and added a line to replace it: TotalMemoryInGB = [math]::round($(get-computerinfo).CsTotalPhysicalMemory/1GB)

This correctly set TotalMemoryInGB=256, and fixed the malformed registration token error, allowing my ASDK to successfully register.

Please update the function GetHardwareInfo() in \\AzS-ERCS01\c$\Program Files\WindowsPowerShell\Modules\Microsoft.AzureStack.Activation\Microsoft.Azurestack.Activation.psm1 so the TotalMemoryInGB is based upon the line of code above.

The fix above will allow those of us with these older AMD Opteron motherboards to continue to use the ASDK with the Azure marketplace in our affordable home-built labs. If you decide not to update with this fix, then please let this comment remain for those of us in the future who would like to have a process to troubleshoot malformed oken related issues.

I am very glad to finally see this: VERBOSE: 2021-03-15.04-38-24: Your environment is now registered and activated using the provided parameters.

keystroke commented 3 years ago