[freenet-cvs] r16442 - trunk/freenet/src/freenet/node

nextgens at freenetproject.org nextgens at freenetproject.org
Sun Dec 9 22:30:54 UTC 2007


Author: nextgens
Date: 2007-12-09 22:30:53 +0000 (Sun, 09 Dec 2007)
New Revision: 16442

Modified:
   trunk/freenet/src/freenet/node/FNPPacketMangler.java
Log:
JFK: improve logging, padd packets only up to the MTU, use static variables where possible

Modified: trunk/freenet/src/freenet/node/FNPPacketMangler.java
===================================================================
--- trunk/freenet/src/freenet/node/FNPPacketMangler.java	2007-12-09 22:29:20 UTC (rev 16441)
+++ trunk/freenet/src/freenet/node/FNPPacketMangler.java	2007-12-09 22:30:53 UTC (rev 16442)
@@ -61,12 +61,12 @@
 public class FNPPacketMangler implements OutgoingPacketMangler, IncomingPacketFilter {
 
 	private static boolean logMINOR;
-	final Node node;
-	final NodeCrypto crypto;
-	final MessageCore usm;
-	final PacketSocketHandler sock;
-	final EntropySource fnpTimingSource;
-	final EntropySource myPacketDataSource;
+	private final Node node;
+	private final NodeCrypto crypto;
+	private final MessageCore usm;
+	private final PacketSocketHandler sock;
+	private final EntropySource fnpTimingSource;
+	private final EntropySource myPacketDataSource;
 	/**
 	 * Objects cached during JFK message exchange: JFK(3,4) with authenticator as key
 	 * The messages are cached in hashmaps because the message retrieval from the cache 
@@ -709,7 +709,7 @@
 	private void processJFKMessage1(byte[] payload,int offset,PeerNode pn,Peer replyTo, boolean unknownInitiator, int setupType)
 	{
 		long t1=System.currentTimeMillis();
-		if(logMINOR) Logger.minor(this, "Got a JFK(1) message, processing it - "+pn);
+		if(logMINOR) Logger.minor(this, "Got a JFK(1) message, processing it - "+pn.getPeer());
 		// FIXME: follow the spec and send IDr' ?
 		if(payload.length < NONCE_SIZE + DiffieHellman.modulusLengthInBytes() + 3 + (unknownInitiator ? NodeCrypto.IDENTITY_LENGTH : 0)) {
 			Logger.error(this, "Packet too short from "+pn+": "+payload.length+" after decryption in JFK(1), should be "+(NONCE_SIZE + DiffieHellman.modulusLengthInBytes()));
@@ -743,7 +743,7 @@
 
 		long t2=System.currentTimeMillis();
 		if((t2-t1)>500)
-			Logger.error(this,"Message1 timeout error:Sending packet for"+pn.getPeer());
+			Logger.error(this,"Message1 timeout error:Processing packet for"+pn.getPeer());
 	}
 
 	/*
@@ -752,7 +752,7 @@
 	 * We send IDr' only if unknownInitiator is set.
 	 */
 	private void sendJFKMessage1(PeerNode pn, Peer replyTo, boolean unknownInitiator, int setupType) {
-		if(logMINOR) Logger.minor(this, "Sending a JFK(1) message to "+replyTo+" for "+pn);
+		if(logMINOR) Logger.minor(this, "Sending a JFK(1) message to "+replyTo+" for "+pn.getPeer());
 		final long now = System.currentTimeMillis();
 		DiffieHellmanLightContext ctx = (DiffieHellmanLightContext) pn.getKeyAgreementSchemeContext();
 		if((ctx == null) || ((pn.jfkContextLifetime + DH_GENERATION_INTERVAL*DH_CONTEXT_BUFFER_SIZE) < now)) {
@@ -782,6 +782,9 @@
 		} else {
 			sendAuthPacket(1,2,0,message1,pn,replyTo);
 		}
+		long t2=System.currentTimeMillis();
+		if((t2-now)>500)
+			Logger.error(this,"Message1 timeout error:Sending packet for"+pn.getPeer());
 	}
 
 	/*
@@ -868,11 +871,11 @@
 	private void processJFKMessage2(byte[] payload,int inputOffset,PeerNode pn,Peer replyTo, boolean unknownInitiator, int setupType)
 	{
 		long t1=System.currentTimeMillis();
-		if(logMINOR) Logger.minor(this, "Got a JFK(2) message, processing it - "+pn);
+		if(logMINOR) Logger.minor(this, "Got a JFK(2) message, processing it - "+pn.getPeer());
 		// FIXME: follow the spec and send IDr' ?
 		int expectedLength = NONCE_SIZE*2 + DiffieHellman.modulusLengthInBytes() + HASH_LENGTH*2;
 		if(payload.length < expectedLength + 3) {
-			Logger.error(this, "Packet too short from "+pn+": "+payload.length+" after decryption in JFK(2), should be "+(expectedLength + 3));
+			Logger.error(this, "Packet too short from "+pn.getPeer()+": "+payload.length+" after decryption in JFK(2), should be "+(expectedLength + 3));
 			return;
 		}
 
@@ -907,7 +910,7 @@
 			message3 = authenticatorCache.get(authenticator);
 		}
 		if(message3 != null) {
-			Logger.normal(this, "We replayed a message from the cache (shouldn't happen often) -"+pn);
+			Logger.normal(this, "We replayed a message from the cache (shouldn't happen often) - "+pn.getPeer());
 			sendAuthPacket(1, 2, 3, (byte[]) message3, pn, replyTo);
 			return;
 		}
@@ -919,7 +922,8 @@
 		}
 		// We don't except such a message;
 		if(myNi == null) {
-			Logger.normal(this, "We received an unexpected JFK(2) message from "+pn);
+			if(shouldLogErrorInHandshake(t1))
+				Logger.normal(this, "We received an unexpected JFK(2) message from "+pn.getPeer());
 			return;
 		} else if(!Arrays.equals(myNi, nonceInitiator)){
 			if(logMINOR)
@@ -928,7 +932,7 @@
 		}
 		
 		if(!DiffieHellman.checkDHExponentialValidity(this.getClass(), _hisExponential)) {
-			Logger.error(this, "We can't accept the exponential "+pn+" sent us!! REDFLAG: IT CAN'T HAPPEN UNLESS AGAINST AN ACTIVE ATTACKER!!");
+			Logger.error(this, "We can't accept the exponential "+pn.getPeer()+" sent us!! REDFLAG: IT CAN'T HAPPEN UNLESS AGAINST AN ACTIVE ATTACKER!!");
 			return;
 		}
 		
@@ -938,7 +942,7 @@
 		byte[] locallyExpectedExponentials = assembleDHParams(_hisExponential, pn.peerCryptoGroup);
 
 		if(!DSA.verify(pn.peerPubKey, remoteSignature, new NativeBigInteger(1, SHA256.digest(locallyExpectedExponentials)), false)) {
-			Logger.error(this, "The signature verification has failed in JFK(2)!! "+pn);
+			Logger.error(this, "The signature verification has failed in JFK(2)!! "+pn.getPeer());
 			return;
 		}
 		
@@ -949,7 +953,7 @@
 
 		long t2=System.currentTimeMillis();
 		if((t2-t1)>500)
-			Logger.error(this,"Message1 timeout error:Sending packet for"+pn.getPeer());
+			Logger.error(this,"Message2 timeout error:Processing packet for"+pn.getPeer());
 	}
 
 	/*
@@ -978,7 +982,7 @@
 	private void processJFKMessage3(byte[] payload, int inputOffset, PeerNode pn,Peer replyTo, boolean oldOpennetPeer, boolean unknownInitiator, int setupType)
 	{
 		final long t1 = System.currentTimeMillis();
-		if(logMINOR) Logger.minor(this, "Got a JFK(3) message, processing it - "+pn);
+		if(logMINOR) Logger.minor(this, "Got a JFK(3) message, processing it - "+pn.getPeer());
 		
 		BlockCipher c = null;
 		try { c = new Rijndael(256, 256); } catch (UnsupportedCipherException e) {}
@@ -990,7 +994,7 @@
 									HASH_LENGTH + // it's at least a signature
 									8;			  // a bootid
 		if(payload.length < expectedLength + 3) {
-			Logger.error(this, "Packet too short from "+pn+": "+payload.length+" after decryption in JFK(3), should be "+(expectedLength + 3));
+			Logger.error(this, "Packet too short from "+pn.getPeer()+": "+payload.length+" after decryption in JFK(3), should be "+(expectedLength + 3));
 			return;
 		}
 		
@@ -1019,7 +1023,8 @@
 		// is it cheaper to wait for the lock on authenticatorCache or to verify the hmac ?
 		HMAC mac = new HMAC(SHA256.getInstance());
 		if(!mac.verify(getTransientKey(), assembleJFKAuthenticator(responderExponential, initiatorExponential, nonceResponder, nonceInitiator, replyTo.getAddress().getAddress()) , authenticator)) {
-			Logger.error(this, "The HMAC doesn't match; let's discard the packet (either we rekeyed or we are victim of forgery) - JFK3");
+			if(shouldLogErrorInHandshake(t1))
+				Logger.normal(this, "The HMAC doesn't match; let's discard the packet (either we rekeyed or we are victim of forgery) - JFK3 - "+pn.getPeer());
 			return;
 		}
 		// Check try to find the authenticator in the cache.
@@ -1030,7 +1035,7 @@
 			message4 = authenticatorCache.get(authenticator);
 		}
 		if(message4 != null) {
-			Logger.normal(this, "We replayed a message from the cache (shouldn't happen often) - "+pn);
+			Logger.normal(this, "We replayed a message from the cache (shouldn't happen often) - "+pn.getPeer());
 			sendAuthPacket(1, 2, 3, (byte[]) message4, pn, replyTo);
 			return;
 		}
@@ -1044,7 +1049,7 @@
 		
 		DiffieHellmanLightContext ctx = findContextByExponential(_ourExponential);
 		if(ctx == null) {
-			Logger.error(this, "WTF? the HMAC verified but we don't know about that exponential! SHOULDN'T HAPPEN! - JFK4");
+			Logger.error(this, "WTF? the HMAC verified but we don't know about that exponential! SHOULDN'T HAPPEN! - JFK3 - "+pn.getPeer());
 			return;
 		}
 		BigInteger computedExponential = ctx.getHMACKey(_hisExponential, Global.DHgroupA);
@@ -1061,7 +1066,7 @@
 		decypheredPayloadOffset += JFK_PREFIX_INITIATOR.length;
 		System.arraycopy(payload, inputOffset, decypheredPayload, decypheredPayloadOffset, decypheredPayload.length-decypheredPayloadOffset);
 		if(!mac.verify(Ka, decypheredPayload, hmac)) {
-			Logger.error(this, "The digest-HMAC doesn't match; let's discard the packet JFK(3) - "+pn);
+			Logger.error(this, "The inner-HMAC doesn't match; let's discard the packet JFK(3) - "+pn.getPeer());
 			return;
 		}
 		
@@ -1101,7 +1106,7 @@
 		// verify the signature
 		DSASignature remoteSignature = new DSASignature(new NativeBigInteger(1,r), new NativeBigInteger(1,s)); 
 		if(!DSA.verify(pn.peerPubKey, remoteSignature, new NativeBigInteger(1, SHA256.digest(assembleDHParams(nonceInitiator, nonceResponder, _hisExponential, _ourExponential, crypto.myIdentity, data))), false)) {
-			Logger.error(this, "The signature verification has failed!! JFK(3) - "+pn);
+			Logger.error(this, "The signature verification has failed!! JFK(3) - "+pn.getPeer());
 			return;
 		}
 		
@@ -1133,12 +1138,12 @@
 			else
 				pn.maybeSendInitialMessages();
 		} else {
-			Logger.error(this, "Handshake failure! with "+pn);
+			Logger.error(this, "Handshake failure! with "+pn.getPeer());
 		}
 		
 		final long t2=System.currentTimeMillis();
 		if((t2-t1)>500)
-			Logger.error(this,"Message3 Sending packet for"+pn.getPeer()+" took "+TimeUtil.formatTime(t2-t1, 3, true));
+			Logger.error(this,"Message3 Processing packet for"+pn.getPeer()+" took "+TimeUtil.formatTime(t2-t1, 3, true));
 	}
 	
 	private PeerNode getPeerNodeFromUnknownInitiator(byte[] hisRef, int setupType, PeerNode pn) {
@@ -1195,7 +1200,7 @@
 	private void processJFKMessage4(byte[] payload, int inputOffset, PeerNode pn, Peer replyTo, boolean oldOpennetPeer, boolean unknownInitiator, int setupType)
 	{
 		final long t1 = System.currentTimeMillis();
-		if(logMINOR) Logger.minor(this, "Got a JFK(4) message, processing it - "+pn);
+		if(logMINOR) Logger.minor(this, "Got a JFK(4) message, processing it - "+pn.getPeer());
 		BlockCipher c = null;
 		try { c = new Rijndael(256, 256); } catch (UnsupportedCipherException e) {}
 		
@@ -1205,7 +1210,7 @@
 									pn.jfkMyRef.length			  // the bootid + mynoderef
 									;
 		if(payload.length < expectedLength + 3) {
-			Logger.error(this, "Packet too short from "+pn+": "+payload.length+" after decryption in JFK(4), should be "+(expectedLength + 3));
+			Logger.error(this, "Packet too short from "+pn.getPeer()+": "+payload.length+" after decryption in JFK(4), should be "+(expectedLength + 3));
 			return;
 		}
 		byte[] jfkBuffer = pn.getJFKBuffer();
@@ -1229,7 +1234,7 @@
 		System.arraycopy(payload, inputOffset, decypheredPayload, decypheredPayloadOffset, payload.length-inputOffset);
 		HMAC mac = new HMAC(SHA256.getInstance());
 		if(!mac.verify(pn.jfkKa, decypheredPayload, hmac)) {
-			Logger.error(this, "The digest-HMAC doesn't match; let's discard the packet");
+			Logger.normal(this, "The digest-HMAC doesn't match; let's discard the packet - "+pn.getPeer());
 			return;
 		}
 		// Get the IV
@@ -1266,7 +1271,7 @@
 		bufferOffset += data.length - pn.jfkMyRef.length;
 		System.arraycopy(pn.jfkMyRef, 0, locallyGeneratedText, bufferOffset, pn.jfkMyRef.length);
 		if(!DSA.verify(pn.peerPubKey, remoteSignature, new NativeBigInteger(1, SHA256.digest(locallyGeneratedText)), false)) {
-			Logger.error(this, "The signature verification has failed!! JFK(4) -"+pn);
+			Logger.error(this, "The signature verification has failed!! JFK(4) -"+pn.getPeer());
 			return;
 		}
 		
@@ -1313,7 +1318,7 @@
 		
 		final long t2=System.currentTimeMillis();
 		if((t2-t1)>500)
-			Logger.error(this,"Message3 timeout error:Sending packet for"+pn.getPeer());
+			Logger.error(this,"Message4 timeout error:Processing packet from "+pn.getPeer());
 	}
 
 	/*
@@ -1327,7 +1332,8 @@
 
 	private void sendJFKMessage3(int version,int negType,int phase,byte[] nonceInitiator,byte[] nonceResponder,byte[] hisExponential, byte[] authenticator, final PeerNode pn, final Peer replyTo, final boolean unknownInitiator, final int setupType)
 	{
-		if(logMINOR) Logger.minor(this, "Sending a JFK(3) message to "+pn);
+		if(logMINOR) Logger.minor(this, "Sending a JFK(3) message to "+pn.getPeer());
+		long t1=System.currentTimeMillis();
 		BlockCipher c = null;
 		try { c = new Rijndael(256, 256); } catch (UnsupportedCipherException e) {}
 		DiffieHellmanLightContext ctx = (DiffieHellmanLightContext) pn.getKeyAgreementSchemeContext();
@@ -1385,12 +1391,9 @@
 		node.random.nextBytes(iv);
 		pcfb.reset(iv);
 		int cleartextOffset = 0;
-		byte[] prefix = null;
-		try { prefix = "I".getBytes("UTF-8"); } catch (UnsupportedEncodingException e) {}
-		
-		byte[] cleartext = new byte[prefix.length + ivLength + Node.SIGNATURE_PARAMETER_LENGTH * 2 + data.length];
-		System.arraycopy(prefix, 0, cleartext, cleartextOffset, prefix.length);
-		cleartextOffset += prefix.length;
+		byte[] cleartext = new byte[JFK_PREFIX_INITIATOR.length + ivLength + Node.SIGNATURE_PARAMETER_LENGTH * 2 + data.length];
+		System.arraycopy(JFK_PREFIX_INITIATOR, 0, cleartext, cleartextOffset, JFK_PREFIX_INITIATOR.length);
+		cleartextOffset += JFK_PREFIX_INITIATOR.length;
 		System.arraycopy(iv, 0, cleartext, cleartextOffset, ivLength);
 		cleartextOffset += ivLength;
 		System.arraycopy(r, 0, cleartext, cleartextOffset, Node.SIGNATURE_PARAMETER_LENGTH);
@@ -1400,7 +1403,7 @@
 		System.arraycopy(data, 0, cleartext, cleartextOffset, data.length);
 		cleartextOffset += data.length;
 		
-		int cleartextToEncypherOffset = prefix.length + ivLength;
+		int cleartextToEncypherOffset = JFK_PREFIX_INITIATOR.length + ivLength;
 		pcfb.blockEncipher(cleartext, cleartextToEncypherOffset, cleartext.length-cleartextToEncypherOffset);
 		
 		// We compute the HMAC of (prefix + cyphertext) Includes the IV!
@@ -1435,6 +1438,9 @@
 				}
 			}
 		}, 5*1000);
+		long t2=System.currentTimeMillis();
+		if((t2-t1)>500)
+			Logger.error(this,"Message3 timeout error:Sending packet for"+pn.getPeer());
 	}
 
 	
@@ -1447,7 +1453,8 @@
 	private void sendJFKMessage4(int version,int negType,int phase,byte[] nonceInitiator,byte[] nonceResponder,byte[] initiatorExponential,byte[] responderExponential, BlockCipher c, byte[] Ke, byte[] Ka, byte[] authenticator, byte[] hisRef, PeerNode pn, Peer replyTo, boolean unknownInitiator, int setupType)
 	{
 		if(logMINOR)
-			Logger.minor(this, "Sending a JFK(4) message to "+pn);
+			Logger.minor(this, "Sending a JFK(4) message to "+pn.getPeer());
+		long t1=System.currentTimeMillis();
 		NativeBigInteger _responderExponential = new NativeBigInteger(1,responderExponential);
 		NativeBigInteger _initiatorExponential = new NativeBigInteger(1,initiatorExponential);
 		
@@ -1466,13 +1473,10 @@
 		byte[] iv=new byte[ivLength];
 		node.random.nextBytes(iv);
 		pk.reset(iv);
-		byte[] prefix = null;
-		try { prefix = "R".getBytes("UTF-8"); } catch (UnsupportedEncodingException e) {}
-
-		byte[] cyphertext = new byte[prefix.length + ivLength + Node.SIGNATURE_PARAMETER_LENGTH * 2 + data.length];
+		byte[] cyphertext = new byte[JFK_PREFIX_RESPONDER.length + ivLength + Node.SIGNATURE_PARAMETER_LENGTH * 2 + data.length];
 		int cleartextOffset = 0;
-		System.arraycopy(prefix, 0, cyphertext, cleartextOffset, prefix.length);
-		cleartextOffset += prefix.length;
+		System.arraycopy(JFK_PREFIX_RESPONDER, 0, cyphertext, cleartextOffset, JFK_PREFIX_RESPONDER.length);
+		cleartextOffset += JFK_PREFIX_RESPONDER.length;
 		System.arraycopy(iv, 0, cyphertext, cleartextOffset, ivLength);
 		cleartextOffset += ivLength;
 		System.arraycopy(r, 0, cyphertext, cleartextOffset, Node.SIGNATURE_PARAMETER_LENGTH);
@@ -1482,7 +1486,7 @@
 		System.arraycopy(data, 0, cyphertext, cleartextOffset, data.length);
 		cleartextOffset += data.length;
 		// Now encrypt the cleartext[Signature]
-		int cleartextToEncypherOffset = prefix.length + ivLength;
+		int cleartextToEncypherOffset = JFK_PREFIX_RESPONDER.length + ivLength;
 		pk.blockEncipher(cyphertext, cleartextToEncypherOffset, cyphertext.length - cleartextToEncypherOffset);
 		
 		// We compute the HMAC of (prefix + iv + signature)
@@ -1508,6 +1512,9 @@
 			sendAnonAuthPacket(1, 2, 3, setupType, message4, pn, replyTo, crypto.anonSetupCipher);
 		else
 			sendAuthPacket(1, 2, 3, message4, pn, replyTo);
+		long t2=System.currentTimeMillis();
+		if((t2-t1)>500)
+			Logger.error(this,"Message4 timeout error:Sending packet for"+pn.getPeer());
 	}
 
 	/**
@@ -1556,12 +1563,13 @@
 //			throw new IllegalStateException("Cannot send auth packet: too long: "+length);
 //		}
 		PCFBMode pcfb = PCFBMode.create(cipher);
-		int paddingLength = node.fastWeakRandom.nextInt(100);
 		byte[] iv = new byte[pcfb.lengthIV()];
 		node.random.nextBytes(iv);
 		byte[] hash = SHA256.digest(output);
 		if(logMINOR) Logger.minor(this, "Data hash: "+HexUtil.bytesToHex(hash));
-		byte[] data = new byte[iv.length + hash.length + 2 /* length */ + output.length + paddingLength];
+		int prePaddingLength = iv.length + hash.length + 2 /* length */ + output.length;
+		int paddingLength = node.fastWeakRandom.nextInt(Math.min(100, sock.getMaxPacketSize() - HEADERS_LENGTH_MINIMUM - prePaddingLength));
+		byte[] data = new byte[prePaddingLength + paddingLength];
 		pcfb.reset(iv);
 		System.arraycopy(iv, 0, data, 0, iv.length);
 		pcfb.blockEncipher(hash, 0, hash.length);
@@ -1597,9 +1605,8 @@
 	/**
 	 * Should we log an error for an event that could easily be
 	 * caused by a handshake across a restart boundary?
-	 */
-	private boolean shouldLogErrorInHandshake() {
-		long now = System.currentTimeMillis();
+	 */	
+	private boolean shouldLogErrorInHandshake(long now) {
 		if(now - node.startupTime < Node.HANDSHAKE_TIMEOUT*2)
 			return false;
 		return true;




More information about the cvs mailing list