SqlServerDsc icon indicating copy to clipboard operation
SqlServerDsc copied to clipboard

SqlLogin: Got message "Failed to invoke DSC Test method: An internal error occurred" when user disabled

Open mrpk1906 opened this issue 5 years ago • 9 comments

Details of the scenario you tried and the problem that is occurring

I'm using ansible with win_dsc module to create an user

  - name: Create user
    win_dsc:
      resource_name: SqlLogin
      Ensure: "{% if db_state == 'absent' %}Absent{% else %}Present{% endif %}"
      Name: "{{ db_user }}"
      LoginType: SqlLogin
      ServerName: "localhost"
      InstanceName: "MSSQLSERVER"
      LoginCredential_username: "{{ db_user }}"
      LoginCredential_password: "{{ db_password }}"
      LoginMustChangePassword: false
      LoginPasswordExpirationEnabled: false
      LoginPasswordPolicyEnforced: false
      Disabled: "{% if db_state == 'disabled' %}True{% else %}False{% endif %}"
    register: mssql_create_user
    when: install_psmodule_dbsrv is succeeded and mssql_service.state == 'running'

If user doesn't exist before, task runs successfully

But if user has exist and disabled, task failed with an error message: Failed to invoke DSC Test method: An internal error occurred.

Verbose logs showing the problem

TASK [create_user : MSSQL: Create user] **************************************************************************************************************************************************************************************************************
fatal: [mssqlserver.com]: FAILED! => {
    "changed": false,
    "module_version": "14.2.1",
    "reboot_required": false
}

MSG:

Failed to invoke DSC Test method: An internal error occurred.

Suggested solution to the issue

I enabled this user then re-run ansible, task ran successfully Maybe we need check if user has been disabled first

SQL Server edition and version the target node is running

Microsoft SQL Server 2016 (RTM) - 13.0.1601.5 (X64) Apr 29 2016 23:23:58 Copyright (c) Microsoft Corporation Enterprise Evaluation Edition (64-bit) on Windows Server 2016 Standard 6.3 <X64> (Build 14393: ) (Hypervisor)

SQL Server PowerShell modules present on the target node

PS C:\Users\Administrator> Get-Module -Name 'sql' -ListAvailable | ? Name -ne 'SqlServerDsc' | ft Name,Version,Path

Name Version Path


SQLPS 1.0 C:\Program Files (x86)\Microsoft SQL Server\130\Tools\PowerShell\Modules\SQLPS\SQLPS.psd1

The operating system the target node is running

OsName : Microsoft Windows Server 2016 Standard OsOperatingSystemSKU : StandardServerEdition OsArchitecture : 64-bit WindowsBuildLabEx : 14393.2580.amd64fre.rs1_release_inmarket.181009-1745 OsLanguage : en-US OsMuiLanguages : {en-US}

Version and build of PowerShell the target node is running

PS C:\Users\Administrator> $PSVersionTable

Name Value


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

Version of the DSC module that was used

PS C:\Users\Administrator> Get-Module -Name 'SqlServerDsc' -ListAvailable | ft Name,Version,Path

Name Version Path


SqlServerDsc 14.2.1 C:\Program Files\WindowsPowerShell\Modules\SqlServerDsc\14.2.1\SqlServerDsc.psd1

mrpk1906 avatar Sep 10 '20 15:09 mrpk1906

Since you are passing LoginCredential the resource tries to validate the password. I'm guessing it might be what fails. There are code to handle this, but there can be yet another error being thrown that is not caught correctly. See code below of what I'm guessing could be failing. Could you try to see if you can find out what part of the code is failing? Verbose messages could be helpful here to see how far it gets. When we know what part is failing we can focus on trying to get the full error message to see if there is more information in an InnerException that we need to handle.

https://github.com/dsccommunity/SqlServerDsc/blob/4a425ead398d67e4b616720e095b7ab885e9fb82/source/DSCResources/DSC_SqlLogin/DSC_SqlLogin.psm1#L536-L592

johlju avatar Sep 12 '20 16:09 johlju

Hi @johlju,

I tried run with verbose mode, this is exception:

System.Exception: System.InvalidOperationException: Failed to connect to SQL instance 'localhost'. (SQLCOMMON0019) ---> System.Management.Automation.MethodInvocationException: Exception calling \"Connect\" with \"0\" argument(s): \"Failed to connect to server localhost.\" ---> Microsoft.SqlServer.Management.Common.ConnectionFailureException: Failed to connect to server localhost. ---> System.Data.SqlClient.SqlException: Login failed for user 'test_user'. Reason: The account is disabled.
   at System.Data.SqlClient.SqlInternalConnectionTds..ctor(DbConnectionPoolIdentity identity, SqlConnectionString connectionOptions, SqlCredential credential, Object providerInfo, String newPassword, SecureString newSecurePassword, Boolean redirectedUserInstance, SqlConnectionString userConnectionOptions, SessionData reconnectSessionData, DbConnectionPool pool, String accessToken, Boolean applyTransientFaultHandling, SqlAuthenticationProviderManager sqlAuthProviderManager)
   at System.Data.SqlClient.SqlConnectionFactory.CreateConnection(DbConnectionOptions options, DbConnectionPoolKey poolKey, Object poolGroupProviderInfo, DbConnectionPool pool, DbConnection owningConnection, DbConnectionOptions userOptions)
   at System.Data.ProviderBase.DbConnectionFactory.CreatePooledConnection(DbConnectionPool pool, DbConnection owningObject, DbConnectionOptions options, DbConnectionPoolKey poolKey, DbConnectionOptions userOptions)
   at System.Data.ProviderBase.DbConnectionPool.CreateObject(DbConnection owningObject, DbConnectionOptions userOptions, DbConnectionInternal oldConnection)
   at System.Data.ProviderBase.DbConnectionPool.UserCreateRequest(DbConnection owningObject, DbConnectionOptions userOptions, DbConnectionInternal oldConnection)
   at System.Data.ProviderBase.DbConnectionPool.TryGetConnection(DbConnection owningObject, UInt32 waitForMultipleObjectsTimeout, Boolean allowCreate, Boolean onlyOneCheckConnection, DbConnectionOptions userOptions, DbConnectionInternal& connection)
   at System.Data.ProviderBase.DbConnectionPool.TryGetConnection(DbConnection owningObject, TaskCompletionSource`1 retry, DbConnectionOptions userOptions, DbConnectionInternal& connection)
   at System.Data.ProviderBase.DbConnectionFactory.TryGetConnection(DbConnection owningConnection, TaskCompletionSource`1 retry, DbConnectionOptions userOptions, DbConnectionInternal oldConnection, DbConnectionInternal& connection)
   at System.Data.ProviderBase.DbConnectionInternal.TryOpenConnectionInternal(DbConnection outerConnection, DbConnectionFactory connectionFactory, TaskCompletionSource`1 retry, DbConnectionOptions userOptions)
   at System.Data.SqlClient.SqlConnection.TryOpenInner(TaskCompletionSource`1 retry)
   at System.Data.SqlClient.SqlConnection.TryOpen(TaskCompletionSource`1 retry)
   at System.Data.SqlClient.SqlConnection.Open()
   at Microsoft.SqlServer.Management.Common.ConnectionManager.InternalConnect(WindowsIdentity impersonatedIdentity)
   at Microsoft.SqlServer.Management.Common.ConnectionManager.Connect()
   --- End of inner exception stack trace ---
   at Microsoft.SqlServer.Management.Common.ConnectionManager.Connect()
   at CallSite.Target(Closure , CallSite , Object )
   --- End of inner exception stack trace ---
   at System.Management.Automation.ExceptionHandlingOps.CheckActionPreference(FunctionContext funcContext, Exception exception)
   at System.Management.Automation.Interpreter.ActionCallInstruction`2.Run(InterpretedFrame frame)
   at System.Management.Automation.Interpreter.EnterTryCatchFinallyInstruction.Run(InterpretedFrame frame)
   at System.Management.Automation.Interpreter.EnterTryCatchFinallyInstruction.Run(InterpretedFrame frame)
   --- End of inner exception stack trace ---

System.Data.SqlClient.SqlException: Login failed for user 'test_user'. Reason: The account is disabled.

I saw exception doesn't have a error number

mrpk1906 avatar Sep 13 '20 06:09 mrpk1906

This issue has been automatically marked as stale because it has not had activity from the community in the last 30 days. It will be closed if no further activity occurs within 10 days. If the issue is labelled with any of the work labels (e.g bug, enhancement, documentation, or tests) then the issue will not auto-close.

stale[bot] avatar Oct 13 '20 06:10 stale[bot]

This issue has been automatically closed because it is has not had activity from the community in the last 40 days.

stale[bot] avatar Nov 22 '20 06:11 stale[bot]

Reopening this as this seems like a bug.

johlju avatar Nov 22 '20 11:11 johlju

i also think this is a bug. i think in the resource row 548 if ($Disabled) should be if ($LoginCredential.Disabled)

as it is, if the login on the server is disabled, but in the configuration it is not, then row 550..581 is not run.

like @mrpk1906 says, enabling the sqluser fixes the problem.

Fiander avatar Dec 06 '20 13:12 Fiander

@mrpk1906 Sorry it tooks so long to get back on this, but there have been a lot with they day job.

I saw exception doesn't have a error number

@mrpk1906 the error might not be outputted or the error you get does not have a number. Is it possible for you to debug the resources and manually look into the ErrorRecord. There are probably nested inner exceptions and one of them is the error System.Data.SqlClient.SqlException: Login failed for user 'test_user'. Reason: The account is disabled. in your output above.

I think this is what throws, and the error record is found in $_, e.g. $_.Exception.InnerException

https://github.com/dsccommunity/SqlServerDsc/blob/458ff92c6a203e0fb50c4e2c6a3021fa0dae9511/source/DSCResources/DSC_SqlLogin/DSC_SqlLogin.psm1#L578-L580

Between line 578 and 579 above, can you add this snippet and run again, it will output all the inner exceptions as verbose messages, hopefully they get an indication of how we can catch this error.

function Write-Exception
{
    # Define parameters
    param
    (
        [Parameter(Mandatory = $true)]
        [System.Exception]
        $ExceptionToSearch
    )

    Write-Verbose -Message '***EXCEPTION START' -Verbose
    Write-Verbose -Message ('***Exception Message: {0}' -f $ExceptionToSearch.Message) -Verbose
    Write-Verbose -Message ('***Exception Number: {0}' -f $ExceptionToSearch.Number) -Verbose
    Write-Verbose -Message ('***Exception Type: {0}' -f $ExceptionToSearch.GetType().Name) -Verbose
    Write-Verbose -Message ('***Exception BaseType: {0}' -f $ExceptionToSearch.GetType().BaseType) -Verbose
    Write-Verbose -Message ('***Exception: {0}' -f ($ExceptionToSearch | Out-String) ) -Verbose
    Write-Verbose -Message '***EXCEPTION END' -Verbose

    if ($ExceptionToSearch.InnerException)
    {
        $errorFound = Write-Exception -ExceptionToSearch $ExceptionToSearch.InnerException
    }
}


Write-Exception -ExceptionToSearch $_.Exception

johlju avatar Dec 24 '20 12:12 johlju

@mrpk1906 Sorry it tooks so long to get back on this, but there have been a lot with they day job.

I saw exception doesn't have a error number

@mrpk1906 the error might not be outputted or the error you get does not have a number. Is it possible for you to debug the resources and manually look into the ErrorRecord. There are probably nested inner exceptions and one of them is the error System.Data.SqlClient.SqlException: Login failed for user 'test_user'. Reason: The account is disabled. in your output above.

I think this is what throws, and the error record is found in $_, e.g. $_.Exception.InnerException

https://github.com/dsccommunity/SqlServerDsc/blob/458ff92c6a203e0fb50c4e2c6a3021fa0dae9511/source/DSCResources/DSC_SqlLogin/DSC_SqlLogin.psm1#L578-L580

Between line 578 and 579 above, can you add this snippet and run again, it will output all the inner exceptions as verbose messages, hopefully they get an indication of how we can catch this error.

function Write-Exception
{
    # Define parameters
    param
    (
        [Parameter(Mandatory = $true)]
        [System.Exception]
        $ExceptionToSearch
    )

    Write-Verbose -Message '***EXCEPTION START' -Verbose
    Write-Verbose -Message ('***Exception Message: {0}' -f $ExceptionToSearch.Message) -Verbose
    Write-Verbose -Message ('***Exception Number: {0}' -f $ExceptionToSearch.Number) -Verbose
    Write-Verbose -Message ('***Exception Type: {0}' -f $ExceptionToSearch.GetType().Name) -Verbose
    Write-Verbose -Message ('***Exception BaseType: {0}' -f $ExceptionToSearch.GetType().BaseType) -Verbose
    Write-Verbose -Message ('***Exception: {0}' -f ($ExceptionToSearch | Out-String) ) -Verbose
    Write-Verbose -Message '***EXCEPTION END' -Verbose

    if ($ExceptionToSearch.InnerException)
    {
        $errorFound = Write-Exception -ExceptionToSearch $ExceptionToSearch.InnerException
    }
}


Write-Exception -ExceptionToSearch $_.Exception

Hi @johlju,

I added snippet above then run again, this is output:

[[SqlLogin]DirectResourceAccess] ***EXCEPTION START
[[SqlLogin]DirectResourceAccess] ***Exception Message: System.InvalidOperationException: Failed to connect to SQL instance 'localhost'. (SQLCOMMON0019) ---> System.Management.Automation.MethodInvocationException: Exception calling "Connect" with "0" argument(s): "Failed to connect to server localhost." ---> Microsoft.SqlServer.Management.Common.ConnectionFailureException: Failed to connect to server localhost. ---> System.Data.SqlClient.SqlException: Login failed for user 'test_user'. Reason: The account is disabled.
   at System.Data.SqlClient.SqlInternalConnectionTds..ctor(DbConnectionPoolIdentity identity, SqlConnectionString connectionOptions, SqlCredential credential, Object providerInfo, String newPassword, SecureString newSecurePassword, Boolean redirectedUserInstance, SqlConnectionString userConnectionOptions, SessionData reconnectSessionData, DbConnectionPool pool, String accessToken, Boolean applyTransientFaultHandling, SqlAuthenticationProviderManager sqlAuthProviderManager)
   at System.Data.SqlClient.SqlConnectionFactory.CreateConnection(DbConnectionOptions options, DbConnectionPoolKey poolKey, Object poolGroupProviderInfo, DbConnectionPool pool, DbConnection owningConnection, DbConnectionOptions userOptions)
   at System.Data.ProviderBase.DbConnectionFactory.CreatePooledConnection(DbConnectionPool pool, DbConnection owningObject, DbConnectionOptions options, DbConnectionPoolKey poolKey, DbConnectionOptions userOptions)
   at System.Data.ProviderBase.DbConnectionPool.CreateObject(DbConnection owningObject, DbConnectionOptions userOptions, DbConnectionInternal oldConnection)
   at System.Data.ProviderBase.DbConnectionPool.UserCreateRequest(DbConnection owningObject, DbConnectionOptions userOptions, DbConnectionInternal oldConnection)
   at System.Data.ProviderBase.DbConnectionPool.TryGetConnection(DbConnection owningObject, UInt32 waitForMultipleObjectsTimeout, Boolean allowCreate, Boolean onlyOneCheckConnection, DbConnectionOptions userOptions, DbConnectionInternal& connection)
   at System.Data.ProviderBase.DbConnectionPool.TryGetConnection(DbConnection owningObject, TaskCompletionSource`1 retry, DbConnectionOptions userOptions, DbConnectionInternal& connection)
   at System.Data.ProviderBase.DbConnectionFactory.TryGetConnection(DbConnection owningConnection, TaskCompletionSource`1 retry, DbConnectionOptions userOptions, DbConnectionInternal oldConnection, DbConnectionInternal& connection)
   at System.Data.ProviderBase.DbConnectionInternal.TryOpenConnectionInternal(DbConnection outerConnection, DbConnectionFactory connectionFactory, TaskCompletionSource`1 retry, DbConnectionOptions userOptions)
   at System.Data.SqlClient.SqlConnection.TryOpenInner(TaskCompletionSource`1 retry)
   at System.Data.SqlClient.SqlConnection.TryOpen(TaskCompletionSource`1 retry)
   at System.Data.SqlClient.SqlConnection.Open()
   at Microsoft.SqlServer.Management.Common.ConnectionManager.InternalConnect(WindowsIdentity impersonatedIdentity)
   at Microsoft.SqlServer.Management.Common.ConnectionManager.Connect()
   --- End of inner exception stack trace ---
   at Microsoft.SqlServer.Management.Common.ConnectionManager.Connect()
   at CallSite.Target(Closure , CallSite , Object )
   --- End of inner exception stack trace ---
   at System.Management.Automation.ExceptionHandlingOps.CheckActionPreference(FunctionContext funcContext, Exception exception)
   at System.Management.Automation.Interpreter.ActionCallInstruction`2.Run(InterpretedFrame frame)
   at System.Management.Automation.Interpreter.EnterTryCatchFinallyInstruction.Run(InterpretedFrame frame)
   at System.Management.Automation.Interpreter.EnterTryCatchFinallyInstruction.Run(InterpretedFrame frame)
   --- End of inner exception stack trace ---
[[SqlLogin]DirectResourceAccess] ***Exception Number:
[[SqlLogin]DirectResourceAccess] ***Exception Type: Exception
[[SqlLogin]DirectResourceAccess] ***Exception BaseType: System.Object
[[SqlLogin]DirectResourceAccess] ***Exception:
				 Message        : System.InvalidOperationException: Failed to connect to SQL instance 'localhost'. (SQLCOMMON0019) ---> 
                 System.Management.Automation.MethodInvocationException: Exception calling "Connect" with "0" 
                 argument(s): "Failed to connect to server localhost." ---> 
                 Microsoft.SqlServer.Management.Common.ConnectionFailureException: Failed to connect to server 
                 localhost. ---> System.Data.SqlClient.SqlException: Login failed for user 'test_user'. Reason: 
                 The account is disabled.
                    at System.Data.SqlClient.SqlInternalConnectionTds..ctor(DbConnectionPoolIdentity identity, 
                 SqlConnectionString connectionOptions, SqlCredential credential, Object providerInfo, String 
                 newPassword, SecureString newSecurePassword, Boolean redirectedUserInstance, SqlConnectionString 
                 userConnectionOptions, SessionData reconnectSessionData, DbConnectionPool pool, String accessToken, 
                 Boolean applyTransientFaultHandling, SqlAuthenticationProviderManager sqlAuthProviderManager)
                    at System.Data.SqlClient.SqlConnectionFactory.CreateConnection(DbConnectionOptions options, 
                 DbConnectionPoolKey poolKey, Object poolGroupProviderInfo, DbConnectionPool pool, DbConnection 
                 owningConnection, DbConnectionOptions userOptions)
                    at System.Data.ProviderBase.DbConnectionFactory.CreatePooledConnection(DbConnectionPool pool, 
                 DbConnection owningObject, DbConnectionOptions options, DbConnectionPoolKey poolKey, 
                 DbConnectionOptions userOptions)
                    at System.Data.ProviderBase.DbConnectionPool.CreateObject(DbConnection owningObject, 
                 DbConnectionOptions userOptions, DbConnectionInternal oldConnection)
                    at System.Data.ProviderBase.DbConnectionPool.UserCreateRequest(DbConnection owningObject, 
                 DbConnectionOptions userOptions, DbConnectionInternal oldConnection)
                    at System.Data.ProviderBase.DbConnectionPool.TryGetConnection(DbConnection owningObject, UInt32 
                 waitForMultipleObjectsTimeout, Boolean allowCreate, Boolean onlyOneCheckConnection, 
                 DbConnectionOptions userOptions, DbConnectionInternal& connection)
                    at System.Data.ProviderBase.DbConnectionPool.TryGetConnection(DbConnection owningObject, 
                 TaskCompletionSource`1 retry, DbConnectionOptions userOptions, DbConnectionInternal& connection)
                    at System.Data.ProviderBase.DbConnectionFactory.TryGetConnection(DbConnection owningConnection, 
                 TaskCompletionSource`1 retry, DbConnectionOptions userOptions, DbConnectionInternal oldConnection, 
                 DbConnectionInternal& connection)
                    at System.Data.ProviderBase.DbConnectionInternal.TryOpenConnectionInternal(DbConnection 
                 outerConnection, DbConnectionFactory connectionFactory, TaskCompletionSource`1 retry, 
                 DbConnectionOptions userOptions)
                    at System.Data.SqlClient.SqlConnection.TryOpenInner(TaskCompletionSource`1 retry)
                    at System.Data.SqlClient.SqlConnection.TryOpen(TaskCompletionSource`1 retry)
                    at System.Data.SqlClient.SqlConnection.Open()
                    at Microsoft.SqlServer.Management.Common.ConnectionManager.InternalConnect(WindowsIdentity 
                 impersonatedIdentity)
                    at Microsoft.SqlServer.Management.Common.ConnectionManager.Connect()
                    --- End of inner exception stack trace ---
                    at Microsoft.SqlServer.Management.Common.ConnectionManager.Connect()
                    at CallSite.Target(Closure , CallSite , Object )
                    --- End of inner exception stack trace ---
                    at System.Management.Automation.ExceptionHandlingOps.CheckActionPreference(FunctionContext 
                 funcContext, Exception exception)
                    at System.Management.Automation.Interpreter.ActionCallInstruction`2.Run(InterpretedFrame frame)
                    at System.Management.Automation.Interpreter.EnterTryCatchFinallyInstruction.Run(InterpretedFrame 
                 frame)
                    at System.Management.Automation.Interpreter.EnterTryCatchFinallyInstruction.Run(InterpretedFrame 
                 frame)
                    --- End of inner exception stack trace ---
				Data           : {}
				InnerException : 
				TargetSite     : 
				StackTrace     : 
				HelpLink       : 
				Source         : 
				HResult        : -2146233088
[[SqlLogin]DirectResourceAccess] ***EXCEPTION END

mrpk1906 avatar Dec 30 '20 05:12 mrpk1906

Did you add the snippet as above? I was expecting it to return several ***EXCEPTION START when it looped through the inner exceptions. But we can see from the output is that it throws the following for exceptions:

  • System.InvalidOperationException: Failed to connect to SQL instance 'localhost'. (SQLCOMMON0019)
  • System.Management.Automation.MethodInvocationException: Exception calling "Connect" with "0" argument(s): "Failed to connect to server localhost."
  • Microsoft.SqlServer.Management.Common.ConnectionFailureException: Failed to connect to server localhost.
  • System.Data.SqlClient.SqlException: Login failed for user 'test_user'. Reason: The account is disabled.

It is the System.Data.SqlClient.SqlException that we need to catch in the code, and I was interested if that exception had any properties that we could use to catch it. Looking at the documentation it should have a property Number https://docs.microsoft.com/en-us/dotnet/api/system.data.sqlclient.sqlexception?view=dotnet-plat-ext-5.0#properties.

I would try to reproduce it if I had the bandwidth but there is a lack of time right now. It is possible for you to try to debug the code an see if you can dig through the error record and see how to output the exception System.Data.SqlClient.SqlException?

Maybe it is possible to add the following additional catch statement to get the properties of System.Data.SqlClient.SqlException.

catch [System.Data.SqlClient.SqlException]
{
    Write-Verbose -Message ('***Exception: {0}' -f ($_.Exception | Out-String)) -Verbose
}
catch
{
    # The current catch-block goes here
}

johlju avatar Dec 30 '20 06:12 johlju