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
>
