Opened 4 weeks ago

Last modified 4 weeks ago

#2592 new defect

libjetty NPE on debian 0.9.41-8

Reported by: Eche|on Owned by: zzz
Priority: minor Milestone: undecided
Component: apps/jetty Version: 0.9.41
Keywords: Cc: str4d
Parent Tickets: Sensitive: no

Description

Hi

I did upgrade my buster system with 0.9.41-8 build.
I did get this now into log:
8/17/19, 11:43:34 AM ERROR [tion tunnels] 2ptunnel.TunnelControllerGroup?: Error loading the client app properties from /home/echelon/.i2p/i2ptunnel.config java.io.FileNotFoundException?: /home/echelon/.i2p/i2ptunnel.config (No such file or directory)
8/17/19, 11:43:34 AM WARN [tion tunnels] 2ptunnel.TunnelControllerGroup?: No i2ptunnel configurations found in /home/echelon/.i2p/i2ptunnel.config or /home/echelon/.i2p/i2ptunnel.config.d
8/17/19, 11:43:34 AM WARN [rtup tunnels] 2ptunnel.TunnelControllerGroup?: No configured tunnels to start
8/17/19, 12:22:44 PM WARN [r-2099968475] rg.eclipse.jetty.server.Server: : java.lang.NullPointerException?
8/17/19, 12:22:44 PM 16 similar messages omitted
8/17/19, 12:32:44 PM 11 similar messages omitted
8/17/19, 12:42:44 PM 10 similar messages omitted

lots of NPE in jetty

dpkg -l |grep jetty
ii libjetty9-extra-java 9.4.15-1 all Java servlet engine and webserver — extra libraries
ii libjetty9-java 9.4.15-1 all Java servlet engine and webserver — core libraries

Java version: Debian 11.0.4 (OpenJDK Runtime Environment 11.0.4+11-post-Debian-1deb10u1)
Wrapper version: 3.5.30
Server version: 9.4.15.v20190215
Servlet version: Jasper JSP 2.3 Engine
JSTL version: standard-taglib 1.2.5
Platform: Linux amd64 4.19.0-5-amd64
Processor: Kaby Lake Core i3/i5/i7 (coreibwl)
JBigI status: Locally optimized native BigInteger? library loaded from file
GMP version: 6.1.2
JBigI version: 4
JCpuId version: 3
Encoding: UTF-8
Charset: UTF-8
Built By: Undefined

Subtickets

Change History (10)

comment:1 Changed 4 weeks ago by zzz

Component: package/debianapps/jetty

Please set org.eclipse.jetty.server.Server=WARN on /configlogging which should then produce a stack trace for the exception, and paste one of them over here

comment:2 Changed 4 weeks ago by Eche|on

HI

could be related to i2pbote
8/18/19, 12:37:10 PM WARN [luginStarter] rg.eclipse.jetty.server.Server: Failed startup of context o.e.j.w.WebAppContext?@2e5c7043{/i2pbote,jar:file:///opt/i2p/plugins/i2pbote/console/webapps/i2pbote.war!/,UNAVAILABLE}{/i2pbote.war}
java.io.FileNotFoundException?: JAR entry WEB-INF/lib/tomcat-el-api-8.5.40.jar!/ not found in /opt/i2p/plugins/i2pbote/console/webapps/i2pbote.war

at java.base/sun.net.www.protocol.jar.JarURLConnection.connect(JarURLConnection.java:147)
at java.base/sun.net.www.protocol.jar.JarURLConnection.getJarFile(JarURLConnection.java:92)
at org.eclipse.jetty.webapp.MetaInfConfiguration?.getTlds(MetaInfConfiguration?.java:438)
at org.eclipse.jetty.webapp.MetaInfConfiguration?.scanForTlds(MetaInfConfiguration?.java:355)
at org.eclipse.jetty.webapp.MetaInfConfiguration?.scanJars(MetaInfConfiguration?.java:173)
at org.eclipse.jetty.webapp.MetaInfConfiguration?.preConfigure(MetaInfConfiguration?.java:107)
at org.eclipse.jetty.webapp.WebAppContext?.preConfigure(WebAppContext?.java:506)
at org.eclipse.jetty.webapp.WebAppContext?.doStart(WebAppContext?.java:544)
at org.eclipse.jetty.util.component.AbstractLifeCycle?.start(AbstractLifeCycle?.java:68)
at net.i2p.router.web.WebAppStarter?.startWebApp(WebAppStarter?.java:71)
at net.i2p.router.web.PluginStarter?.startPlugin(PluginStarter?.java:478)
at net.i2p.router.web.PluginStarter?.startPlugins(PluginStarter?.java:267)
at net.i2p.router.web.PluginStarter?.run(PluginStarter?.java:127)
at java.base/java.lang.Thread.run(Thread.java:834)
at net.i2p.util.I2PThread.run(I2PThread.java:103)

8/18/19, 12:37:10 PM ERROR [luginStarter] t.i2p.router.web.PluginStarter?: Error resolving '/home/echelon/.i2p/plugins/i2pbote/console/webapps/i2pbote.war' in '/home/echelon/.i2p/plugins/i2pbote/console/webapps
java.io.FileNotFoundException?: JAR entry WEB-INF/lib/tomcat-el-api-8.5.40.jar!/ not found in /opt/i2p/plugins/i2pbote/console/webapps/i2pbote.war

at java.base/sun.net.www.protocol.jar.JarURLConnection.connect(JarURLConnection.java:147)
at java.base/sun.net.www.protocol.jar.JarURLConnection.getJarFile(JarURLConnection.java:92)
at org.eclipse.jetty.webapp.MetaInfConfiguration?.getTlds(MetaInfConfiguration?.java:438)
at org.eclipse.jetty.webapp.MetaInfConfiguration?.scanForTlds(MetaInfConfiguration?.java:355)
at org.eclipse.jetty.webapp.MetaInfConfiguration?.scanJars(MetaInfConfiguration?.java:173)
at org.eclipse.jetty.webapp.MetaInfConfiguration?.preConfigure(MetaInfConfiguration?.java:107)
at org.eclipse.jetty.webapp.WebAppContext?.preConfigure(WebAppContext?.java:506)
at org.eclipse.jetty.webapp.WebAppContext?.doStart(WebAppContext?.java:544)
at org.eclipse.jetty.util.component.AbstractLifeCycle?.start(AbstractLifeCycle?.java:68)
at net.i2p.router.web.WebAppStarter?.startWebApp(WebAppStarter?.java:71)
at net.i2p.router.web.PluginStarter?.startPlugin(PluginStarter?.java:478)
at net.i2p.router.web.PluginStarter?.startPlugins(PluginStarter?.java:267)
at net.i2p.router.web.PluginStarter?.run(PluginStarter?.java:127)
at java.base/java.lang.Thread.run(Thread.java:834)
at net.i2p.util.I2PThread.run(I2PThread.java:103)

8/18/19, 12:37:12 PM WARN [ handler 1/1] er.transport.udp.PacketHandler?: NTP failure, UDP adjusting clock by 349ms
8/18/19, 12:37:20 PM WARN [Timestamper ] .router.time.RouterTimestamper?: Unable to reach any of the NTP servers [85.125.61.2, 129.27.2.3] - network disconnected? Or set time.sntpServerList=myserver1.com,myserver2.com in advanced configuration.
8/18/19, 12:37:40 PM WARN [JettyStarter?] rg.eclipse.jetty.server.Server: GzipFilter? is deprecated. Use GzipHandler?
8/18/19, 12:38:02 PM WARN [ole Jetty-97] rg.eclipse.jetty.server.Server: Problem checking if id 1faxo0sy8esvm1qtng8vlcp3l3 is in use java.lang.NullPointerException?
8/18/19, 12:39:02 PM WARN [ole Jetty-97] rg.eclipse.jetty.server.Server: Problem checking if id u2f72ps679hc11cete9rpkvoy is in use java.lang.NullPointerException?
8/18/19, 12:40:02 PM WARN [ole Jetty-97] rg.eclipse.jetty.server.Server: Problem checking if id 1npk55nq8zh3fbwpr95w3lteg is in use java.lang.NullPointerException?
8/18/19, 12:40:59 PM WARN [ole Jetty-97] rg.eclipse.jetty.server.Server: Problem checking if id 114ego5aft5ep17nxf3v5l27v6 is in use java.lang.NullPointerException?
8/18/19, 12:42:00 PM WARN [le Jetty-137] rg.eclipse.jetty.server.Server: Problem checking if id 1chxfom9qbxxd1ve8sdzy7hwxt is in use java.lang.NullPointerException?
8/18/19, 12:43:00 PM WARN [le Jetty-137] rg.eclipse.jetty.server.Server: Problem checking if id xp5s4nmujw3ccehezk9t8pm2 is in use java.lang.NullPointerException?
8/18/19, 12:44:00 PM WARN [le Jetty-137] rg.eclipse.jetty.server.Server: Problem checking if id 1tltoxs1eolka1v298hx9rm7fc is in use java.lang.NullPointerException?
8/18/19, 12:45:00 PM WARN [ole Jetty-99] rg.eclipse.jetty.server.Server: Problem checking if id 8zo48l2c38v31344zddjpj1po is in use java.lang.NullPointerException?
8/18/19, 12:45:57 PM WARN [ole Jetty-99] rg.eclipse.jetty.server.Server: Problem checking if id 15yftc1gcwg7aeyk5sp89rm2p is in use java.lang.NullPointerException?
8/18/19, 12:46:57 PM WARN [ole Jetty-99] rg.eclipse.jetty.server.Server: Problem checking if id y5w6pvvgtagvs5382hlj8n1x is in use java.lang.NullPointerException?
8/18/19, 12:47:57 PM WARN [ole Jetty-99] rg.eclipse.jetty.server.Server: Problem checking if id 1s9m768xpikk416nw62i4qq20 is in use java.lang.NullPointerException?

comment:3 Changed 4 weeks ago by zzz

unfortunately due to flaws in the jetty-to-i2p logging bridge, that still isn't giving us the stack trace we need… working on it…

comment:4 Changed 4 weeks ago by zzz

Logging fix in a9a28e378ec94e24e77a59e13f546c7fbc147f46 0.9.41-9-rc, please retest with that to hopefully get a stack trace for the NPE

comment:5 Changed 4 weeks ago by zzz

Cc: str4d added

Also, something's going on with bote. Bote is bundling 3 tomcat jars in its war, and they are not being loaded. We already have those jars in the distribution. These jars should not be bundled. Why jetty isn't loading them, I'm not sure. I do see similar errors here (with jetty 9.2.25) when I start bote, but it isn't fatal… bote still runs.

It's possible that it is fatal on 9.4.15 and is the cause of the NPEs? not sure. Once you have the stack traces, please disable the bote plugin and then restart and see if that fixes it.

comment:6 Changed 4 weeks ago by Eche|on

Cc: str4d removed
8/18/19, 5:16:31 PM WARN  [le Jetty-140] rg.eclipse.jetty.server.Server: Problem checking if id 1vn28fnzbevl81d7xtp84tcwyl is in use java.lang.NullPointerException
java.lang.NullPointerException
	at org.eclipse.jetty.server.session.SessionHandler.isIdInUse(SessionHandler.java:1462)
	at org.eclipse.jetty.server.session.DefaultSessionIdManager.isIdInUse(DefaultSessionIdManager.java:325)
	at org.eclipse.jetty.server.session.DefaultSessionIdManager.newSessionId(DefaultSessionIdManager.java:230)
	at org.eclipse.jetty.server.session.SessionHandler.newHttpSession(SessionHandler.java:858)
	at org.eclipse.jetty.server.Request.getSession(Request.java:1570)
	at org.eclipse.jetty.server.Request.getSession(Request.java:1543)
	at javax.servlet.http.HttpServletRequestWrapper.getSession(HttpServletRequestWrapper.java:250)
	at org.apache.jasper.runtime.PageContextImpl.initialize(PageContextImpl.java:133)
	at org.apache.jasper.runtime.JspFactoryImpl.internalGetPageContext(JspFactoryImpl.java:109)
	at org.apache.jasper.runtime.JspFactoryImpl.getPageContext(JspFactoryImpl.java:60)
	at net.i2p.router.web.jsp.xhr1_jsp._jspService(xhr1_jsp.java:114)
	at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:70)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:741)
	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:873)
	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1623)
	at net.i2p.servlet.filters.XSSFilter.doFilter(XSSFilter.java:30)
	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1602)
	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:540)
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:146)
	at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548)
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:257)
	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1701)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255)
	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1345)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203)
	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:480)
	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1668)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201)
	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1247)
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144)
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
	at net.i2p.router.web.LocaleWebAppHandler.handle(LocaleWebAppHandler.java:104)
	at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:220)
	at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:753)
	at net.i2p.router.web.HostCheckHandler.handle(HostCheckHandler.java:118)
	at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:126)
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
	at org.eclipse.jetty.server.Server.handle(Server.java:502)
	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:370)
	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:267)
	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:305)
	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103)
	at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:117)
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:333)
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:310)
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:168)
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:126)
	at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:366)
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:765)
	at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:683)
	at java.base/java.lang.Thread.run(Thread.java:834)
8/18/19, 5:16:36 PM WARN  [JettyStarter] rg.eclipse.jetty.server.Server: GzipFilter is deprecated. Use GzipHandler
8/18/19, 5:17:31 PM WARN  [le Jetty-138] rg.eclipse.jetty.server.Server: Problem checking if id gngabmwxriemjjppo185dtng is in use java.lang.NullPointerException
java.lang.NullPointerException
Last edited 4 weeks ago by zzz (previous) (diff)

comment:7 Changed 4 weeks ago by Eche|on

Cc: str4d added

comment:8 Changed 4 weeks ago by zzz

Thanks. No ideas so far. SessionHandler?.doStart() is apparently not being called so _sessionCache is null in isIdInUse(). It's coming from the sidebar XHR so it's triggered once a minute. Seems harmless as it's being caught. Haven't seen here yet on 9.2 (with/without bote), but haven't tried with 9.4 yet.

comment:9 Changed 4 weeks ago by zzz

#2601 entered for the bote tomcat jar issue

comment:10 Changed 4 weeks ago by zzz

Tested with my jetty94 branch (not Debian) and got the same file not found errors as in comment 3, and bote failed to start. I did not get any NPEs.

Note: See TracTickets for help on using tickets.