Search code examples
powershelljson.netazure-data-lakeu-sqlazure-automation

Submit-AdlJob fails with Method not Found when running in Azure Automation Runbook


I am attempting to schedule some U-SQL Scripts that I have previously run on Azure Data Lake Analytics via the Azure Automation Service (I did also attempt to do this in ADF but it also didn't work for me, I'll draw up another question to address that path).

This is simplified runbook code based on the MS Docs Guidance that still has the error for me:

$Conn = Get-AutomationConnection -Name AzureRunAsConnection
Connect-AzureRmAccount -ServicePrincipal `
 -Tenant $Conn.TenantID `
 -ApplicationId $Conn.ApplicationID `
 -CertificateThumbprint $Conn.CertificateThumbprint

$adla = "example_adla01"

$script = @"
@a  = 
    SELECT * FROM 
    (VALUES
        ("Contoso", 1500.0),
        ("Woodgrove", 2700.0)
    ) AS D( customer, amount );
OUTPUT @a
TO "/data.csv"
USING Outputters.Csv();
"@

Submit-AdlJob -AccountName $adla -Script $script -Name "Demo"

The version of the command being called.

CommandType  Name            Version   Source
-----------  ----            -------   ------                                    
Alias        Submit-AdlJob   4.2.3     AzureRM.DataLakeAnalytics   

This jobs runs fine in my local Powershell ISE and Cloud Shell; but fails in the Azure Automation Service Test runner with this error (updated to include a more verbose error):

Submit-AzureRmDataLakeAnalyticsJob : A command that prompts the user failed because the host program or the command type does not support user interaction. The host was attempting to request confirmation with the following message: 

Method not found: 'Newtonsoft.Json.Serialization.IAttributeProvider 
Newtonsoft.Json.Serialization.JsonProperty.get_AttributeProvider()'.
At line:23 char:1

+ Submit-AzureRmDataLakeAnalyticsJob -AccountName $adla -Script $script ...    
+ ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
+ CategoryInfo          : NotImplemented: (:) [Submit-AzureRmDataLakeAnalyticsJob], HostException
+ FullyQualifiedErrorId : HostFunctionNotImplemented,Microsoft.Azure.Commands.DataLakeAnalytics.SubmitAzureDataLakeAnalyticsJob

I have imported what I think are the correct modules and have been unable to find any additional ones that relate to JSON, or why the JSON Serializer is being called at all, this is otherwise a brand new Automation Instance that I stood up this morning.

enter image description here

Debug output for the command:

7:04:53 PM - SubmitAzureDataLakeAnalyticsJob begin processing with ParameterSet 'SubmitUSqlJob'.

7:04:53 PM - using account id 'xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx'...
[Common.Authentication]: Authenticating using Account: 'xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx', environment:  'AzureCloud', tenant: 'xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx'

Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 : 

04/23/2018 19:04:54:xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx - AcquireTokenForClientHandler: === Token Acquisition started:
    Authority: https://login.microsoftonline.com/xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx/
    Resource: https://management.core.windows.net/
    ClientId: xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx
    CacheType: Microsoft.Azure.Commands.Common.Authentication.AuthenticationStoreTokenCache (1 items)
    Authentication Target: Client


Microsoft.IdentityModel.Clients.ActiveDirectory Verbose: 1 : 04/23/2018 19:04:54: xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx - <RunAsync>d__0: Looking up cache for a token...
Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 : 04/23/2018 19:04:54: xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx - TokenCache: An item matching the requested resource was found in the cache
Microsoft.IdentityModel.Clients.ActiveDirectory Verbose: 1 : 04/23/2018 19:04:54: xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx - <RunAsync>d__0: 59.9101559033333 minutes left until token in cache expires
Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 : 04/23/2018 19:04:54: xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx - <RunAsync>d__0: A matching item (access token or refresh token or both) was found in the cache
Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :

04/23/2018 19:04:54: xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx - AcquireTokenHandlerBase: === Token Acquisition finished 
successfully. An access token was retuned:
    Access Token Hash: //removed
    Refresh Token Hash: [No Refresh Token]
    Expiration Time: 04/23/2018 20:04:48 +00:00
    User Hash: null


Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 : 04/23/2018 19:04:54:  - AuthenticationStoreTokenCache: Serializing token cache with 1 items.

[Common.Authentication]: Authenticating using Account: 'xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx', environment: 'AzureCloud', tenant: 'xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx'

Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 : 
04/23/2018 19:04:54: xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx - AcquireTokenForClientHandler: === Token Acquisition started:
    Authority: https://login.microsoftonline.com/xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx/
    Resource: https://datalake.azure.net/
    ClientId: xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx
    CacheType: Microsoft.Azure.Commands.Common.Authentication.AuthenticationStoreTokenCache (1 items)
    Authentication Target: Client
Microsoft.IdentityModel.Clients.ActiveDirectory Verbose: 1 : 04/23/2018 19:04:54: xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx - <RunAsync>d__0: Looking up cache for a token...
Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 : 04/23/2018 19:04:54: xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx - <RunAsync>d__0: No matching token was found in the cache
Microsoft.IdentityModel.Clients.ActiveDirectory Verbose: 1 : 04/23/2018 19:04:54: xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx - <RunAsync>d__0: Storing token in the cache...
Microsoft.IdentityModel.Clients.ActiveDirectory Verbose: 1 : 04/23/2018 19:04:54: xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx - <RunAsync>d__0: An item was stored in the cache

Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :

04/23/2018 19:04:54: xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx - AcquireTokenHandlerBase: === Token Acquisition finished successfully. An access token was retuned:
    Access Token Hash: //removed
    Refresh Token Hash: [No Refresh Token]
    Expiration Time: 04/23/2018 20:04:53 +00:00
    User Hash: null

Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 : 04/23/2018 19:04:54:  - AuthenticationStoreTokenCache: Serializing token cache with 2 items.
[Common.Authentication]: Authenticating using Account: 'xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx', environment: 'AzureCloud', tenant: 'xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx'

Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 : 

04/23/2018 19:04:54: 1cdd67fa-ce99-4931-b1aa-4ced126fa018 - AcquireTokenForClientHandler: === Token Acquisition started:
    Authority: https://login.microsoftonline.com/xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx/
    Resource: https://datalake.azure.net/
    ClientId: xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx
    CacheType: Microsoft.Azure.Commands.Common.Authentication.AuthenticationStoreTokenCache (2 items)
    Authentication Target: Client


Microsoft.IdentityModel.Clients.ActiveDirectory Verbose: 1 : 04/23/2018 19:04:54: xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx - <RunAsync>d__0: Looking up cache for a token...
Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 : 04/23/2018 19:04:54: xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx - TokenCache: An item matching the requested resource was found in the cache
Microsoft.IdentityModel.Clients.ActiveDirectory Verbose: 1 : 04/23/2018 19:04:54: xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx - <RunAsync>d__0: 59.9828124866667 minutes left until token in cache expires
Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 : 04/23/2018 19:04:54: xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx - <RunAsync>d__0: A matching item (access token or refresh token or both) was found in the cache
Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 :

04/23/2018 19:04:54: xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx - AcquireTokenHandlerBase: === Token Acquisition finished successfully. An access token was retuned:
    Access Token Hash: //remove
    Refresh Token Hash: [No Refresh Token]
    Expiration Time: 04/23/2018 20:04:53 +00:00
    User Hash: null

Microsoft.IdentityModel.Clients.ActiveDirectory Information: 2 : 04/23/2018 19:04:54:  - AuthenticationStoreTokenCache: Serializing token cache with 2 items.

Solution

  • It looks like since I opened this question a change was made and now I get a different (more useful error message).

    Environments                                                                                                            
    ------------                                                                                                            
    
    {[AzureUSGovernment, AzureUSGovernment], [AzureChinaCloud, AzureChinaCloud], 
    [AzureGermanCloud, AzureGermanCloud], [A...
    Submit-AzureRmDataLakeAnalyticsJob : The user is not authorized to perform this operation on storage.
    
    At line:21 char:1
    + Submit-AzureRmDataLakeAnalyticsJob -AccountName $adla -Script $script ...
    + ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
    + CategoryInfo          : CloseError: (:) [Submit-AzureRmDataLakeAnalyticsJob], CloudException
    + FullyQualifiedErrorId : Microsoft.Azure.Commands.DataLakeAnalytics.SubmitAzureDataLakeAnalyticsJob
    

    I had to add the Azure Automation RunAs Account to have access to the underlying Azure Data Lake Storage account, as while it inherited access to the compute from being a Contributor on the Subscription, it did not gain default permissions to the Azure Data Lake Storage Account.

    I did this from the Azure Data Lake "Add user wizard"

    I now see the Azure Automation user being able to trigger jobs against the Job Manager in the Azure Data Lake Analytics Blade.