diff --git a/router/java/src/net/i2p/router/message/HandleGarlicMessageJob.java b/router/java/src/net/i2p/router/message/HandleGarlicMessageJob.java index 397d8bb4f..e8a6277b8 100644 --- a/router/java/src/net/i2p/router/message/HandleGarlicMessageJob.java +++ b/router/java/src/net/i2p/router/message/HandleGarlicMessageJob.java @@ -25,6 +25,7 @@ import net.i2p.router.KeyManager; import net.i2p.router.LeaseSetKeys; import net.i2p.router.MessageHistory; import net.i2p.router.Router; +import net.i2p.stat.StatManager; import net.i2p.util.Clock; import net.i2p.util.Log; @@ -42,123 +43,140 @@ public class HandleGarlicMessageJob extends JobImpl { private Hash _fromHash; private static Map _cloves; // map of clove Id --> Expiration of cloves we've already seen + static { + StatManager.getInstance().createRateStat("crypto.garlic.decryptFail", "How often garlic messages are undecryptable", "Encryption", new long[] { 5*60*1000, 60*60*1000, 24*60*60*1000 }); + } + private final static int FORWARD_PRIORITY = 50; public HandleGarlicMessageJob(GarlicMessage msg, RouterIdentity from, Hash fromHash) { - super(); - if (_log.shouldLog(Log.DEBUG)) - _log.debug("New handle garlicMessageJob called w/ message from [" + from + "]", new Exception("Debug")); - _message = msg; - _from = from; - _fromHash = fromHash; - _cloves = new HashMap(); + super(); + if (_log.shouldLog(Log.DEBUG)) + _log.debug("New handle garlicMessageJob called w/ message from [" + from + "]", new Exception("Debug")); + _message = msg; + _from = from; + _fromHash = fromHash; + _cloves = new HashMap(); } public String getName() { return "Handle Inbound Garlic Message"; } public void runJob() { - CloveSet set = GarlicMessageParser.getInstance().getGarlicCloves(_message, KeyManager.getInstance().getPrivateKey()); - if (set == null) { - Set keys = KeyManager.getInstance().getAllKeys(); - if (_log.shouldLog(Log.DEBUG)) - _log.debug("Decryption with the router's key failed, now try with the " + keys.size() + " leaseSet keys"); - // our router key failed, which means that it was either encrypted wrong - // or it was encrypted to a LeaseSet's PublicKey - for (Iterator iter = keys.iterator(); iter.hasNext();) { - LeaseSetKeys lskeys = (LeaseSetKeys)iter.next(); - set = GarlicMessageParser.getInstance().getGarlicCloves(_message, lskeys.getDecryptionKey()); - if (set != null) { - if (_log.shouldLog(Log.DEBUG)) - _log.debug("Decrypted garlic message with lease set key for destination " + lskeys.getDestination().calculateHash().toBase64() + " SUCCEEDED: " + set); - break; - } else { - if (_log.shouldLog(Log.DEBUG)) - _log.debug("Decrypting garlic message with lease set key for destination " + lskeys.getDestination().calculateHash().toBase64() + " failed"); - } - } - } else { - if (_log.shouldLog(Log.DEBUG)) - _log.debug("Decrypted clove set found " + set.getCloveCount() + " cloves: " + set); - } - if (set != null) { - for (int i = 0; i < set.getCloveCount(); i++) { - GarlicClove clove = set.getClove(i); - handleClove(clove); - } - } else { - if (_log.shouldLog(Log.ERROR)) - _log.error("CloveMessageParser failed to decrypt the message [" + _message.getUniqueId() + "] to us when received from [" + _fromHash + "] / [" + _from + "]", new Exception("Decrypt garlic failed")); - MessageHistory.getInstance().messageProcessingError(_message.getUniqueId(), _message.getClass().getName(), "Garlic could not be decrypted"); - } + CloveSet set = GarlicMessageParser.getInstance().getGarlicCloves(_message, KeyManager.getInstance().getPrivateKey()); + if (set == null) { + Set keys = KeyManager.getInstance().getAllKeys(); + if (_log.shouldLog(Log.DEBUG)) + _log.debug("Decryption with the router's key failed, now try with the " + keys.size() + " leaseSet keys"); + // our router key failed, which means that it was either encrypted wrong + // or it was encrypted to a LeaseSet's PublicKey + for (Iterator iter = keys.iterator(); iter.hasNext();) { + LeaseSetKeys lskeys = (LeaseSetKeys)iter.next(); + set = GarlicMessageParser.getInstance().getGarlicCloves(_message, lskeys.getDecryptionKey()); + if (set != null) { + if (_log.shouldLog(Log.DEBUG)) + _log.debug("Decrypted garlic message with lease set key for destination " + + lskeys.getDestination().calculateHash().toBase64() + " SUCCEEDED: " + set); + break; + } else { + if (_log.shouldLog(Log.DEBUG)) + _log.debug("Decrypting garlic message with lease set key for destination " + + lskeys.getDestination().calculateHash().toBase64() + " failed"); + } + } + } else { + if (_log.shouldLog(Log.DEBUG)) + _log.debug("Decrypted clove set found " + set.getCloveCount() + " cloves: " + set); + } + if (set != null) { + for (int i = 0; i < set.getCloveCount(); i++) { + GarlicClove clove = set.getClove(i); + handleClove(clove); + } + } else { + if (_log.shouldLog(Log.ERROR)) + _log.error("CloveMessageParser failed to decrypt the message [" + _message.getUniqueId() + + "] to us when received from [" + _fromHash + "] / [" + _from + "]", + new Exception("Decrypt garlic failed")); + StatManager.getInstance().addRateData("crypto.garlic.decryptFail", 1, 0); + MessageHistory.getInstance().messageProcessingError(_message.getUniqueId(), + _message.getClass().getName(), + "Garlic could not be decrypted"); + } } private static boolean isKnown(long cloveId) { - boolean known = false; - synchronized (_cloves) { - known = _cloves.containsKey(new Long(cloveId)); - } - if (_log.shouldLog(Log.DEBUG)) - _log.debug("isKnown("+cloveId+"): " + known); - return known; + boolean known = false; + synchronized (_cloves) { + known = _cloves.containsKey(new Long(cloveId)); + } + if (_log.shouldLog(Log.DEBUG)) + _log.debug("isKnown("+cloveId+"): " + known); + return known; } private static void cleanupCloves() { - // this should be in its own thread perhaps? and maybe _cloves should be - // synced to disk? - List toRemove = new ArrayList(32); - long now = Clock.getInstance().now(); - synchronized (_cloves) { - for (Iterator iter = _cloves.keySet().iterator(); iter.hasNext();) { - Long id = (Long)iter.next(); - Date exp = (Date)_cloves.get(id); - if (exp == null) continue; // wtf, not sure how this can happen yet, but i've seen it. grr. - if (now > exp.getTime()) - toRemove.add(id); - } - for (int i = 0; i < toRemove.size(); i++) - _cloves.remove(toRemove.get(i)); - } + // this should be in its own thread perhaps? and maybe _cloves should be + // synced to disk? + List toRemove = new ArrayList(32); + long now = Clock.getInstance().now(); + synchronized (_cloves) { + for (Iterator iter = _cloves.keySet().iterator(); iter.hasNext();) { + Long id = (Long)iter.next(); + Date exp = (Date)_cloves.get(id); + if (exp == null) continue; // wtf, not sure how this can happen yet, but i've seen it. grr. + if (now > exp.getTime()) + toRemove.add(id); + } + for (int i = 0; i < toRemove.size(); i++) + _cloves.remove(toRemove.get(i)); + } } private static boolean isValid(GarlicClove clove) { - if (isKnown(clove.getCloveId())) { - _log.error("Duplicate garlic clove received - replay attack in progress? [cloveId = " + - clove.getCloveId() + " expiration = " + clove.getExpiration()); - return false; - } else { - _log.debug("Clove " + clove.getCloveId() + " expiring on " + clove.getExpiration() + " is not known"); - } - long now = Clock.getInstance().now(); - if (clove.getExpiration().getTime() < now) { - if (clove.getExpiration().getTime() < now + Router.CLOCK_FUDGE_FACTOR) { - _log.warn("Expired garlic received, but within our fudge factor [" + clove.getExpiration() + "]"); - } else { - if (_log.shouldLog(Log.DEBUG)) - _log.error("Expired garlic clove received - replay attack in progress? [cloveId = " + - clove.getCloveId() + " expiration = " + clove.getExpiration() + " now = " + (new Date(Clock.getInstance().now()))); - return false; - } - - } - synchronized (_cloves) { - _cloves.put(new Long(clove.getCloveId()), clove.getExpiration()); - } - cleanupCloves(); - return true; + if (isKnown(clove.getCloveId())) { + _log.error("Duplicate garlic clove received - replay attack in progress? [cloveId = " + + clove.getCloveId() + " expiration = " + clove.getExpiration()); + return false; + } else { + _log.debug("Clove " + clove.getCloveId() + " expiring on " + clove.getExpiration() + + " is not known"); + } + long now = Clock.getInstance().now(); + if (clove.getExpiration().getTime() < now) { + if (clove.getExpiration().getTime() < now + Router.CLOCK_FUDGE_FACTOR) { + _log.warn("Expired garlic received, but within our fudge factor [" + + clove.getExpiration() + "]"); + } else { + if (_log.shouldLog(Log.DEBUG)) + _log.error("Expired garlic clove received - replay attack in progress? [cloveId = " + + clove.getCloveId() + " expiration = " + clove.getExpiration() + + " now = " + (new Date(Clock.getInstance().now()))); + return false; + } + } + synchronized (_cloves) { + _cloves.put(new Long(clove.getCloveId()), clove.getExpiration()); + } + cleanupCloves(); + return true; } private void handleClove(GarlicClove clove) { - if (!isValid(clove)) { - if (_log.shouldLog(Log.DEBUG)) - _log.warn("Invalid clove " + clove); - return; - } - boolean requestAck = (clove.getSourceRouteBlockAction() == GarlicClove.ACTION_STATUS); - long sendExpiration = clove.getExpiration().getTime(); - MessageHandler.getInstance().handleMessage(clove.getInstructions(), clove.getData(), requestAck, clove.getSourceRouteBlock(), - clove.getCloveId(), _from, _fromHash, sendExpiration, FORWARD_PRIORITY); + if (!isValid(clove)) { + if (_log.shouldLog(Log.DEBUG)) + _log.warn("Invalid clove " + clove); + return; + } + boolean requestAck = (clove.getSourceRouteBlockAction() == GarlicClove.ACTION_STATUS); + long sendExpiration = clove.getExpiration().getTime(); + MessageHandler.getInstance().handleMessage(clove.getInstructions(), clove.getData(), + requestAck, clove.getSourceRouteBlock(), + clove.getCloveId(), _from, _fromHash, + sendExpiration, FORWARD_PRIORITY); } public void dropped() { - MessageHistory.getInstance().messageProcessingError(_message.getUniqueId(), _message.getClass().getName(), "Dropped due to overload"); + MessageHistory.getInstance().messageProcessingError(_message.getUniqueId(), + _message.getClass().getName(), + "Dropped due to overload"); } }