[xwiki-devs] custom authentication firing twice

I am writing a custom authentication class following notes from http://platform.xwiki.org/xwiki/bin/view/AdminGuide/Authentication and the sample given in http://bodez.wordpress.com/2008/10/15/xwiki-user-authentication-with-oracle… The class is written and I can see the Remote Authentication is called and returns just fine and my method returns a new XWikiUser however, in my logs I see the checkAuth being fired twice, once with the j_username = entered username... but the second time it is fired set to null. Here is my checkAuth method: public XWikiUser checkAuth(XWikiContext context) throws XWikiException { log.debug("ARFSSOAuthServiceImpl.checkAuth"); String user = getRemoteUser(context); if (user==null || user.equals("")){ log.error("SSOAuthServiceImpl: User cannot be authenticated (REMOTE_USER is null)"); // TODO: redirect login. return null; }else{ log.warn("ARFSSOAuthServiceImpl: User " + user + " has been authenticated"); this.createUser(user, context); user = "XWiki." + user; } log.warn("SSOAuthServiceImpl: authentication successful context.setUser " + user); context.setUser(user); return new XWikiUser(user); } Here is the log from a single post of the credentials: 2012-08-25 11:11:30,285 [ http://zzzzzzz/xwiki/bin/loginsubmit/XWiki/XWikiLogin] WARN sso.ARFSSOAuthServiceImpl - sso Auth check auth before super 2012-08-25 11:11:30,287 [ http://zzzzzzz/xwiki/bin/loginsubmit/XWiki/XWikiLogin] WARN sso.ARFSSOAuthServiceImpl - request j_username = testuser 2012-08-25 11:11:30,287 [ http://zzzzzzz/xwiki/bin/loginsubmit/XWiki/XWikiLogin] WARN sso.ARFSSOAuthServiceImpl - request j_password = testpwd 2012-08-25 11:11:30,287 [ http://zzzzzzz/xwiki/bin/loginsubmit/XWiki/XWikiLogin] WARN sso.ARFWebAuthenticator - processLogin j_username = testuser 2012-08-25 11:11:30,288 [ http://zzzzzzz/xwiki/bin/loginsubmit/XWiki/XWikiLogin] WARN sso.ARFWebAuthenticator - processLogin j_password = testpwd 2012-08-25 11:11:30,289 [ http://zzzzzzz/xwiki/bin/loginsubmit/XWiki/XWikiLogin] WARN net.ARFHttpClient - ARFHttpClient post request to: http://localhost.com/test.php 2012-08-25 11:11:30,417 [ http://zzzzzzz/xwiki/bin/loginsubmit/XWiki/XWikiLogin] WARN net.ARFHttpClient - ARFHttpClient response string: status=0|firstname=Test|lastname=User 2012-08-25 11:11:30,418 [ http://zzzzzzz/xwiki/bin/loginsubmit/XWiki/XWikiLogin] WARN sso.ARFWebAuthenticator - processLogin... webresponse status = 0 2012-08-25 11:11:30,421 [ http://zzzzzzz/xwiki/bin/loginsubmit/XWiki/XWikiLogin] WARN sso.ARFWebAuthenticator - convertARFResponseToUsername token = TestUser 2012-08-25 11:11:30,421 [ http://zzzzzzz/xwiki/bin/loginsubmit/XWiki/XWikiLogin] WARN sso.ARFSSOAuthServiceImpl - ARFSSOAuthServiceImpl: User TestUser has been authenticated 2012-08-25 11:11:30,422 [ http://zzzzzzz/xwiki/bin/loginsubmit/XWiki/XWikiLogin] WARN sso.ARFSSOAuthServiceImpl - ARFSSOAuthServiceImpl.createUser: User TestUser before find. 2012-08-25 11:11:30,427 [ http://zzzzzzz/xwiki/bin/loginsubmit/XWiki/XWikiLogin] WARN sso.ARFSSOAuthServiceImpl - ARFSSOAuthServiceImpl.createUser: XwikiUser XWiki.TestUser after find. 2012-08-25 11:11:30,427 [ http://zzzzzzz/xwiki/bin/loginsubmit/XWiki/XWikiLogin] WARN sso.ARFSSOAuthServiceImpl - SSOAuthServiceImpl: authentication successful context.setUser XWiki.TestUser 2012-08-25 11:11:31,080 [http://zzzzzzz/xwiki/bin/view/Main/?srid=HNnJrnSa] WARN sso.ARFSSOAuthServiceImpl - sso Auth check auth before super 2012-08-25 11:11:31,081 [http://zzzzzzz/xwiki/bin/view/Main/?srid=HNnJrnSa] WARN sso.ARFSSOAuthServiceImpl - request j_username = null 2012-08-25 11:11:31,081 [http://zzzzzzz/xwiki/bin/view/Main/?srid=HNnJrnSa] WARN sso.ARFSSOAuthServiceImpl - request j_password = null 2012-08-25 11:11:31,081 [http://zzzzzzz/xwiki/bin/view/Main/?srid=HNnJrnSa] WARN sso.ARFWebAuthenticator - processLogin j_username = null 2012-08-25 11:11:31,081 [http://zzzzzzz/xwiki/bin/view/Main/?srid=HNnJrnSa] WARN sso.ARFWebAuthenticator - processLogin j_password = null 2012-08-25 11:11:31,081 [http://zzzzzzz/xwiki/bin/view/Main/?srid=HNnJrnSa] WARN net.ARFHttpClient - ARFHttpClient post request to: http://localhost.com/test.php 2012-08-25 11:11:31,159 [http://zzzzzzz/xwiki/bin/view/Main/?srid=HNnJrnSa] WARN net.ARFHttpClient - ARFHttpClient response string: status=100 2012-08-25 11:11:31,159 [http://zzzzzzz/xwiki/bin/view/Main/?srid=HNnJrnSa] WARN sso.ARFWebAuthenticator - processLogin... webresponse status = 100 2012-08-25 11:11:31,159 [http://zzzzzzz/xwiki/bin/view/Main/?srid=HNnJrnSa] ERROR sso.ARFSSOAuthServiceImpl - SSOAuthServiceImpl: User cannot be authenticated (REMOTE_USER is null) 2012-08-25 11:11:31,810 [ http://zzzzzzz/xwiki/bin/login/XWiki/XWikiLogin?srid=HNnJrnSa&xredirect…] WARN sso.ARFSSOAuthServiceImpl - sso Auth check auth before super 2012-08-25 11:11:31,810 [ http://zzzzzzz/xwiki/bin/login/XWiki/XWikiLogin?srid=HNnJrnSa&xredirect…] WARN sso.ARFSSOAuthServiceImpl - request j_username = null 2012-08-25 11:11:31,810 [ http://zzzzzzz/xwiki/bin/login/XWiki/XWikiLogin?srid=HNnJrnSa&xredirect…] WARN sso.ARFSSOAuthServiceImpl - request j_password = null 2012-08-25 11:11:31,810 [ http://zzzzzzz/xwiki/bin/login/XWiki/XWikiLogin?srid=HNnJrnSa&xredirect…] WARN sso.ARFWebAuthenticator - processLogin j_username = null 2012-08-25 11:11:31,810 [ http://zzzzzzz/xwiki/bin/login/XWiki/XWikiLogin?srid=HNnJrnSa&xredirect…] WARN sso.ARFWebAuthenticator - processLogin j_password = null 2012-08-25 11:11:31,811 [ http://zzzzzzz/xwiki/bin/login/XWiki/XWikiLogin?srid=HNnJrnSa&xredirect…] WARN net.ARFHttpClient - ARFHttpClient post request to: http://localhost.com/test.php 2012-08-25 11:11:31,877 [ http://zzzzzzz/xwiki/bin/login/XWiki/XWikiLogin?srid=HNnJrnSa&xredirect…] WARN net.ARFHttpClient - ARFHttpClient response string: status=100 2012-08-25 11:11:31,878 [ http://zzzzzzz/xwiki/bin/login/XWiki/XWikiLogin?srid=HNnJrnSa&xredirect…] WARN sso.ARFWebAuthenticator - processLogin... webresponse status = 100 2012-08-25 11:11:31,878 [ http://zzzzzzz/xwiki/bin/login/XWiki/XWikiLogin?srid=HNnJrnSa&xredirect…] ERROR sso.ARFSSOAuthServiceImpl - SSOAuthServiceImpl: User cannot be authenticated (REMOTE_USER is null) 2012-08-25 11:11:32,041 [ http://zzzzzzz/xwiki/bin/login/XWiki/XWikiLogin?srid=HNnJrnSa&xredirect…] WARN internal.DefaultVelocityEngine - Deprecated usage of method [com.xpn.xwiki.api.XWiki.parseMessage] in /templates/login.vm@28,33 Any help is appreciated, Bob XWiki Version: XWiki Enterprise 3.0-rc-1.35909 Do I need to upgrade to get this functionality?