Re: "could not accept SSPI security context"

I just heard back from our IT. There's nothing in the logs for this
connection attempt, but they noted in the Npgsql log that the authentication
was attempted using NTLM. However our domain controller no longer supports
NTLM, but only LDAP(s) and kerberos (it's a Windows 2008 server). From the
docs I understand that with SSPI, pg should try kerberos first and fall back
to NTLM. This works when connecting from psql. Maybe Npgsql goes straight
for NTLM, at least when using it the way I do?

2010/11/29 Reto Schöning <reto(dot)schoening(at)gmail(dot)com>

> thanks a lot for the hints.
>
> client side logging: the user name corresponds to the expected user,
> without the domain prefix ("rsc"). See the full log output below.
>
> security event log: I should get that shortly from our IT.
> Regards, Reto
>
> 29.11.2010 10:37:17 4412 Debug Entering
> NpgsqlConnection.NpgsqlConnection(NpgsqlConnection())
> 29.11.2010 10:37:18 4412 Debug ConnectionString Option: HOST = <ip>
> 29.11.2010 10:37:18 4412 Debug ConnectionString Option: PORT = 5432
> 29.11.2010 10:37:18 4412 Debug ConnectionString Option: PROTOCOL = 3
> 29.11.2010 10:37:18 4412 Debug ConnectionString Option: DATABASE = some_db
> 29.11.2010 10:37:18 4412 Debug ConnectionString Option: USER ID =
> 29.11.2010 10:37:18 4412 Debug ConnectionString Option: PASSWORD =
> 29.11.2010 10:37:18 4412 Debug ConnectionString Option: SSL = False
> 29.11.2010 10:37:18 4412 Debug ConnectionString Option: SSLMODE = Disable
> 29.11.2010 10:37:18 4412 Debug ConnectionString Option: TIMEOUT = 15
> 29.11.2010 10:37:18 4412 Debug ConnectionString Option: SEARCHPATH =
> 29.11.2010 10:37:18 4412 Debug ConnectionString Option: POOLING = True
> 29.11.2010 10:37:18 4412 Debug ConnectionString Option: CONNECTIONLIFETIME
> = 15
> 29.11.2010 10:37:18 4412 Debug ConnectionString Option: MINPOOLSIZE = 1
> 29.11.2010 10:37:18 4412 Debug ConnectionString Option: MAXPOOLSIZE = 20
> 29.11.2010 10:37:18 4412 Debug ConnectionString Option: SYNCNOTIFICATION =
> False
> 29.11.2010 10:37:18 4412 Debug ConnectionString Option: COMMANDTIMEOUT = 20
> 29.11.2010 10:37:18 4412 Debug ConnectionString Option: ENLIST = False
> 29.11.2010 10:37:18 4412 Debug ConnectionString Option: PRELOADREADER =
> False
> 29.11.2010 10:37:18 4412 Debug ConnectionString Option: USEEXTENDEDTYPES =
> False
> 29.11.2010 10:37:18 4412 Debug ConnectionString Option: INTEGRATED SECURITY
> = true
> 29.11.2010 10:37:18 4412 Debug ConnectionString Option: COMPATIBLE =
> 2.0.11.0
> 29.11.2010 10:37:18 4412 Debug Entering NpgsqlConnection.Open()
> 29.11.2010 10:37:18 4412 Debug Get NpgsqlClosedState.Instance
> 29.11.2010 10:37:18 4412 Debug Get NpgsqlClosedState.Instance
> 29.11.2010 10:37:18 4412 Debug Entering NpgsqlClosedState.Open()
> 29.11.2010 10:37:19 4412 Debug Attempt to connect to '<ip>'.
> 29.11.2010 10:37:19 4412 Normal Connected to: <ip>:5432.
> 29.11.2010 10:37:19 4412 Debug Entering
> NpgsqlStartupPacket.NpgsqlStartupPacket()
> 29.11.2010 10:37:19 4412 Debug Entering NpgsqlStartupPacket.WriteToStream()
> 29.11.2010 10:37:19 4412 Debug Entering
> NpgsqlStartupPacket.WriteToStream_Ver_3()
> 29.11.2010 10:37:19 4412 Debug Entering PGUtil.WriteString()
> 29.11.2010 10:37:19 4412 Debug String written: user.
> 29.11.2010 10:37:19 4412 Debug Entering PGUtil.WriteString()
> 29.11.2010 10:37:19 4412 Debug String written: rsc.
> 29.11.2010 10:37:19 4412 Debug Entering PGUtil.WriteString()
> 29.11.2010 10:37:19 4412 Debug String written: database.
> 29.11.2010 10:37:19 4412 Debug Entering PGUtil.WriteString()
> 29.11.2010 10:37:19 4412 Debug String written: some_db.
> 29.11.2010 10:37:19 4412 Debug Entering PGUtil.WriteString()
> 29.11.2010 10:37:19 4412 Debug String written: DateStyle.
> 29.11.2010 10:37:19 4412 Debug Entering PGUtil.WriteString()
> 29.11.2010 10:37:19 4412 Debug String written: ISO.
> 29.11.2010 10:37:19 4412 Debug Entering
> NpgsqlState.ProcessBackendResponses()
> 29.11.2010 10:37:19 4412 Debug AuthenticationRequest message received from
> server.
> 29.11.2010 10:37:19 4412 Debug Entering NpgsqlStartupState.Authenticate()
> 29.11.2010 10:37:19 4412 Debug Entering
> NpgsqlPasswordPacket.NpgsqlPasswordPacket()
> 29.11.2010 10:37:19 4412 Debug Entering
> NpgsqlPasswordPacket.WriteToStream()
> 29.11.2010 10:37:19 4412 Debug Entering PGUtil.WriteString()
> 29.11.2010 10:37:19 4412 Debug String written: NTLMSSP ?
> ? (
> .
> 29.11.2010 10:37:19 4412 Debug AuthenticationRequest message received from
> server.
> 29.11.2010 10:37:19 4412 Debug Entering NpgsqlStartupState.Authenticate()
> 29.11.2010 10:37:19 4412 Debug Entering
> NpgsqlPasswordPacket.NpgsqlPasswordPacket()
> 29.11.2010 10:37:19 4412 Debug Entering
> NpgsqlPasswordPacket.WriteToStream()
> 29.11.2010 10:37:19 4412 Debug Entering PGUtil.WriteString()
> 29.11.2010 10:37:19 4412 Debug String written: NTLMSSP t ? H `
> f ? ?" (
> T E S T . X Y Z - D E r s c T R I D E N T ????J?#0 ?n^
> V?1d1m?5???7O+???? .
> 29.11.2010 10:37:21 4412 Debug Entering PGUtil.ReadString()
> 29.11.2010 10:37:21 4412 Debug Get NpgsqlEventLog.LogLevel
> 29.11.2010 10:37:21 4412 Debug String read: FATAL.
> 29.11.2010 10:37:21 4412 Debug Entering PGUtil.ReadString()
> 29.11.2010 10:37:21 4412 Debug Get NpgsqlEventLog.LogLevel
> 29.11.2010 10:37:21 4412 Debug String read: XX000.
> 29.11.2010 10:37:21 4412 Debug Entering PGUtil.ReadString()
> 29.11.2010 10:37:21 4412 Debug Get NpgsqlEventLog.LogLevel
> 29.11.2010 10:37:21 4412 Debug String read: could not accept SSPI security
> context.
> 29.11.2010 10:37:21 4412 Debug Entering PGUtil.ReadString()
> 29.11.2010 10:37:21 4412 Debug Get NpgsqlEventLog.LogLevel
> 29.11.2010 10:37:21 4412 Debug String read: The logon attempt failed
> (8009030c).
> 29.11.2010 10:37:21 4412 Debug Entering PGUtil.ReadString()
> 29.11.2010 10:37:21 4412 Debug Get NpgsqlEventLog.LogLevel
> 29.11.2010 10:37:21 4412 Debug String read: .\src\backend\libpq\auth.c.
> 29.11.2010 10:37:21 4412 Debug Entering PGUtil.ReadString()
> 29.11.2010 10:37:21 4412 Debug Get NpgsqlEventLog.LogLevel
> 29.11.2010 10:37:21 4412 Debug String read: 621.
> 29.11.2010 10:37:21 4412 Debug Entering PGUtil.ReadString()
> 29.11.2010 10:37:21 4412 Debug Get NpgsqlEventLog.LogLevel
> 29.11.2010 10:37:21 4412 Debug String read: pg_SSPI_error.
> 29.11.2010 10:37:21 4412 Debug ErrorResponse message from Server: could not
> accept SSPI security context.
> 29.11.2010 10:37:21 4412 Normal An NpgsqlException occured: FATAL: XX000:
> could not accept SSPI security context.
>
>
> 2010/11/23 Brar Piening <brar(at)gmx(dot)de>
>
> On Mon, 22 Nov 2010 13:43:14 +0100, Magnus Hagander <magnus(at)hagander(dot)net>
>> wrote:
>>
>>> Hmm. That's a simple SEC_E_LOGON_DENIED. Simply meaning
>>> usedname/password is incorrect. The security eventlog on the server
>>> (or domain controller) might have more information around it. If not,
>>> I'm not sure what's wrong there - if it happens only in npgsql it must
>>> be related to that. Or perhaps - based on your reproduction - the .net
>>> app is running with a different user than you think?
>>>
>>>
>> If you've got access to the sources of your client app that uses Npgsql
>> you might want to put :
>>
>> NpgsqlEventLog.Level = LogLevel.Debug;
>> NpgsqlEventLog.LogName = @"C:\somePath\NpgsqlEventLog.txt";
>>
>> in the code before the first call of NpgsqlConnection.Open() to find out
>> details about the user name that's actually connecting.
>>
>>
>> Just look for
>>
>> Entering PGUtil.WriteString()
>> String written: user.
>> Entering PGUtil.WriteString()
>> String written: YOURCONNECTINGUSERNAME.
>>
>> after
>>
>> Entering NpgsqlStartupPacket.NpgsqlStartupPacket()
>> Entering NpgsqlStartupPacket.WriteToStream()
>> Entering NpgsqlStartupPacket.WriteToStream_Ver_3()
>>
>> Regards,
>>
>> Brar
>>
>
>