added stat - crypto.garlic.decryptFail

formatting / logging
This commit is contained in:
jrandom
2004-04-18 03:36:12 +00:00
committed by zzz
parent 38091c3c25
commit 0d3d4b60ce

View File

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