Opened 6 years ago

Closed 2 years ago

#996 closed defect (fixed)

java.lang.NullPointerException: invalid args to aes

Reported by: tyro Owned by: zzz
Priority: major Milestone: 0.9.29
Component: router/transport Version: 0.9.7
Keywords: Cc: zab@…
Parent Tickets:

Description

I2P version: 0.9.7-16
Java version: Oracle Corporation 1.8.0-ea (Java(TM) SE Runtime Environment 1.8.0-ea-b100)
Wrapper version: 3.5.17
Server version: 7.6.11.v20130520
Servlet version: Jasper JSP 2.1 Engine
Platform: Linux arm 3.6.11+
Processor: uninitialized (arm)
Jbigi: Locally optimized native BigInteger? library loaded from file
Encoding: UTF-8
Charset: UTF-8

Using latest JVM (ARM preview for Pi).

02/08/13 07:58:40 CRIT [P writer 4/4] p.router.transport.ntcp.Writer: Error in the ntcp writer

java.lang.NullPointerException?: invalid args to aes
at net.i2p.crypto.CryptixAESEngine.encrypt(CryptixAESEngine.java:86)
at net.i2p.router.transport.ntcp.NTCPConnection.sendMeta(NTCPConnection.java:1294)
at net.i2p.router.transport.ntcp.NTCPConnection.prepareNextWriteFast(NTCPConnection.java:699)
at net.i2p.router.transport.ntcp.NTCPConnection.prepareNextWrite(NTCPConnection.java:578)
at net.i2p.router.transport.ntcp.Writer$Runner.run(Writer.java:122)
at java.lang.Thread.run(Thread.java:724)
at net.i2p.util.I2PThread.run(I2PThread.java:85)

Subtickets

Change History (23)

comment:1 Changed 6 years ago by zzz

  • Component changed from unspecified to router/transport
  • Owner set to zab
  • Priority changed from minor to major
  • Status changed from new to assigned

Hmm. Haven't seen this before. Could be the RPi ARM Java chaos monkey...

_meta and encrypted can't be null, so that leaves _sessionKey and _prevWriteEnd.

Those are set in synchronized methods finishInboundEstablishment() and finishOutboundEstablishment(). Perhaps block in sendMeta() should be synched on this instead of _meta? Or both? But I don't think sendMeta() could be called before finishXXXEstablishment() is called? So maybe could be fixed by volatile or synch.

Or is it somehow related to VerifiedEstablishState????

Hoping zab can continue the chase from here.

comment:2 Changed 6 years ago by zab

NTCPConnection.prepareNextWrite(..) is already synchronized on NTCPConnection. The only way this stack trace is possible is if finish{Inbound,Outbound}Establishment is not yet called. Or there is indeed something wrong with the ARM jvm.

comment:3 Changed 6 years ago by zab

  • Cc zab@… added

comment:4 Changed 6 years ago by guest

  • Resolution set to worksforme
  • Status changed from assigned to closed

comment:5 Changed 6 years ago by str4d

  • Resolution worksforme deleted
  • Status changed from closed to reopened

comment:6 Changed 6 years ago by guest

  • Resolution set to not a bug
  • Status changed from reopened to closed

comment:7 Changed 6 years ago by str4d

  • Resolution not a bug deleted
  • Status changed from closed to reopened

comment:8 Changed 6 years ago by zzz

  • Milestone 0.9.8 deleted
  • Resolution set to worksforme
  • Status changed from reopened to closed

assuming a JVM issue

comment:9 Changed 6 years ago by killyourtv

FWIW, I've also (finally) gotten this.

I2P version: 0.9.8.1-0
Java version: Oracle Corporation 1.8.0-ea (Java(TM) SE Runtime Environment 1.8.0-ea-b109)
Wrapper version: 3.5.20
Server version: 7.6.12.v20130726
Servlet version: Jasper JSP 2.1 Engine
Platform: Linux arm 3.6.11+
Processor: uninitialized (arm)
Jbigi: Locally optimized native BigInteger library loaded from file
Encoding: UTF-8
Charset: UTF-8
23/10/13 15:07:44 CRIT [P writer 1/4] p.router.transport.ntcp.Writer: Error in the ntcp writer
     java.lang.NullPointerException: invalid args to aes
     at net.i2p.crypto.CryptixAESEngine.encrypt(CryptixAESEngine.java:86)
     at net.i2p.router.transport.ntcp.NTCPConnection.sendMeta(NTCPConnection.java:1321)
     at net.i2p.router.transport.ntcp.NTCPConnection.prepareNextWriteFast(NTCPConnection.java:728)
     at net.i2p.router.transport.ntcp.NTCPConnection.prepareNextWrite(NTCPConnection.java:607)
     at net.i2p.router.transport.ntcp.Writer$Runner.run(Writer.java:122)
     at java.lang.Thread.run(Thread.java:724)
     at net.i2p.util.I2PThread.run(I2PThread.java:85)

Raspberry Pi, Model B w/ 512 MB of RAM

comment:10 Changed 6 years ago by zzz

  • Resolution worksforme deleted
  • Status changed from closed to reopened

Also on RPI. hmm.

Reopening, worth another look.

comment:11 Changed 6 years ago by killyourtv

That error was logged once more on the 3rd with an identical traceback. At this point that RaPI router has been up for ~27 days.

comment:12 Changed 5 years ago by zzz

Again reported in #1225, again on RPi.

comment:13 Changed 5 years ago by zzz

Tweaked the logging in 0.9.12-5 to help get to the bottom of this

comment:14 Changed 5 years ago by zzz

  • Milestone set to 0.9.13
  • Owner changed from zab to zzz
  • Status changed from reopened to accepted

Unrelated ticket #1271 has this NPE on -15 on x86. see 3rd line of wrapper log there. The null parameter is the Session Key. The meta is being sent before the session is established. The fix will be to initialize _nextMetaTime to Long.MAX_VALUE.

comment:15 Changed 5 years ago by zzz

  • Status changed from accepted to testing

Hopefully fixed in da96b33d4dd0fbda966d594ac591f7cd97f76d21 to be 0.9.12-16

comment:16 Changed 5 years ago by killyourtv

  • Status changed from testing to needs_work

On my Raspberry Pi:

I2P version: 0.9.13-0
Java version: Oracle Corporation 1.7.0_40 (Java(TM) SE Runtime Environment 1.7.0_40-b43)
Wrapper version: 3.5.22
Server version: 8.1.14.v20131031
Servlet version: Jasper JSP 2.1 Engine
Platform: Linux arm 3.10.30+
Processor: uninitialized (arm)
Jbigi: Locally optimized native BigInteger library loaded from file
Encoding: UTF-8
Charset: UTF-8
01/06/14 22:29:05 CRIT [P writer 3/4] p.router.transport.ntcp.Writer: Error in the ntcp writer on NTCP conn to DhZWxZ created 3018ms ago, last send 3018ms ago, last recv 3018ms ago, sent 0, rcvd 0
     java.lang.NullPointerException: invalid args to aes - sessionKey
     at net.i2p.crypto.CryptixAESEngine.encrypt(CryptixAESEngine.java:89)
     at net.i2p.router.transport.ntcp.NTCPConnection.prepareNextWriteFast(NTCPConnection.java:796)
     at net.i2p.router.transport.ntcp.NTCPConnection.prepareNextWrite(NTCPConnection.java:622)
     at net.i2p.router.transport.ntcp.Writer$Runner.run(Writer.java:129)
     at java.lang.Thread.run(Thread.java:724)
     at net.i2p.util.I2PThread.run(I2PThread.java:84)

comment:17 Changed 5 years ago by zzz

  • Milestone changed from 0.9.13 to 0.9.14
  • Status changed from needs_work to accepted

Interesting. A different case that wasn't fixed, as it's coming from prepareNextWriteFast(), not sendMeta().

comment:18 Changed 5 years ago by killyourtv

I2P version: 0.9.14.1-0
Java version: Oracle Corporation 1.7.0_40 (Java(TM) SE Runtime Environment 1.7.0_40-b43)
Wrapper version: 3.5.25
Server version: 8.1.15.v20140411
Servlet version: Jasper JSP 2.1 Engine
Platform: Linux arm 3.12.26+
Processor: uninitialized (arm)
Jbigi: Locally optimized native BigInteger library loaded from file
Encoding: UTF-8
Charset: UTF-8
14/09/14 05:56:11 CRIT [P writer 2/4] p.router.transport.ntcp.Writer: Error in the ntcp writer on NTCP conn to 98tQvZ created 1939ms ago, last send 1939ms ago, last recv 1939ms ago, sent 0, rcvd 0
     java.lang.NullPointerException: invalid args to aes - sessionKey
     at net.i2p.crypto.CryptixAESEngine.encrypt(CryptixAESEngine.java:115)
     at net.i2p.router.transport.ntcp.NTCPConnection.prepareNextWriteFast(NTCPConnection.java:796)
     at net.i2p.router.transport.ntcp.NTCPConnection.prepareNextWrite(NTCPConnection.java:622)
     at net.i2p.router.transport.ntcp.Writer$Runner.run(Writer.java:129)
     at java.lang.Thread.run(Thread.java:724)
     at net.i2p.util.I2PThread.run(I2PThread.java:84)

comment:19 Changed 5 years ago by str4d

I2P version: 0.9.15-0
Java version: Oracle Corporation 1.7.0_65 (OpenJDK Runtime Environment 1.7.0_65-b32)
Wrapper version: 3.1.1
Server version: 8.1.15.v20140411
Servlet version: Jasper JSP 2.1 Engine
Platform: Linux i386 3.15.4-x86_64-linode45
Processor: uninitialized (unrecognized)
Jbigi: Locally optimized native BigInteger library loaded from file
Encoding: ANSI_X3.4-1968
Charset: US-ASCII
23:49:51 | CRIT  [P writer 1/4] p.router.transport.ntcp.Writer: Error in the ntcp writer on NTCP conn to pby3Rs created 6s ago, last send 6s ago, last recv 10ms ago, sent 0, rcvd 1
23:49:51 | java.lang.NullPointerException: invalid args to aes - sessionKey
23:49:51 | 	at net.i2p.crypto.CryptixAESEngine.encrypt(CryptixAESEngine.java:115)
23:49:51 | 	at net.i2p.router.transport.ntcp.NTCPConnection.prepareNextWriteFast(NTCPConnection.java:796)
23:49:51 | 	at net.i2p.router.transport.ntcp.NTCPConnection.prepareNextWrite(NTCPConnection.java:622)
23:49:51 | 	at net.i2p.router.transport.ntcp.Writer$Runner.run(Writer.java:129)
23:49:51 | 	at java.lang.Thread.run(Thread.java:745)
23:49:51 | 	at net.i2p.util.I2PThread.run(I2PThread.java:84)
00:40:42 | CRIT  [P writer 4/4] p.router.transport.ntcp.Writer: Error in the ntcp writer on NTCP conn to j9ukcz created 2256ms ago, last send 2256ms ago, last recv 2256ms ago, sent 0, rcvd 0
00:40:42 | java.lang.NullPointerException: invalid args to aes - sessionKey
00:40:42 | 	at net.i2p.crypto.CryptixAESEngine.encrypt(CryptixAESEngine.java:115)
00:40:42 | 	at net.i2p.router.transport.ntcp.NTCPConnection.prepareNextWriteFast(NTCPConnection.java:796)
00:40:42 | 	at net.i2p.router.transport.ntcp.NTCPConnection.prepareNextWrite(NTCPConnection.java:622)
00:40:42 | 	at net.i2p.router.transport.ntcp.Writer$Runner.run(Writer.java:129)
00:40:42 | 	at java.lang.Thread.run(Thread.java:745)
00:40:42 | 	at net.i2p.util.I2PThread.run(I2PThread.java:84)
01:24:20 | JVM appears hung: Timed out waiting for signal from JVM.
01:24:21 | JVM did not exit on request, terminated
01:24:35 | Launching a JVM...
01:24:36 | OpenJDK Server VM warning: You have loaded library /home/i2p/bin/i2p/lib/libwrapper.so which might have disabled stack guard. The VM will try to fix the stack guard now.
01:24:36 | It's highly recommended that you fix the library with 'execstack -c <libfile>', or link it with '-z noexecstack'.
01:24:36 | Wrapper (Version 3.1.1) http://wrapper.tanukisoftware.org

comment:20 Changed 5 years ago by dg

Observed on 0.9.15. Not RPi. x86_64.

CRIT [P writer 1/4] p.router.transport.ntcp.Writer: Error in the ntcp writer on NTCP conn to REMOVED created 138ms ago, last send 138ms ago, last recv 138ms ago, sent 0, rcvd 0
     java.lang.NullPointerException: invalid args to aes - sessionKey
     at net.i2p.crypto.CryptixAESEngine.encrypt(CryptixAESEngine.java:115)
     at net.i2p.router.transport.ntcp.NTCPConnection.prepareNextWriteFast(NTCPConnection.java:796)
     at net.i2p.router.transport.ntcp.NTCPConnection.prepareNextWrite(NTCPConnection.java:622)
     at net.i2p.router.transport.ntcp.Writer$Runner.run(Writer.java:129)
     at java.lang.Thread.run(Thread.java:745)
     at net.i2p.util.I2PThread.run(I2PThread.java:84)
Last edited 5 years ago by dg (previous) (diff)

comment:21 Changed 4 years ago by str4d

  • Milestone 0.9.14 deleted

comment:22 Changed 2 years ago by zzz

  • Milestone set to 0.9.29

NTCPConnection.prepareNextWriteFast() only checks for !isEstablished() for outbound conns. But we don't have a session key unless established, either for inbound or outbound. Looks like a race. Will test checking for established for inbound conns too.

comment:23 Changed 2 years ago by zzz

  • Resolution set to fixed
  • Status changed from accepted to closed

in 965d805af922d30e1008edecc34512e467f37866 to be 0.9.28-6

Note: See TracTickets for help on using tickets.