Win32Exception: The logon attempt failed

Feb 1, 2011 at 12:25 PM
Edited Feb 2, 2011 at 9:34 AM

Hi! Might be someone already faced with similar problem:

 

2011-02-01 15:13:38,787 INFO  [ru.massmo.common.security.authentication.waffle.NegotiateSecurityFilter] GET /t2wd/, contentlength: 0
2011-02-01 15:13:38,787 INFO  [waffle.servlet.spi.NegotiateSecurityFilterProvider] security package: NTLM, connection id: 10.77.252.231:-1
2011-02-01 15:13:38,787 INFO  [waffle.servlet.spi.NegotiateSecurityFilterProvider] token buffer: 40 byte(s)
2011-02-01 15:13:38,791 INFO  [waffle.servlet.spi.NegotiateSecurityFilterProvider] continue token: TlRMTVNT...
2011-02-01 15:13:38,791 INFO  [waffle.servlet.spi.NegotiateSecurityFilterProvider] continue required: true
2011-02-01 15:13:38,799 INFO  [ru.massmo.common.security.authentication.waffle.NegotiateSecurityFilter] GET /t2wd/, contentlength: 0
2011-02-01 15:13:38,799 INFO  [waffle.servlet.spi.NegotiateSecurityFilterProvider] security package: NTLM, connection id: 10.77.252.231:-1
2011-02-01 15:13:38,799 INFO  [waffle.servlet.spi.NegotiateSecurityFilterProvider] token buffer: 532 byte(s)
2011-02-01 15:13:38,802 WARN  [ru.massmo.common.security.authentication.waffle.NegotiateSecurityFilter] Cant login user by header: NTLM TlRMTVNTUAADAAAAGAA...
com.sun.jna.platform.win32.Win32Exception: The logon attempt failed

	at waffle.windows.auth.impl.WindowsAuthProviderImpl.acceptSecurityToken(Unknown Source)
	at waffle.servlet.spi.NegotiateSecurityFilterProvider.doFilter(Unknown Source)
	at waffle.servlet.spi.SecurityFilterProviderCollection.doFilter(Unknown Source)
	at ru.massmo.common.security.authentication.waffle.NegotiateSecurityFilter.doFilter(NegotiateSecurityFilter.java:74)
	at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:380)
	at org.springframework.security.web.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:187)
	at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:380)
	at org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:105)
	at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:380)
	at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:79)
	at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:380)
	at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:169)
	at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:237)
	at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:167)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
	at org.jboss.web.tomcat.filters.ReplyHeaderFilter.doFilter(ReplyHeaderFilter.java:96)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:235)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
	at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:183)
	at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:95)
	at org.jboss.web.tomcat.security.SecurityContextEstablishmentValve.process(SecurityContextEstablishmentValve.java:126)
	at org.jboss.web.tomcat.security.SecurityContextEstablishmentValve.invoke(SecurityContextEstablishmentValve.java:70)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
	at org.jboss.web.tomcat.service.jca.CachedConnectionValve.invoke(CachedConnectionValve.java:158)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:330)
	at org.apache.coyote.ajp.AjpAprProcessor.process(AjpAprProcessor.java:419)
	at org.apache.coyote.ajp.AjpAprProtocol$AjpConnectionHandler.process(AjpAprProtocol.java:402)
	at org.apache.tomcat.util.net.AprEndpoint$Worker.run(AprEndpoint.java:2036)
	at java.lang.Thread.run(Thread.java:619)

 

Login/password combination is correct. Is it possible for example that account restricted to have only one log on?

Coordinator
Feb 1, 2011 at 12:39 PM

There could be three dozen things wrong here. For starters, the account under which the service runs might not have the right privileges to logon this user. This user might be on a domain without a trust. There're other policies that can be in-play. Etc.  

Unfortunately I don't have a good story about debugging this. It would be nice if someone wrote it up.

Feb 1, 2011 at 2:19 PM

- sometimes the same user are successfully logged in
- sometimes other users are logged in without any problems

We started Tomcat under SYSTEM, most probably that SYSTEM don't have privileges to logon domain users. But starting service under domain user is a bad practice as I understand. It there any recommended solution for our situation?

Coordinator
Feb 1, 2011 at 2:37 PM

I don't think you have a grip on what's going on. Sometimes users are successfully logged in doesn't sound right. If it's from the same machine and one request succeeds while the other fails, there's something fishy going on. If it's from different machines you'll see clear differences in the requests.

If the server is in the domain, SYSTEM will use the machine account which will be able to logon the users.

Feb 1, 2011 at 2:58 PM

It's from the same machine. Hmm. 

Feb 2, 2011 at 9:33 AM
Edited Feb 2, 2011 at 9:39 AM

Brrr. At my application log:

2011-02-02 13:18:06,273 WARN  (-0.0.0.0-8009-5) [ru.massmo.common.security.authentication.waffle.NegotiateSecurityFilter] Cant login user by header: Negotiate TlRMTVNTUAADAAA...
com.sun.jna.platform.win32.Win32Exception: The logon attempt failed

	at waffle.windows.auth.impl.WindowsAuthProviderImpl.acceptSecurityToken(Unknown Source)
	at waffle.servlet.spi.NegotiateSecurityFilterProvider.doFilter(Unknown Source)
	at waffle.servlet.spi.SecurityFilterProviderCollection.doFilter(Unknown Source)
	at ru.massmo.common.security.authentication.waffle.NegotiateSecurityFilter.doFilter(NegotiateSecurityFilter.java:74)
	at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:380)
	at org.springframework.security.web.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:187)
	at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:380)
	at org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:105)
	at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:380)
	at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:79)
	at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:380)
	at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:169)
	at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:237)
	at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:167)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
	at org.jboss.web.tomcat.filters.ReplyHeaderFilter.doFilter(ReplyHeaderFilter.java:96)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:235)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
	at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:183)
	at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:95)
	at org.jboss.web.tomcat.security.SecurityContextEstablishmentValve.process(SecurityContextEstablishmentValve.java:126)
	at org.jboss.web.tomcat.security.SecurityContextEstablishmentValve.invoke(SecurityContextEstablishmentValve.java:70)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
	at org.jboss.web.tomcat.service.jca.CachedConnectionValve.invoke(CachedConnectionValve.java:158)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:330)
	at org.apache.coyote.ajp.AjpAprProcessor.process(AjpAprProcessor.java:419)
	at org.apache.coyote.ajp.AjpAprProtocol$AjpConnectionHandler.process(AjpAprProtocol.java:402)
	at org.apache.tomcat.util.net.AprEndpoint$Worker.run(AprEndpoint.java:2036)
	at java.lang.Thread.run(Thread.java:619)

In Tomcat's machine event log (I've enabled kerberos logging during my unsucessfull attempts to configure Win SSO via Kerberos):

Log Name:      System
Source:        LsaSrv
Date:          02.02.2011 13:18:06
Event ID:      6037
Task Category: None
Level:         Warning
Keywords:      Classic
User:          N/A
Computer:      T2RU-WDAPP-02.corp.tele2.ru
Description:
The program java.exe, with the assigned process ID 5988, could not authenticate locally by using the target name HTTP/www.tst.t2wd.tele2.ru.
The target name used is not valid. A target name should refer to one of the local computer names, for example, the DNS host name.
 
Try a different target name.

Then next failed logon of application:

2011-02-02 13:18:26,977 WARN  (-0.0.0.0-8009-5) [ru.massmo.common.security.authentication.waffle.NegotiateSecurityFilter] Cant login user by header: Negotiate TlRMTVNTUAADAA...
com.sun.jna.platform.win32.Win32Exception: The logon attempt failed

	at waffle.windows.auth.impl.WindowsAuthProviderImpl.acceptSecurityToken(Unknown Source)
	at waffle.servlet.spi.NegotiateSecurityFilterProvider.doFilter(Unknown Source)
	at waffle.servlet.spi.SecurityFilterProviderCollection.doFilter(Unknown Source)
	at ru.massmo.common.security.authentication.waffle.NegotiateSecurityFilter.doFilter(NegotiateSecurityFilter.java:74)
	at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:380)
	at org.springframework.security.web.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:187)
	at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:380)
	at org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:105)
	at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:380)
	at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:79)
	at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:380)
	at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:169)
	at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:237)
	at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:167)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
	at org.jboss.web.tomcat.filters.ReplyHeaderFilter.doFilter(ReplyHeaderFilter.java:96)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:235)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
	at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:183)
	at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:95)
	at org.jboss.web.tomcat.security.SecurityContextEstablishmentValve.process(SecurityContextEstablishmentValve.java:126)
	at org.jboss.web.tomcat.security.SecurityContextEstablishmentValve.invoke(SecurityContextEstablishmentValve.java:70)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
	at org.jboss.web.tomcat.service.jca.CachedConnectionValve.invoke(CachedConnectionValve.java:158)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:330)
	at org.apache.coyote.ajp.AjpAprProcessor.process(AjpAprProcessor.java:419)
	at org.apache.coyote.ajp.AjpAprProtocol$AjpConnectionHandler.process(AjpAprProtocol.java:402)
	at org.apache.tomcat.util.net.AprEndpoint$Worker.run(AprEndpoint.java:2036)
	at java.lang.Thread.run(Thread.java:619)

And this in event log:

Log Name:      System
Source:        Microsoft-Windows-Security-Kerberos
Date:          02.02.2011 13:18:26
Event ID:      3
Task Category: None
Level:         Error
Keywords:      Classic
User:          N/A
Computer:      T2RU-WDAPP-02.corp.tele2.ru
Description:
A Kerberos Error Message was received:
 on logon session CORP.TELE2.RU\Supp.Mass
 Client Time: 
 Server Time: 10:18:26.0000 2/2/2011 Z
 Error Code: 0x19 KDC_ERR_PREAUTH_REQUIRED
 Extended Error: 
 Client Realm: 
 Client Name: 
 Server Realm: T2RU
 Server Name: krbtgt/T2RU
 Target Name: krbtgt/T2RU@T2RU
 Error Text: 
 File: e
 Line: 9fe
 Error Data is in record data.

What's going on? And how to prevent this attempts to authenticate via Kerberos? :)

Feb 2, 2011 at 2:30 PM

It seems that all is correct with these events. IE just are saying "I can't authenticate via Kerberos" in event log. And than it should fallback to NTLM. 

My "The logon attempt failed" problems are caused by something else.

Feb 2, 2011 at 3:12 PM
Edited Feb 2, 2011 at 3:13 PM

But enabled NTLM audit events gives me a little bit strange information:

 

Log Name:      Microsoft-Windows-NTLM/Operational
Source:        Microsoft-Windows-NTLM
Date:          02.02.2011 19:06:26
Event ID:      8001
Task Category: Auditing NTLM
Level:         Information
Keywords:      
User:          SYSTEM
Computer:      T2-WDAPP-02.corp.tele2.ru
Description:
NTLM client blocked audit: Audit outgoing NTLM authentication traffic that would be blocked.
Target server: HTTP/www.tst.t2wd.tele2.ru
Supplied user: Supp.XXX
Supplied domain: T2
PID of client process: 1612
Name of client process: C:\Program Files (x86)\Internet Explorer\iexplore.exe
LUID of client process: 0x1424c411
User identity of client process: Supp.XXX
Domain name of user identity of client process: T2
Mechanism OID: (NULL)

...

Is this correct that target server identified as HTTP/www.tst.t2wd.tele2.ru?

 


Feb 2, 2011 at 3:22 PM

And this I found in system event log:

Log Name:      System
Source:        LsaSrv
Date:          02.02.2011 19:06:26
Event ID:      6037
Task Category: None
Level:         Warning
Keywords:      Classic
User:          N/A
Computer:      T2-WDAPP-02.corp.tele2.ru
Description:
The program java.exe, with the assigned process ID 5988, could not authenticate locally by using the target name HTTP/www.tst.t2wd.tele2.ru. The target name used is not valid. A target name should refer to one of the local computer names, for example, the DNS host name.
 
 Try a different target name.
Coordinator
Feb 2, 2011 at 4:39 PM

Ok. Сейчас всё станет намного сложнее :)

It looks like this is SPN-related or DCOM-configuration-related. Good luck with that ;) I am really not an expert on this, Google is your best friend. I would love it if someone explained how to solve this with great detail, so if you pursue it an find a solution, please tell us!

As a quick workaround (and if you don't care), I would disable Kerberos in Waffle configuration and just do NTLM. That would reduce the problematic surface. 

Coordinator
Feb 2, 2011 at 4:42 PM

One more thing. Waffle does specify the "target name" in code in 1.4 (last parameter to any IWindowsSecurityContext in initialize). It's possible that this is implemented wrong and may need to be other than null or bogus (aka configurable) in some scenarios. 

Feb 2, 2011 at 5:17 PM

Observed such strange thing.

We have cluster of two physical hosts (Win Server 2008R2) that are after load balancer. When I open IE 8  on one of that hosts (via RDP) and access our clustered web application than I got a bunch of that problems with authentication.

When I open IE 8 (via RDP) on test workstation (other physical host, Win XP, connected to domain) all works without any problems!

 

Coordinator
Feb 3, 2011 at 2:17 AM
dorlov wrote:

Observed such strange thing.

We have cluster of two physical hosts (Win Server 2008R2) that are after load balancer. When I open IE 8  on one of that hosts (via RDP) and access our clustered web application than I got a bunch of that problems with authentication.

When I open IE 8 (via RDP) on test workstation (other physical host, Win XP, connected to domain) all works without any problems!

 

 It doesn't sound all that strange. Negotiate migh be selecting NTLM in one case and Kerberos in another. Then you're comparing apples and oranges.

Feb 3, 2011 at 7:52 AM

Кажется я решил загадку :)

We changed option described in this kb http://support.microsoft.com/kb/957097 and rebooted hosts. Application opened from sever's IE become authenticate users (in most cases).

We have other problems now. Sometimes logon dialog still popups during some of our AJAX requests. But seems that it relates to http://waffle.codeplex.com/Thread/View.aspx?ThreadId=244329 So I am going there :)

Feb 3, 2011 at 9:48 AM
Edited Feb 3, 2011 at 10:42 AM

Some set of links that I'd recommend to read and possibly try when you are in trouble:

Enable Kerberos and NTLM logs:

http://support.microsoft.com/?id=262177
http://blogs.technet.com/b/askds/archive/2009/10/08/ntlm-blocking-and-you-application-analysis-and-auditing-methodologies-in-windows-7.aspx

Check this kbs that could relates to your problem:

http://support.microsoft.com/kb/896861
http://technet.microsoft.com/en-us/library/dd566199(v=WS.10).aspx
http://support.microsoft.com/kb/326040

In case you get troubles with Kerberos setup you could check this huge doc from MS:
http://www.microsoft.com/downloads/en/details.aspx?familyid=99b0f94f-e28a-4726-bffe-2f64ae2f59a2&displaylang=en

Coordinator
Feb 3, 2011 at 12:16 PM

Awesome. I've added a bunch of links to Troubleshooting Negotiate.