Opened 5 years ago

Closed 5 years ago

#1271 closed defect (not a bug)

-15 performs much worse than 14 here

Reported by: user Owned by:
Priority: minor Milestone: 0.9.13
Component: router/general Version: 0.9.12
Keywords: Cc:
Parent Tickets: Sensitive: no

Description (last modified by zzz)

on -15 I get some restarts that I didn't have on -14

much slower / less part tunnels trhan with -14
and message delay is much higher: 17s now
overall throughput MUCH lower / i2psnark much slower

and something about a NPE in logs

I2P version: 0.9.12-15
Java version: Oracle Corporation 1.7.0_55 (Java(TM) SE Runtime Environment 1.7.0_55-b14)
Wrapper version: 3.5.22
Server version: 8.1.14.v20131031
Servlet version: Jasper JSP 2.1 Engine
Platform: Windows Vista x86 6.0
Processor: Core 2 (Conroe) (core2)
Jbigi: Locally optimized native BigInteger library loaded from file
Encoding: Cp1252
Charset: windows-1252
2014/05/07 19:14:48 | SLF4J: See http://www.slf4j.org/codes.html#no_static_mdc_binder for further details.
2014/05/07 19:14:53 | KRITISCH [chid Starter] outer.startup.RouterAppManager: Client outproxy START_FAILED 
2014/05/08 10:00:15 | KRITISCH [P writer 2/4] p.router.transport.ntcp.Writer: Error in the ntcp writer on NTCP conn to qiosO5 created 3178ms ago, last send 3178ms ago, last recv 3178ms ago, sent 0, rcvd 0
2014/05/08 10:00:15 | java.lang.NullPointerException: invalid args to aes - sessionKey
2014/05/08 10:00:15 | 	at net.i2p.crypto.CryptixAESEngine.encrypt(CryptixAESEngine.java:89)
2014/05/08 10:00:15 | 	at net.i2p.router.transport.ntcp.NTCPConnection.sendMeta(NTCPConnection.java:1299)
2014/05/08 10:00:15 | 	at net.i2p.router.transport.ntcp.NTCPConnection.prepareNextWriteFast(NTCPConnection.java:743)
2014/05/08 10:00:15 | 	at net.i2p.router.transport.ntcp.NTCPConnection.prepareNextWrite(NTCPConnection.java:621)
2014/05/08 10:00:15 | 	at net.i2p.router.transport.ntcp.Writer$Runner.run(Writer.java:129)
2014/05/08 10:00:15 | 	at java.lang.Thread.run(Unknown Source)
2014/05/08 10:00:15 | 	at net.i2p.util.I2PThread.run(I2PThread.java:84)
2014/05/09 01:18:13 | Exception in thread "Shutdown task i2p.bote.I2PBote$1" java.lang.NullPointerException
2014/05/09 01:18:13 | 	at i2p.bote.imap.MapperFactory.stopListening(MapperFactory.java:90)
2014/05/09 01:18:13 | 	at i2p.bote.imap.ImapService.stop(ImapService.java:207)
2014/05/09 01:18:13 | 	at i2p.bote.I2PBote.stopImap(I2PBote.java:579)
2014/05/09 01:18:13 | 	at i2p.bote.I2PBote.stopAllServices(I2PBote.java:796)
2014/05/09 01:18:13 | 	at i2p.bote.I2PBote.shutDown(I2PBote.java:403)
2014/05/09 01:18:13 | 	at i2p.bote.I2PBote$1.run(I2PBote.java:173)
2014/05/09 01:18:13 | 	at java.lang.Thread.run(Unknown Source)
2014/05/09 01:18:13 | 2014-05-08 23:18:12.080:INFO:oejs.Server:Graceful shutdown SelectChannelConnector@127.0.0.1:7657
2014/05/09 01:18:13 | 2014-05-08 23:18:12.080:INFO:oejs.Server:Graceful shutdown SelectChannelConnector@::1:7657
2014/05/09 01:18:13 | 2014-05-08 23:18:12.080:INFO:oejs.Server:Graceful shutdown o.e.j.w.WebAppContext{/,jar:file:/C:/Program%20Files/i2p/webapps/routerconsole.war!/},C:\Program Files\i2p\webapps/routerconsole.war
2014/05/09 01:18:13 | 2014-05-08 23:18:12.081:INFO:oejs.Server:Graceful shutdown o.e.j.w.WebAppContext{/addressbook,jar:file:/C:/Program%20Files/i2p/webapps/addressbook.war!/},C:\Program Files\i2p\webapps\addressbook.war
2014/05/09 01:18:13 | 2014-05-08 23:18:12.081:INFO:oejs.Server:Graceful shutdown o.e.j.w.WebAppContext{/i2psnark,jar:file:/C:/Program%20Files/i2p/webapps/i2psnark.war!/},C:\Program Files\i2p\webapps\i2psnark.war
2014/05/09 01:18:13 | 2014-05-08 23:18:12.081:INFO:oejs.Server:Graceful shutdown o.e.j.w.WebAppContext{/i2ptunnel,jar:file:/C:/Program%20Files/i2p/webapps/i2ptunnel.war!/},C:\Program Files\i2p\webapps\i2ptunnel.war
2014/05/09 01:18:13 | 2014-05-08 23:18:12.081:INFO:oejs.Server:Graceful shutdown o.e.j.w.WebAppContext{/susidns,jar:file:/C:/Program%20Files/i2p/webapps/susidns.war!/},C:\Program Files\i2p\webapps\susidns.war
2014/05/09 01:18:13 | 2014-05-08 23:18:12.081:INFO:oejs.Server:Graceful shutdown o.e.j.w.WebAppContext{/susimail,jar:file:/C:/Program%20Files/i2p/webapps/susimail.war!/},C:\Program Files\i2p\webapps\susimail.war
2014/05/09 01:18:13 | 2014-05-08 23:18:12.081:INFO:oejs.Server:Graceful shutdown o.e.j.w.WebAppContext{/orchid,jar:file:/C:/ProgramData/Application%20Data/i2p/plugins/orchid/console/webapps/orchid.war!/},C:\ProgramData\Application Data\i2p\plugins\orchid\console\webapps\orchid.war
2014/05/09 01:18:13 | 2014-05-08 23:18:12.081:INFO:oejs.Server:Graceful shutdown o.e.j.w.WebAppContext{/i2pbote,jar:file:/C:/ProgramData/Application%20Data/i2p/plugins/i2pbote/console/webapps/i2pbote.war!/},C:\ProgramData\Application Data\i2p\plugins\i2pbote\console\webapps\i2pbote.war
2014/05/09 01:18:13 | 2014-05-08 23:18:13.340:WARN:oejuc.AbstractLifeCycle:FAILED o.e.j.w.WebAppContext{/i2pbote,jar:file:/C:/ProgramData/Application%20Data/i2p/plugins/i2pbote/console/webapps/i2pbote.war!/},C:\ProgramData\Application Data\i2p\plugins\i2pbote\console\webapps\i2pbote.war: java.lang.NullPointerException
2014/05/09 01:18:13 | java.lang.NullPointerException
2014/05/09 01:18:13 | 	at i2p.bote.imap.MapperFactory.stopListening(MapperFactory.java:90)
2014/05/09 01:18:13 | 	at i2p.bote.imap.ImapService.stop(ImapService.java:207)
2014/05/09 01:18:13 | 	at i2p.bote.I2PBote.stopImap(I2PBote.java:579)
2014/05/09 01:18:13 | 	at i2p.bote.I2PBote.stopAllServices(I2PBote.java:796)
2014/05/09 01:18:13 | 	at i2p.bote.I2PBote.shutDown(I2PBote.java:403)
2014/05/09 01:18:13 | 	at i2p.bote.web.ServiceInitializer.contextDestroyed(ServiceInitializer.java:35)
2014/05/09 01:18:13 | 	at org.eclipse.jetty.server.handler.ContextHandler.doStop(ContextHandler.java:823)
2014/05/09 01:18:13 | 	at org.eclipse.jetty.servlet.ServletContextHandler.doStop(ServletContextHandler.java:160)
2014/05/09 01:18:13 | 	at org.eclipse.jetty.webapp.WebAppContext.doStop(WebAppContext.java:518)
2014/05/09 01:18:13 | 	at org.eclipse.jetty.util.component.AbstractLifeCycle.stop(AbstractLifeCycle.java:89)
2014/05/09 01:18:13 | 	at net.i2p.router.web.WebAppStarter.stopWebApp(WebAppStarter.java:130)
2014/05/09 01:18:13 | 	at net.i2p.router.web.PluginStarter.stopPlugin(PluginStarter.java:462)
2014/05/09 01:18:13 | 	at net.i2p.router.web.PluginStopper.stopPlugins(PluginStopper.java:37)
2014/05/09 01:18:13 | 	at net.i2p.router.web.PluginStopper.run(PluginStopper.java:22)
2014/05/09 01:18:13 | 	at java.lang.Thread.run(Unknown Source)
2014/05/09 01:18:13 | 	at net.i2p.util.I2PThread.run(I2PThread.java:84)
2014/05/09 01:18:13 | INFO: BOB is now shutting down...
2014/05/09 01:18:14 | INFO: BOB is now stopped.
2014/05/09 01:18:37 | KRITISCH [hutdown hook] net.i2p.router.Router         : Shutting down after a brief delay
2014/05/09 01:18:37 | KRITISCH [hutdown hook] net.i2p.router.Router         : Starting final shutdown(3)
2014/05/09 01:18:38 | 2014-05-08 23:18:38.075:INFO:oejs.Server:Graceful shutdown SelectChannelConnector@127.0.0.1:7658
2014/05/09 01:18:38 | 2014-05-08 23:18:38.085:INFO:oejs.Server:Graceful shutdown o.e.j.s.ServletContextHandler{/,file:/C:/ProgramData/Application%20Data/i2p/eepsite/docroot/}
2014/05/09 01:18:38 | 2014-05-08 23:18:38.085:INFO:oejs.Server:Graceful shutdown o.e.j.s.ServletContextHandler{/cgi-bin,file:/C:/ProgramData/Application%20Data/i2p/eepsite/cgi-bin/}
2014/05/09 01:18:55 | KRITISCH [hutdown hook] net.i2p.router.Router         : Shutdown(3) complete
2014/05/09 01:19:02 | <-- Wrapper Stopped
2014/05/09 02:38:47 | Unable to write to the configured log directory: C:\Windows\system32\config\systemprofile\AppData\Roaming\i2p (Das System kann den angegebenen Pfad nicht finden. (0x3))
2014/05/09 02:38:47 |   The directory does not exist.
2014/05/09 02:38:47 | Unable to write to the configured log file: C:\Windows\system32\config\systemprofile\AppData\Roaming\i2p\wrapper.log (Das System kann den angegebenen Pfad nicht finden. (0x3))
2014/05/09 02:38:47 |   Falling back to the default file in the current working directory: wrapper.log
2014/05/09 02:38:47 | --> Wrapper Started as Service
2014/05/09 02:38:47 | Java Service Wrapper Community Edition 32-bit 3.5.22
2014/05/09 02:38:47 |   Copyright (C) 1999-2013 Tanuki Software, Ltd. All Rights Reserved.
2014/05/09 02:38:47 |     http://wrapper.tanukisoftware.com
2014/05/09 02:38:47 | 
2014/05/09 02:38:48 | Launching a JVM...
2014/05/09 02:38:50 | WrapperManager: Initializing...
2014/05/09 02:38:50 | Starting I2P 0.9.12-14
2014/05/09 02:38:51 | INFO: Update file exists [i2pupdate.zip] - installing
2014/05/09 02:39:05 | INFO: 451 files extracted to C:\Program Files\i2p
2014/05/09 02:39:05 | INFO: File [deletelist.txt] deleted
2014/05/09 02:39:05 | INFO: Update installed
2014/05/09 02:39:05 | INFO: Restarting after update
2014/05/09 02:39:07 | on_exit trigger matched.  Restarting the JVM.  (Exit code: 4)
2014/05/09 02:39:22 | Launching a JVM...
2014/05/09 02:39:23 | WrapperManager: Initializing...
2014/05/09 02:39:23 | Starting I2P 0.9.12-15
2014/05/09 02:39:24 | INFO: Native CPUID library jcpuid-x86-windows loaded from file
2014/05/09 02:39:24 | INFO: Locally optimized native BigInteger library loaded from file
2014/05/09 02:40:25 | INFO: Jetty 8.1.14.v20131031 logging to I2P logs using class org.eclipse.jetty.server.Server
2014/05/09 02:40:27 | #
2014/05/09 02:40:27 | # A fatal error has been detected by the Java Runtime Environment:
2014/05/09 02:40:27 | #
2014/05/09 02:40:27 | #  Internal Error (safepoint.cpp:717), pid=2368, tid=2344
2014/05/09 02:40:27 | #  fatal error: Illegal threadstate encountered: 4
2014/05/09 02:40:27 | #
2014/05/09 02:40:27 | # JRE version: Java(TM) SE Runtime Environment (7.0_55-b14) (build 1.7.0_55-b14)
2014/05/09 02:40:27 | # Java VM: Java HotSpot(TM) Client VM (24.55-b03 mixed mode, sharing windows-x86 )
2014/05/09 02:40:27 | # Failed to write core dump. Minidumps are not enabled by default on client versions of Windows
2014/05/09 02:40:27 | #
2014/05/09 02:40:27 | # An error report file with more information is saved as:
2014/05/09 02:40:27 | # C:\Program Files\i2p\hs_err_pid2368.log
2014/05/09 02:40:28 | #
2014/05/09 02:40:28 | # If you would like to submit a bug report, please visit:
2014/05/09 02:40:28 | #   http://bugreport.sun.com/bugreport/crash.jsp
2014/05/09 02:40:28 | # The crash happened outside the Java Virtual Machine in native code.
2014/05/09 02:40:28 | # See problematic frame for where to report the bug.
2014/05/09 02:40:28 | #
2014/05/09 02:40:28 | JVM exited unexpectedly.
2014/05/09 02:40:44 | Launching a JVM...
2014/05/09 02:40:46 | WrapperManager: Initializing...
2014/05/09 02:40:47 | Starting I2P 0.9.12-15
2014/05/09 02:40:47 | WARN: There may be another router already running. Waiting a while to be sure...
2014/05/09 02:41:22 | WARN: Old router was not shut down gracefully, deleting router.ping
2014/05/09 02:41:22 | INFO: No, there wasn't another router already running. Proceeding with startup.
2014/05/09 02:41:23 | INFO: Native CPUID library jcpuid-x86-windows loaded from file
2014/05/09 02:41:23 | INFO: Locally optimized native BigInteger library loaded from file
2014/05/09 02:41:28 | INFO: Jetty 8.1.14.v20131031 logging to I2P logs using class org.eclipse.jetty.server.Server
2014/05/09 02:41:31 | 2014-05-09 00:41:31.015:INFO:oejs.Server:jetty-8.1.14.v20131031
2014/05/09 02:41:39 | INFO: BOB is now running.
2014/05/09 02:41:39 | Adding C:\ProgramData\Application Data\i2p\plugins\orchid/lib/orchid.jar to classpath for orchid
2014/05/09 02:41:39 | Adding C:\ProgramData\Application Data\i2p\plugins\orchid/lib/xmlrpc-commons.jar to classpath for orchid
2014/05/09 02:41:39 | Adding C:\ProgramData\Application Data\i2p\plugins\orchid/lib/xmlrpc-client.jar to classpath for orchid
2014/05/09 02:41:41 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/i2pbote.jar to classpath for i2pbote
2014/05/09 02:41:41 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/mailapi.jar to classpath for i2pbote
2014/05/09 02:41:41 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/bcprov-ecc-jdk16-146.jar to classpath for i2pbote
2014/05/09 02:41:41 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/flexi-gmss-1.7p1.jar to classpath for i2pbote
2014/05/09 02:41:41 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/ntruenc-1.2.jar to classpath for i2pbote
2014/05/09 02:41:41 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/scrypt-1.4.0.jar to classpath for i2pbote
2014/05/09 02:41:41 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/lzma-9.20.jar to classpath for i2pbote
2014/05/09 02:41:41 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/apache-james-imap-api-0.3.jar to classpath for i2pbote
2014/05/09 02:41:41 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/apache-james-imap-message-0.3.jar to classpath for i2pbote
2014/05/09 02:41:41 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/apache-james-imapprocessor-0.3.jar to classpath for i2pbote
2014/05/09 02:41:41 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/apache-james-mailbox-api-0.4.jar to classpath for i2pbote
2014/05/09 02:41:41 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/apache-james-mailbox-store-0.4.jar to classpath for i2pbote
2014/05/09 02:41:41 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/apache-mime4j-core-0.7.2.jar to classpath for i2pbote
2014/05/09 02:41:41 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/commons-codec-1.5.jar to classpath for i2pbote
2014/05/09 02:41:41 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/commons-collections-3.2.1.jar to classpath for i2pbote
2014/05/09 02:41:41 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/commons-configuration-1.6.jar to classpath for i2pbote
2014/05/09 02:41:41 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/commons-io-2.0.1.jar to classpath for i2pbote
2014/05/09 02:41:41 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/commons-lang-2.6.jar to classpath for i2pbote
2014/05/09 02:41:41 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/james-server-lifecycle-api-3.0-beta4.jar to classpath for i2pbote
2014/05/09 02:41:41 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/james-server-protocols-imap4-3.0-beta4.jar to classpath for i2pbote
2014/05/09 02:41:42 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/james-server-protocols-library-3.0-beta4.jar to classpath for i2pbote
2014/05/09 02:41:42 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/james-server-util-3.0-beta4.jar to classpath for i2pbote
2014/05/09 02:41:42 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/jutf7-1.0.0.jar to classpath for i2pbote
2014/05/09 02:41:42 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/netty-3.3.1.Final.jar to classpath for i2pbote
2014/05/09 02:41:42 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/protocols-api-1.6.2.jar to classpath for i2pbote
2014/05/09 02:41:42 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/protocols-netty-1.6.2.jar to classpath for i2pbote
2014/05/09 02:41:42 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/slf4j-api-1.6.1.jar to classpath for i2pbote
2014/05/09 02:41:42 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/slf4j-jcl-1.7.5.jar to classpath for i2pbote
2014/05/09 02:41:42 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/subethasmtp-3.1.7.jar to classpath for i2pbote
2014/05/09 02:41:52 | KRITISCH [chid Starter] outer.startup.RouterAppManager: Client outproxy START_FAILED 
2014/05/09 02:41:58 | 2014-05-09 00:41:58.874:INFO:oejs.Server:jetty-8.1.14.v20131031
2014/05/09 02:42:04 | SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder".
2014/05/09 02:42:04 | SLF4J: Defaulting to no-operation (NOP) logger implementation
2014/05/09 02:42:04 | SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details.
2014/05/09 02:42:09 | SLF4J: Failed to load class "org.slf4j.impl.StaticMDCBinder".
2014/05/09 02:42:09 | SLF4J: Defaulting to no-operation MDCAdapter implementation.
2014/05/09 02:42:09 | SLF4J: See http://www.slf4j.org/codes.html#no_static_mdc_binder for further details.
2014/05/09 03:05:47 | INFO: BOB is now shutting down...
2014/05/09 03:05:47 | INFO: BOB is now stopped.
2014/05/09 03:06:17 | INFO: BOB is now running.
2014/05/09 07:02:17 | KRITISCH [uterWatchdog] 2p.router.tasks.RouterWatchdog: Router appears hung, or there is severe network congestion.  Watchdog starts barking!
2014/05/09 15:29:22 | JVM appears hung: Timed out waiting for signal from JVM.  Restarting JVM.
2014/05/09 15:29:23 | 2014-05-09 13:29:23.561:INFO:oejs.Server:Graceful shutdown SelectChannelConnector@127.0.0.1:7658
2014/05/09 15:29:23 | 2014-05-09 13:29:23.562:INFO:oejs.Server:Graceful shutdown o.e.j.s.ServletContextHandler{/,file:/C:/ProgramData/Application%20Data/i2p/eepsite/docroot/}
2014/05/09 15:29:23 | 2014-05-09 13:29:23.563:INFO:oejs.Server:Graceful shutdown o.e.j.s.ServletContextHandler{/cgi-bin,file:/C:/ProgramData/Application%20Data/i2p/eepsite/cgi-bin/}
2014/05/09 15:29:24 | KRITISCH [r 1 shutdown] net.i2p.router.Router         : Shutting down the router...
2014/05/09 15:29:24 | KRITISCH [r 1 shutdown] net.i2p.router.Router         : Starting final shutdown(3)
2014/05/09 15:29:25 | Exception in thread "Shutdown task i2p.bote.I2PBote$1" java.lang.NullPointerException
2014/05/09 15:29:25 | 	at i2p.bote.imap.MapperFactory.stopListening(MapperFactory.java:90)
2014/05/09 15:29:25 | 	at i2p.bote.imap.ImapService.stop(ImapService.java:207)
2014/05/09 15:29:25 | 	at i2p.bote.I2PBote.stopImap(I2PBote.java:579)
2014/05/09 15:29:25 | 	at i2p.bote.I2PBote.stopAllServices(I2PBote.java:796)
2014/05/09 15:29:25 | 	at i2p.bote.I2PBote.shutDown(I2PBote.java:403)
2014/05/09 15:29:25 | 	at i2p.bote.I2PBote$1.run(I2PBote.java:173)
2014/05/09 15:29:25 | 	at java.lang.Thread.run(Unknown Source)
2014/05/09 15:29:29 | 2014-05-09 13:29:29.308:INFO:oejs.Server:Graceful shutdown SelectChannelConnector@127.0.0.1:7657
2014/05/09 15:29:29 | 2014-05-09 13:29:29.321:WARN:oejuc.AbstractLifeCycle:FAILED o.e.j.w.WebAppContext{/i2pbote,jar:file:/C:/ProgramData/Application%20Data/i2p/plugins/i2pbote/console/webapps/i2pbote.war!/},C:\ProgramData\Application Data\i2p\plugins\i2pbote\console\webapps\i2pbote.war: java.lang.NullPointerException
2014/05/09 15:29:29 | java.lang.NullPointerException
2014/05/09 15:29:29 | 	at i2p.bote.imap.MapperFactory.stopListening(MapperFactory.java:90)
2014/05/09 15:29:29 | 	at i2p.bote.imap.ImapService.stop(ImapService.java:207)
2014/05/09 15:29:29 | 	at i2p.bote.I2PBote.stopImap(I2PBote.java:579)
2014/05/09 15:29:29 | 	at i2p.bote.I2PBote.stopAllServices(I2PBote.java:796)
2014/05/09 15:29:29 | 	at i2p.bote.I2PBote.shutDown(I2PBote.java:403)
2014/05/09 15:29:29 | 	at i2p.bote.web.ServiceInitializer.contextDestroyed(ServiceInitializer.java:35)
2014/05/09 15:29:29 | 	at org.eclipse.jetty.server.handler.ContextHandler.doStop(ContextHandler.java:823)
2014/05/09 15:29:29 | 	at org.eclipse.jetty.servlet.ServletContextHandler.doStop(ServletContextHandler.java:160)
2014/05/09 15:29:29 | 	at org.eclipse.jetty.webapp.WebAppContext.doStop(WebAppContext.java:518)
2014/05/09 15:29:29 | 	at org.eclipse.jetty.util.component.AbstractLifeCycle.stop(AbstractLifeCycle.java:89)
2014/05/09 15:29:29 | 	at net.i2p.router.web.WebAppStarter.stopWebApp(WebAppStarter.java:130)
2014/05/09 15:29:29 | 	at net.i2p.router.web.PluginStarter.stopPlugin(PluginStarter.java:462)
2014/05/09 15:29:29 | 	at net.i2p.router.web.PluginStopper.stopPlugins(PluginStopper.java:37)
2014/05/09 15:29:29 | 	at net.i2p.router.web.PluginStopper.run(PluginStopper.java:22)
2014/05/09 15:29:29 | 	at java.lang.Thread.run(Unknown Source)
2014/05/09 15:29:29 | 	at net.i2p.util.I2PThread.run(I2PThread.java:84)
2014/05/09 15:29:29 | 2014-05-09 13:29:29.378:INFO:oejs.Server:Graceful shutdown SelectChannelConnector@::1:7657
2014/05/09 15:29:29 | 2014-05-09 13:29:29.398:INFO:oejs.Server:Graceful shutdown o.e.j.w.WebAppContext{/,jar:file:/C:/Program%20Files/i2p/webapps/routerconsole.war!/},C:\Program Files\i2p\webapps/routerconsole.war
2014/05/09 15:29:29 | 2014-05-09 13:29:29.399:INFO:oejs.Server:Graceful shutdown o.e.j.w.WebAppContext{/addressbook,jar:file:/C:/Program%20Files/i2p/webapps/addressbook.war!/},C:\Program Files\i2p\webapps\addressbook.war
2014/05/09 15:29:29 | 2014-05-09 13:29:29.399:INFO:oejs.Server:Graceful shutdown o.e.j.w.WebAppContext{/i2psnark,jar:file:/C:/Program%20Files/i2p/webapps/i2psnark.war!/},C:\Program Files\i2p\webapps\i2psnark.war
2014/05/09 15:29:29 | 2014-05-09 13:29:29.399:INFO:oejs.Server:Graceful shutdown o.e.j.w.WebAppContext{/i2ptunnel,jar:file:/C:/Program%20Files/i2p/webapps/i2ptunnel.war!/},C:\Program Files\i2p\webapps\i2ptunnel.war
2014/05/09 15:29:29 | 2014-05-09 13:29:29.402:INFO:oejs.Server:Graceful shutdown o.e.j.w.WebAppContext{/susidns,jar:file:/C:/Program%20Files/i2p/webapps/susidns.war!/},C:\Program Files\i2p\webapps\susidns.war
2014/05/09 15:29:29 | 2014-05-09 13:29:29.402:INFO:oejs.Server:Graceful shutdown o.e.j.w.WebAppContext{/susimail,jar:file:/C:/Program%20Files/i2p/webapps/susimail.war!/},C:\Program Files\i2p\webapps\susimail.war
2014/05/09 15:29:50 | INFO: BOB is now shutting down...
2014/05/09 15:29:50 | INFO: BOB is now stopped.
2014/05/09 15:30:33 | KRITISCH [r 1 shutdown] net.i2p.router.Router         : Shutdown(3) complete
2014/05/09 15:30:52 | Launching a JVM...
2014/05/09 15:30:57 | WrapperManager: Initializing...
2014/05/09 15:30:59 | Starting I2P 0.9.12-15
2014/05/09 15:31:00 | INFO: Native CPUID library jcpuid-x86-windows loaded from file
2014/05/09 15:31:01 | INFO: Locally optimized native BigInteger library loaded from file
2014/05/09 15:31:04 | INFO: Jetty 8.1.14.v20131031 logging to I2P logs using class org.eclipse.jetty.server.Server
2014/05/09 15:31:06 | 2014-05-09 13:31:06.060:INFO:oejs.Server:jetty-8.1.14.v20131031
2014/05/09 15:31:12 | Adding C:\ProgramData\Application Data\i2p\plugins\orchid/lib/orchid.jar to classpath for orchid
2014/05/09 15:31:12 | Adding C:\ProgramData\Application Data\i2p\plugins\orchid/lib/xmlrpc-commons.jar to classpath for orchid
2014/05/09 15:31:12 | Adding C:\ProgramData\Application Data\i2p\plugins\orchid/lib/xmlrpc-client.jar to classpath for orchid
2014/05/09 15:31:13 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/i2pbote.jar to classpath for i2pbote
2014/05/09 15:31:13 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/mailapi.jar to classpath for i2pbote
2014/05/09 15:31:13 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/bcprov-ecc-jdk16-146.jar to classpath for i2pbote
2014/05/09 15:31:13 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/flexi-gmss-1.7p1.jar to classpath for i2pbote
2014/05/09 15:31:13 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/ntruenc-1.2.jar to classpath for i2pbote
2014/05/09 15:31:13 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/scrypt-1.4.0.jar to classpath for i2pbote
2014/05/09 15:31:13 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/lzma-9.20.jar to classpath for i2pbote
2014/05/09 15:31:13 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/apache-james-imap-api-0.3.jar to classpath for i2pbote
2014/05/09 15:31:13 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/apache-james-imap-message-0.3.jar to classpath for i2pbote
2014/05/09 15:31:13 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/apache-james-imapprocessor-0.3.jar to classpath for i2pbote
2014/05/09 15:31:13 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/apache-james-mailbox-api-0.4.jar to classpath for i2pbote
2014/05/09 15:31:13 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/apache-james-mailbox-store-0.4.jar to classpath for i2pbote
2014/05/09 15:31:13 | INFO: BOB is now running.
2014/05/09 15:31:13 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/apache-mime4j-core-0.7.2.jar to classpath for i2pbote
2014/05/09 15:31:13 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/commons-codec-1.5.jar to classpath for i2pbote
2014/05/09 15:31:13 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/commons-collections-3.2.1.jar to classpath for i2pbote
2014/05/09 15:31:13 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/commons-configuration-1.6.jar to classpath for i2pbote
2014/05/09 15:31:13 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/commons-io-2.0.1.jar to classpath for i2pbote
2014/05/09 15:31:13 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/commons-lang-2.6.jar to classpath for i2pbote
2014/05/09 15:31:13 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/james-server-lifecycle-api-3.0-beta4.jar to classpath for i2pbote
2014/05/09 15:31:13 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/james-server-protocols-imap4-3.0-beta4.jar to classpath for i2pbote
2014/05/09 15:31:13 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/james-server-protocols-library-3.0-beta4.jar to classpath for i2pbote
2014/05/09 15:31:13 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/james-server-util-3.0-beta4.jar to classpath for i2pbote
2014/05/09 15:31:13 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/jutf7-1.0.0.jar to classpath for i2pbote
2014/05/09 15:31:13 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/netty-3.3.1.Final.jar to classpath for i2pbote
2014/05/09 15:31:13 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/protocols-api-1.6.2.jar to classpath for i2pbote
2014/05/09 15:31:13 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/protocols-netty-1.6.2.jar to classpath for i2pbote
2014/05/09 15:31:13 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/slf4j-api-1.6.1.jar to classpath for i2pbote
2014/05/09 15:31:13 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/slf4j-jcl-1.7.5.jar to classpath for i2pbote
2014/05/09 15:31:13 | Adding C:\ProgramData\Application Data\i2p\plugins\i2pbote/lib/subethasmtp-3.1.7.jar to classpath for i2pbote
2014/05/09 15:31:15 | Mai 09, 2014 1:31:15 PM com.subgraph.orchid.TorClient start
2014/05/09 15:31:15 | Information: Starting Orchid (version: 1.0.0)
2014/05/09 15:31:16 | Mai 09, 2014 1:31:16 PM com.subgraph.orchid.TorClient verifyUnlimitedStrengthPolicyInstalled
2014/05/09 15:31:16 | Schwerwiegend: Unlimited Strength Jurisdiction Policy Files are required but not installed.
2014/05/09 15:31:26 | SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder".
2014/05/09 15:31:26 | SLF4J: Defaulting to no-operation (NOP) logger implementation
2014/05/09 15:31:26 | SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details.
2014/05/09 15:31:29 | KRITISCH [chid Starter] outer.startup.RouterAppManager: Client outproxy START_FAILED 
2014/05/09 15:31:30 | SLF4J: Failed to load class "org.slf4j.impl.StaticMDCBinder".
2014/05/09 15:31:30 | SLF4J: Defaulting to no-operation MDCAdapter implementation.
2014/05/09 15:31:30 | SLF4J: See http://www.slf4j.org/codes.html#no_static_mdc_binder for further details.
2014/05/09 15:31:33 | 2014-05-09 13:31:33.900:INFO:oejs.Server:jetty-8.1.14.v20131031

Subtickets

Attachments (3)

hs_err_pid2368.log (25.6 KB) - added by user 5 years ago.
hs_err_pid3468.log (23.8 KB) - added by user 5 years ago.
hs_err_pid5564.log (23.6 KB) - added by user 5 years ago.

Download all attachments as: .zip

Change History (15)

comment:1 Changed 5 years ago by zzz

I2PBote NPE entered as separate ticket #1272

comment:2 Changed 5 years ago by zzz

Description: modified (diff)

comment:3 Changed 5 years ago by user

at that time it shutdown itself, without me requesting it.
also: i just needed quite a few tries to reconnect to trac and the forum.
i2psnark is down form constantly about 250KBps to about onlky 50KB, everything became slower. so fr no further self-sutdown. I'll keep an eye on it.

comment:4 Changed 5 years ago by zzz

Please attach the dump file C:\Program Files\i2p\hs_err_pid2368.log

NPE at line 3 of wrapper log will help fix #996

There's nothing obvious in -15 vs. -14 that would cause performance issues but I'll keep looking.

Please check local internet connection, local CPU load, etc. for any possible cause.

Changed 5 years ago by user

Attachment: hs_err_pid2368.log added

Changed 5 years ago by user

Attachment: hs_err_pid3468.log added

Changed 5 years ago by user

Attachment: hs_err_pid5564.log added

comment:5 Changed 5 years ago by user

a router restart temporarily improved the situation

comment:6 Changed 5 years ago by zzz

The JVM crashes are in systray, see #756 which we thought was fixed. Comment 7 contains a workaround.

comment:7 Changed 5 years ago by user

some other odd messages I found while going through the logs:

11.05.14 12:50:38 ERROR [cheduler 4/4] i2p.client.I2PSessionMuxedImpl: Message NOT removed!  id=30009794: [MessagePayloadMessage: 
	SessionId: 49207
	MessageId: 30009794
	Payload: [Payload: 5370 bytes]]
11.05.14 12:50:38 ERROR [cheduler 4/4] i2p.client.I2PSessionMuxedImpl: Message NOT removed!  id=30009681: [MessagePayloadMessage: 
	SessionId: 49207
	MessageId: 30009681
	Payload: [Payload: 5364 bytes]]
11.05.14 12:50:38 ERROR [cheduler 4/4] i2p.client.I2PSessionMuxedImpl: Message NOT removed!  id=30009701: [MessagePayloadMessage: 
	SessionId: 49207
	MessageId: 30009701
	Payload: [Payload: 6140 bytes]]
11.05.14 12:50:38 ERROR [cheduler 4/4] i2p.client.I2PSessionMuxedImpl: Message NOT removed!  id=30009751: [MessagePayloadMessage: 
	SessionId: 49207
	MessageId: 30009751
	Payload: [Payload: 501 bytes]]
11.05.14 12:50:39 ERROR [ms #49207]: ] i2p.client.I2PSessionMuxedImpl: Receive message 30009629 had no matches
11.05.14 12:50:39 ERROR [ms #49207]: ] i2p.client.I2PSessionMuxedImpl: Error: message 30009629 already received!
11.05.14 12:50:39 ERROR [ms #49207]: ] i2p.client.I2PSessionMuxedImpl: Error notifying app of message availability
java.lang.NullPointerException
	at java.io.ByteArrayInputStream.<init>(Unknown Source)
	at net.i2p.client.datagram.I2PDatagramDissector.loadI2PDatagram(I2PDatagramDissector.java:64)
	at net.i2p.sam.SAMDatagramSession.messageReceived(SAMDatagramSession.java:99)
	at net.i2p.sam.SAMMessageSession$SAMMessageSessionHandler.messageAvailable(SAMMessageSession.java:242)
	at net.i2p.client.I2PSessionDemultiplexer$NoPortsListener.messageAvailable(I2PSessionDemultiplexer.java:130)
	at net.i2p.client.I2PSessionDemultiplexer.messageAvailable(I2PSessionDemultiplexer.java:39)
	at net.i2p.client.I2PSessionMuxedImpl$MuxedAvailabilityNotifier.run(I2PSessionMuxedImpl.java:352)
	at java.lang.Thread.run(Unknown Source)
	at net.i2p.util.I2PThread.run(I2PThread.java:84)
11.05.14 12:51:39 ERROR [cheduler 3/4] i2p.client.I2PSessionMuxedImpl: Message NOT removed!  id=30010420: [MessagePayloadMessage: 
	SessionId: 49207
	MessageId: 30010420
	Payload: [Payload: 4979 bytes]]
11.05.14 12:51:39 ERROR [cheduler 3/4] i2p.client.I2PSessionMuxedImpl: Message NOT removed!  id=30010479: [MessagePayloadMessage: 
	SessionId: 49207
	MessageId: 30010479
	Payload: [Payload: 501 bytes]]
11.05.14 12:51:39 ERROR [cheduler 3/4] i2p.client.I2PSessionMuxedImpl: Message NOT removed!  id=30010464: [MessagePayloadMessage: 
	SessionId: 49207
	MessageId: 30010464
	Payload: [Payload: 4970 bytes]]
11.05.14 12:51:39 ERROR [cheduler 3/4] i2p.client.I2PSessionMuxedImpl: Message NOT removed!  id=30010442: [MessagePayloadMessage: 
	SessionId: 49207
	MessageId: 30010442
	Payload: [Payload: 4973 bytes]]
11.05.14 12:51:39 ERROR [cheduler 3/4] i2p.client.I2PSessionMuxedImpl: Message NOT removed!  id=30010409: [MessagePayloadMessage: 
	SessionId: 49207
	MessageId: 30010409
	Payload: [Payload: 905 bytes]]
....

tons of those and tons of the others, alternating

and:

11.05.14 17:32:53 ^^^ 23 similar messages omitted ^^^
11.05.14 17:33:29 ^^^ 20 similar messages omitted ^^^
11.05.14 17:34:01 ^^^ 74 similar messages omitted ^^^
11.05.14 17:34:24 ^^^ 80 similar messages omitted ^^^
11.05.14 17:34:50 ^^^ 59 similar messages omitted ^^^
11.05.14 17:35:00 ERROR [I2PSendQueue] i2p.bote.network.I2PSendQueue : Can't send packet.
net.i2p.client.I2PSessionException: Timed out waiting while write queue was full
	at net.i2p.client.I2PSessionImpl.sendMessage(I2PSessionImpl.java:806)
	at net.i2p.client.I2CPMessageProducer.sendMessage(I2CPMessageProducer.java:161)
	at net.i2p.client.I2PSessionImpl2.sendNoEffort(I2PSessionImpl2.java:424)
	at net.i2p.client.I2PSessionMuxedImpl.sendMessage(I2PSessionMuxedImpl.java:212)
	at net.i2p.client.I2PSessionMuxedImpl.sendMessage(I2PSessionMuxedImpl.java:175)
	at net.i2p.client.I2PSessionMuxedImpl.sendMessage(I2PSessionMuxedImpl.java:134)
	at i2p.bote.network.I2PSendQueue.sendDatagram(I2PSendQueue.java:250)
	at i2p.bote.network.I2PSendQueue.send(I2PSendQueue.java:233)
	at i2p.bote.network.I2PSendQueue.run(I2PSendQueue.java:195)
11.05.14 18:09:08 ERROR [al Reader 12] te.network.I2PPacketDispatcher: Router says: Error sending the signed leaseSet
net.i2p.client.I2PSessionException: Timed out waiting while write queue was full
	at net.i2p.client.I2PSessionImpl.sendMessage(I2PSessionImpl.java:806)
	at net.i2p.client.I2CPMessageProducer.createLeaseSet(I2CPMessageProducer.java:356)
	at net.i2p.client.RequestLeaseSetMessageHandler.signLeaseSet(RequestLeaseSetMessageHandler.java:120)
	at net.i2p.client.RequestVariableLeaseSetMessageHandler.handleMessage(RequestVariableLeaseSetMessageHandler.java:39)
	at net.i2p.client.I2PSessionImpl.messageReceived(I2PSessionImpl.java:733)
	at net.i2p.internal.QueuedI2CPMessageReader$QueuedI2CPMessageReaderRunner.run(QueuedI2CPMessageReader.java:56)
	at java.lang.Thread.run(Unknown Source)
	at net.i2p.util.I2PThread.run(I2PThread.java:84)

comment:8 Changed 5 years ago by user

the {{{
ERROR [cheduler 4/4] i2p.client.I2PSessionMuxedImpl: Message NOT removed!
}}}
comes in all variants cheduler ¼, 4, ¾, 4/4

[11.05.14 22:32:23 ERROR [ms #49207]: ] i2p.client.I2PSessionMuxedImpl: Receive message 30232148 had no matches
11.05.14 22:32:23 ERROR [ms #49207]: ] i2p.client.I2PSessionMuxedImpl: Error: message 30232148 already received!
11.05.14 22:32:23 ERROR [ms #49207]: ] i2p.client.I2PSessionMuxedImpl: Error notifying app of message availability
java.lang.NullPointerException
	at java.io.ByteArrayInputStream.<init>(Unknown Source)
	at net.i2p.client.datagram.I2PDatagramDissector.loadI2PDatagram(I2PDatagramDissector.java:64)
	at net.i2p.sam.SAMDatagramSession.messageReceived(SAMDatagramSession.java:99)
	at net.i2p.sam.SAMMessageSession$SAMMessageSessionHandler.messageAvailable(SAMMessageSession.java:242)
	at net.i2p.client.I2PSessionDemultiplexer$NoPortsListener.messageAvailable(I2PSessionDemultiplexer.java:130)
	at net.i2p.client.I2PSessionDemultiplexer.messageAvailable(I2PSessionDemultiplexer.java:39)
	at net.i2p.client.I2PSessionMuxedImpl$MuxedAvailabilityNotifier.run(I2PSessionMuxedImpl.java:352)
	at java.lang.Thread.run(Unknown Source)
	at net.i2p.util.I2PThread.run(I2PThread.java:84)

actually almost the entire log is full of that second message

comment:9 Changed 5 years ago by zzz

SAM NPE in comments 7 and 8 above copied to new ticket #1275

Last edited 5 years ago by zzz (previous) (diff)

comment:10 Changed 5 years ago by zzz

The "message not removed" errors in comment 7 above are symptoms of either: 1) massive router or CPU overload; or 2) some critical handler in the router crashed and it isn't handling messages at all any more.

I see no symptoms of 2) in what you've posted. Please look back in the logs, before all the "message not removed" errors, for any different type of error that may have triggered all the errors that follow.

In addition, the NPE in comment 7 and 8 above, while fixed in 0.9.12-18-rc (ticket #1275), could only happen on a hopelessly overloaded router.

It appears you have a lot running - at a minimum, bote, and a SAM app, and BOB (and a BOB app?), and you're starting Orchid but it fails due to a lack of unlimited policy files. Perhaps stop your clients one at a time and see if that will clear the congestion, and identify the culprit?

That's also why I ask about "local" issues in comment 4 above - any other processes hogging the CPU, etc.

It also isn't clear if the logs in comments 7 and 8 above were before or after the restart you mentioned in comment 5. Has the probelem recurred or not?

comment:11 Changed 5 years ago by user

so far everything looks good.
am on -19 now and increased tunnel count for i2psnark.
I had no bob app running, but was playing around with I2Phex and Nachtblitz lately.
Can't tell you the exact times though.
Right now, only Bote, Sam, Bob, and i2psnark. and the failing orchid. will look into the unlimited powers….

7,8 were pre coment5 restart.
the "temporarily" was re performance. Guess it has to do with con lims at the gateways, when using too many torrents and up to 2000 dht peers on too few snark tunnels. With upgrade to -19 I also upped snark's tunnel count from 3 to 5 and so far it looks better.

comment:12 Changed 5 years ago by zzz

Resolution: not a bug
Status: newclosed

OK. So 5 days later we discover that your router is actually heavily loaded with snark torrents, and that -15 may not be worse than -14. I do recommend 5-6 tunnels for snark with a huge amount of torrents or bandwidth.

Anyway, jumbled into all this was at least 5 other unrelated issues:

#756
#996
#1201
#1272
#1275

And yes we should recover better from overload, or deal with it better. But as the original thesis of this ticket is incorrect, and the other issues have other tickets, I'm closing this one.

Note: See TracTickets for help on using tickets.