I2CP Congestion Control

[guest]

I2P version: 0.9.3-0
Java version: Oracle Corporation 1.7.0_09 (OpenJDK Runtime Environment 1.7.0_09-b30)
Wrapper version: 3.1.1
Server version: 6.1.26
Servlet version: Jasper JSP 2.1 Engine
Platform: Linux amd64 3.5.0-17-generic
Processor: Phenom II / Opteron Gen 3 (Shanghai/Deneb/Heka/Callisto?, 45 nm) (athlon64)
Jbigi: Locally optimized native BigInteger? library loaded from file
Encoding: UTF-8
Charset: UTF-8

running 0.9.3 for some hours. now these two error messages popup in the log several times and participating tunnels dropped from >1000 to about 200 now:

[P reader 2/4] uter.client.MessageReceivedJob: Error writing out the message status message
     net.i2p.data.i2cp.I2CPMessageException: I2CP write to queue failed
     at net.i2p.router.client.QueuedClientConnectionRunner.doSend(QueuedClientConnectionRunner.java:71)
     at net.i2p.router.client.MessageReceivedJob.messageAvailable(MessageReceivedJob.java:66)
     at net.i2p.router.client.MessageReceivedJob.runJob(MessageReceivedJob.java:44)
     at net.i2p.router.client.ClientConnectionRunner.receiveMessage(ClientConnectionRunner.java:394)
     at net.i2p.router.client.ClientManager$HandleJob.runJob(ClientManager.java:495)
     at net.i2p.router.client.ClientManager.messageReceived(ClientManager.java:472)
     at net.i2p.router.client.ClientManagerFacadeImpl.messageReceived(ClientManagerFacadeImpl.java:188)
     at net.i2p.router.tunnel.InboundMessageDistributor.handleClove(InboundMessageDistributor.java:233)
     at net.i2p.router.message.GarlicMessageReceiver.handleClove(GarlicMessageReceiver.java:106)
     at net.i2p.router.message.GarlicMessageReceiver.receive(GarlicMessageReceiver.java:81)
     at net.i2p.router.tunnel.InboundMessageDistributor.distribute(InboundMessageDistributor.java:105)
     at net.i2p.router.tunnel.TunnelParticipant$DefragmentedHandler.receiveComplete(TunnelParticipant.java:179)
     at net.i2p.router.tunnel.FragmentHandler.receiveComplete(FragmentHandler.java:487)
     at net.i2p.router.tunnel.FragmentHandler.receiveSubsequentFragment(FragmentHandler.java:442)
     at net.i2p.router.tunnel.FragmentHandler.receiveFragment(FragmentHandler.java:295)
     at net.i2p.router.tunnel.FragmentHandler.receiveTunnelMessage(FragmentHandler.java:150)
     at net.i2p.router.tunnel.TunnelParticipant.dispatch(TunnelParticipant.java:128)
     at net.i2p.router.tunnel.TunnelDispatcher.dispatch(TunnelDispatcher.java:439)
     at net.i2p.router.InNetMessagePool.doShortCircuitTunnelData(InNetMessagePool.java:321)
     at net.i2p.router.InNetMessagePool.shortCircuitTunnelData(InNetMessagePool.java:306)
     at net.i2p.router.InNetMessagePool.add(InNetMessagePool.java:174)
     at net.i2p.router.transport.TransportManager.messageReceived(TransportManager.java:467)
     at net.i2p.router.transport.TransportImpl.messageReceived(TransportImpl.java:446)
     at net.i2p.router.transport.ntcp.NTCPConnection$ReadState.receiveLastBlock(NTCPConnection.java:1442)
     at net.i2p.router.transport.ntcp.NTCPConnection$ReadState.receiveSubsequent(NTCPConnection.java:1400)
     at net.i2p.router.transport.ntcp.NTCPConnection$ReadState.receiveBlock(NTCPConnection.java:1350)
     at net.i2p.router.transport.ntcp.NTCPConnection.recvUnencryptedI2NP(NTCPConnection.java:1157)
     at net.i2p.router.transport.ntcp.NTCPConnection.recvEncryptedFast(NTCPConnection.java:1139)
     at net.i2p.router.transport.ntcp.NTCPConnection.recvEncryptedI2NP(NTCPConnection.java:1070)
     at net.i2p.router.transport.ntcp.Reader.processRead(Reader.java:182)
     at net.i2p.router.transport.ntcp.Reader.access$400(Reader.java:21)
     at net.i2p.router.transport.ntcp.Reader$Runner.run(Reader.java:118)
     at java.lang.Thread.run(Thread.java:722)
     at net.i2p.util.I2PThread.run(I2PThread.java:85)



[nal Reader 3] ent.ClientMessageEventListener: Error delivering the payload
     net.i2p.data.i2cp.I2CPMessageException: I2CP write to queue failed
     at net.i2p.router.client.QueuedClientConnectionRunner.doSend(QueuedClientConnectionRunner.java:71)
     at net.i2p.router.client.ClientMessageEventListener.handleReceiveBegin(ClientMessageEventListener.java:254)
     at net.i2p.router.client.ClientMessageEventListener.messageReceived(ClientMessageEventListener.java:88)
     at net.i2p.internal.QueuedI2CPMessageReader$QueuedI2CPMessageReaderRunner.run(QueuedI2CPMessageReader.java:56)
     at java.lang.Thread.run(Thread.java:722)
     at net.i2p.util.I2PThread.run(I2PThread.java:85)

[zzz]

Excellent. As part of the whole bufferbloat project I put limits on the I2CP queue sizes. Some destination on your router must have been very busy.

I'd completely forgotten about this change. I'll take another look at the limits and probably change the error to a warning. And maybe change the queues to codel w/ priority.

Nothing to worry about, and not a direct cause of your participating tunnel count dropping - although the high local traffic would cause participating tunnels to drop.

Thanks for the report. Great to see that a new limit kicked in for somebody.

[zzz]

Log as a warn instead of throwing exception in 0.9.3-3.

Leaving open as I'm considering switching these queues to CoDelPriorityBlockingQueue?.

[zab]

I would be curious to find out why the destination was very busy. Also, was the destination over NTCP or SSU? This may be a symptom of another problem (starvation, deadlock, $UNKNOWN).

I'm trying to think what would be a good way to diagnose this. A thread & heap dumps would be ideal if we can catch them the moment the queue overfills. I'll open a separate ticket with some related ideas.

[guest]

Well, the only thing I can add is that my router is always quite busy (especially since 0.9.2) at about 700-1000kb/s upload. And I'm seeding a lot of torrents, so it's half i2psnark and half participating.
But it never shows any delayed tasks and message delay is about 100-400ms.

[zzz]

@zab you're conflating local destinations and transports. The queue that overflowed was in I2CP, unrelated to transport (NTCP/SSU) queues.

I'm not happy with my simple fix in -3 as it will leak resources. I'm going to redo it for -4 and plug more leaks along the way.

Also in -4 I'm going to implement a change to reduce the number of I2CP messages which will keep that queue from filling up so quickly.

Snark does have some issues with holding locks for a long time during checking operations. There's also timer congestion/blocking issues in streaming and in the I2CP bandwidth throttler. Any of these could cause snark to fall behind.

[zzz]

Improved fix in 0.9.3-4, throw exception so resources can be reclaimed, but log as WARN where caught.

[guest]

btw.: thanks for the great work!

[zzz]

0.9.3-5 contains additional fixes for dropped leaseset requests over i2cp.

Leaving this ticket open to fully review I2CP for correct handling of dropped messages and ensuring no resource leaks. Right now there's no cleaner one map on the router side but I worked around it by implementing 'fast receive' so we don't use that map.

I also have priorities and codel all coded up but probably won't check it in anytime soon. Part of the problem is a blocking put() on the client side that we lose if we go to PBQ.

Some issues are also different for in-JVM and external clients.

The whole issue of congestion control and anti-bufferbloat in I2CP needs some attention.

The immediate issue in the OP should be addressed, so renaming the ticket and pushing out a release, for further study.

[zzz]

declaring fixed, as much as we are going to.