2.4-M1 DB exception in LiftActor, works in Boot

[Terje Sten Bjerkseth]

Jetty 6.1.24-6 on Ubuntu 11.04, Java 1.6.0_22, MySQL driver configured
via JNDI and DefaultConnectionIdentifier.jndiName.

App works with Lift 2.3 on 2.8.1. After upgrading to 2.4-M1 on 2.9.0-1
I'm getting the exception below on a find() DB access that happens in
a LiftActor. If I move this call into Boot.scala outside any actors it
works as expected.

I don't yet have a public repo for reproducing the error, just
checking for any known or unknown issues?

[pool-1-thread-4] [ERROR] [2011-06-06 14:06:06,812] n.l.a.ActorLogger:
Actor threw an exception
java.lang.NullPointerException: Looking for Connection Identifier
ConnectionIdentifier(jdbc/xx) but failed to find either a JNDI data
source with the name jdbc/xx or a lift connection manager with the
correct name
at net.liftweb.db.DB$$anonfun$7$$anonfun$apply$11.apply(DB.scala:154)
~[Jetty-8234821449678846508.jar:2.4-M1]
at net.liftweb.db.DB$$anonfun$7$$anonfun$apply$11.apply(DB.scala:154)
~[Jetty-8234821449678846508.jar:2.4-M1]
at net.liftweb.common.EmptyBox.openOr(Box.scala:574)
~[Jetty-5247092475656255008.jar:2.4-M1]
at net.liftweb.db.DB$$anonfun$7.apply(DB.scala:153)
~[Jetty-8234821449678846508.jar:2.4-M1]
at net.liftweb.db.DB$$anonfun$7.apply(DB.scala:153)
~[Jetty-8234821449678846508.jar:2.4-M1]
at net.liftweb.common.EmptyBox.openOr(Box.scala:574)
~[Jetty-5247092475656255008.jar:2.4-M1]
at net.liftweb.db.DB$class.newConnection(DB.scala:147)
~[Jetty-8234821449678846508.jar:2.4-M1]
at net.liftweb.db.DB$class.getConnection(DB.scala:262)
~[Jetty-8234821449678846508.jar:2.4-M1]
at net.liftweb.db.DB$class.use(DB.scala:615)
~[Jetty-8234821449678846508.jar:2.4-M1]
at net.liftweb.db.DB$$anon$1.use(DB.scala:38)
~[Jetty-8234821449678846508.jar:2.4-M1]
at net.liftweb.mapper.KeyedMetaMapper$class.findDb(MetaMapper.scala:
1882) ~[Jetty-990497711281286582.jar:2.4-M1]
at nevi.nevi_order_queue$.findDb(Models.scala:55) ~[classes/:na]
at net.liftweb.mapper.KeyedMetaMapper$class.findDb(MetaMapper.scala:
1878) ~[Jetty-990497711281286582.jar:2.4-M1]
at nevi.nevi_order_queue$.findDb(Models.scala:55) ~[classes/:na]
at net.liftweb.mapper.KeyedMetaMapper$class.find(MetaMapper.scala:
1875) ~[Jetty-990497711281286582.jar:2.4-M1]
at nevi.nevi_order_queue$.find(Models.scala:55) ~[classes/:na]
at nevi.order.OrderProcessor.process(OrderProcessor.scala:25)
[classes/:na]
at nevi.order.OrderProcessor$$anonfun$messageHandler
$1.apply(OrderProcessor.scala:20) ~[classes/:na]
at nevi.order.OrderProcessor$$anonfun$messageHandler
$1.apply(OrderProcessor.scala:17) ~[classes/:na]
at net.liftweb.actor.LiftActor$class.execTranslate(LiftActor.scala:
441) ~[Jetty-4002577764226495363.jar:2.4-M1]
at nevi.order.OrderProcessor.execTranslate(OrderProcessor.scala:14)
[classes/:na]
at net.liftweb.actor.SpecializedLiftActor$class.net$liftweb$actor
$SpecializedLiftActor$$proc2(LiftActor.scala:289)
[Jetty-4002577764226495363.jar:2.4-M1]
at net.liftweb.actor.SpecializedLiftActor$$anonfun$net$liftweb$actor
$SpecializedLiftActor$$processMailbox$1.apply(LiftActor.scala:210)
[Jetty-4002577764226495363.jar:2.4-M1]
at net.liftweb.actor.SpecializedLiftActor$$anonfun$net$liftweb$actor
$SpecializedLiftActor$$processMailbox$1.apply(LiftActor.scala:210)
[Jetty-4002577764226495363.jar:2.4-M1]
at net.liftweb.actor.SpecializedLiftActor
$class.around(LiftActor.scala:224) [Jetty-4002577764226495363.jar:2.4-
M1]
at nevi.order.OrderProcessor.around(OrderProcessor.scala:14)
[classes/:na]
at net.liftweb.actor.SpecializedLiftActor$class.net$liftweb$actor
$SpecializedLiftActor$$processMailbox(LiftActor.scala:209)
[Jetty-4002577764226495363.jar:2.4-M1]
at net.liftweb.actor.SpecializedLiftActor$$anonfun$2$$anonfun$apply
$mcV$sp$1.apply$mcV$sp(LiftActor.scala:173)
[Jetty-4002577764226495363.jar:2.4-M1]
at net.liftweb.actor.LAScheduler$$anonfun$9$$anon$2$$anon
$3.run(LiftActor.scala:64) [Jetty-4002577764226495363.jar:2.4-M1]
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:
1110) [na:1.6.0_20]
at java.util.concurrent.ThreadPoolExecutor
$Worker.run(ThreadPoolExecutor.java:603) [na:1.6.0_20]
at java.lang.Thread.run(Thread.java:636) [na:1.6.0_20]

[Derek Chen-Becker]

I think it's unfortunate that we use a NullPointerException there, since that's really not what it is. Here's the code in question:

val ret =
  ...obtain via connection manager... openOr {
  ...obtain via 
  } openOr {
        throw new NullPointerException("Looking for Connection Identifier " + name + " but failed to find either a JNDI data source " +
                                       "with the name " + name.jndiName + " or a lift connection manager with the correct name")
      }

Basically, it means it couldn't locate the datasource via JNDI. The actual code doing the work is :

 val conn = (new InitialContext).lookup("java:/comp/env").asInstanceOf[Context].lookup(<put your JNDI name here>).asInstanceOf[DataSource].getConnection

Could you try that in your actor code and see if that has an issue or works? Just put the proper JNDI name in where I've indicated.

Thanks,

Derek

--
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=en.

[Terje Sten Bjerkseth]

On Jun 6, 6:09 pm, Derek Chen-Becker <dchenbec...@gmail.com> wrote:
> I think it's unfortunate that we use a NullPointerException there, since
> that's really not what it is. Here's the code in question:
>
> val ret =
>   ...obtain via connection manager... openOr {
>   ...obtain via
>   } openOr {
>         throw new NullPointerException("Looking for Connection Identifier "
> + name + " but failed to find either a JNDI data source " +
>                                        "with the name " + name.jndiName + "
> or a lift connection manager with the correct name")
>       }
>
> Basically, it means it couldn't locate the datasource via JNDI. The actual
> code doing the work is :
>
>  val conn = (new
> InitialContext).lookup("java:/comp/env").asInstanceOf[Context].lookup(<put
> your JNDI name here>).asInstanceOf[DataSource].getConnection
>
> Could you try that in your actor code and see if that has an issue or works?
> Just put the proper JNDI name in where I've indicated.

Thanks for replying, Derek.

I tried your calls directly in boot and in the actor. It works in
boot. It works in the actor on first message, but not after using
LAPinger. Here's what I get on the subsequent calls:

[pool-1-thread-2] [ERROR] [2011-06-06 19:48:39,413] n.l.a.ActorLogger:
Actor threw an exception
javax.naming.NoInitialContextException: Need to specify class name in
environment or system property, or as an applet parameter, or in an
application resource file: java.naming.factory.initial
at
javax.naming.spi.NamingManager.getInitialContext(NamingManager.java:
662) ~[na:1.6.0_22]
at javax.naming.InitialContext.getDefaultInitCtx(InitialContext.java:
305) ~[na:1.6.0_22]
at
javax.naming.InitialContext.getURLOrDefaultInitCtx(InitialContext.java:
342) ~[na:1.6.0_22]
at javax.naming.InitialContext.lookup(InitialContext.java:409) ~[na:
1.6.0_22]


More careful reading of the logs shows that the JNDI worked within the
actor on the first message, but after I use LAPinger.schedule(this,
ProcessOrders(), 20*1000) it fails on subsequent messages.

Could this in any way be related to the Tomcat fix in ticket #1001
(I'm on Jetty) that sets the context class loader to null? I haven't
yet set up a local Lift build, so I haven't yet been able to try
without that fix...

Regards,
Terje

[Derek Chen-Becker]

It may be related. What happens if you just try

val initCtxt = new InitialContext

 val conn = initCtxt.lookup("java:/

comp/env").asInstanceOf[Context].lookup(<put your JNDI name here>).asInstanceOf[DataSource].getConnection

That would at least isolate the exception to either the procurement of the InitialContext or its use.

Derek

--

[Terje Sten Bjerkseth]

On Jun 6, 8:53 pm, Derek Chen-Becker <dchenbec...@gmail.com> wrote:
> It may be related. What happens if you just try
>
> val initCtxt = new InitialContext
>
>  val conn = initCtxt.lookup("java:/
> comp/env").asInstanceOf[Context].lookup(<put your JNDI name
> here>).asInstanceOf[DataSource].getConnection
>
> That would at least isolate the exception to either the procurement of the
> InitialContext or its use.

Tried this, and the exception comes in lookup (but I'm not sure just
initializing the context does anything?):

actor processing...
getting context...
using context...
[pool-1-thread-2] [ERROR] [2011-06-06 20:59:38,989] n.l.a.ActorLogger:

Actor threw an exception
javax.naming.NoInitialContextException: Need to specify class name in
environment or system property, or as an applet parameter, or in an
application resource file: java.naming.factory.initial
at
javax.naming.spi.NamingManager.getInitialContext(NamingManager.java:
662) ~[na:1.6.0_22]
at javax.naming.InitialContext.getDefaultInitCtx(InitialContext.java:
305) ~[na:1.6.0_22]
at
javax.naming.InitialContext.getURLOrDefaultInitCtx(InitialContext.java:
342) ~[na:1.6.0_22]
at javax.naming.InitialContext.lookup(InitialContext.java:409) ~[na:
1.6.0_22]

So this is in the actor on subsequents messages after
LAPinger.schedule(this, ...).

It works for the first message:

actor processing...
getting context...
using context...
actor: com.mysql.jdbc.JDBC4Connection@5a01f91

[Terje Sten Bjerkseth]

It works against a local 2.4-SNAPSHOT build if I undo the change from
ticket #1001:

~/code/lift/framework (master) ➔ git diff
diff --git a/core/actor/src/main/scala/net/liftweb/actor/
LAPinger.scala b/core/actor/src/main/scala/net/liftweb/actor/
LAPinger.scala
index 323701d..d88f04f 100644
--- a/core/actor/src/main/scala/net/liftweb/actor/LAPinger.scala
+++ b/core/actor/src/main/scala/net/liftweb/actor/LAPinger.scala
@@ -76,7 +76,7 @@ private object TF extends ThreadFactory {
val d: Thread = threadFactory.newThread(r)
d setName "ActorPinger"
d setDaemon true
- d setContextClassLoader null
+ //d setContextClassLoader null
d
}
}

That change was a workaround (?) for Tomcat, but I'm not sure it works
correctly for Jetty 6.

How do I proceed?

Btw, I haven't yet been able to set up a sample repository for
reproducing the error using Jetty, JNDI and H2. I have previously
gotten MySQL to work with JNDI, sbt jetty-start and override def
jettyEnvXml, so I haven't given up yet :)

[Terje Sten Bjerkseth]

Naturally, I got my repo working as soon as I posted my previous
message - for JNDI config, H2 requires username/password it seems.

So, https://github.com/terjesb/lift-actor-classpath can be used to
repro this:

sbt
jetty-run

fails with the current 2.4-M1:

))) processing
11:46:55.359 [pool-1-thread-1] DEBUG net.liftweb.db.DB$$anon$1 -
Connection ID 795224653352 for JNDI connection jdbc/lift_proto opened
11:46:55.392 [pool-1-thread-1] DEBUG net.liftweb.db.DB$$anon$1 -
Connection ID 795224653352 for JNDI connection jdbc/lift_proto closed
[info] Started SelectChann...@0.0.0.0:8080
[info] == jetty-run ==
[success] Successful.
[info]
[info] Total time: 2 s, completed Jun 7, 2011 11:46:55 AM
> ))) processing
11:47:00.430 [pool-1-thread-2] DEBUG net.liftweb.db.DB$$anon$1 -
Connection ID 795224653353 for JNDI connection jdbc/lift_proto opened
11:47:00.439 [pool-1-thread-2] ERROR net.liftweb.actor.ActorLogger -

Actor threw an exception
java.lang.NullPointerException: Looking for Connection Identifier

ConnectionIdentifier(jdbc/lift_proto) but failed to find either a JNDI
data source with the name jdbc/lift_proto or a lift connection manager
with the correct name


If I rebuild with 2.3 it works:


))) processing
11:47:56.737 [pool-1-thread-1] DEBUG net.liftweb.db.DB$$anon$1 -
Connection ID 1223312220909 for JNDI connection jdbc/lift_proto opened
11:47:56.781 [pool-1-thread-1] DEBUG net.liftweb.db.DB$$anon$1 -
Connection ID 1223312220909 for JNDI connection jdbc/lift_proto closed
[info] Started SelectChann...@0.0.0.0:8080
[info] == jetty-run ==
[success] Successful.
[info]
[info] Total time: 9 s, completed Jun 7, 2011 11:47:56 AM
> ))) processing
11:48:01.820 [pool-1-thread-2] DEBUG net.liftweb.db.DB$$anon$1 -
Connection ID 1223312220910 for JNDI connection jdbc/lift_proto opened
11:48:01.855 [pool-1-thread-2] DEBUG net.liftweb.db.DB$$anon$1 -
Connection ID 1223312220910 for JNDI connection jdbc/lift_proto closed


It also works with my local 2.4-SNAPSHOT on 2.9.0-1 with the previous
patch to uncomment d setContextClassLoader null:


))) processing
11:50:11.457 [pool-1-thread-1] DEBUG net.liftweb.db.DB$$anon$1 -
Connection ID 802441110220 for JNDI connection jdbc/lift_proto opened
11:50:11.508 [pool-1-thread-1] DEBUG net.liftweb.db.DB$$anon$1 -
Connection ID 802441110220 for JNDI connection jdbc/lift_proto closed
[info] Started SelectChann...@0.0.0.0:8080
[info] == jetty-run ==
[success] Successful.
[info]
[info] Total time: 15 s, completed Jun 7, 2011 11:50:11 AM
> ))) processing
11:50:16.529 [pool-1-thread-2] DEBUG net.liftweb.db.DB$$anon$1 -
Connection ID 802441110221 for JNDI connection jdbc/lift_proto opened
11:50:16.585 [pool-1-thread-2] DEBUG net.liftweb.db.DB$$anon$1 -
Connection ID 802441110221 for JNDI connection jdbc/lift_proto closed

[David Pollak]

Can you put together a reproducible example?  I'd like to see what the core issue is.

--
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=en.

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

Simply Lift http://simply.liftweb.net
Follow me: http://twitter.com/dpp
Blog: http://goodstuff.im

[Terje Sten Bjerkseth]

On Jun 7, 8:52 pm, David Pollak <feeder.of.the.be...@gmail.com> wrote:
> Can you put together a reproducible example?  I'd like to see what the core
> issue is.

Sure. Please check https://github.com/terjesb/lift-actor-classpath.

Let it run with jetty-run. This works for 2.3, but fails after a few
seconds with 2.4-M1.

If I comment

d setContextClassLoader null

in core/actor/src/main/scala/net/liftweb/actor/LAPinger.scala it also
works against a local 2.4-SNAPSHOT.

Regards,
Terje

[David Pollak]

On Tue, Jun 7, 2011 at 12:45 PM, Terje Sten Bjerkseth <te...@ceteo.no> wrote:

On Jun 7, 8:52 pm, David Pollak <feeder.of.the.be...@gmail.com> wrote:
> Can you put together a reproducible example?  I'd like to see what the core
> issue is.

Okay... looks like the JNDI code is looking to figure out its context via the thread's contextclasspath and when it's null, bad things (tm) happen.

Please open a ticket (http://ticket.liftweb.net you must be a watcher of the LiftWeb space on Assembla) referencing this thread.  I will make the nulling of the contextClassLoader optional.

In the mean time, I'd suggest capturing the contextClassLoader in Boot.scala and putting it in a global someplace.  On entry to your Actor, set the ContextClassLoader of the thread and that should work around the issue until 2.4-M2.

Hope this helps and thanks for all your time and effort to package this issue up so I could understand it!

Thanks,

David
 

Sure. Please check https://github.com/terjesb/lift-actor-classpath.

Let it run with jetty-run. This works for 2.3, but fails after a few
seconds with 2.4-M1.

If I comment

d setContextClassLoader null

in core/actor/src/main/scala/net/liftweb/actor/LAPinger.scala it also
works against a local 2.4-SNAPSHOT.

Regards,
Terje

--

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=en.

[Terje Sten Bjerkseth]

On Jun 7, 10:32 pm, David Pollak <feeder.of.the.be...@gmail.com>

wrote:
> On Tue, Jun 7, 2011 at 12:45 PM, Terje Sten Bjerkseth <te...@ceteo.no>wrote:
>
> > On Jun 7, 8:52 pm, David Pollak <feeder.of.the.be...@gmail.com> wrote:
> > > Can you put together a reproducible example?  I'd like to see what the
> > core
> > > issue is.
>
> Okay... looks like the JNDI code is looking to figure out its context via
> the thread's contextclasspath and when it's null, bad things (tm) happen.
>

> Please open a ticket (http://ticket.liftweb.netyou must be a watcher of the

> LiftWeb space on Assembla) referencing this thread.  I will make the nulling
> of the contextClassLoader optional.
>
> In the mean time, I'd suggest capturing the contextClassLoader in Boot.scala
> and putting it in a global someplace.  On entry to your Actor, set the
> ContextClassLoader of the thread and that should work around the issue until
> 2.4-M2.
>
> Hope this helps and thanks for all your time and effort to package this
> issue up so I could understand it!

Thanks a lot, David.

Ticket created:
http://www.assembla.com/spaces/liftweb/tickets/1036-jetty-jndi-issue-with-liftactor-s-scheduler

Terje.