i2p jvm taking up 100% of cpu

[anonymous]

After i2p 0.7.13-0 was up for several hours without problems, I now noticed the i2p java process taking up 100% of the cpu. The number of participating tunnels was around the normal 200. Usually the cpu never exceeds 35% for 200 tunnels.

Unfortunately I shut the router down when I noticed the cpu usage, so I don't know whether the cpu usage would have gone down again. I'm also not quite sure for how long the cpu was at 100%, but it must have been a couple of minutes since the cpu fan came up.

Also, when i pressed the shutdown button, it said "Shutdown in 6m" instead of the usual "Shutdown in 11m".

The following clients were enabled (as configured on ​http://127.0.0.1:7657/configclients.jsp):

• Application tunnels: True
• Running webapps: addressbook, i2psnark, i2ptunnel, susidns, susimail
• No plugins were running

i2psnark was running, but all up- and downloads had been stopped several hours before (is there a way to terminate running webapps?).

$ java -version:
java version "1.6.0_0"
OpenJDK  Runtime Environment (build 1.6.0_0-b11)
OpenJDK Client VM (build 1.6.0_0-b11, mixed mode, sharing)

The log states 2 errors, but i don't know if they are related to the cpu usage.
Sorry about the vague bug report, next time it happens I'll try to find out more.

The error log is:

Please include this information in bug reports: 
I2P version: 0.7.13-0
 Java version: Sun Microsystems Inc. 1.6.0_0
 Platform: Linux i386 2.6.26-2-686
 Processor: Pentium IV (130 nm) (pentium4)
 Jbigi: Locally optimized native BigInteger library loaded from the library path
 Encoding: ANSI_X3.4-1968


[...]/.i2p/logs/log-router-0.txt

19:31:56.954 ERROR [acket pusher] ter.transport.udp.PacketPusher: SSU Output Queue Error
java.lang.IllegalStateException: Already written
	at net.i2p.data.i2np.I2NPMessageImpl.verifyUnwritten(I2NPMessageImpl.java:358)
	at net.i2p.data.i2np.GarlicMessage.writeMessageBody(GarlicMessage.java:59)
	at net.i2p.data.i2np.I2NPMessageImpl.toByteArray(I2NPMessageImpl.java:234)
	at net.i2p.router.transport.ntcp.NTCPConnection.bufferedPrepare(NTCPConnection.java:672)
	at net.i2p.router.transport.ntcp.NTCPConnection.send(NTCPConnection.java:287)
	at net.i2p.router.transport.ntcp.NTCPTransport.outboundMessageReady(NTCPTransport.java:188)
	at net.i2p.router.transport.TransportImpl.send(TransportImpl.java:358)
	at net.i2p.router.transport.GetBidsJob.getBids(GetBidsJob.java:80)
	at net.i2p.router.transport.CommSystemFacadeImpl.processMessage(CommSystemFacadeImpl.java:134)
	at net.i2p.router.OutNetMessagePool.add(OutNetMessagePool.java:61)
	at net.i2p.router.transport.TransportImpl.afterSend(TransportImpl.java:253)
	at net.i2p.router.transport.TransportImpl.afterSend(TransportImpl.java:164)
	at net.i2p.router.transport.udp.UDPTransport.failed(UDPTransport.java:1393)
	at net.i2p.router.transport.udp.PeerState.dropOutbound(PeerState.java:1142)
	at net.i2p.router.transport.udp.UDPTransport.dropPeer(UDPTransport.java:888)
	at net.i2p.router.transport.udp.UDPTransport.failed(UDPTransport.java:1384)
	at net.i2p.router.transport.udp.UDPTransport.failed(UDPTransport.java:1360)
	at net.i2p.router.transport.udp.PeerState.finishMessages(PeerState.java:1222)
	at net.i2p.router.transport.udp.OutboundMessageFragments.finishMessages(OutboundMessageFragments.java:222)
	at net.i2p.router.transport.udp.OutboundMessageFragments.getNextVolley(OutboundMessageFragments.java:246)
	at net.i2p.router.transport.udp.PacketPusher.run(PacketPusher.java:37)
	at java.lang.Thread.run(Thread.java:636)
	at net.i2p.util.I2PThread.run(I2PThread.java:77)
17:33:28.530 ERROR [NTCP read 0 ] t.i2p.router.OutNetMessagePool: Already expired!  wtf: [OutNetMessage contains a 50 byte net.i2p.data.i2np.TunnelGatewayMessage expiring on Tue May 04 17:33:20 GMT 2010 targetting 4TqVEQUSTjgkTw5z~~AAMSRFOAROACdHeESMapY2F3I= {timestamps: 
}]
java.lang.Exception: Expired message
	at net.i2p.router.OutNetMessagePool.validate(OutNetMessagePool.java:81)
	at net.i2p.router.OutNetMessagePool.add(OutNetMessagePool.java:44)
	at net.i2p.router.tunnel.OutboundMessageDistributor.distribute(OutboundMessageDistributor.java:71)
	at net.i2p.router.tunnel.OutboundMessageDistributor.distribute(OutboundMessageDistributor.java:43)
	at net.i2p.router.tunnel.OutboundTunnelEndpoint$DefragmentedHandler.receiveComplete(OutboundTunnelEndpoint.java:58)
	at net.i2p.router.tunnel.FragmentHandler.receiveComplete(FragmentHandler.java:489)
	at net.i2p.router.tunnel.FragmentHandler.receiveInitialFragment(FragmentHandler.java:400)
	at net.i2p.router.tunnel.FragmentHandler.receiveFragment(FragmentHandler.java:300)
	at net.i2p.router.tunnel.FragmentHandler.receiveTunnelMessage(FragmentHandler.java:159)
	at net.i2p.router.tunnel.OutboundTunnelEndpoint.dispatch(OutboundTunnelEndpoint.java:43)
	at net.i2p.router.tunnel.TunnelDispatcher.dispatch(TunnelDispatcher.java:361)
	at net.i2p.router.InNetMessagePool.doShortCircuitTunnelData(InNetMessagePool.java:309)
	at net.i2p.router.InNetMessagePool.shortCircuitTunnelData(InNetMessagePool.java:294)
	at net.i2p.router.InNetMessagePool.add(InNetMessagePool.java:162)
	at net.i2p.router.transport.TransportManager.messageReceived(TransportManager.java:468)
	at net.i2p.router.transport.TransportImpl.messageReceived(TransportImpl.java:417)
	at net.i2p.router.transport.ntcp.NTCPConnection$ReadState.receiveLastBlock(NTCPConnection.java:1253)
	at net.i2p.router.transport.ntcp.NTCPConnection$ReadState.receiveSubsequent(NTCPConnection.java:1212)
	at net.i2p.router.transport.ntcp.NTCPConnection$ReadState.receiveBlock(NTCPConnection.java:1169)
	at net.i2p.router.transport.ntcp.NTCPConnection.recvUnencryptedI2NP(NTCPConnection.java:1012)
	at net.i2p.router.transport.ntcp.NTCPConnection.recvEncryptedI2NP(NTCPConnection.java:995)
	at net.i2p.router.transport.ntcp.Reader.processRead(Reader.java:168)
	at net.i2p.router.transport.ntcp.Reader.access$400(Reader.java:17)
	at net.i2p.router.transport.ntcp.Reader$Runner.run(Reader.java:106)
	at java.lang.Thread.run(Thread.java:636)
	at net.i2p.util.I2PThread.run(I2PThread.java:77)
17:44:28.680 CRIT  [hutdown hook] net.i2p.router.Router         : Graceful shutdown progress - no more tunnels, safe to die
17:44:38.156 CRIT  [hutdown hook] net.i2p.router.Router         : Shutdown(2) complete
java.lang.Exception: Shutdown
	at net.i2p.router.Router.finalShutdown(Router.java:926)
	at net.i2p.router.Router.shutdown(Router.java:916)
	at net.i2p.router.Router$GracefulShutdown.run(Router.java:1020)
	at java.lang.Thread.run(Thread.java:636)
	at net.i2p.util.I2PThread.run(I2PThread.java:77)

[zzz]

Thanks for the detailed report.

Unfortunately the first error is a known issue unrelated to your problem, and the 2nd error is a symptom of the 100% CPU and not a cause.

So that leaves us with no clues at all. If it happens again, please take a thread dump.

[zzz]

Bug isolated by postman, patch delivered to him for testing in September, awaiting test report.

[zzz]

1st patch to postman didn't work, awaiting test report from postman on revised patch, reassigning to him for now

[zzz]

See also #551 - lots of changes in the 0.8.11-x cycle.

[zzz]

The patch referenced above was modified and checked in ~0.8.11-7. The OP of #551 reports no problems since -6. Haven't heard any info from postman in quite some time on this. Closing this ticket in a burst of optimism, see #551 for status, will hopefully close that one soon.

[zzz]

Not 100% fixed. Leaving this ticket closed. All future status will be tracked in ticket #551