Opened 9 years ago

Closed 9 years ago

#349 closed defect (invalid)

Random tunnel collapse due to possible plugin problem. (i2p-bote/streaming)

Reported by: sponge Owned by: sponge
Priority: minor Milestone: 0.8.5
Component: streaming Version: 0.8.1
Keywords: Cc:
Parent Tickets: Sensitive: no

Description

I2P version: 0.8.1-18
Java version: Sun Microsystems Inc. 1.6.0_18 (Java(TM) SE Runtime Environment 1.6.0_18-b07)
Platform: Linux amd64 2.6.36
Processor: uninitialized (athlon64)
Jbigi: Locally optimized native BigInteger library loaded from the library path
Encoding: UTF-8

After starting i2p-bote, and running it for a while, I tripped up a really neat bug, apparently.

My irc tunnel collapsed, though, so it's like a WTF? error :-)

Is it just that bote is eating to many resources??!!

The reason really is not all that clear but does point at streaming lib, so filed under streaming.

I'm not sure if it's really i2p-bote, streaming, or what.

My IP address has not changed, etc…

Will shut down bote and see if irc recovers.

Wrapper.log
INFO   | jvm 3    | 2010/12/07 02:05:47 | java.io.IOException: Inactivity timeout
INFO   | jvm 3    | 2010/12/07 02:05:47 |       at net.i2p.client.streaming.Connection$ActivityTimer.timeReached(Connection.java:944)
INFO   | jvm 3    | 2010/12/07 02:05:47 |       at net.i2p.util.SimpleTimer2$TimedEvent.run(SimpleTimer2.java:220)
INFO   | jvm 3    | 2010/12/07 02:05:47 |       at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)
INFO   | jvm 3    | 2010/12/07 02:05:47 |       at java.util.concurrent.FutureTask$Sync.innerRun(Unknown Source)
INFO   | jvm 3    | 2010/12/07 02:05:47 |       at java.util.concurrent.FutureTask.run(Unknown Source)
INFO   | jvm 3    | 2010/12/07 02:05:47 |       at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(Unknown Source)
INFO   | jvm 3    | 2010/12/07 02:05:47 |       at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source)
INFO   | jvm 3    | 2010/12/07 02:05:47 |       at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
INFO   | jvm 3    | 2010/12/07 02:05:47 |       at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
INFO   | jvm 3    | 2010/12/07 02:05:47 |       at java.lang.Thread.run(Unknown Source)

and

log-router
# 02:16:29.822 ERROR [ntBuilder2.4] p.i2ptunnel.I2PTunnelIRCClient: Error connecting
     java.net.NoRouteToHostException: Connection timed out
     at net.i2p.client.streaming.I2PSocketManagerFull.connect(I2PSocketManagerFull.java:214)
     at net.i2p.i2ptunnel.I2PTunnelClientBase.createI2PSocket(I2PTunnelClientBase.java:524)
     at net.i2p.i2ptunnel.I2PTunnelClientBase.createI2PSocket(I2PTunnelClientBase.java:503)
     at net.i2p.i2ptunnel.I2PTunnelIRCClient.clientConnectionRun(I2PTunnelIRCClient.java:91)
     at net.i2p.i2ptunnel.I2PTunnelClientBase$TunnelConnectionBuilder.run(I2PTunnelClientBase.java:724)
     at java.lang.Thread.run(Unknown Source)
     at net.i2p.util.I2PThread.run(I2PThread.java:77)
# 02:15:19.766 ERROR [ntBuilder2.4] p.i2ptunnel.I2PTunnelIRCClient: Error connecting
     java.net.NoRouteToHostException: Connection timed out
     at net.i2p.client.streaming.I2PSocketManagerFull.connect(I2PSocketManagerFull.java:214)
     at net.i2p.i2ptunnel.I2PTunnelClientBase.createI2PSocket(I2PTunnelClientBase.java:524)
     at net.i2p.i2ptunnel.I2PTunnelClientBase.createI2PSocket(I2PTunnelClientBase.java:503)
     at net.i2p.i2ptunnel.I2PTunnelIRCClient.clientConnectionRun(I2PTunnelIRCClient.java:91)
     at net.i2p.i2ptunnel.I2PTunnelClientBase$TunnelConnectionBuilder.run(I2PTunnelClientBase.java:724)
     at java.lang.Thread.run(Unknown Source)
     at net.i2p.util.I2PThread.run(I2PThread.java:77)
# 02:14:09.759 ERROR [ntBuilder2.4] p.i2ptunnel.I2PTunnelIRCClient: Error connecting
     java.net.NoRouteToHostException: Connection timed out
     at net.i2p.client.streaming.I2PSocketManagerFull.connect(I2PSocketManagerFull.java:214)
     at net.i2p.i2ptunnel.I2PTunnelClientBase.createI2PSocket(I2PTunnelClientBase.java:524)
     at net.i2p.i2ptunnel.I2PTunnelClientBase.createI2PSocket(I2PTunnelClientBase.java:503)
     at net.i2p.i2ptunnel.I2PTunnelIRCClient.clientConnectionRun(I2PTunnelIRCClient.java:91)
     at net.i2p.i2ptunnel.I2PTunnelClientBase$TunnelConnectionBuilder.run(I2PTunnelClientBase.java:724)
     at java.lang.Thread.run(Unknown Source)
     at net.i2p.util.I2PThread.run(I2PThread.java:77)
# 02:12:59.752 ERROR [ntBuilder2.4] p.i2ptunnel.I2PTunnelIRCClient: Error connecting
     java.net.NoRouteToHostException: Connection timed out
     at net.i2p.client.streaming.I2PSocketManagerFull.connect(I2PSocketManagerFull.java:214)
     at net.i2p.i2ptunnel.I2PTunnelClientBase.createI2PSocket(I2PTunnelClientBase.java:524)
     at net.i2p.i2ptunnel.I2PTunnelClientBase.createI2PSocket(I2PTunnelClientBase.java:503)
     at net.i2p.i2ptunnel.I2PTunnelIRCClient.clientConnectionRun(I2PTunnelIRCClient.java:91)
     at net.i2p.i2ptunnel.I2PTunnelClientBase$TunnelConnectionBuilder.run(I2PTunnelClientBase.java:724)
     at java.lang.Thread.run(Unknown Source)
     at net.i2p.util.I2PThread.run(I2PThread.java:77)
# 02:11:49.745 ERROR [ntBuilder2.4] p.i2ptunnel.I2PTunnelIRCClient: Error connecting
     java.net.NoRouteToHostException: Connection timed out
     at net.i2p.client.streaming.I2PSocketManagerFull.connect(I2PSocketManagerFull.java:214)
     at net.i2p.i2ptunnel.I2PTunnelClientBase.createI2PSocket(I2PTunnelClientBase.java:524)
     at net.i2p.i2ptunnel.I2PTunnelClientBase.createI2PSocket(I2PTunnelClientBase.java:503)
     at net.i2p.i2ptunnel.I2PTunnelIRCClient.clientConnectionRun(I2PTunnelIRCClient.java:91)
     at net.i2p.i2ptunnel.I2PTunnelClientBase$TunnelConnectionBuilder.run(I2PTunnelClientBase.java:724)
     at java.lang.Thread.run(Unknown Source)
     at net.i2p.util.I2PThread.run(I2PThread.java:77)

and…

Job lag:	0
Message delay:	1891 ms
Tunnel lag:	926 ms
Backlog:	0
Rejecting tunnels: High message delay

Subtickets

Attachments (5)

router.memoryUsed.png (2.5 KB) - added by sponge 9 years ago.
stream.trend.png (2.7 KB) - added by sponge 9 years ago.
tunnel.participatingTunnels.png (2.7 KB) - added by sponge 9 years ago.
tunnel.participatingBandwidth.png (2.8 KB) - added by sponge 9 years ago.
somehours.gif (72.5 KB) - added by sponge 9 years ago.

Download all attachments as: .zip

Change History (13)

comment:1 Changed 9 years ago by sponge

IRC came back, did not shut down bote yet… still confused.

Changed 9 years ago by sponge

Attachment: router.memoryUsed.png added

Changed 9 years ago by sponge

Attachment: stream.trend.png added

Changed 9 years ago by sponge

Changed 9 years ago by sponge

Changed 9 years ago by sponge

Attachment: somehours.gif added

comment:2 Changed 9 years ago by sponge

If you know the cause, and it's not bote, perhaps there needs to be better reporting?

comment:3 Changed 9 years ago by sponge

Owner: set to zzz
Status: newassigned

comment:4 Changed 9 years ago by sponge

And now another interesting message…

02:48:51.720 CRIT [acket pusher] ter.transport.udp.PacketPusher: SSU Output Queue Error
     java.lang.IllegalStateException: Already written
     at net.i2p.data.i2np.I2NPMessageImpl.verifyUnwritten(I2NPMessageImpl.java:360)
     at net.i2p.data.i2np.GarlicMessage.writeMessageBody(GarlicMessage.java:58)
     at net.i2p.data.i2np.I2NPMessageImpl.toByteArray(I2NPMessageImpl.java:236)
     at net.i2p.router.transport.ntcp.NTCPConnection.bufferedPrepare(NTCPConnection.java:675)
     at net.i2p.router.transport.ntcp.NTCPConnection.send(NTCPConnection.java:290)
     at net.i2p.router.transport.ntcp.NTCPTransport.outboundMessageReady(NTCPTransport.java:208)
     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:1398)
     at net.i2p.router.transport.udp.UDPTransport.failed(UDPTransport.java:1365)
     at net.i2p.router.transport.udp.PeerState.finishMessages(PeerState.java:1212)
     at net.i2p.router.transport.udp.OutboundMessageFragments.finishMessages(OutboundMessageFragments.java:223)
     at net.i2p.router.transport.udp.OutboundMessageFragments.getNextVolley(OutboundMessageFragments.java:245)
     at net.i2p.router.transport.udp.PacketPusher.run(PacketPusher.java:37)
     at java.lang.Thread.run(Unknown Source)
     at net.i2p.util.I2PThread.run(I2PThread.java:77)

comment:5 Changed 9 years ago by zzz

Milestone: 0.8.3
Priority: criticalminor

I really don't understand what's going on here. But as things seemed to recover, I'm changing priority from critical to minor.

You have anything in the router logs from 2:05:47, corresponding with the wrapper log entry? This seems to be the most interesting, and also seems to be unrelated to the router logs at 2:11 - 2:16. I don't see how this made it to the wrapper log as a CRIT. Some exception needs to be caught somewhere, and it wasn't.

Those router log errors at 2:11 - 2:16 appear to be a simple failure to connect to the IRC server. Whether they should be errors in the log? Maybe not.

The SSU Output Queue Error is unrelated and should be fixed in 0.8.1-22.

comment:6 Changed 9 years ago by zzz

Milestone: 0.8.30.8.5
Owner: changed from zzz to sponge

no response from sponge, reassigning to him.

comment:7 Changed 9 years ago by sponge

Not sure what happened either, that's why the logs. Router has been quiet and nice lately other than the irc client complaints in the router log. Nothing in critical after 2 weeks uptime, but then I have had bote off…

comment:8 Changed 9 years ago by sponge

Resolution: invalid
Status: assignedclosed

i2p-Bote was indeed the issue.

Note: See TracTickets for help on using tickets.