Thanks for replying Carlin, I've been trying to reproduce this with a simple test, but haven't been able to. At the simplest level all that is in play is a Controller with 2 action methods, begin() and start(). begin() forwards to start() with redirect = true in the annotation. There is a servlet filter that is calling the PageFlowUtils.getCurrentPageFlow() method because it needs to pull various items from the Controller. We expect for the requests to Controller.jpf/begin.do that getCurrentPageFlow will return null. However, it is also happening (sometimes) for the request to start.do. It usually is only for the first pass through after I have deployed my application. Thereafter, even if I start a new session, it all seems to work normally.
As you saw from the logs, what is happening in the failure case is that the servlet filter gets run for start.do request before the DeferredSessionStorageHandler applies its changes to the session for the Controller.jpf/begin.do request. The DeferredSessionStorageHandler I don't believe is being called as a result of anything the servlet filter does, but rather the DeferredSessionStorageHandler is called because the Controller.jpf/begin.do request has finished. But there seems to be some kind of timing issue. I'll continue to see if I can come up with a simple test case that reproduces this...but if you have any insight as to what may be happening I'd appreciate it. I looked over the issue you mentioned, but it looks a little bit different than what I'm seeing. In my case all the action is within one controller, and the multiple thread part is just a function of redirect=true I believe. Thanks, Micah -----Original Message----- From: Carlin Rogers [mailto:[EMAIL PROTECTED] Sent: Thursday, June 28, 2007 1:54 PM To: Beehive Users Subject: Re: DeferredSessionStorageHandler race condition? Hi Micah, Thanks for the detail and the log information. I'm not sure I fully understand what's happening and am curious about the ComponentRequestFilter. Is it a servlet filter? What exactly does that do or call? I noticed that when that fires the thread enters into the DeferredSessionStorageHandler but am unclear as to how this occurs. What is the other request doing in thread #2 and what is the user interaction that has the two concurrent threads. Sorry if I'm missing this from the original post. There is a similar and known issue described in BEEHIVE-1100 but the issue is that one thread goes to a different page flow. It's not a common scenario but may shed some light on what happens here. https://issues.apache.org/jira/browse/BEEHIVE-1100 Kind regards, Carlin On 6/27/07, Micah Koch <[EMAIL PROTECTED]> wrote: > We are having an issue in our application whereby we have a request > filter that calls PageFlowUtils.getCurrentPageFlow( HttpServletRequest > request, ServletContext servletContext ). Sometimes(but not always) > this is returning null even though the filter is running for the > request after the begin() method is called on our Controller. Here's > the sequence of events: > 1) Controller's begin() method is called > 2) begin() forwards to another action with redirect = true > 3) request filter fires > > Now, at the point the request filter fires for the request > corresponding to the next action the DeferredSessionStorageHandler may > not have yet applied its changes so _netui:curPageFlow isn't yet > committed to the session and this causes PageFlowUtils.getCurrentPageFlow to return null. > This usually only happens the first time I try to run the flow. Even > if I close my browser and make sure I get a new session, the following > attempts all seem to work just fine. I'm not sure what it is about > the first run that seems to make things fail. Here's the relevant log > information: > 2007-06-27 14:22:01,000|DEBUG|csm |Thread-16 > |org.apache.beehive.netui.pageflow.PageFlowRequestProcessor|---------- > |-- > ------------------- Start Request #1 ----------------------------------- > 2007-06-27 14:22:01,078|DEBUG|csm |Thread-16 > |org.apache.beehive.netui.pageflow.DefaultPageFlowEventReporter|beginA > |ct > ionRequest: > Request=org.apache.beehive.netui.pageflow.internal.PageFlowRequestWrap > pe [EMAIL PROTECTED], > [EMAIL PROTECTED] > 2007-06-27 14:22:01,156|DEBUG|csm |Thread-16 > |org.apache.beehive.netui.pageflow.PageFlowRequestProcessor|Got > |request > for /csm/dispatcher/Controller.jpf, forwarding to /dispatcher/begin.do > 2007-06-27 14:22:01,187|DEBUG|csm |Thread-16 > |org.apache.beehive.netui.pageflow.internal.DeferredSessionStorageHand > |le > r|getAttribute: _netui:nestingStack > 2007-06-27 14:22:01,187|DEBUG|csm |Thread-16 > |org.apache.beehive.netui.pageflow.PageFlowRequestProcessor|---------- > |-- > ------------------- Start Request #2 ----------------------------------- > 2007-06-27 14:22:01,187|DEBUG|csm |Thread-16 > |org.apache.beehive.netui.pageflow.DefaultPageFlowEventReporter|beginA > |ct > ionRequest: > Request=org.apache.beehive.netui.pageflow.internal.PageFlowRequestWrap > pe [EMAIL PROTECTED], > [EMAIL PROTECTED] > 2007-06-27 14:22:01,187|INFO |csm |Thread-16 > |org.apache.beehive.netui.pageflow.PageFlowRequestProcessor|Attempting > to instantiate SharedFlowControllers for request > /csm/dispatcher/begin.do > 2007-06-27 14:22:01,187|DEBUG|csm |Thread-16 > |org.apache.beehive.netui.pageflow.internal.DeferredSessionStorageHand > |le > r|getAttribute: _netui:sharedFlow:global.Global > 2007-06-27 14:22:01,187|DEBUG|csm |Thread-16 > |org.apache.beehive.netui.pageflow.internal.DeferredSessionStorageHand > |le > r|getAttribute: _netui:sharedFlow:global.Global > 2007-06-27 14:22:01,203|INFO |csm |Thread-16 > |org.apache.beehive.netui.pageflow.FlowControllerFactory|No Global.app > was found in /csm > 2007-06-27 14:22:01,234|DEBUG|csm |Thread-16 > |org.apache.beehive.netui.pageflow.internal.DeferredSessionStorageHand > |le > r|getAttribute: _netui:sharedFlow:global.Global > 2007-06-27 14:22:01,234|DEBUG|csm |Thread-16 > |org.apache.beehive.netui.pageflow.internal.DeferredSessionStorageHand > |le > r|getAttribute: _netui:curLongLivedModule > 2007-06-27 14:22:01,234|DEBUG|csm |Thread-16 > |org.apache.beehive.netui.pageflow.internal.DeferredSessionStorageHand > |le > r|getAttribute: _netui:curPageFlow > 2007-06-27 14:22:01,234|DEBUG|csm |Thread-16 > |org.apache.beehive.netui.pageflow.internal.DeferredSessionStorageHand > |le > r|getAttribute: _netui:nestingStack > 2007-06-27 14:22:01,234|DEBUG|csm |Thread-16 > |org.apache.beehive.netui.pageflow.FlowControllerFactory|Creating > PageFlowController of type dispatcher.Controller > 2007-06-27 14:22:01,484|DEBUG|csm |Thread-16 > |org.apache.beehive.netui.pageflow.internal.JavaControlUtils|No > |control > field annotations were found for [EMAIL PROTECTED] > 2007-06-27 14:22:01,515|DEBUG|csm |Thread-16 > |org.apache.beehive.netui.pageflow.internal.DeferredSessionStorageHand > |le > r|getAttribute: _netui:PageFlowControlContainerInstance > 2007-06-27 14:22:01,546|DEBUG|csm |Thread-16 > |org.apache.beehive.netui.pageflow.internal.DeferredSessionStorageHand > |le > r|setAttribute: > _netui:PageFlowControlContainerInstance=org.apache.beehive.netui.pagef > lo > [EMAIL PROTECTED] > 2007-06-27 14:22:01,625|DEBUG|csm |Thread-16 > |org.apache.beehive.netui.pageflow.internal.DeferredSessionStorageHand > |le > r|getAttribute: _netui:PageFlowControlContainerInstance > 2007-06-27 14:22:01,625|DEBUG|csm |Thread-16 > |org.apache.beehive.netui.pageflow.DefaultPageFlowEventReporter|flowCo > |nt > rollerCreated: [EMAIL PROTECTED], > Request=org.apache.beehive.netui.pageflow.internal.PageFlowRequestWrap > pe [EMAIL PROTECTED], > [EMAIL PROTECTED] > 2007-06-27 14:22:01,625|DEBUG|csm |Thread-16 > |org.apache.beehive.netui.pageflow.internal.DeferredSessionStorageHand > |le > r|getAttribute: _netui:curLongLivedModule > 2007-06-27 14:22:01,625|DEBUG|csm |Thread-16 > |org.apache.beehive.netui.pageflow.internal.DeferredSessionStorageHand > |le > r|getAttribute: _netui:curPageFlow > 2007-06-27 14:22:01,625|DEBUG|csm |Thread-16 > |org.apache.beehive.netui.pageflow.internal.DeferredSessionStorageHand > |le > r|getAttribute: _netui:curLongLivedModule > 2007-06-27 14:22:01,625|DEBUG|csm |Thread-16 > |org.apache.beehive.netui.pageflow.internal.DeferredSessionStorageHand > |le > r|getAttribute: _netui:curPageFlow > 2007-06-27 14:22:01,625|DEBUG|csm |Thread-16 > |org.apache.beehive.netui.pageflow.internal.DeferredSessionStorageHand > |le > r|setAttribute: _netui:[EMAIL PROTECTED] > 2007-06-27 14:22:01,625|DEBUG|csm |Thread-16 > |org.apache.beehive.netui.pageflow.internal.DeferredSessionStorageHand > |le > r|removeAttribute: _netui:curLongLivedModule > 2007-06-27 14:22:01,625|DEBUG|csm |Thread-16 > |org.apache.beehive.netui.pageflow.internal.DeferredSessionStorageHand > |le > r|getAttribute: _netui:curLongLivedModule > 2007-06-27 14:22:01,625|DEBUG|csm |Thread-16 > |org.apache.beehive.netui.pageflow.internal.DeferredSessionStorageHand > |le > r|getAttribute: _netui:curPageFlow > 2007-06-27 14:22:01,625|DEBUG|csm |Thread-16 > |org.apache.beehive.netui.pageflow.internal.DeferredSessionStorageHand > |le > r|removeAttribute: _netui:facesBacking > 2007-06-27 14:22:01,625|DEBUG|csm |Thread-16 > |org.apache.beehive.netui.pageflow.internal.DeferredSessionStorageHand > |le > r|getAttribute: _netui:facesBacking > 2007-06-27 14:22:01,765|DEBUG|csm |Thread-16 > |org.apache.beehive.netui.pageflow.PageFlowRequestProcessor|Populating > bean properties from this request > 2007-06-27 14:22:02,046|DEBUG|csm |Thread-16 > |org.apache.beehive.netui.script.common.ImplicitObjectUtil|using form > |of > type: org.apache.beehive.netui.pageflow.internal.AnyBeanActionForm > 2007-06-27 14:22:02,421|DEBUG|csm |Thread-16 > |org.apache.beehive.netui.pageflow.internal.DeferredSessionStorageHand > |le > r|getAttribute: _netui:PageFlowControlContainerInstance > 2007-06-27 14:22:02,421|DEBUG|csm |Thread-16 > |org.apache.beehive.netui.pageflow.DefaultPageFlowEventReporter|action > |Ra > ised: [EMAIL PROTECTED], > ActionMapping=[delegate to > ActionConfig[path=/begin,name=baseConfigBean,parameter=com.motive.comm > sf > low.arch.pageflow.ComponentPageFlowController,scope=request,type=org.a > pa che.beehive.netui.pageflow.internal.FlowControllerAction], > ActionForm=[AnyBeanActionForm wrapper for > [EMAIL PROTECTED], > Request=org.apache.beehive.netui.pageflow.internal.PageFlowRequestWrap > pe [EMAIL PROTECTED], > [EMAIL PROTECTED] > 2007-06-27 14:22:02,562|DEBUG|csm |Thread-16 > |org.apache.beehive.netui.pageflow.FlowController|Invoking action > |method > begin(com.motive.commsflow.arch.component.BaseConfigBean) > 2007-06-27 14:22:02,625|DEBUG|csm |Thread-16 > |org.apache.beehive.netui.pageflow.internal.DefaultActionForwardHandle > |r| > Redirecting to /start.do > 2007-06-27 14:22:02,625|DEBUG|csm |Thread-16 > |org.apache.beehive.netui.pageflow.DefaultPageFlowEventReporter|action > |Su > ccess: [EMAIL PROTECTED], > ActionMapping=[delegate to > ActionConfig[path=/begin,name=baseConfigBean,parameter=com.motive.comm > sf > low.arch.pageflow.ComponentPageFlowController,scope=request,type=org.a > pa che.beehive.netui.pageflow.internal.FlowControllerAction], > ActionForm=[AnyBeanActionForm wrapper for > [EMAIL PROTECTED], > Request=org.apache.beehive.netui.pageflow.internal.PageFlowRequestWrap > pe [EMAIL PROTECTED], > [EMAIL PROTECTED], > ActionForward=ForwardConfig[name=start,path=/start.do,redirect=true,co > nt extRelative=false], TimeTakenMillis=204 > 2007-06-27 14:22:02,640|DEBUG|csm |Thread-16 > |org.apache.beehive.netui.pageflow.PageFlowRequestProcessor|processFor > |wa > rdConfig(ForwardConfig[name=start,path=/start.do,redirect=true,context > Re > lative=false]) > 2007-06-27 14:22:02,687|DEBUG|csm |Thread-16 > |org.apache.beehive.netui.pageflow.DefaultPageFlowEventReporter|endAct > |io > nRequest: > Request=org.apache.beehive.netui.pageflow.internal.PageFlowRequestWrap > pe [EMAIL PROTECTED], > [EMAIL PROTECTED], > TimeTakenMillis=1500 > 2007-06-27 14:22:02,687|DEBUG| |[ACTIVE] > ExecuteThread: '2' for queue: 'weblogic.kernel.Default > (self-tuning)'|com.motive.commsflow.arch.pageflow.ComponentRequestFilt > er > |Entering ComponentRequestFilter... > 2007-06-27 14:22:02,687|DEBUG| |[ACTIVE] > ExecuteThread: '2' for queue: 'weblogic.kernel.Default > (self-tuning)'|org.apache.beehive.netui.pageflow.internal.DeferredSess > io > nStorageHandler|getAttribute: _netui:curLongLivedModule > 2007-06-27 14:22:02,687|DEBUG| |[ACTIVE] > ExecuteThread: '2' for queue: 'weblogic.kernel.Default > (self-tuning)'|org.apache.beehive.netui.pageflow.internal.DeferredSess > io > nStorageHandler|getAttribute: _netui:curPageFlow > 2007-06-27 14:22:02,687|DEBUG| |[ACTIVE] > ExecuteThread: '2' for queue: 'weblogic.kernel.Default > (self-tuning)'|com.motive.commsflow.arch.pageflow.ComponentRequestFilt > er > |componentController = null > 2007-06-27 14:22:02,718|DEBUG|csm |Thread-16 > |org.apache.beehive.netui.pageflow.PageFlowRequestProcessor|---------- > |-- > -------------------- End Request #2 ------------------------------------ > 2007-06-27 14:22:02,718|DEBUG|csm |Thread-16 > |org.apache.beehive.netui.pageflow.internal.DeferredSessionStorageHand > |le > r|Applying changes for request /csm/dispatcher/Controller.jpf. > Identity: 3845217 > 2007-06-27 14:22:02,765|DEBUG|csm |Thread-16 > |org.apache.beehive.netui.util.internal.ServletUtils|Using session > |lock > of type: class weblogic.servlet.internal.session.MemorySessionData > 2007-06-27 14:22:02,765|DEBUG|csm |Thread-16 > |org.apache.beehive.netui.pageflow.internal.DeferredSessionStorageHand > |le > r|Removing attribute _netui:facesBacking from the session. > 2007-06-27 14:22:02,765|DEBUG|csm |Thread-16 > |org.apache.beehive.netui.pageflow.internal.DeferredSessionStorageHand > |le > r|Removing attribute _netui:curLongLivedModule from the session. > 2007-06-27 14:22:02,765|DEBUG|csm |Thread-16 > |org.apache.beehive.netui.pageflow.internal.DeferredSessionStorageHand > |le > r|Committing attribute _netui:PageFlowControlContainerInstance to the > session. > 2007-06-27 14:22:02,765|DEBUG|csm |Thread-16 > |org.apache.beehive.netui.pageflow.internal.DeferredSessionStorageHand > |le > r|Committing attribute _netui:curPageFlow to the session. > 2007-06-27 14:22:02,765|DEBUG|csm |Thread-16 > |org.apache.beehive.netui.pageflow.internal.DeferredSessionStorageHand > |le > r|Ensure failover for attribute _netui:curPageFlow > 2007-06-27 14:22:02,765|DEBUG|csm |Thread-16 > |org.apache.beehive.netui.pageflow.internal.DeferredSessionStorageHand > |le > r|Completed applying changes for request /csm/dispatcher/Controller.jpf. > Identity: 3845217 > 2007-06-27 14:22:02,765|DEBUG|csm |Thread-16 > |org.apache.beehive.netui.pageflow.DefaultPageFlowEventReporter|endAct > |io > nRequest: > Request=org.apache.beehive.netui.pageflow.internal.PageFlowRequestWrap > pe [EMAIL PROTECTED], > [EMAIL PROTECTED], > TimeTakenMillis=1687 > 2007-06-27 14:22:02,765|DEBUG|csm |Thread-16 > |org.apache.beehive.netui.pageflow.PageFlowRequestProcessor|---------- > |-- > -------------------- End Request #1 > ------------------------------------ > > > Should I log a bug, or am I doing something wrong? I haven't yet > tried to create a simple test case. I'm on WebLogic 9.2 MP1, BTW. If > it is a bug, is there any suggested work around? I'd like/need to > keep my redirect = true. Thanks, Micah >
