] p.router.transport.ntcp.Writer: Error in the ntcp writer

[echelon]

20:19:42.421 CRIT [P writer 2/4] p.router.transport.ntcp.Writer: Error in the ntcp writer

java.lang.RuntimeException?: buf is null for contains *no message* expiring on Sat Jan 22 19:19:51 GMT 2011 failed delivery on transports [NTCP? targetting UudgZDDzFwNSuF0W7AML0x34ijSknCGXDq56AjlNUJg= {timestamps:
}]
at net.i2p.router.transport.ntcp.NTCPConnection.prepareNextWriteFast(NTCPConnection.java:631)
at net.i2p.router.transport.ntcp.NTCPConnection.prepareNextWrite(NTCPConnection.java:461)
at net.i2p.router.transport.ntcp.Writer$Runner.run(Writer.java:115)
at java.lang.Thread.run(Thread.java:619)
at net.i2p.util.I2PThread.run(I2PThread.java:77)

18:17:14.649 CRIT [P writer 2/4] p.router.transport.ntcp.Writer: Error in the ntcp writer

java.lang.RuntimeException?: buf is null for contains *no message* expiring on Sat Jan 22 17:17:24 GMT 2011 failed delivery on transports [NTCP? targetting UudgZDDzFwNSuF0W7AML0x34ijSknCGXDq56AjlNUJg= {timestamps:
}]
at net.i2p.router.transport.ntcp.NTCPConnection.prepareNextWriteFast(NTCPConnection.java:631)
at net.i2p.router.transport.ntcp.NTCPConnection.prepareNextWrite(NTCPConnection.java:461)
at net.i2p.router.transport.ntcp.Writer$Runner.run(Writer.java:115)
at java.lang.Thread.run(Thread.java:619)
at net.i2p.util.I2PThread.run(I2PThread.java:77)

21:48:03.151 CRIT [P writer 3/4] p.router.transport.ntcp.Writer: Error in the ntcp writer

java.lang.RuntimeException?: buf is null for contains *no message* expiring on Fri Jan 21 20:48:12 GMT 2011 failed delivery on transports [NTCP? targetting UudgZDDzFwNSuF0W7AML0x34ijSknCGXDq56AjlNUJg= {timestamps:
}]
at net.i2p.router.transport.ntcp.NTCPConnection.prepareNextWriteFast(NTCPConnection.java:631)
at net.i2p.router.transport.ntcp.NTCPConnection.prepareNextWrite(NTCPConnection.java:461)
at net.i2p.router.transport.ntcp.Writer$Runner.run(Writer.java:115)
at java.lang.Thread.run(Thread.java:619)
at net.i2p.util.I2PThread.run(I2PThread.java:77)

[sponge]

Seen same here...

CRIT [P writer 4/4] p.router.transport.ntcp.Writer: Error in the ntcp writer
java.lang.RuntimeException?: buf is null for [OutNetMessage? contains *no message* expiring on ...
}]

at net.i2p.router.transport.ntcp.NTCPConnection.prepareNextWriteFast(NTCPConnection.java:634)
at net.i2p.router.transport.ntcp.NTCPConnection.prepareNextWrite(NTCPConnection.java:464)
at net.i2p.router.transport.ntcp.Writer$Runner.run(Writer.java:115)
at java.lang.Thread.run(Unknown Source)
at net.i2p.util.I2PThread.run(I2PThread.java:77)

[slow]

Same error on 0.8.10-0.

some_time CRIT [P writer 2/4] p.router.transport.ntcp.Writer: Error in the ntcp writer
     java.lang.RuntimeException: buf is null for [OutNetMessage containing *no message* expiring on Sat Oct 22 03:23:32 GMT 2011 failed delivery on transports [NTCP] targetting abg-vXuZchSR16i-YQ11fFHVSedAwFxxsMTDgg6SA2M=]
     at net.i2p.router.transport.ntcp.NTCPConnection.prepareNextWriteFast(NTCPConnection.java:634)
     at net.i2p.router.transport.ntcp.NTCPConnection.prepareNextWrite(NTCPConnection.java:464)
     at net.i2p.router.transport.ntcp.Writer$Runner.run(Writer.java:115)
     at java.lang.Thread.run(Thread.java:619)
     at net.i2p.util.I2PThread.run(I2PThread.java:85)

[zzz]

There's some sort of race here. Since the toString is "no message" that means OutNetMessage?.discardData() has been called (from TransportImpl?.afterSend()), which means most likely it was sent on one transport then is being retried in the other.

The other possibility is a race with NTCPConnection.close(), which calls msg.releasePreparationBuffer(), which is not synchronized. Even if it were synchronized, close() calls afterSend() which nulls out the message.

Part of the problem also is the horrible fake priority queue scanning of _outbound just above line 634 which makes some of these races possible.

This definitely needs work. In the meantime changing the log from CRIT to WARN as it only affects the one message. Also changing the version back to 0.8.2 as reported by the OP.

Also changing to minor as it's just one message and very rare.

[zzz]

Milestone 0.8.14 deleted

[str4d]

Related: #565 (failing on both SSU and NTCP)