DFS and Kerberos : authenfication failed after a while

Hi,

I'm currently experiencing some difficulties to use DFS and Kerberos : i'm able to query my docbase using my kerberos credentials but after 5 minutes (exactly), the DFS server responds

com.emc.documentum.fs.rt.AuthenticationException: java.lang.NullPointerException

at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)

at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:44)

at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:39)

at java.lang.reflect.Constructor.newInstance(Constructor.java:516)

at com.emc.documentum.fs.rt.context.impl.compat.ClientReflectionServiceInvokerCompat60.getExceptionInstance(ClientReflectionServiceInvokerCompat60.java:180)

at com.emc.documentum.fs.rt.context.impl.compat.ClientReflectionServiceInvokerCompat60.invoke(ClientReflectionServiceInvokerCompat60.java:78)

at com.emc.documentum.fs.rt.context.impl.UcfClientInvocationHandler.invoke(UcfClientInvocationHandler.java:49)

at com.emc.documentum.fs.rt.context.impl.SoapClientInvocationHandler.invoke(SoapClientInvocationHandler.java:66)

at com.emc.documentum.fs.rt.context.impl.MtomCompatHandler60SP1.invoke(MtomCompatHandler60SP1.java:60)

at com.emc.documentum.fs.rt.context.impl.HttpSessionInvocationHandler.invoke(HttpSessionInvocationHandler.java:88)

at com.emc.documentum.fs.rt.context.impl.RemoteServiceInterfaceInvocationHandler.invoke(RemoteServiceInterfaceInvocationHandler.java:30)

at com.emc.documentum.fs.rt.context.impl.ReturnedContentTransformationHandler.invoke(ReturnedContentTransformationHandler.java:45)

at com.emc.documentum.fs.rt.context.impl.OperationOptionsHandler.invoke(OperationOptionsHandler.java:72)

at com.emc.documentum.fs.rt.context.impl.ContextThreadLocalInvocationHandler.invoke(ContextThreadLocalInvocationHandler.java:51)

at com.emc.documentum.fs.rt.context.impl.ServiceContextInvocationHandler.invoke(ServiceContextInvocationHandler.java:30)

at $Proxy22.execute(Unknown Source)

at com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator.main(ServiceTicketGenerator.java:209)

Caused by: java.lang.NullPointerException

at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)

at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:44)

at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:39)

at java.lang.reflect.Constructor.newInstance(Constructor.java:516)

at com.emc.documentum.fs.rt.context.impl.compat.ClientReflectionServiceInvokerCompat60.getExceptionInstance(ClientReflectionServiceInvokerCompat60.java:148)

at com.emc.documentum.fs.rt.context.impl.compat.ClientReflectionServiceInvokerCompat60.invoke(ClientReflectionServiceInvokerCompat60.java:77)

... 11 more

The log generated on the server side is the following :

[12/15/11 17:01:01:952 CET] 00000023 SystemOut

O 302642 [WebContainer : 6] ERROR com.emc.documentum.fs.services.core.QueryServiceWebService - java.lang.NullPointerException

com.emc.documentum.fs.rt.AuthenticationException: java.lang.NullPointerException

	at com.emc.documentum.fs.rt.handlers.KerberosTokenServerHandler.exception(KerberosTokenServerHandler.java:277)
	at com.emc.documentum.fs.rt.handlers.KerberosTokenServerHandler.handleMessage(KerberosTokenServerHandler.java:128)
	at com.emc.documentum.fs.rt.handlers.KerberosTokenServerHandler.handleMessage(KerberosTokenServerHandler.java:1)
	at com.sun.xml.ws.handler.HandlerProcessor.callHandleMessage(HandlerProcessor.java:284)
	at com.sun.xml.ws.handler.HandlerProcessor.callHandlersRequest(HandlerProcessor.java:135)
	at com.sun.xml.ws.handler.ServerSOAPHandlerTube.callHandlersOnRequest(ServerSOAPHandlerTube.java:134)
	at com.sun.xml.ws.handler.HandlerTube.processRequest(HandlerTube.java:116)
	at com.sun.xml.ws.api.pipe.Fiber.__doRun(Fiber.java:598)
	at com.sun.xml.ws.api.pipe.Fiber._doRun(Fiber.java:557)
	at com.sun.xml.ws.api.pipe.Fiber.doRun(Fiber.java:542)
	at com.sun.xml.ws.api.pipe.Fiber.runSync(Fiber.java:439)
	at com.sun.xml.ws.server.WSEndpointImpl$2.process(WSEndpointImpl.java:243)
	at com.sun.xml.ws.transport.http.HttpAdapter$HttpToolkit.handle(HttpAdapter.java:471)
	at com.sun.xml.ws.transport.http.HttpAdapter.handle(HttpAdapter.java:244)
	at com.sun.xml.ws.transport.http.servlet.ServletAdapter.handle(ServletAdapter.java:135)
	at com.sun.xml.ws.transport.http.servlet.WSServletDelegate.doGet(WSServletDelegate.java:129)
	at com.sun.xml.ws.transport.http.servlet.WSServletDelegate.doPost(WSServletDelegate.java:160)
	at com.sun.xml.ws.transport.http.servlet.WSServlet.doPost(WSServlet.java:75)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:738)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:831)
	at com.ibm.ws.webcontainer.servlet.ServletWrapper.service(ServletWrapper.java:1663)
	at com.ibm.ws.webcontainer.servlet.ServletWrapper.handleRequest(ServletWrapper.java:939)
	at com.ibm.ws.webcontainer.servlet.ServletWrapper.handleRequest(ServletWrapper.java:502)
	at com.ibm.ws.webcontainer.servlet.ServletWrapperImpl.handleRequest(ServletWrapperImpl.java:179)
	at com.ibm.ws.webcontainer.servlet.CacheServletWrapper.handleRequest(CacheServletWrapper.java:91)
	at com.ibm.ws.webcontainer.WebContainer.handleRequest(WebContainer.java:864)
	at com.ibm.ws.webcontainer.WSWebContainer.handleRequest(WSWebContainer.java:1583)
	at com.ibm.ws.webcontainer.channel.WCChannelLink.ready(WCChannelLink.java:186)
	at com.ibm.ws.http.channel.inbound.impl.HttpInboundLink.handleDiscrimination(HttpInboundLink.java:445)
	at com.ibm.ws.http.channel.inbound.impl.HttpInboundLink.handleNewRequest(HttpInboundLink.java:504)
	at com.ibm.ws.http.channel.inbound.impl.HttpInboundLink.processRequest(HttpInboundLink.java:301)
	at com.ibm.ws.http.channel.inbound.impl.HttpInboundLink.ready(HttpInboundLink.java:275)
	at com.ibm.ws.tcp.channel.impl.NewConnectionInitialReadCallback.sendToDiscriminators(NewConnectionInitialReadCallback.java:214)
	at com.ibm.ws.tcp.channel.impl.NewConnectionInitialReadCallback.complete(NewConnectionInitialReadCallback.java:113)
	at com.ibm.ws.tcp.channel.impl.AioReadCompletionListener.futureCompleted(AioReadCompletionListener.java:165)
	at com.ibm.io.async.AbstractAsyncFuture.invokeCallback(AbstractAsyncFuture.java:217)
	at com.ibm.io.async.AsyncChannelFuture.fireCompletionActions(AsyncChannelFuture.java:161)
	at com.ibm.io.async.AsyncFuture.completed(AsyncFuture.java:138)
	at com.ibm.io.async.ResultHandler.complete(ResultHandler.java:204)
	at com.ibm.io.async.ResultHandler.runEventProcessingLoop(ResultHandler.java:775)
	at com.ibm.io.async.ResultHandler$2.run(ResultHandler.java:905)
	at com.ibm.ws.util.ThreadPool$Worker.run(ThreadPool.java:1563)

Caused by:

java.lang.NullPointerException

	at org.apache.commons.codec.binary.Base64.encodeBase64(Base64.java:233)
	at org.apache.commons.codec.binary.Base64.encode(Base64.java:521)
	at com.emc.documentum.kerberos.utility.AcceptAction.run(AcceptAction.java:33)
	at com.emc.documentum.kerberos.utility.AcceptAction.run(AcceptAction.java:11)
	at java.security.AccessController.doPrivileged(AccessController.java:284)
	at javax.security.auth.Subject.doAs(Subject.java:573)
	at com.emc.documentum.kerberos.utility.KerberosUtility.executePrivilegedAction(KerberosUtility.java:133)
	at com.emc.documentum.kerberos.utility.KerberosUtility.executeAcceptAction(KerberosUtility.java:113)
	at com.emc.documentum.kerberos.utility.KerberosUtility.accept(KerberosUtility.java:54)
	at com.emc.documentum.fs.rt.handlers.KerberosTokenServerHandler.authenticate(KerberosTokenServerHandler.java:218)
	at com.emc.documentum.fs.rt.handlers.KerberosTokenServerHandler.handleMessage(KerberosTokenServerHandler.java:96)
	... 40 more

Due to the fact that the problem is occuring exactly after 5 minutes, i'm thinking that it's a timeout issue or something like that but i can't find out where ...

I'm attaching a snippet that i use to recover my kerberos credentials and query the repository, may be i'm doing something there too.

Do you have any idea ?

I'm using DFS 6.7sp1 on a 6.7sp1 Content Server hosted on Windows 2008 R2

Find more posts tagged with

Note:

If there are Accepted Answers, those will be shown by default. You can switch to 'All Replies' by selecting the tab below.

Accepted answers

Jeremy Saumen

I found out what is the issue :

[12/28/11 9:18:28:614 CET] 0000001e SystemErr     R org.ietf.jgss.GSSException, major code: 10, minor code: 37
     major string: Defective token
     minor string: Client time Wednesday, December 28, 2011 at 9:13:27 AM too skewed
[12/28/11 9:18:28:615 CET] 0000001e SystemErr     R      at com.ibm.security.jgss.i18n.I18NException.throwGSSException(I18NException.java:7)

It's the parameter clockskew in the krb5.ini.

I think since I only generate a service ticket 1 time, the "client time" inside the ticket doesn't change so I only can use it inside the clockskew limit.

All comments

abc123

It is strange that there was no exception thrown from JGSS API. You can enlarge service ticket lifetime. The default value is 10 hours. Please refer to: http://technet.microsoft.com/en-us/library/dd277401.aspx. Some of Kerberos implementation also reads timeout from ticket_lifetime of krb5.conf, please check http://www.daemon-systems.org/man/krb5.conf.5.html.

If you are using SUN JGSS, you can open the Kerberos trace by setting system property: -Dsun.security.krb5.debug=true. For IBM JDK, setting system property: -Dcom.ibm.security.jgss.debug=all

William

Jeremy Saumen

Thanks for your answer but unfortunatly, i already tried that. The TGT and Service ticket are valid 10 hours.

Here's what i obtain when i execute my code :

0 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - Creating subject[JGSS_DBG_CRED] JAAS config: debug=true[JGSS_DBG_CRED] JAAS config: credsType=initiate only (default)[JGSS_DBG_CRED] config: useDefaultCcache=true[JGSS_DBG_CRED] config: useCcache=null[JGSS_DBG_CRED] config: useDefaultKeytab=false (default)[JGSS_DBG_CRED] config: useKeytab=null[JGSS_DBG_CRED] JAAS config: forwardable=false (default)[JGSS_DBG_CRED] JAAS config: renewable=false (default)[JGSS_DBG_CRED] JAAS config: proxiable=false (default)[JGSS_DBG_CRED] JAAS config: noAddress=false (default)[JGSS_DBG_CRED] JAAS config: tryFirstPass=false (default)[JGSS_DBG_CRED] JAAS config: useFirstPass=false (default)[JGSS_DBG_CRED] JAAS config: moduleBanner=false (default)[JGSS_DBG_CRED] JAAS config: interactive login? no[JGSS_DBG_CRED] Retrieving Kerberos creds from cache for principal=null[JGSS_DBG_CRED] Non-interactive login; no callbacks necessary.[JGSS_DBG_CRED] Done retrieving Kerberos creds from cache[JGSS_DBG_CRED] Login successful[JGSS_DBG_CRED] SaumenJ@LU.EMA.AD.PWCINTERNAL.COM added to Subject[JGSS_DBG_CRED] Kerberos ticket for SaumenJ@LU.EMA.AD.PWCINTERNAL.COM added to Subject[JGSS_DBG_CRED] No keys to add to Subject for SaumenJ@LU.EMA.AD.PWCINTERNAL.COM58 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - Subject has been created : Subject:    Principal: SaumenJ@LU.EMA.AD.PWCINTERNAL.COM    Private Credential: Ticket (hex) = [TGT_TICKET]
Client Principal = SaumenJ@LU.EMA.AD.PWCINTERNAL.COMServer Principal = krbtgt/LU.EMA.AD.PWCINTERNAL.COM@LU.EMA.AD.PWCINTERNAL.COMSession Key = EncryptionKey: keyType=23 keyBytes (hex dump)=[PRIVATE_KEY]Forwardable Ticket trueForwarded Ticket falseProxiable Ticket falseProxy Ticket falsePostdated Ticket falseRenewable Ticket trueInitial Ticket trueAuth Time = Tue Dec 27 11:28:33 CET 2011Start Time = Tue Dec 27 11:28:33 CET 2011End Time = Tue Dec 27 21:28:33 CET 2011Renew Till = Tue Jan 03 11:28:33 CET 2012Client Addresses  Null 60 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - Creating client credentials140 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - Client credentials have been created => --- GSSCredential ---    Number of mehanism credentials: 1[1] Kerberos credential, mechanism: 1.2.840.113554.1.2.2    Owner:        SaumenJ@LU.EMA.AD.PWCINTERNAL.COM    Usage:        initiate only    StartTime:    12/27/11 11:35 AM    InitLifeTime:    35,567 seconds     AcceptLifeTime:    unknown    Krb5Client:    SaumenJ@LU.EMA.AD.PWCINTERNAL.COM    Krb5Server:    krbtgt/LU.EMA.AD.PWCINTERNAL.COM@LU.EMA.AD.PWCINTERNAL.COM--- End of GSSCredential ---140 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - Creating Context158 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - Context has been created => --- GSSContext ---    Owner:        SaumenJ@LU.EMA.AD.PWCINTERNAL.COM    Peer:        DFS/saumenjwin7.lu.ema.ad.pwcinternal.com:9080@LU.EMA.AD.PWCINTERNAL.COM    State:        initialized    Lifetime:    35,567 seconds     Ready:        no    Flags:        Confidentiality        off        Delegation        on        Integrity        off        MutualAuthn        off        ReplayDetection        off        SequenceDetection    off        DelegatedCred:        unknown--- End of GSSContext ---480 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - Service ticket has been created1006 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - 0h 0min 1sec : 2827.0 object found6011 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - Using old TGT (expired in 9h 52min 41sec)6011 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - Using old service ticket (expired in 9h 52min 41sec)6332 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - 0h 0min 6sec : 2827.0 object found11341 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - Using old TGT (expired in 9h 52min 35sec)11342 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - Using old service ticket (expired in 9h 52min 35sec)11689 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - 0h 0min 12sec : 2827.0 object found[.........]
294634 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - Using old TGT (expired in 9h 47min 52sec)294634 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - Using old service ticket (expired in 9h 47min 52sec)294952 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - 0h 4min 55sec : 2827.0 object found299957 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - Using old TGT (expired in 9h 47min 47sec)299958 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - Using old service ticket (expired in 9h 47min 47sec)300275 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - 0h 5min 0sec : 2827.0 object found305281 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - Using old TGT (expired in 9h 47min 42sec)305281 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - Using old service ticket (expired in 9h 47min 42sec)com.emc.documentum.fs.rt.AuthenticationException: java.lang.NullPointerException    at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)    at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:44)    at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:39)    at java.lang.reflect.Constructor.newInstance(Constructor.java:516)    at com.emc.documentum.fs.rt.context.impl.compat.ClientReflectionServiceInvokerCompat60.getExceptionInstance(ClientReflectionServiceInvokerCompat60.java:180)    at com.emc.documentum.fs.rt.context.impl.compat.ClientReflectionServiceInvokerCompat60.invoke(ClientReflectionServiceInvokerCompat60.java:78)    at com.emc.documentum.fs.rt.context.impl.UcfClientInvocationHandler.invoke(UcfClientInvocationHandler.java:49)    at com.emc.documentum.fs.rt.context.impl.SoapClientInvocationHandler.invoke(SoapClientInvocationHandler.java:66)    at com.emc.documentum.fs.rt.context.impl.MtomCompatHandler60SP1.invoke(MtomCompatHandler60SP1.java:60)    at com.emc.documentum.fs.rt.context.impl.HttpSessionInvocationHandler.invoke(HttpSessionInvocationHandler.java:88)    at com.emc.documentum.fs.rt.context.impl.RemoteServiceInterfaceInvocationHandler.invoke(RemoteServiceInterfaceInvocationHandler.java:30)    at com.emc.documentum.fs.rt.context.impl.ReturnedContentTransformationHandler.invoke(ReturnedContentTransformationHandler.java:45)    at com.emc.documentum.fs.rt.context.impl.OperationOptionsHandler.invoke(OperationOptionsHandler.java:72)    at com.emc.documentum.fs.rt.context.impl.ContextThreadLocalInvocationHandler.invoke(ContextThreadLocalInvocationHandler.java:51)    at com.emc.documentum.fs.rt.context.impl.ServiceContextInvocationHandler.invoke(ServiceContextInvocationHandler.java:30)    at $Proxy22.execute(Unknown Source)    at com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator.main(ServiceTicketGenerator.java:213)Caused by: java.lang.NullPointerException    at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)    at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:44)    at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:39)    at java.lang.reflect.Constructor.newInstance(Constructor.java:516)    at com.emc.documentum.fs.rt.context.impl.compat.ClientReflectionServiceInvokerCompat60.getExceptionInstance(ClientReflectionServiceInvokerCompat60.java:148)    at com.emc.documentum.fs.rt.context.impl.compat.ClientReflectionServiceInvokerCompat60.invoke(ClientReflectionServiceInvokerCompat60.java:77)    ... 11 more

As you can see, both tickets have a large timeout before their expirations.

From the server side, here's what i get when the error occurs :

[12/27/11 13:24:19:866 CET] 00000026 SystemOut     O 7604966 [WebContainer : 2] WARN  com.emc.documentum.fs.tracing.DFSTracer - 
java.lang.NullPointerException
    at com.ibm.ws.webcontainer.srt.SRTServletRequest$SRTServletRequestHelper.access$1800(SRTServletRequest.java:2629)
    at com.ibm.ws.webcontainer.srt.SRTServletRequest.getQueryString(SRTServletRequest.java:1623)
    at com.sun.xml.ws.transport.http.servlet.ServletConnectionImpl.getQueryString(ServletConnectionImpl.java:214)
    at sun.reflect.GeneratedMethodAccessor57.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:600)
    at com.sun.xml.ws.api.PropertySet$MethodAccessor.get(PropertySet.java:283)
    at com.sun.xml.ws.api.PropertySet$3.getValue(PropertySet.java:421)
    at java.util.HashMap.putAllImpl(HashMap.java:679)
    at java.util.HashMap.putAll(HashMap.java:669)
    at com.sun.xml.ws.server.EndpointMessageContextImpl.createBackupMap(EndpointMessageContextImpl.java:192)
    at com.sun.xml.ws.server.EndpointMessageContextImpl.access$100(EndpointMessageContextImpl.java:65)
    at com.sun.xml.ws.server.EndpointMessageContextImpl$EntrySet.size(EndpointMessageContextImpl.java:185)
    at java.util.AbstractMap.size(AbstractMap.java:585)
    at java.util.AbstractMap.isEmpty(AbstractMap.java:449)
    at java.util.AbstractMap.toString(AbstractMap.java:595)
    at java.lang.String.valueOf(String.java:1511)
    at java.lang.StringBuilder.append(StringBuilder.java:191)
    at java.util.AbstractMap.toString(AbstractMap.java:613)
    at com.emc.documentum.fs.tracing.DFSTracer.resultToString(DFSTracer.java:761)
    at com.emc.documentum.fs.tracing.DFSTracer.traceMethodExit(DFSTracer.java:233)
    at com.emc.documentum.fs.aspects.Tracing.ajc$afterReturning$com_emc_documentum_fs_aspects_Tracing$2$8b9079b8(Tracing.aj:66)
    at com.emc.documentum.fs.rt.impl.ThreadLocalStorage.getStorage(ThreadLocalStorage.java:32)
    at com.emc.documentum.fs.rt.impl.ThreadLocalStorage.set(ThreadLocalStorage.java:21)
    at com.emc.documentum.fs.rt.impl.handler.ServerContextHandler.handleMessage(ServerContextHandler.java:130)
    at com.emc.documentum.fs.rt.impl.handler.ServerContextHandler.handleMessage(ServerContextHandler.java:1)
    at com.sun.xml.ws.handler.HandlerProcessor.callHandleMessage(HandlerProcessor.java:284)
    at com.sun.xml.ws.handler.HandlerProcessor.callHandlersRequest(HandlerProcessor.java:135)
    at com.sun.xml.ws.handler.ServerSOAPHandlerTube.callHandlersOnRequest(ServerSOAPHandlerTube.java:134)
    at com.sun.xml.ws.handler.HandlerTube.processRequest(HandlerTube.java:116)
    at com.sun.xml.ws.api.pipe.Fiber.__doRun(Fiber.java:598)
    at com.sun.xml.ws.api.pipe.Fiber._doRun(Fiber.java:557)
    at com.sun.xml.ws.api.pipe.Fiber.doRun(Fiber.java:542)
    at com.sun.xml.ws.api.pipe.Fiber.runSync(Fiber.java:439)
    at com.sun.xml.ws.server.WSEndpointImpl$2.process(WSEndpointImpl.java:243)
    at com.sun.xml.ws.transport.http.HttpAdapter$HttpToolkit.handle(HttpAdapter.java:471)
    at com.sun.xml.ws.transport.http.HttpAdapter.handle(HttpAdapter.java:244)
    at com.sun.xml.ws.transport.http.servlet.ServletAdapter.handle(ServletAdapter.java:135)
    at com.sun.xml.ws.transport.http.servlet.WSServletDelegate.doGet(WSServletDelegate.java:129)
    at com.sun.xml.ws.transport.http.servlet.WSServletDelegate.doPost(WSServletDelegate.java:160)
    at com.sun.xml.ws.transport.http.servlet.WSServlet.doPost(WSServlet.java:75)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:738)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:831)
    at com.ibm.ws.webcontainer.servlet.ServletWrapper.service(ServletWrapper.java:1663)
    at com.ibm.ws.webcontainer.servlet.ServletWrapper.handleRequest(ServletWrapper.java:939)
    at com.ibm.ws.webcontainer.servlet.ServletWrapper.handleRequest(ServletWrapper.java:502)
    at com.ibm.ws.webcontainer.servlet.ServletWrapperImpl.handleRequest(ServletWrapperImpl.java:179)
    at com.ibm.ws.webcontainer.servlet.CacheServletWrapper.handleRequest(CacheServletWrapper.java:91)
    at com.ibm.ws.webcontainer.WebContainer.handleRequest(WebContainer.java:864)
    at com.ibm.ws.webcontainer.WSWebContainer.handleRequest(WSWebContainer.java:1583)
    at com.ibm.ws.webcontainer.channel.WCChannelLink.ready(WCChannelLink.java:186)
    at com.ibm.ws.http.channel.inbound.impl.HttpInboundLink.handleDiscrimination(HttpInboundLink.java:445)
    at com.ibm.ws.http.channel.inbound.impl.HttpInboundLink.handleNewRequest(HttpInboundLink.java:504)
    at com.ibm.ws.http.channel.inbound.impl.HttpInboundLink.processRequest(HttpInboundLink.java:301)
    at com.ibm.ws.http.channel.inbound.impl.HttpInboundLink.ready(HttpInboundLink.java:275)
    at com.ibm.ws.tcp.channel.impl.NewConnectionInitialReadCallback.sendToDiscriminators(NewConnectionInitialReadCallback.java:214)
    at com.ibm.ws.tcp.channel.impl.NewConnectionInitialReadCallback.complete(NewConnectionInitialReadCallback.java:113)
    at com.ibm.ws.tcp.channel.impl.AioReadCompletionListener.futureCompleted(AioReadCompletionListener.java:165)
    at com.ibm.io.async.AbstractAsyncFuture.invokeCallback(AbstractAsyncFuture.java:217)
    at com.ibm.io.async.AsyncChannelFuture.fireCompletionActions(AsyncChannelFuture.java:161)
    at com.ibm.io.async.AsyncFuture.completed(AsyncFuture.java:138)
    at com.ibm.io.async.ResultHandler.complete(ResultHandler.java:204)
    at com.ibm.io.async.ResultHandler.runEventProcessingLoop(ResultHandler.java:775)
    at com.ibm.io.async.ResultHandler$2.run(ResultHandler.java:905)
    at com.ibm.ws.util.ThreadPool$Worker.run(ThreadPool.java:1563)
     [12/27/11 13:24:19:867 CET] 00000026 SystemOut     O 7604967 [WebContainer : 2] WARN  com.emc.documentum.fs.tracing.DFSTracer - 
     java.lang.NullPointerException
    at com.ibm.ws.webcontainer.srt.SRTServletRequest.getScheme(SRTServletRequest.java:573)
    at com.ibm.ws.webcontainer.srt.SRTServletRequest.getRequestURL(SRTServletRequest.java:2422)
    at com.sun.xml.ws.transport.http.servlet.ServletConnectionImpl.getRequestURL(ServletConnectionImpl.java:256)
    at sun.reflect.GeneratedMethodAccessor59.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:600)
    at com.sun.xml.ws.api.PropertySet$MethodAccessor.get(PropertySet.java:283)
    at com.sun.xml.ws.api.PropertySet$3.getValue(PropertySet.java:421)
    at java.util.HashMap.putAllImpl(HashMap.java:679)
    at java.util.HashMap.putAll(HashMap.java:669)
    at com.sun.xml.ws.server.EndpointMessageContextImpl.createBackupMap(EndpointMessageContextImpl.java:192)
    at com.sun.xml.ws.server.EndpointMessageContextImpl.access$100(EndpointMessageContextImpl.java:65)
    at com.sun.xml.ws.server.EndpointMessageContextImpl$EntrySet.size(EndpointMessageContextImpl.java:185)
    at java.util.AbstractMap.size(AbstractMap.java:585)
    at java.util.AbstractMap.isEmpty(AbstractMap.java:449)
    at java.util.AbstractMap.toString(AbstractMap.java:595)
    at java.lang.String.valueOf(String.java:1511)
    at java.lang.StringBuilder.append(StringBuilder.java:191)
    at java.util.AbstractMap.toString(AbstractMap.java:613)
    at com.emc.documentum.fs.tracing.DFSTracer.resultToString(DFSTracer.java:761)
    at com.emc.documentum.fs.tracing.DFSTracer.traceMethodExit(DFSTracer.java:233)
    at com.emc.documentum.fs.aspects.Tracing.ajc$afterReturning$com_emc_documentum_fs_aspects_Tracing$2$8b9079b8(Tracing.aj:66)
    at com.emc.documentum.fs.rt.impl.ThreadLocalStorage.getStorage(ThreadLocalStorage.java:32)
    at com.emc.documentum.fs.rt.impl.ThreadLocalStorage.set(ThreadLocalStorage.java:21)
    at com.emc.documentum.fs.rt.impl.handler.ServerContextHandler.handleMessage(ServerContextHandler.java:134)
    at com.emc.documentum.fs.rt.impl.handler.ServerContextHandler.handleMessage(ServerContextHandler.java:1)
    at com.sun.xml.ws.handler.HandlerProcessor.callHandleMessage(HandlerProcessor.java:284)
    at com.sun.xml.ws.handler.HandlerProcessor.callHandlersRequest(HandlerProcessor.java:135)
    at com.sun.xml.ws.handler.ServerSOAPHandlerTube.callHandlersOnRequest(ServerSOAPHandlerTube.java:134)
    at com.sun.xml.ws.handler.HandlerTube.processRequest(HandlerTube.java:116)
    at com.sun.xml.ws.api.pipe.Fiber.__doRun(Fiber.java:598)
    at com.sun.xml.ws.api.pipe.Fiber._doRun(Fiber.java:557)
    at com.sun.xml.ws.api.pipe.Fiber.doRun(Fiber.java:542)
    at com.sun.xml.ws.api.pipe.Fiber.runSync(Fiber.java:439)
    at com.sun.xml.ws.server.WSEndpointImpl$2.process(WSEndpointImpl.java:243)
    at com.sun.xml.ws.transport.http.HttpAdapter$HttpToolkit.handle(HttpAdapter.java:471)
    at com.sun.xml.ws.transport.http.HttpAdapter.handle(HttpAdapter.java:244)
    at com.sun.xml.ws.transport.http.servlet.ServletAdapter.handle(ServletAdapter.java:135)
    at com.sun.xml.ws.transport.http.servlet.WSServletDelegate.doGet(WSServletDelegate.java:129)
    at com.sun.xml.ws.transport.http.servlet.WSServletDelegate.doPost(WSServletDelegate.java:160)
    at com.sun.xml.ws.transport.http.servlet.WSServlet.doPost(WSServlet.java:75)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:738)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:831)
    at com.ibm.ws.webcontainer.servlet.ServletWrapper.service(ServletWrapper.java:1663)
    at com.ibm.ws.webcontainer.servlet.ServletWrapper.handleRequest(ServletWrapper.java:939)
    at com.ibm.ws.webcontainer.servlet.ServletWrapper.handleRequest(ServletWrapper.java:502)
    at com.ibm.ws.webcontainer.servlet.ServletWrapperImpl.handleRequest(ServletWrapperImpl.java:179)
    at com.ibm.ws.webcontainer.servlet.CacheServletWrapper.handleRequest(CacheServletWrapper.java:91)
    at com.ibm.ws.webcontainer.WebContainer.handleRequest(WebContainer.java:864)
    at com.ibm.ws.webcontainer.WSWebContainer.handleRequest(WSWebContainer.java:1583)
    at com.ibm.ws.webcontainer.channel.WCChannelLink.ready(WCChannelLink.java:186)
    at com.ibm.ws.http.channel.inbound.impl.HttpInboundLink.handleDiscrimination(HttpInboundLink.java:445)
    at com.ibm.ws.http.channel.inbound.impl.HttpInboundLink.handleNewRequest(HttpInboundLink.java:504)
    at com.ibm.ws.http.channel.inbound.impl.HttpInboundLink.processRequest(HttpInboundLink.java:301)
    at com.ibm.ws.http.channel.inbound.impl.HttpInboundLink.ready(HttpInboundLink.java:275)
    at com.ibm.ws.tcp.channel.impl.NewConnectionInitialReadCallback.sendToDiscriminators(NewConnectionInitialReadCallback.java:214)
    at com.ibm.ws.tcp.channel.impl.NewConnectionInitialReadCallback.complete(NewConnectionInitialReadCallback.java:113)
    at com.ibm.ws.tcp.channel.impl.AioReadCompletionListener.futureCompleted(AioReadCompletionListener.java:165)
    at com.ibm.io.async.AbstractAsyncFuture.invokeCallback(AbstractAsyncFuture.java:217)
    at com.ibm.io.async.AsyncChannelFuture.fireCompletionActions(AsyncChannelFuture.java:161)
    at com.ibm.io.async.AsyncFuture.completed(AsyncFuture.java:138)
    at com.ibm.io.async.ResultHandler.complete(ResultHandler.java:204)
    at com.ibm.io.async.ResultHandler.runEventProcessingLoop(ResultHandler.java:775)
    at com.ibm.io.async.ResultHandler$2.run(ResultHandler.java:905)
    at com.ibm.ws.util.ThreadPool$Worker.run(ThreadPool.java:1563)
     [12/27/11 13:24:19:869 CET] 00000026 SystemOut     O [JGSS_DBG_CRED] JAAS config: debug=true
     [12/27/11 13:24:19:869 CET] 00000026 SystemOut     O [JGSS_DBG_CRED] JAAS config: principal=DFS/saumenjwin7.lu.ema.ad.pwcinternal.com:9080@LU.EMA.AD.PWCINTERNAL.COM
     [12/27/11 13:24:19:869 CET] 00000026 SystemOut     O [JGSS_DBG_CRED] JAAS config: credsType=initiate and accept
     [12/27/11 13:24:19:869 CET] 00000026 SystemOut     O [JGSS_DBG_CRED] config: useDefaultCcache=false
     [12/27/11 13:24:19:869 CET] 00000026 SystemOut     O [JGSS_DBG_CRED] config: useCcache=null
     [12/27/11 13:24:19:870 CET] 00000026 SystemOut     O [JGSS_DBG_CRED] config: useDefaultKeytab=false
     [12/27/11 13:24:19:870 CET] 00000026 SystemOut     O [JGSS_DBG_CRED] config: useKeytab=FILE:C:/APP/kerberos/EcmDevKbs.keytab
     [12/27/11 13:24:19:870 CET] 00000026 SystemOut     O [JGSS_DBG_CRED] JAAS config: forwardable=false (default)
     [12/27/11 13:24:19:870 CET] 00000026 SystemOut     O [JGSS_DBG_CRED] JAAS config: renewable=true
     [12/27/11 13:24:19:870 CET] 00000026 SystemOut     O [JGSS_DBG_CRED] JAAS config: proxiable=false (default)
     [12/27/11 13:24:19:870 CET] 00000026 SystemOut     O [JGSS_DBG_CRED] JAAS config: noAddress=false (default)
     [12/27/11 13:24:19:871 CET] 00000026 SystemOut     O [JGSS_DBG_CRED] JAAS config: tryFirstPass=false (default)
     [12/27/11 13:24:19:871 CET] 00000026 SystemOut     O [JGSS_DBG_CRED] JAAS config: useFirstPass=false (default)
     [12/27/11 13:24:19:871 CET] 00000026 SystemOut     O [JGSS_DBG_CRED] JAAS config: moduleBanner=false (default)
     [12/27/11 13:24:19:872 CET] 00000026 SystemOut     O [JGSS_DBG_CRED] JAAS config: interactive login? no
     [12/27/11 13:24:19:872 CET] 00000026 SystemOut     O [JGSS_DBG_CRED] Retrieving Kerberos creds from keytab for principal=DFS/saumenjwin7.lu.ema.ad.pwcinternal.com:9080@LU.EMA.AD.PWCINTERNAL.COM
     [12/27/11 13:24:19:872 CET] 00000026 SystemOut     O [JGSS_DBG_CRED] Service name=DFS/saumenjwin7.lu.ema.ad.pwcinternal.com:9080@LU.EMA.AD.PWCINTERNAL.COM
     [12/27/11 13:24:19:872 CET] 00000026 SystemOut     O [JGSS_DBG_CRED] No Kerberos creds in keytab : java.io.BufferedInputStream@21402140
     [12/27/11 13:24:19:872 CET] 00000026 SystemOut     O [JGSS_DBG_CRED] Done retrieving Kerberos creds from keytab
     [12/27/11 13:24:19:873 CET] 00000026 SystemOut     O [JGSS_DBG_CRED] Retrieving Kerberos creds from cache for principal=DFS/saumenjwin7.lu.ema.ad.pwcinternal.com:9080@LU.EMA.AD.PWCINTERNAL.COM
     [12/27/11 13:24:19:873 CET] 00000026 SystemOut     O [JGSS_DBG_CRED] Non-interactive login; no callbacks necessary.
     [12/27/11 13:24:19:873 CET] 00000026 SystemOut     O [JGSS_DBG_CRED] No Kerberos creds in cache for principal DFS/saumenjwin7.lu.ema.ad.pwcinternal.com:9080@LU.EMA.AD.PWCINTERNAL.COM
     [12/27/11 13:24:19:873 CET] 00000026 SystemOut     O [JGSS_DBG_CRED] Doing Kerberos login for principal DFS/saumenjwin7.lu.ema.ad.pwcinternal.com:9080@LU.EMA.AD.PWCINTERNAL.COM
     [12/27/11 13:24:19:875 CET] 00000026 SystemOut     O [JGSS_DBG_CRED] trying key type rc4-hmac
     [12/27/11 13:24:20:088 CET] 00000026 SystemOut     O [JGSS_DBG_CRED] Kerberos login complete
     [12/27/11 13:24:20:088 CET] 00000026 SystemOut     O [JGSS_DBG_CRED] Login successful
     [12/27/11 13:24:20:088 CET] 00000026 SystemOut     O [JGSS_DBG_CRED] DFS/saumenjwin7.lu.ema.ad.pwcinternal.com:9080@LU.EMA.AD.PWCINTERNAL.COM added to Subject
     [12/27/11 13:24:20:089 CET] 00000026 SystemOut     O [JGSS_DBG_CRED] Kerberos ticket for DFS/saumenjwin7.lu.ema.ad.pwcinternal.com:9080@LU.EMA.AD.PWCINTERNAL.COM added to Subject
     [12/27/11 13:24:20:089 CET] 00000026 SystemOut     O [JGSS_DBG_CRED] Attempting to add 1 Kerberos key(s) to Subject for DFS/saumenjwin7.lu.ema.ad.pwcinternal.com:9080@LU.EMA.AD.PWCINTERNAL.COM
     [12/27/11 13:24:20:089 CET] 00000026 SystemOut     O [JGSS_DBG_CRED] added key of type rc4-hmac
     [12/27/11 13:24:20:089 CET] 00000026 SystemOut     O [JGSS_DBG_CRED] Successfully added 1 keys to Subject.
     [12/27/11 13:24:20:100 CET] 00000026 SystemOut     O 7605199 [WebContainer : 2] WARN  com.emc.documentum.fs.tracing.DFSTracer - 
     java.lang.reflect.UndeclaredThrowableException
    at $Proxy117.toString(Unknown Source)
    at com.emc.documentum.fs.tracing.DFSTracer.resultToString(DFSTracer.java:761)
    at com.emc.documentum.fs.tracing.DFSTracer.traceMethodExit(DFSTracer.java:233)
    at com.emc.documentum.fs.aspects.Tracing.ajc$afterReturning$com_emc_documentum_fs_aspects_Tracing$2$8b9079b8(Tracing.aj:66)
    at com.emc.documentum.fs.rt.context.impl.ServerServiceContext.getService(ServerServiceContext.java:88)
    at com.emc.documentum.fs.services.core.QueryServiceWebService.getService(QueryServiceWebService.java:17)
    at com.emc.documentum.fs.services.core.QueryServiceWebService.execute(QueryServiceWebService.java:38)
    at sun.reflect.GeneratedMethodAccessor63.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:600)
    at com.sun.xml.ws.api.server.InstanceResolver$1.invoke(InstanceResolver.java:246)
    at com.sun.xml.ws.server.InvokerTube$2.invoke(InvokerTube.java:146)
    at com.sun.xml.ws.server.sei.EndpointMethodHandler.invoke(EndpointMethodHandler.java:257)
    at com.sun.xml.ws.server.sei.SEIInvokerTube.processRequest(SEIInvokerTube.java:93)
    at com.sun.xml.ws.api.pipe.Fiber.__doRun(Fiber.java:598)
    at com.sun.xml.ws.api.pipe.Fiber._doRun(Fiber.java:557)
    at com.sun.xml.ws.api.pipe.Fiber.doRun(Fiber.java:542)
    at com.sun.xml.ws.api.pipe.Fiber.runSync(Fiber.java:439)
    at com.sun.xml.ws.server.WSEndpointImpl$2.process(WSEndpointImpl.java:243)
    at com.sun.xml.ws.transport.http.HttpAdapter$HttpToolkit.handle(HttpAdapter.java:471)
    at com.sun.xml.ws.transport.http.HttpAdapter.handle(HttpAdapter.java:244)
    at com.sun.xml.ws.transport.http.servlet.ServletAdapter.handle(ServletAdapter.java:135)
    at com.sun.xml.ws.transport.http.servlet.WSServletDelegate.doGet(WSServletDelegate.java:129)
    at com.sun.xml.ws.transport.http.servlet.WSServletDelegate.doPost(WSServletDelegate.java:160)
    at com.sun.xml.ws.transport.http.servlet.WSServlet.doPost(WSServlet.java:75)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:738)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:831)
    at com.ibm.ws.webcontainer.servlet.ServletWrapper.service(ServletWrapper.java:1663)
    at com.ibm.ws.webcontainer.servlet.ServletWrapper.handleRequest(ServletWrapper.java:939)
    at com.ibm.ws.webcontainer.servlet.ServletWrapper.handleRequest(ServletWrapper.java:502)
    at com.ibm.ws.webcontainer.servlet.ServletWrapperImpl.handleRequest(ServletWrapperImpl.java:179)
    at com.ibm.ws.webcontainer.servlet.CacheServletWrapper.handleRequest(CacheServletWrapper.java:91)
    at com.ibm.ws.webcontainer.WebContainer.handleRequest(WebContainer.java:864)
    at com.ibm.ws.webcontainer.WSWebContainer.handleRequest(WSWebContainer.java:1583)
    at com.ibm.ws.webcontainer.channel.WCChannelLink.ready(WCChannelLink.java:186)
    at com.ibm.ws.http.channel.inbound.impl.HttpInboundLink.handleDiscrimination(HttpInboundLink.java:445)
    at com.ibm.ws.http.channel.inbound.impl.HttpInboundLink.handleNewRequest(HttpInboundLink.java:504)
    at com.ibm.ws.http.channel.inbound.impl.HttpInboundLink.processRequest(HttpInboundLink.java:301)
    at com.ibm.ws.http.channel.inbound.impl.HttpInboundLink.ready(HttpInboundLink.java:275)
    at com.ibm.ws.tcp.channel.impl.NewConnectionInitialReadCallback.sendToDiscriminators(NewConnectionInitialReadCallback.java:214)
    at com.ibm.ws.tcp.channel.impl.NewConnectionInitialReadCallback.complete(NewConnectionInitialReadCallback.java:113)
    at com.ibm.ws.tcp.channel.impl.AioReadCompletionListener.futureCompleted(AioReadCompletionListener.java:165)
    at com.ibm.io.async.AbstractAsyncFuture.invokeCallback(AbstractAsyncFuture.java:217)
    at com.ibm.io.async.AsyncChannelFuture.fireCompletionActions(AsyncChannelFuture.java:161)
    at com.ibm.io.async.AsyncFuture.completed(AsyncFuture.java:138)
    at com.ibm.io.async.ResultHandler.complete(ResultHandler.java:204)
    at com.ibm.io.async.ResultHandler.runEventProcessingLoop(ResultHandler.java:775)
    at com.ibm.io.async.ResultHandler$2.run(ResultHandler.java:905)
    at com.ibm.ws.util.ThreadPool$Worker.run(ThreadPool.java:1563)
     Caused by: 
     com.emc.documentum.fs.rt.AuthenticationException: java.lang.NullPointerException
    at com.emc.documentum.fs.rt.handlers.KerberosTokenServerHandler.exception(KerberosTokenServerHandler.java:277)
    at com.emc.documentum.fs.rt.handlers.KerberosTokenServerHandler.handleMessage(KerberosTokenServerHandler.java:128)
    at com.emc.documentum.fs.rt.handlers.KerberosTokenServerHandler.handleMessage(KerberosTokenServerHandler.java:1)
    at com.sun.xml.ws.handler.HandlerProcessor.callHandleMessage(HandlerProcessor.java:284)
    at com.sun.xml.ws.handler.HandlerProcessor.callHandlersRequest(HandlerProcessor.java:135)
    at com.sun.xml.ws.handler.ServerSOAPHandlerTube.callHandlersOnRequest(ServerSOAPHandlerTube.java:134)
    at com.sun.xml.ws.handler.HandlerTube.processRequest(HandlerTube.java:116)
    ... 35 more
     Caused by: 
     java.lang.NullPointerException
    at org.apache.commons.codec.binary.Base64.encodeBase64(Base64.java:233)
    at org.apache.commons.codec.binary.Base64.encode(Base64.java:521)
    at com.emc.documentum.kerberos.utility.AcceptAction.run(AcceptAction.java:33)
    at com.emc.documentum.kerberos.utility.AcceptAction.run(AcceptAction.java:11)
    at java.security.AccessController.doPrivileged(AccessController.java:284)
    at javax.security.auth.Subject.doAs(Subject.java:573)
    at com.emc.documentum.kerberos.utility.KerberosUtility.executePrivilegedAction(KerberosUtility.java:133)
    at com.emc.documentum.kerberos.utility.KerberosUtility.executeAcceptAction(KerberosUtility.java:113)
    at com.emc.documentum.kerberos.utility.KerberosUtility.accept(KerberosUtility.java:54)
    at com.emc.documentum.fs.rt.handlers.KerberosTokenServerHandler.authenticate(KerberosTokenServerHandler.java:218)
    at com.emc.documentum.fs.rt.handlers.KerberosTokenServerHandler.handleMessage(KerberosTokenServerHandler.java:96)
    ... 40 more
     [12/27/11 13:24:20:103 CET] 00000026 SystemOut     O 13:24:20,102 ERROR [WebContainer : 2] com.emc.documentum.fs.services.core.QueryServiceWebService - java.lang.NullPointerException
     com.emc.documentum.fs.rt.AuthenticationException: java.lang.NullPointerException
    at com.emc.documentum.fs.rt.handlers.KerberosTokenServerHandler.exception(KerberosTokenServerHandler.java:277)
    at com.emc.documentum.fs.rt.handlers.KerberosTokenServerHandler.handleMessage(KerberosTokenServerHandler.java:128)
    at com.emc.documentum.fs.rt.handlers.KerberosTokenServerHandler.handleMessage(KerberosTokenServerHandler.java:1)
    at com.sun.xml.ws.handler.HandlerProcessor.callHandleMessage(HandlerProcessor.java:284)
    at com.sun.xml.ws.handler.HandlerProcessor.callHandlersRequest(HandlerProcessor.java:135)
    at com.sun.xml.ws.handler.ServerSOAPHandlerTube.callHandlersOnRequest(ServerSOAPHandlerTube.java:134)
    at com.sun.xml.ws.handler.HandlerTube.processRequest(HandlerTube.java:116)
    at com.sun.xml.ws.api.pipe.Fiber.__doRun(Fiber.java:598)
    at com.sun.xml.ws.api.pipe.Fiber._doRun(Fiber.java:557)
    at com.sun.xml.ws.api.pipe.Fiber.doRun(Fiber.java:542)
    at com.sun.xml.ws.api.pipe.Fiber.runSync(Fiber.java:439)
    at com.sun.xml.ws.server.WSEndpointImpl$2.process(WSEndpointImpl.java:243)
    at com.sun.xml.ws.transport.http.HttpAdapter$HttpToolkit.handle(HttpAdapter.java:471)
    at com.sun.xml.ws.transport.http.HttpAdapter.handle(HttpAdapter.java:244)
    at com.sun.xml.ws.transport.http.servlet.ServletAdapter.handle(ServletAdapter.java:135)
    at com.sun.xml.ws.transport.http.servlet.WSServletDelegate.doGet(WSServletDelegate.java:129)
    at com.sun.xml.ws.transport.http.servlet.WSServletDelegate.doPost(WSServletDelegate.java:160)
    at com.sun.xml.ws.transport.http.servlet.WSServlet.doPost(WSServlet.java:75)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:738)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:831)
    at com.ibm.ws.webcontainer.servlet.ServletWrapper.service(ServletWrapper.java:1663)
    at com.ibm.ws.webcontainer.servlet.ServletWrapper.handleRequest(ServletWrapper.java:939)
    at com.ibm.ws.webcontainer.servlet.ServletWrapper.handleRequest(ServletWrapper.java:502)
    at com.ibm.ws.webcontainer.servlet.ServletWrapperImpl.handleRequest(ServletWrapperImpl.java:179)
    at com.ibm.ws.webcontainer.servlet.CacheServletWrapper.handleRequest(CacheServletWrapper.java:91)
    at com.ibm.ws.webcontainer.WebContainer.handleRequest(WebContainer.java:864)
    at com.ibm.ws.webcontainer.WSWebContainer.handleRequest(WSWebContainer.java:1583)
    at com.ibm.ws.webcontainer.channel.WCChannelLink.ready(WCChannelLink.java:186)
    at com.ibm.ws.http.channel.inbound.impl.HttpInboundLink.handleDiscrimination(HttpInboundLink.java:445)
    at com.ibm.ws.http.channel.inbound.impl.HttpInboundLink.handleNewRequest(HttpInboundLink.java:504)
    at com.ibm.ws.http.channel.inbound.impl.HttpInboundLink.processRequest(HttpInboundLink.java:301)
    at com.ibm.ws.http.channel.inbound.impl.HttpInboundLink.ready(HttpInboundLink.java:275)
    at com.ibm.ws.tcp.channel.impl.NewConnectionInitialReadCallback.sendToDiscriminators(NewConnectionInitialReadCallback.java:214)
    at com.ibm.ws.tcp.channel.impl.NewConnectionInitialReadCallback.complete(NewConnectionInitialReadCallback.java:113)
    at com.ibm.ws.tcp.channel.impl.AioReadCompletionListener.futureCompleted(AioReadCompletionListener.java:165)
    at com.ibm.io.async.AbstractAsyncFuture.invokeCallback(AbstractAsyncFuture.java:217)
    at com.ibm.io.async.AsyncChannelFuture.fireCompletionActions(AsyncChannelFuture.java:161)
    at com.ibm.io.async.AsyncFuture.completed(AsyncFuture.java:138)
    at com.ibm.io.async.ResultHandler.complete(ResultHandler.java:204)
    at com.ibm.io.async.ResultHandler.runEventProcessingLoop(ResultHandler.java:775)
    at com.ibm.io.async.ResultHandler$2.run(ResultHandler.java:905)
    at com.ibm.ws.util.ThreadPool$Worker.run(ThreadPool.java:1563)
     Caused by: 
     java.lang.NullPointerException
    at org.apache.commons.codec.binary.Base64.encodeBase64(Base64.java:233)
    at org.apache.commons.codec.binary.Base64.encode(Base64.java:521)
    at com.emc.documentum.kerberos.utility.AcceptAction.run(AcceptAction.java:33)
    at com.emc.documentum.kerberos.utility.AcceptAction.run(AcceptAction.java:11)
    at java.security.AccessController.doPrivileged(AccessController.java:284)
    at javax.security.auth.Subject.doAs(Subject.java:573)
    at com.emc.documentum.kerberos.utility.KerberosUtility.executePrivilegedAction(KerberosUtility.java:133)
    at com.emc.documentum.kerberos.utility.KerberosUtility.executeAcceptAction(KerberosUtility.java:113)
    at com.emc.documentum.kerberos.utility.KerberosUtility.accept(KerberosUtility.java:54)
    at com.emc.documentum.fs.rt.handlers.KerberosTokenServerHandler.authenticate(KerberosTokenServerHandler.java:218)
    at com.emc.documentum.fs.rt.handlers.KerberosTokenServerHandler.handleMessage(KerberosTokenServerHandler.java:96)
    ... 40 more
     [12/27/11 13:24:20:113 CET] 00000026 SystemOut     O 7605203 [WebContainer : 2] ERROR com.emc.documentum.fs.services.core.QueryServiceWebService - java.lang.NullPointerException
     com.emc.documentum.fs.rt.AuthenticationException: java.lang.NullPointerException
    at com.emc.documentum.fs.rt.handlers.KerberosTokenServerHandler.exception(KerberosTokenServerHandler.java:277)
    at com.emc.documentum.fs.rt.handlers.KerberosTokenServerHandler.handleMessage(KerberosTokenServerHandler.java:128)
    at com.emc.documentum.fs.rt.handlers.KerberosTokenServerHandler.handleMessage(KerberosTokenServerHandler.java:1)
    at com.sun.xml.ws.handler.HandlerProcessor.callHandleMessage(HandlerProcessor.java:284)
    at com.sun.xml.ws.handler.HandlerProcessor.callHandlersRequest(HandlerProcessor.java:135)
    at com.sun.xml.ws.handler.ServerSOAPHandlerTube.callHandlersOnRequest(ServerSOAPHandlerTube.java:134)
    at com.sun.xml.ws.handler.HandlerTube.processRequest(HandlerTube.java:116)
    at com.sun.xml.ws.api.pipe.Fiber.__doRun(Fiber.java:598)
    at com.sun.xml.ws.api.pipe.Fiber._doRun(Fiber.java:557)
    at com.sun.xml.ws.api.pipe.Fiber.doRun(Fiber.java:542)
    at com.sun.xml.ws.api.pipe.Fiber.runSync(Fiber.java:439)
    at com.sun.xml.ws.server.WSEndpointImpl$2.process(WSEndpointImpl.java:243)
    at com.sun.xml.ws.transport.http.HttpAdapter$HttpToolkit.handle(HttpAdapter.java:471)
    at com.sun.xml.ws.transport.http.HttpAdapter.handle(HttpAdapter.java:244)
    at com.sun.xml.ws.transport.http.servlet.ServletAdapter.handle(ServletAdapter.java:135)
    at com.sun.xml.ws.transport.http.servlet.WSServletDelegate.doGet(WSServletDelegate.java:129)
    at com.sun.xml.ws.transport.http.servlet.WSServletDelegate.doPost(WSServletDelegate.java:160)
    at com.sun.xml.ws.transport.http.servlet.WSServlet.doPost(WSServlet.java:75)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:738)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:831)
    at com.ibm.ws.webcontainer.servlet.ServletWrapper.service(ServletWrapper.java:1663)
    at com.ibm.ws.webcontainer.servlet.ServletWrapper.handleRequest(ServletWrapper.java:939)
    at com.ibm.ws.webcontainer.servlet.ServletWrapper.handleRequest(ServletWrapper.java:502)
    at com.ibm.ws.webcontainer.servlet.ServletWrapperImpl.handleRequest(ServletWrapperImpl.java:179)
    at com.ibm.ws.webcontainer.servlet.CacheServletWrapper.handleRequest(CacheServletWrapper.java:91)
    at com.ibm.ws.webcontainer.WebContainer.handleRequest(WebContainer.java:864)
    at com.ibm.ws.webcontainer.WSWebContainer.handleRequest(WSWebContainer.java:1583)
    at com.ibm.ws.webcontainer.channel.WCChannelLink.ready(WCChannelLink.java:186)
    at com.ibm.ws.http.channel.inbound.impl.HttpInboundLink.handleDiscrimination(HttpInboundLink.java:445)
    at com.ibm.ws.http.channel.inbound.impl.HttpInboundLink.handleNewRequest(HttpInboundLink.java:504)
    at com.ibm.ws.http.channel.inbound.impl.HttpInboundLink.processRequest(HttpInboundLink.java:301)
    at com.ibm.ws.http.channel.inbound.impl.HttpInboundLink.ready(HttpInboundLink.java:275)
    at com.ibm.ws.tcp.channel.impl.NewConnectionInitialReadCallback.sendToDiscriminators(NewConnectionInitialReadCallback.java:214)
    at com.ibm.ws.tcp.channel.impl.NewConnectionInitialReadCallback.complete(NewConnectionInitialReadCallback.java:113)
    at com.ibm.ws.tcp.channel.impl.AioReadCompletionListener.futureCompleted(AioReadCompletionListener.java:165)
    at com.ibm.io.async.AbstractAsyncFuture.invokeCallback(AbstractAsyncFuture.java:217)
    at com.ibm.io.async.AsyncChannelFuture.fireCompletionActions(AsyncChannelFuture.java:161)
    at com.ibm.io.async.AsyncFuture.completed(AsyncFuture.java:138)
    at com.ibm.io.async.ResultHandler.complete(ResultHandler.java:204)
    at com.ibm.io.async.ResultHandler.runEventProcessingLoop(ResultHandler.java:775)
    at com.ibm.io.async.ResultHandler$2.run(ResultHandler.java:905)
    at com.ibm.ws.util.ThreadPool$Worker.run(ThreadPool.java:1563)
     Caused by: 
     java.lang.NullPointerException
    at org.apache.commons.codec.binary.Base64.encodeBase64(Base64.java:233)
    at org.apache.commons.codec.binary.Base64.encode(Base64.java:521)
    at com.emc.documentum.kerberos.utility.AcceptAction.run(AcceptAction.java:33)
    at com.emc.documentum.kerberos.utility.AcceptAction.run(AcceptAction.java:11)
    at java.security.AccessController.doPrivileged(AccessController.java:284)
    at javax.security.auth.Subject.doAs(Subject.java:573)
    at com.emc.documentum.kerberos.utility.KerberosUtility.executePrivilegedAction(KerberosUtility.java:133)
    at com.emc.documentum.kerberos.utility.KerberosUtility.executeAcceptAction(KerberosUtility.java:113)
    at com.emc.documentum.kerberos.utility.KerberosUtility.accept(KerberosUtility.java:54)
    at com.emc.documentum.fs.rt.handlers.KerberosTokenServerHandler.authenticate(KerberosTokenServerHandler.java:218)
    at com.emc.documentum.fs.rt.handlers.KerberosTokenServerHandler.handleMessage(KerberosTokenServerHandler.java:96)
    ... 40 more

I tried to play with the time limit and if I limit the service ticket to 5 min, it works perfectly but i would like to know why i have this 5 minutes timeout.

There's another thing strange i'm experiencing : if i try to limit the service ticket to, for example, 30 seconds and i try to use the ticket after that, it continues to work fine (until i reach the 5 minutes "timeout")

522 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - Service ticket has been created2143 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - 0h 0min 2sec : 2837.0 object found7151 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - Using old TGT (expired in 9h 5min 59sec)7152 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - Using old service ticket (expired in 0h 0min 23sec)7507 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - 0h 0min 8sec : 2837.0 object found12517 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - Using old TGT (expired in 9h 5min 54sec)12518 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - Using old service ticket (expired in 0h 0min 18sec)12853 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - 0h 0min 13sec : 2837.0 object found17862 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - Using old TGT (expired in 9h 5min 48sec)17862 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - Using old service ticket (expired in 0h 0min 12sec)18194 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - 0h 0min 18sec : 2837.0 object found23200 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - Using old TGT (expired in 9h 5min 43sec)23200 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - Using old service ticket (expired in 0h 0min 7sec)23561 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - 0h 0min 24sec : 2837.0 object found28570 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - Using old TGT (expired in 9h 5min 38sec)28571 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - Using old service ticket (expired in 0h 0min 2sec)28897 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - 0h 0min 29sec : 2837.0 object found33902 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - Using old TGT (expired in 9h 5min 32sec)33902 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - Using old service ticket (expired in 0h 0min 0sec)34226 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - 0h 0min 34sec : 2837.0 object found39235 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - Using old TGT (expired in 9h 5min 27sec)39236 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - Using old service ticket (expired in 0h 0min 0sec)39560 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - 0h 0min 40sec : 2837.0 object found

Even if i reduce the TGT lifetime, (which limits also the service ticket) i can continue to use the service ticket when its timeout is reached ; the only operation i can't do is to ask for another service ticket when the TGT is timeout.

482 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - Service ticket has been created989 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - 0h 0min 1sec : 2838.0 object found5994 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - Using old TGT (expired in 0h 0min 9sec)5994 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - Using old service ticket (expired in 0h 0min 9sec)6311 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - 0h 0min 6sec : 2838.0 object found11320 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - Using old TGT (expired in 0h 0min 4sec)11320 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - Using old service ticket (expired in 0h 0min 4sec)11638 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - 0h 0min 12sec : 2838.0 object found16643 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - Using old TGT (expired in 0h 0min 0sec)16643 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - Using old service ticket (expired in 0h 0min 0sec)16935 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - 0h 0min 17sec : 2838.0 object found21944 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - Using old TGT (expired in 0h 0min 0sec)21945 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - Using old service ticket (expired in 0h 0min 0sec)22268 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - 0h 0min 22sec : 2839.0 object found27276 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - Using old TGT (expired in 0h 0min 0sec)27276 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - Using old service ticket (expired in 0h 0min 0sec)27606 [main] INFO  com.pwc.lu.business.plugin.ecm.dynamic.tools.kerberos.ServiceTicketGenerator - 0h 0min 28sec : 2839.0 object found

Jeremy Saumen

I found out what is the issue :

[12/28/11 9:18:28:614 CET] 0000001e SystemErr     R org.ietf.jgss.GSSException, major code: 10, minor code: 37
     major string: Defective token
     minor string: Client time Wednesday, December 28, 2011 at 9:13:27 AM too skewed
[12/28/11 9:18:28:615 CET] 0000001e SystemErr     R      at com.ibm.security.jgss.i18n.I18NException.throwGSSException(I18NException.java:7)

It's the parameter clockskew in the krb5.ini.

I think since I only generate a service ticket 1 time, the "client time" inside the ticket doesn't change so I only can use it inside the clockskew limit.