I have a number of NPEs occuring when, implicitly, calling request.getAttribute("atg.parent.session.id"). The stack trace is below (wrapped between the trace log).
[2012/02/03 12:53:26:953 SAST] 00000162 srt 1 com.ibm.ws.webcontainer.srt.SRTServletRequest getHeader this->com.ibm.ws.webcontainer.srt.SRTServletRequest@14f314f3: name --> SOAPAction header --> "http://acme.com/services/pick/SubmitOrder2"
[2012/02/03 12:53:26:953 SAST] 00000162 http 1 com.ibm.ws.webcontainer.srt.http.HttpInputStream fill fill
[2012/02/03 12:53:26:960 SAST] 00000162 channel 1 com.ibm.ws.webcontainer.channel.WCCByteBufferInputStream bufferIsGood buffer is good remaining --> 1635
[2012/02/03 12:53:26:960 SAST] 00000162 http 1 com.ibm.ws.webcontainer.srt.http.HttpInputStream read read length -->2048
[2012/02/03 12:53:26:960 SAST] 00000162 channel 1 com.ibm.ws.webcontainer.channel.WCCByteBufferInputStream bufferIsGood buffer is good remaining --> 1123
[2012/02/03 12:53:26:960 SAST] 00000162 channel 1 com.ibm.ws.webcontainer.channel.WCCByteBufferInputStream read Reset requested len --> 1574 to size remaining in current buffer --> 1123
[2012/02/03 12:53:26:960 SAST] 00000162 http 1 com.ibm.ws.webcontainer.srt.http.HttpInputStream read read returning -->1597, total=1635,limit=1635
[2012/02/03 12:53:26:961 SAST] 00000162 http 1 com.ibm.ws.webcontainer.srt.http.HttpInputStream read read length -->2048
[2012/02/03 12:53:26:962 SAST] 00000162 http 1 com.ibm.ws.webcontainer.srt.http.HttpInputStream read Over the limit: -1
[2012/02/03 12:53:26:962 SAST] 00000162 http > com.ibm.ws.webcontainer.srt.http.HttpInputStream close ENTRY total=1635,limit=1635
[2012/02/03 12:53:26:962 SAST] 00000162 http 1 com.ibm.ws.webcontainer.srt.http.HttpInputStream finish finish
[2012/02/03 12:53:26:962 SAST] 00000162 srt 1 com.ibm.ws.webcontainer.srt.SRTServletResponse isSkipInputStreamRead skipInputStreamRead = false
[2012/02/03 12:53:26:962 SAST] 00000162 http < com.ibm.ws.webcontainer.srt.http.HttpInputStream close RETURN total=1635,limit=1635
[2012/02/03 12:53:26:964 SAST] 00000162 PickingManage I com.acme.services.pick.PickingManagementHttpBindingImpl submitOrder2 Method: submitOrder2
[2012/02/03 12:53:26:967 SAST] 00000162 webapp 1 com.ibm.ws.webcontainer.webapp.WebAppDispatcherContextImpl isSecurityEnabledForApplication serverSecurityEnabled
[2012/02/03 12:53:26:967 SAST] 00000162 srt 1 com.ibm.ws.webcontainer.srt.SRTServletRequest getRemoteUser (security enabled)--> user XXXX
[2012/02/03 12:53:26:968 SAST] 00000162 PickingManage I com.acme.services.pick.PickingManagementHttpBindingImpl getUsername current user is: XXXX
[2012/02/03 12:53:26:971 SAST] 00000162 channel 1 com.ibm.ws.webcontainer.channel.WCCRequestImpl getHeader header --> Axis/1.4
[2012/02/03 12:53:26:971 SAST] 00000162 srt 1 com.ibm.ws.webcontainer.srt.SRTServletRequest getHeader this->com.ibm.ws.webcontainer.srt.SRTServletRequest@14f314f3: name --> user-agent
[2012/02/03 12:53:27:564 SAST] 00000162 srt 1 com.ibm.ws.webcontainer.srt.SRTServletRequest getAttribute this->com.ibm.ws.webcontainer.srt.SRTServletRequest@28e428e4: name --> atg.parent.session.id
[2012/02/03 12:53:27:565 SAST] 00000162 SystemOut O /com/acme/order/picking/PickingService An exception occurred: java.lang.NullPointerException java.lang.NullPointerException
at com.ibm.ws.webcontainer.srt.SRTServletRequest$SRTServletRequestHelper.access$200(SRTServletRequest.java:2629)
at com.ibm.ws.webcontainer.srt.SRTServletRequest.getAttribute(SRTServletRequest.java:276)
at atg.servlet.MutableHttpServletRequest.getAttribute(MutableHttpServletRequest.java:505)
at atg.servlet.MutableHttpServletRequest.getAttribute(MutableHttpServletRequest.java:470)
at atg.servlet.NameContextManager.getNameContextId(NameContextManager.java:320)
at atg.servlet.ServletUtil.getParentSessionId(ServletUtil.java:558)
at atg.commerce.messaging.CommerceMessageImpl.<init>(CommerceMessageImpl.java:230)
at com.acme.fulfillment.PickingMessage.<init>(PickingMessage.java:5)
at com.acme.order.picking.PickingService.submitOrder(PickingService.java:128)
at com.acme.services.pick.PickingManagementHttpBindingImpl.submitOrder2(PickingManagementHttpBindingImpl.java:177)
at com.acme.services.pick.PickingManagementHttpBindingSkeleton.submitOrder2(PickingManagementHttpBindingSkeleton.java:165)
at sun.reflect.GeneratedMethodAccessor1040.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:37)
at java.lang.reflect.Method.invoke(Method.java:600)
at org.apache.axis.providers.java.RPCProvider.invokeMethod(RPCProvider.java:388)
at org.apache.axis.providers.java.RPCProvider.processMessage(RPCProvider.java:283)
at org.apache.axis.providers.java.JavaProvider.invoke(JavaProvider.java:323)
at org.apache.axis.strategies.InvocationStrategy.visit(InvocationStrategy.java:32)
at org.apache.axis.SimpleChain.doVisiting(SimpleChain.java:118)
at org.apache.axis.SimpleChain.invoke(SimpleChain.java:83)
at org.apache.axis.handlers.soap.SOAPService.invoke(SOAPService.java:453)
at org.apache.axis.server.AxisServer.invoke(AxisServer.java:281)
at org.apache.axis.transport.http.AxisServlet.doPost(AxisServlet.java:699)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:738)
at org.apache.axis.transport.http.AxisServletBase.service(AxisServletBase.java:327)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:831)
[2012/02/03 12:53:27:566 SAST] 00000162 SystemOut O
[2012/02/03 12:53:27:571 SAST] 00000162 PickingManage E com.acme.services.pick.PickingManagementHttpBindingImpl submitOrder2 An exception occurred: java.lang.NullPointerException
java.lang.NullPointerException
at com.ibm.ws.webcontainer.srt.SRTServletRequest$SRTServletRequestHelper.access$200(SRTServletRequest.java:2629)
at com.ibm.ws.webcontainer.srt.SRTServletRequest.getAttribute(SRTServletRequest.java:276)
at atg.servlet.MutableHttpServletRequest.getAttribute(MutableHttpServletRequest.java:505)
at atg.servlet.MutableHttpServletRequest.getAttribute(MutableHttpServletRequest.java:470)
at atg.servlet.NameContextManager.getNameContextId(NameContextManager.java:320)
at atg.servlet.ServletUtil.getParentSessionId(ServletUtil.java:558)
at atg.commerce.messaging.CommerceMessageImpl.<init>(CommerceMessageImpl.java:230)
at com.acme.fulfillment.PickingMessage.<init>(PickingMessage.java:5)
at com.acme.order.picking.PickingService.submitOrder(PickingService.java:128)
at com.acme.services.pick.PickingManagementHttpBindingImpl.submitOrder2(PickingManagementHttpBindingImpl.java:177)
at com.acme.services.pick.PickingManagementHttpBindingSkeleton.submitOrder2(PickingManagementHttpBindingSkeleton.java:165)
at sun.reflect.GeneratedMethodAccessor1040.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:37)
at java.lang.reflect.Method.invoke(Method.java:600)
at org.apache.axis.providers.java.RPCProvider.invokeMethod(RPCProvider.java:388)
at org.apache.axis.providers.java.RPCProvider.processMessage(RPCProvider.java:283)
at org.apache.axis.providers.java.JavaProvider.invoke(JavaProvider.java:323)
at org.apache.axis.strategies.InvocationStrategy.visit(InvocationStrategy.java:32)
at org.apache.axis.SimpleChain.doVisiting(SimpleChain.java:118)
at org.apache.axis.SimpleChain.invoke(SimpleChain.java:83)
at org.apache.axis.handlers.soap.SOAPService.invoke(SOAPService.java:453)
at org.apache.axis.server.AxisServer.invoke(AxisServer.java:281)
at org.apache.axis.transport.http.AxisServlet.doPost(AxisServlet.java:699)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:738)
at org.apache.axis.transport.http.AxisServletBase.service(AxisServletBase.java:327)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:831)
at com.ibm.ws.webcontainer.servlet.ServletWrapper.service(ServletWrapper.java:1655)
at com.ibm.ws.webcontainer.servlet.ServletWrapper.service(ServletWrapper.java:1595)
[2012/02/03 12:53:27:586 SAST] 00000162 srt > com.ibm.ws.webcontainer.srt.SRTServletResponse setStatus ENTRY status --> 500 [com.ibm.ws.webcontainer.srt.SRTServletResponse@15651565]
[2012/02/03 12:53:27:586 SAST] 00000162 srt 1 com.ibm.ws.webcontainer.srt.SRTServletResponse getRequest request=com.ibm.ws.webcontainer.srt.SRTServletRequest@14f314f3
[2012/02/03 12:53:27:587 SAST] 00000162 srt 1 com.ibm.ws.webcontainer.srt.SRTServletRequest getWebAppDispatcherContext
So initially, the thread was happily using request @14f314f3. Then, for an unknown reason it tries to retieve the atg.parent.session.id from a different request (@28e428e4) and after it all goes wrong it returns to the original request (@14f314f3).
When this exception occurs, it will, almost always, repeat itself until the instance on which the EAR is deployed is restarted. It seems as if there is some stale data on the request and it gets held on to in some way but I am unable to track this down.
The scope of the PickingService component is 'global' but it appears to be threadsafe. The PickingMessage extension of CommerceMessageImpl is overriding a method that has no impact on the request.
Is there any way for me to work out why/how the request suddenly changes? This problem doesn't happen consistently on all instances nor for all requests. It is however causing a problem within our production environment. Any help appreciated.
