odd ajax issue (works every other time)

[O'Rorke Paul]

Not in a place where I can really debug this right now but I'm curious
whether anybody else has seen this and knows the solution...

since rebuilding a day or two ago with no recent code or other changes:
every second time I go to click on an ajax checkbox or select widget,
I get effectively no response.
actually, it looks like there is a very quick spinning wheel (almost
imperceptible) but the page doesn't get repainted and the database
does not change.
If I use another operation that is non ajax (going in and editing an
item and doing old fashioned get / posts) everything works fine after
that (one time).
Or if I reload the page then if I use an ajax widget after reloading
ajax works (once).

This is with 2.7.5 Scala and Lift 1.1-SNAPSHOT.

Perhaps not coincidentally, I am getting "Multiple versions of scala
libraries detected!" warnings and have not yet figured out how to get
rid of them.
I don't see another version of Scala in my pom or eclipse maven
dependency graph and have been going around nuking old copies of scala
but to no avail as yet.

Another odd thing that is now happening is that when I shutdown with a
control C in the terminal window, I get the following error:

> INFO - Service request (GET) /ajax_request/liftAjax.js took 2
> Milliseconds
> ^C2009-11-16 15:29:01.634::INFO: Shutdown hook executing
> 2009-11-16 15:29:02.249::INFO: Shutdown hook complete
> [INFO] Jetty server exiting.
> [INFO]
> ------------------------------------------------------------------------
> [INFO] BUILD SUCCESSFUL
> [INFO]
> ------------------------------------------------------------------------
> [INFO] Total time: 33 minutes 4 seconds
> [INFO] Finished at: Mon Nov 16 15:29:02 PST 2009
> [INFO] Final Memory: 23M/257M
> [INFO]
> ------------------------------------------------------------------------
> ERROR - Couldn't start SessionMaster ping
> net.liftweb.util.ActorPingException: net.liftweb.http.SessionMaster
> $CheckAndPurge$@1cab4a5 could not be scheduled on
> net.liftweb.http.SessionMaster$@119c2af
> at net.liftweb.util.ActorPing$.schedule(ActorPing.scala:54)
> at net.liftweb.http.SessionMaster$.net$liftweb$http$SessionMaster$
> $doPing(LiftSession.scala:187)
> at net.liftweb.http.SessionMaster$$anonfun$1.apply
> (LiftSession.scala:169)
> at net.liftweb.http.SessionMaster$$anonfun$1.apply
> (LiftSession.scala:135)
> at net.liftweb.actor.LiftActor$class.execTranslate(LiftActor.scala:
> 247)
> at net.liftweb.http.SessionMaster$.execTranslate(LiftSession.scala:
> 91)
> at net.liftweb.actor.SpecializedLiftActor$class.net$liftweb$actor
> $SpecializedLiftActor$$processMailbox(LiftActor.scala:142)
> at net.liftweb.actor.SpecializedLiftActor$$anonfun$3$$anonfun$apply
> $1.apply(LiftActor.scala:109)
> at net.liftweb.actor.SpecializedLiftActor$$anonfun$3$$anonfun$apply
> $1.apply(LiftActor.scala:109)
> at net.liftweb.actor.LAScheduler$$anonfun$1$$anon$1$$anon$2.run
> (LiftActor.scala:37)
> at java.util.concurrent.ThreadPoolExecutor$Worker.runTask
> (ThreadPoolExecutor.java:886)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run
> (ThreadPoolExecutor.java:908)
> at java.lang.Thread.run(Thread.java:637)
> Caused by: java.util.concurrent.RejectedExecutionException
> at java.util.concurrent.ThreadPoolExecutor
> $AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:1760)
> at java.util.concurrent.ThreadPoolExecutor.reject
> (ThreadPoolExecutor.java:767)
> at java.util.concurrent.ScheduledThreadPoolExecutor.delayedExecute
> (ScheduledThreadPoolExecutor.java:216)
> at java.util.concurrent.ScheduledThreadPoolExecutor.schedule
> (ScheduledThreadPoolExecutor.java:379)
> at java.util.concurrent.Executors
> $DelegatedScheduledExecutorService.schedule(Executors.java:654)
> at net.liftweb.util.ActorPing$.schedule(ActorPing.scala:52)
> ... 12 more
>

Ideas / Suggestions for any of these issues (perhaps they are
related?) most welcome!
---Paul O

[Ross Mellgren]

I can't comment on the AJAX issue in particular, though you should
switch to Scala 2.7.7 -- that's the version that should be used with
1.1-SNAPSHOT.

-Ross

> --
>
> You received this message because you are subscribed to the Google
> Groups "Lift" group.
> To post to this group, send email to lif...@googlegroups.com.
> To unsubscribe from this group, send email to liftweb+u...@googlegroups.com
> .
> For more options, visit this group at http://groups.google.com/group/liftweb?hl=
> .
>
>

[Kris Nuttycombe]

I am able to duplicate this error. I was concerned that it might be
the result of my Loc changes, so I just rebuilt Lift without the
patches associated with that change and reproduced the problem again.

Here are the conditions under which I'm able to reproduce the failure:

1) load a page where the snippets are managed by a StatefulSnippet
2) some page elements (in my case select boxes) have their values
update by AJAX in response to user events. This appears to work
normally.
3) upon submission of the form on the page, the page is re-rendered.
Logging in the submission function indicates that it is never called.
4) if I fill in the form again and resubmit after the initial failure,
the form submit behaves properly.
5) I believe I've seen at least one instance (though I can't reliably
reproduce this) where just a normal AJAX call (modifying one of the
select boxes) caused the entire page to reload.

Kris

Kris

[Kris Nuttycombe]

Added as ticket #198

Kris

[David Pollak]

On Tue, Nov 17, 2009 at 4:12 PM, Kris Nuttycombe <kris.nu...@gmail.com> wrote:

Added as ticket #198

Tnx.

Do you want to work it or should I (unless I hear from anyone else)
 

--
Lift, the simply functional web framework http://liftweb.net
Beginning Scala http://www.apress.com/book/view/1430219890
Follow me: http://twitter.com/dpp
Surf the harmonics

[Kris Nuttycombe]

I've looked a bit and will give it another couple of hours tonight or
in the morning. If you have any ideas of places to start looking
please let me know.

Kris

[David Pollak]

I am able to reproduce the problem with a simple Ajax control.

It's very, very odd.  It seems to be an intermittent failure of the servlet container to find the HttpServletSession.  The client is presenting the cookie correctly, but Jetty is not recognizing it.

[David Pollak]

On Tue, Nov 17, 2009 at 10:33 PM, David Pollak <feeder.of...@gmail.com> wrote:

I am able to reproduce the problem with a simple Ajax control.

It's very, very odd.  It seems to be an intermittent failure of the servlet container to find the HttpServletSession.  The client is presenting the cookie correctly, but Jetty is not recognizing it.

For some reason, even though the browser sends the right cookies, Jetty is not recognizing them.  This is pretty easy to reproduce with Firefox, but I haven't seen it with Chrome.

I'm enclosing a simple version of the project I used for testing... just keep pressing on the button and eventually the page will reload (indicating that the session was lost) or the counter will stop counting (same indication).

I'm out of pocket for most of today (I might be on email just a little).

This is a super ultra mega high priority in my book.  If Marius or Tim or Derek or any of the other Lift committers could shake loose time to look at this one, I'd really appreciate it... and Kris thanks for the time/effort you've put into this.  Please keep plugging.

Thanks,

David
 

[Kris Nuttycombe]

I've got a few other things that I have to take care of today, but if
I can get those out of the way I will run a git bisect, compiling &
running with your test project to see if I can at least figure out the
commit that introduced the error. I've been wanting to learn about
bisect anyway. :)

Kris

[David Pollak]

Kris,

As far as I can tell, it's a Jetty issue.  Could you start by trying to reproduce the problem in Tomcat?  If you can repro it in Tomcat, then clearly the problem is in Lift.  If, however, the problem does not manifest in Tomcat, then we're poking Jetty wrong.

Thanks,

David

[David Pollak]

Okay, I've reproduced the issue on Tomcat, so it's definitely something in Lift that's borking the session....

[Kris Nuttycombe]

I'm reproducing it on Glassfish, so yes I think it's Lift.

Kris

On Wed, Nov 18, 2009 at 1:18 PM, David Pollak

> http://groups.google.com/group/liftweb?hl=en.
>

[Marius]

I've noticed this today as well but in a different context. Sometimes
out of the sudden, I'm being kicked out of the session to the login
page.

Dave I wonder is this may have been caused by the S.init call inside
LiftSession#contextFuncBuilder. I can't think of a reason right now on
why would that such effect though.

Br's,
Marius

On Nov 18, 10:18 pm, David Pollak <feeder.of.the.be...@gmail.com>
wrote:

> Okay, I've reproduced the issue on Tomcat, so it's definitely something in
> Lift that's borking the session....
>
> On Wed, Nov 18, 2009 at 12:00 PM, David Pollak <
>

> >> >>> On Tue, Nov 17, 2009 at 4:07 PM, O'Rorke Paul <p...@ororke.com>

> >> >>> > liftweb+u...@googlegroups.com<liftweb%2Bunsu...@googlegroups.com>
> >> .

> >> >>> > For more options, visit this group at
> >> >>> >http://groups.google.com/group/liftweb?hl=.
>
> >> >>> --
>
> >> >>> You received this message because you are subscribed to the Google
> >> Groups
> >> >>> "Lift" group.
> >> >>> To post to this group, send email to lif...@googlegroups.com.
> >> >>> To unsubscribe from this group, send email to

> >> >>> liftweb+u...@googlegroups.com<liftweb%2Bunsu...@googlegroups.com>
> >> .

> >> >>> For more options, visit this group at
> >> >>>http://groups.google.com/group/liftweb?hl=.
>
> >> >> --
> >> >> Lift, the simply functional web frameworkhttp://liftweb.net

> >> >> Beginning Scalahttp://www.apress.com/book/view/1430219890

> >> >> Follow me:http://twitter.com/dpp
> >> >> Surf the harmonics
>
> >> > --
> >> > Lift, the simply functional web frameworkhttp://liftweb.net
> >> > Beginning Scala
>

> ...
>
> read more »

[Marius]

Ok I did some more debugging on this.


I put traces in the code and at some point when LiftRules is
requesting the session from the SessionMaster I'm seeing a different
sessionId provided to the SessionMaster thus the session is not found.
I removed my addition from LiftSession#contextFuncBuilder

//S.init(req, session) {
S.CurrentLocation.doWith(curLoc) {
snippetMap.doWith(snippetMap.is ++ currentMap) {
super.apply(in)
}
}
// }

so I commented out the S.init and I wasn't able to reproduce the
problem anymore. Therefore I took the liberty of pushing this change
into master without going through the review board process. I did this
due to the urgency nature.

Please test this and see if you can reproduce the problem


Br's,
Marius

> ...
>
> read more »

[Marius]

My assumption on the causality is that things remained set on
ThreadGlobals and threads are re-used by container. I know it doesn't
make the most sense what I'm saying since the ThredGlobals are
properly scoped but the previous thread-global value is cached and
restored after the closure execution. At least this is my assumption
right now (so late) ...

Br's,
Marius

> ...
>
> read more »

[David Pollak]

Marius,

Thanks for tracking this down and checking in a fix.

I'm still curious as to why a double-init was causing session destruction... I'll do more digging.

We should also document this in the code (and maybe even thrown an exception on a double-init).

Thanks,

David

> ...
>
> read more »

--

You received this message because you are subscribed to the Google Groups "Lift" group.
To post to this group, send email to lif...@googlegroups.com.

To unsubscribe from this group, send email to liftweb+u...@googlegroups.com.

For more options, visit this group at http://groups.google.com/group/liftweb?hl=.

--

Lift, the simply functional web framework http://liftweb.net

Beginning Scala http://www.apress.com/book/view/1430219890

[Kris Nuttycombe]

Okay, I finally got to test this an the fix looks good to me. Thanks Marius!

Kris

> To unsubscribe from this group, send email to liftweb+u...@googlegroups.com.

[Marius]

Cool.

On Nov 19, 6:54 am, Kris Nuttycombe <kris.nuttyco...@gmail.com> wrote:
> Okay, I finally got to test this an the fix looks good to me. Thanks Marius!
>
> Kris
>

> ...
>
> read more »

[Marius]

That makes two of us David ...

The thing is that during my debugging there was no session destruction
and I traced this right in the guts of SessionMaster. The session was
always there. But somehow the sessionId fed in was different even
though the cookie seemed to be correct. I know I know ... it doesn't
make much sense but if you find more info on this please do let me
know. This is killing me :)

Br's,
Marius

On Nov 19, 2:20 am, David Pollak <feeder.of.the.be...@gmail.com>
wrote:

> Marius,
>
> Thanks for tracking this down and checking in a fix.
>
> I'm still curious as to why a double-init was causing session destruction...
> I'll do more digging.
>
> We should also document this in the code (and maybe even thrown an exception
> on a double-init).
>
> Thanks,
>
> David
>

> ...
>
> read more »

[David Pollak]

On Wed, Nov 18, 2009 at 10:28 PM, Marius <marius...@gmail.com> wrote:

That makes two of us David ...

The thing is that during my debugging there was no session destruction
and I traced this right in the guts of SessionMaster.

I went further and it seemed that the sessions were destroyed at the Servlet Container level.

I really need a couple of hours to figure this one out.  Sigh.
 

The session was
always there. But somehow the sessionId fed in was different even
though the cookie seemed to be correct. I know I know ... it doesn't
make much sense but if you find more info on this please do let me
know. This is killing me :)

It's killing me, too... but if we're both dead...
 

> ...
>
> read more »

--

You received this message because you are subscribed to the Google Groups "Lift" group.
To post to this group, send email to lif...@googlegroups.com.
To unsubscribe from this group, send email to liftweb+u...@googlegroups.com.
For more options, visit this group at http://groups.google.com/group/liftweb?hl=.

[Jeppe Nejsum Madsen]

On Nov 19, 8:16 pm, David Pollak <feeder.of.the.be...@gmail.com>
wrote:

> On Wed, Nov 18, 2009 at 10:28 PM, Marius <marius.dan...@gmail.com> wrote:
> > That makes two of us David ...
>
> > The thing is that during my debugging there was no session destruction
> > and I traced this right in the guts of SessionMaster.
>
> I went further and it seemed that the sessions were destroyed at the Servlet
> Container level.

I can't say I grok the lift request cycle, but I looked into the jetty
part and this is what I think happens:

At some point getCookies is called (by Lift) on a HttpServletRequest
that seems invalid (ie empty). This causes the internal state of the
request object to be marked "cookies are parsed". Just there are no
cookies since the request is empty.

Jetty recycles the request objects, so later when a request comes in
that reuses this request object and it tries to fetch the session
cookie, it sees that cookies are already parsed but can't find the
session cookie (there are none) and thus creates a new session.

Why the request object is not re-initialized for the new request I
don't know...also it doesn't really explain the error on Tomcat

Not sure if this helps...:-)

/Jeppe

[David Pollak]

On Thu, Nov 19, 2009 at 1:45 PM, Jeppe Nejsum Madsen <je...@ingolfs.dk> wrote:

On Nov 19, 8:16 pm, David Pollak <feeder.of.the.be...@gmail.com>
wrote:

> On Wed, Nov 18, 2009 at 10:28 PM, Marius <marius.dan...@gmail.com> wrote:
> > That makes two of us David ...
>
> > The thing is that during my debugging there was no session destruction
> > and I traced this right in the guts of SessionMaster.
>
> I went further and it seemed that the sessions were destroyed at the Servlet
> Container level.

I can't say I grok the lift request cycle, but I looked into the jetty
part and this is what I think happens:

At some point getCookies is called (by Lift) on a HttpServletRequest
that seems invalid (ie empty).

Excellent... I understand... this is awesomely helpful (and subject to a simple and very lazy fix)  Thanks!
 

This causes the internal state of the
request object to be marked "cookies are parsed". Just there are no
cookies since the request is empty.

Jetty recycles the request objects, so later when a request comes in
that reuses this request object and it tries to fetch the session
cookie, it sees that cookies are already parsed but can't find the
session cookie (there are none) and thus creates a new session.

Why the request object is not re-initialized for the new request I
don't know...also it doesn't really explain the error on Tomcat

Not sure if this helps...:-)

/Jeppe

--

You received this message because you are subscribed to the Google Groups "Lift" group.
To post to this group, send email to lif...@googlegroups.com.
To unsubscribe from this group, send email to liftweb+u...@googlegroups.com.
For more options, visit this group at http://groups.google.com/group/liftweb?hl=.

[O'Rorke Paul]

thanks, Ross: this fixed the "multiple versions of scala" warning.
---Paul O

[O'Rorke Paul]

thanks, Marius, Kris, and Dave, Kris for making a patch so quickly.

(The patch is working for me now:  ajax widgets work every time rather than every other time and shutdowns are clean.)

Thanks for making this high pri and for making simple examples and looking on multiple platforms.

I'm really impressed, too, that you're looking for the deeper explanation instead of just being satisfied with a quick patch that works.

---Paul O

[O'Rorke Paul]

Hi:  I am still getting "Couldn't start SessionMaster ping" errors when I shut down with a control C.

Is this just something to be expected on shutting down that way?

or do I need to edit my pom.xml and change

 <scanIntervalSeconds>5</scanIntervalSeconds>
to
 <scanIntervalSeconds>0</scanIntervalSeconds>

?

This  happens when performance of a simple application degrades to the point that it is unusable (note huge times below).

So I'm wondering it it's a sign of something that contributes to the performance issues somehow.

Lord knows my app and the platform it's running on contribute a lot to degraded performance but still...

The odd thing is that when I do form based operations for editing and deleting things they seem to work more reliably and quickly but

the preferred ajax alternatives seem to get bogged down eventually.  Dunno if it has something to do with leaving the thing running overnight or what but I wonder if there's still a lurking issue remaining from what happened a while back when the ajax controls only worked every other time.

(this is on Lift 1.1-Snapshot with Scala 2.7.7 with Jetty)

---Paul O

^CINFO - Service request (POST) /ajax_request/F298186085375KAN/ took 77226 Milliseconds

INFO - Service request (POST) /ajax_request/F298186085375KAN/ took 196142 Milliseconds

INFO - Service request (POST) /ajax_request/F298186085375KAN/ took 143854 Milliseconds

INFO - Service request (POST) /ajax_request/F298186085375KAN/ took 43697 Milliseconds

INFO - Service request (POST) /ajax_request/F298186085375KAN/ took 68474 Milliseconds

INFO - Service request (POST) /ajax_request/F298186085375KAN/ took 93456 Milliseconds

INFO - Service request (POST) /ajax_request/F298186085375KAN/ took 420481 Milliseconds

INFO - Service request (POST) /ajax_request/F298186085375KAN/ took 88169 Milliseconds

INFO - Service request (POST) /ajax_request/F298186085375KAN/ took 210859 Milliseconds

INFO - Service request (POST) /ajax_request/F298186085375KAN/ took 47672 Milliseconds

INFO - Service request (POST) /ajax_request/F298186085375KAN/ took 428182 Milliseconds

2009-12-13 21:08:30.070:INFO::Shutdown hook executing

INFO - Service request (POST) /ajax_request/F298186085375KAN/ took 425694 Milliseconds

INFO - Service request (POST) /ajax_request/F298186085375KAN/ took 686149 Milliseconds

INFO - Service request (POST) /ajax_request/F298186085375KAN/ took 652480 Milliseconds

ERROR - Couldn't start SessionMaster ping

net.liftweb.util.ActorPingException: net.liftweb.http.SessionMaster$CheckAndPurge$@a8ada5 could not be scheduled on net.liftweb.http.SessionMaster$@203e70

at net.liftweb.util.ActorPing$.schedule(ActorPing.scala:54)

at net.liftweb.http.SessionMaster$.net$liftweb$http$SessionMaster$$doPing(LiftSession.scala:188)

at net.liftweb.http.SessionMaster$$anonfun$1.apply(LiftSession.scala:170)

at net.liftweb.http.SessionMaster$$anonfun$1.apply(LiftSession.scala:136)

at net.liftweb.actor.LiftActor$class.execTranslate(LiftActor.scala:252)

at net.liftweb.http.SessionMaster$.execTranslate(LiftSession.scala:91)

at net.liftweb.actor.SpecializedLiftActor$class.net$liftweb$actor$SpecializedLiftActor$$processMailbox(LiftActor.scala:147)

at net.liftweb.actor.SpecializedLiftActor$$anonfun$3$$anonfun$apply$1.apply(LiftActor.scala:114)

at net.liftweb.actor.SpecializedLiftActor$$anonfun$3$$anonfun$apply$1.apply(LiftActor.scala:114)

at net.liftweb.actor.LAScheduler$$anonfun$1$$anon$1$$anon$2.run(LiftActor.scala:42)

at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)

at java.lang.Thread.run(Thread.java:637)

Caused by: java.util.concurrent.RejectedExecutionException

at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:1760)

at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:767)

at java.util.concurrent.ScheduledThreadPoolExecutor.delayedExecute(ScheduledThreadPoolExecutor.java:216)

at java.util.concurrent.ScheduledThreadPoolExecutor.schedule(ScheduledThreadPoolExecutor.java:379)

at java.util.concurrent.Executors$DelegatedScheduledExecutorService.schedule(Executors.java:654)

at net.liftweb.util.ActorPing$.schedule(ActorPing.scala:52)

... 12 more

INFO - Service request (POST) /ajax_request/F298186085375KAN/ took 566612 Milliseconds

2009-12-13 21:14:17.627:INFO::Shutdown hook complete

[INFO] Jetty server exiting.

[INFO] ------------------------------------------------------------------------

[INFO] BUILD SUCCESSFUL

[INFO] ------------------------------------------------------------------------

[INFO] Total time: 4933 minutes 51 seconds

[INFO] Finished at: Sun Dec 13 21:14:18 PST 2009

<--

Paul O'Rorke

408.202.7429

650.749.0052

http://ororke.com/paul/blog

http://www.linkedin.com/in/paulororke

Begin forwarded message:

[Marius]

On Dec 14, 7:37 am, O'Rorke Paul <p...@ororke.com> wrote:
> Hi:  I am still getting "Couldn't start SessionMaster ping" errors when I shut down with a control C.
> Is this just something to be expected on shutting down that way?
>
> or do I need to edit my pom.xml and change
>  <scanIntervalSeconds>5</scanIntervalSeconds>
> to
>  <scanIntervalSeconds>0</scanIntervalSeconds>
> ?
>
> This  happens when performance of a simple application degrades to the point that it is unusable (note huge times below).
> So I'm wondering it it's a sign of something that contributes to the performance issues somehow.
> Lord knows my app and the platform it's running on contribute a lot to degraded performance but still...
> The odd thing is that when I do form based operations for editing and deleting things they seem to work more reliably and quickly but
> the preferred ajax alternatives seem to get bogged down eventually.  Dunno if it has something to do with leaving the thing running overnight or what but I wonder if there's still a lurking issue remaining from what happened a while back when the ajax controls only worked every other time.

I don't think that the degradation you're experiencing has anything to
do with that fix. That code was removed. I've also seen that exception
when terminating the app by CTRL-C and even if it's not cause problems
as the application will stop we should remove that exception.

I'm not sure why exactly you're seeing this degradation as those are
pretty huge numbers. Are you talking with some external services from
your ajax functions ?

> 650.749.0052http://ororke.com/paul/bloghttp://www.linkedin.com/in/paulororke
>
> Begin forwarded message: