Ratchet: Improve muxed decrypt

Try tags for both ratchet and AES before DH for either
Return empty CloveSet for ratchet errors after successful decrypt
Don't corrupt data in ECIESEngine on NS/NSR failure, for subsequent ElG attempt
Log tweaks

router/java/src/net/i2p/router/crypto/ElGamalAESEngine.java

@@ -114,7 +114,7 @@ public final class ElGamalAESEngine {
         if (key != null) {
             //if (_log.shouldLog(Log.DEBUG)) _log.debug("Key is known for tag " + st);
             if (shouldDebug)
-                _log.debug("Decrypting existing session encrypted with tag: " + st.toString() + ": key: " + key.toBase64() + ": " + data.length + " bytes " /* + Base64.encode(data, 0, 64) */ );
+                _log.debug("Decrypting existing session with tag: " + st.toString() + ": key: " + key.toBase64() + ": " + data.length + " bytes ");
             
             decrypted = decryptExistingSession(data, key, targetPrivateKey, foundTags, usedKey, foundKey);
             if (decrypted != null) {
@@ -128,8 +128,7 @@ public final class ElGamalAESEngine {
                     _log.warn("ElG decrypt fail: known tag [" + st + "], failed decrypt");
                 }
             }
-        } else {
+        } else if (data.length >= ELG_ENCRYPTED_LENGTH) {
-            if (shouldDebug) _log.debug("Key is NOT known for tag " + st);
             decrypted = decryptNewSession(data, targetPrivateKey, foundTags, usedKey, foundKey);
             if (decrypted != null) {
                 _context.statManager().updateFrequency("crypto.elGamalAES.decryptNewSession");
@@ -140,6 +139,8 @@ public final class ElGamalAESEngine {
                 if (_log.shouldLog(Log.WARN))
                     _log.warn("ElG decrypt fail: unknown tag: " + st);
             }
+        } else {
+            return null;
         }
 
         //if ((key == null) && (decrypted == null)) {
@@ -160,6 +161,95 @@ public final class ElGamalAESEngine {
         return decrypted;
     }
 
+    /**
+     * Tags only. For MuxedEngine use only.
+     *
+     * @return decrypted data or null on failure
+     * @since 0.9.46
+     */
+    public byte[] decryptFast(byte data[], PrivateKey targetPrivateKey,
+                              SessionKeyManager keyManager) throws DataFormatException {
+        if (data == null)
+            return null;
+        if (data.length < MIN_ENCRYPTED_SIZE)
+            return null;
+        byte tag[] = new byte[32];
+        System.arraycopy(data, 0, tag, 0, 32);
+        SessionTag st = new SessionTag(tag);
+        SessionKey key = keyManager.consumeTag(st);
+        if (key == null)
+            return null;
+        SessionKey foundKey = new SessionKey();
+        SessionKey usedKey = new SessionKey();
+        Set<SessionTag> foundTags = new HashSet<SessionTag>();
+        final boolean shouldDebug = _log.shouldDebug();
+        if (shouldDebug)
+            _log.debug("Decrypting existing session with tag: " + st.toString() + ": key: " + key.toBase64() + ": " + data.length + " bytes");
+        byte[] decrypted = decryptExistingSession(data, key, targetPrivateKey, foundTags, usedKey, foundKey);
+        if (decrypted != null) {
+            _context.statManager().updateFrequency("crypto.elGamalAES.decryptExistingSession");
+            if (!foundTags.isEmpty() && shouldDebug)
+                _log.debug("ElG/AES decrypt success with " + st + ": found tags: " + foundTags);
+            if (!foundTags.isEmpty()) {
+                if (foundKey.getData() != null) {
+                    if (shouldDebug) 
+                        _log.debug("Found key: " + foundKey.toBase64() + " tags: " + foundTags + " in existing session");
+                    keyManager.tagsReceived(foundKey, foundTags);
+                } else if (usedKey.getData() != null) {
+                    if (shouldDebug) 
+                        _log.debug("Used key: " + usedKey.toBase64() + " tags: " + foundTags + " in existing session");
+                    keyManager.tagsReceived(usedKey, foundTags);
+                }
+            }
+        } else {
+            _context.statManager().updateFrequency("crypto.elGamalAES.decryptFailed");
+            if (_log.shouldLog(Log.WARN)) {
+                _log.warn("ElG decrypt fail: known tag [" + st + "], failed decrypt");
+            }
+        }
+        return decrypted;
+    }
+
+    /**
+     * Full ElG only. For MuxedEngine use only.
+     *
+     * @return decrypted data or null on failure
+     * @since 0.9.46
+     */
+    public byte[] decryptSlow(byte data[], PrivateKey targetPrivateKey,
+                              SessionKeyManager keyManager) throws DataFormatException {
+        if (data == null)
+            return null;
+        if (data.length < ELG_ENCRYPTED_LENGTH)
+            return null;
+        SessionKey foundKey = new SessionKey();
+        SessionKey usedKey = new SessionKey();
+        Set<SessionTag> foundTags = new HashSet<SessionTag>();
+        byte[] decrypted = decryptNewSession(data, targetPrivateKey, foundTags, usedKey, foundKey);
+        final boolean shouldDebug = _log.shouldDebug();
+        if (decrypted != null) {
+            _context.statManager().updateFrequency("crypto.elGamalAES.decryptNewSession");
+        } else {
+            _context.statManager().updateFrequency("crypto.elGamalAES.decryptFailed");
+            if (_log.shouldLog(Log.WARN))
+                _log.warn("ElG decrypt fail as new session");
+        }
+        if (!foundTags.isEmpty()) {
+            if (shouldDebug)
+                _log.debug("ElG decrypt success: found tags: " + foundTags);
+            if (foundKey.getData() != null) {
+                if (shouldDebug) 
+                    _log.debug("Found key: " + foundKey.toBase64() + " tags: " + foundTags + " in new session");
+                keyManager.tagsReceived(foundKey, foundTags);
+            } else if (usedKey.getData() != null) {
+                if (shouldDebug) 
+                    _log.debug("Used key: " + usedKey.toBase64() + " tags: " + foundTags + " in new session");
+                keyManager.tagsReceived(usedKey, foundTags);
+            }
+        }
+        return decrypted;
+    }
+
     /**
      * scenario 1: 
      * Begin with 222 bytes, ElG encrypted, containing:
@@ -180,13 +270,6 @@ public final class ElGamalAESEngine {
      */
     private byte[] decryptNewSession(byte data[], PrivateKey targetPrivateKey, Set<SessionTag> foundTags, SessionKey usedKey,
                                     SessionKey foundKey) throws DataFormatException {
-        if (data == null) {
-            //if (_log.shouldLog(Log.WARN)) _log.warn("Data is null, unable to decrypt new session");
-            return null;
-        } else if (data.length < ELG_ENCRYPTED_LENGTH) {
-            //if (_log.shouldLog(Log.WARN)) _log.warn("Data length is too small (" + data.length + ")");
-            return null;
-        }
         byte elgEncr[] = new byte[ELG_ENCRYPTED_LENGTH];
         if (data.length > ELG_ENCRYPTED_LENGTH) {
             System.arraycopy(data, 0, elgEncr, 0, ELG_ENCRYPTED_LENGTH);
@@ -423,8 +506,8 @@ public final class ElGamalAESEngine {
                 throw new IllegalArgumentException("Bad public key type " + type);
         }
         if (currentTag == null) {
-            if (_log.shouldLog(Log.INFO))
+            if (_log.shouldDebug())
-                _log.info("Current tag is null, encrypting as new session");
+                _log.debug("Encrypting as new session");
             _context.statManager().updateFrequency("crypto.elGamalAES.encryptNewSession");
             return encryptNewSession(data, target, key, tagsForDelivery, newKey, paddedSize);
         }
@@ -535,12 +618,12 @@ public final class ElGamalAESEngine {
 
         //_log.debug("Pre IV for encryptNewSession: " + DataHelper.toString(preIV, 32));
         //_log.debug("SessionKey for encryptNewSession: " + DataHelper.toString(key.getData(), 32));
-        long before = _context.clock().now();
+        //long before = _context.clock().now();
         byte elgEncr[] = _context.elGamalEngine().encrypt(elgSrcData, target);
-        if (_log.shouldLog(Log.INFO)) {
+        //if (_log.shouldDebug()) {
-            long after = _context.clock().now();
+        //    long after = _context.clock().now();
-            _log.info("elgEngine.encrypt of the session key took " + (after - before) + "ms");
+        //    _log.debug("elgEngine.encrypt of the session key took " + (after - before) + "ms");
-        }
+        //}
         if (elgEncr.length < ELG_ENCRYPTED_LENGTH) {
             // ??? ElGamalEngine.encrypt() always returns 514 bytes
             byte elg[] = new byte[ELG_ENCRYPTED_LENGTH];

router/java/src/net/i2p/router/crypto/ratchet/ECIESAEADEngine.java

@@ -65,6 +65,10 @@ public final class ECIESAEADEngine {
     private static final long MAX_NS_FUTURE = 2*60*1000;
     // debug, send ACKREQ in every ES
     private static final boolean ACKREQ_IN_ES = false;
+    // return value for a payload failure after a successful decrypt,
+    // so we don't continue with ElG
+    private static final GarlicClove[] NO_GARLIC = new GarlicClove[] {};
+    private static final CloveSet NO_CLOVES = new CloveSet(NO_GARLIC, Certificate.NULL_CERT, 0, 0);
 
     private static final String INFO_0 = "SessionReplyTags";
     private static final String INFO_6 = "AttachPayloadKDF";
@@ -149,10 +153,10 @@ public final class ECIESAEADEngine {
         } catch (DataFormatException dfe) {
             if (_log.shouldWarn())
                 _log.warn("ECIES decrypt error", dfe);
-            throw dfe;
+            return NO_CLOVES;
         } catch (Exception e) {
             _log.error("ECIES decrypt error", e);
-            return null;
+            return NO_CLOVES;
         }
     }
 
@@ -165,8 +169,8 @@ public final class ECIESAEADEngine {
             return null;
         }
         if (data.length < MIN_ENCRYPTED_SIZE) {
-            if (_log.shouldLog(Log.ERROR))
+            if (_log.shouldWarn())
-                _log.error("Data is less than the minimum size (" + data.length + " < " + MIN_ENCRYPTED_SIZE + ")");
+                _log.warn("Data is less than the minimum size (" + data.length + " < " + MIN_ENCRYPTED_SIZE + ")");
             return null;
         }
 
@@ -177,14 +181,81 @@ public final class ECIESAEADEngine {
         CloveSet decrypted;
         final boolean shouldDebug = _log.shouldDebug();
         if (key != null) {
+            decrypted = xx_decryptFast(tag, st, key, data, targetPrivateKey, keyManager);
+            // we do NOT retry as NS
+        } else {
+            decrypted = x_decryptSlow(data, targetPrivateKey, keyManager);
+        }
+        return decrypted;
+    }
+
+    /**
+     * NSR/ES only. For MuxedEngine use only.
+     *
+     * @return decrypted data or null on failure
+     * @since 0.9.46
+     */
+    CloveSet decryptFast(byte data[], PrivateKey targetPrivateKey,
+                         RatchetSKM keyManager) throws DataFormatException {
+        try {
+            return x_decryptFast(data, targetPrivateKey, keyManager);
+        } catch (DataFormatException dfe) {
+            if (_log.shouldWarn())
+                _log.warn("ECIES decrypt error", dfe);
+            return NO_CLOVES;
+        } catch (Exception e) {
+            _log.error("ECIES decrypt error", e);
+            return NO_CLOVES;
+        }
+    }
+
+    /**
+     * NSR/ES only.
+     *
+     * @return decrypted data or null on failure
+     * @since 0.9.46
+     */
+    private CloveSet x_decryptFast(byte data[], PrivateKey targetPrivateKey,
+                                   RatchetSKM keyManager) throws DataFormatException {
+        if (data.length < MIN_ENCRYPTED_SIZE) {
+            if (_log.shouldWarn())
+                _log.warn("Data is less than the minimum size (" + data.length + " < " + MIN_ENCRYPTED_SIZE + ")");
+            return null;
+        }
+        byte tag[] = new byte[TAGLEN];
+        System.arraycopy(data, 0, tag, 0, TAGLEN);
+        RatchetSessionTag st = new RatchetSessionTag(tag);
+        SessionKeyAndNonce key = keyManager.consumeTag(st);
+        CloveSet decrypted;
+        if (key != null) {
+            decrypted = xx_decryptFast(tag, st, key, data, targetPrivateKey, keyManager);
+        } else {
+            decrypted = null;
+        }
+        return decrypted;
+    }
+
+    /**
+     * NSR/ES only.
+     *
+     * @param key non-null
+     * @param data non-null
+     * @return decrypted data or null on failure
+     * @since 0.9.46
+     */
+    private CloveSet xx_decryptFast(byte[] tag, RatchetSessionTag st, SessionKeyAndNonce key,
+                                    byte data[], PrivateKey targetPrivateKey,
+                                    RatchetSKM keyManager) throws DataFormatException {
+        CloveSet decrypted;
+        final boolean shouldDebug = _log.shouldDebug();
         HandshakeState state = key.getHandshakeState();
         if (state == null) {
             if (shouldDebug)
-                    _log.debug("Decrypting ES with tag: " + st.toBase64() + " key: " + key.toBase64() + ": " + data.length + " bytes");
+                _log.debug("Decrypting ES with tag: " + st.toBase64() + " key: " + key + ": " + data.length + " bytes");
             decrypted = decryptExistingSession(tag, data, key, targetPrivateKey, keyManager);
         } else if (data.length >= MIN_NSR_SIZE) {
             if (shouldDebug)
-                    _log.debug("Decrypting NSR with tag: " + st.toBase64() + " key: " + key.toBase64() + ": " + data.length + " bytes");
+                _log.debug("Decrypting NSR with tag: " + st.toBase64() + " key: " + key + ": " + data.length + " bytes");
             decrypted = decryptNewSessionReply(tag, data, state, keyManager);
         } else {
             decrypted = null;
@@ -192,16 +263,46 @@ public final class ECIESAEADEngine {
                 _log.warn("ECIES decrypt fail, tag found but no state and too small for NSR: " + data.length + " bytes");
         }
         if (decrypted != null) {
-///
             _context.statManager().updateFrequency("crypto.eciesAEAD.decryptExistingSession");
         } else {
             _context.statManager().updateFrequency("crypto.eciesAEAD.decryptFailed");
             if (_log.shouldWarn()) {
-                    _log.warn("ECIES decrypt fail: known tag [" + st + "], failed decrypt");
+                _log.warn("ECIES decrypt fail: known tag [" + st + "], failed decrypt with key " + key);
             }
         }
-        } else if (data.length >= MIN_NS_SIZE) {
+        return decrypted;
-            if (shouldDebug) _log.debug("IB Tag " + st + " not found, trying NS decrypt");
+    }
+
+    /**
+     * NS only. For MuxedEngine use only.
+     *
+     * @return decrypted data or null on failure
+     * @since 0.9.46
+     */
+    CloveSet decryptSlow(byte data[], PrivateKey targetPrivateKey,
+                            RatchetSKM keyManager) throws DataFormatException {
+        try {
+            return x_decryptSlow(data, targetPrivateKey, keyManager);
+        } catch (DataFormatException dfe) {
+            if (_log.shouldWarn())
+                _log.warn("ECIES decrypt error", dfe);
+            return NO_CLOVES;
+        } catch (Exception e) {
+            _log.error("ECIES decrypt error", e);
+            return NO_CLOVES;
+        }
+    }
+
+    /**
+     * NS only.
+     *
+     * @return decrypted data or null on failure
+     * @since 0.9.46
+     */
+    private CloveSet x_decryptSlow(byte data[], PrivateKey targetPrivateKey,
+                                   RatchetSKM keyManager) throws DataFormatException {
+        CloveSet decrypted;
+        if (data.length >= MIN_NS_SIZE) {
             decrypted = decryptNewSession(data, targetPrivateKey, keyManager);
             if (decrypted != null) {
                 _context.statManager().updateFrequency("crypto.eciesAEAD.decryptNewSession");
@@ -213,9 +314,8 @@ public final class ECIESAEADEngine {
         } else {
             decrypted = null;
             if (_log.shouldWarn())
-                _log.warn("ECIES decrypt fail, tag not found and too small for NS: " + data.length + " bytes");
+                _log.warn("ECIES decrypt fail, too small for NS: " + data.length + " bytes");
         }
-
         return decrypted;
     }
 
@@ -260,6 +360,7 @@ public final class ECIESAEADEngine {
                 _log.warn("Elg2 decode fail NS");
             return null;
         }
+        // rewrite in place, must restore below on failure
         System.arraycopy(pk.getData(), 0, data, 0, KEYLEN);
 
         int payloadlen = data.length - (KEYLEN + KEYLEN + MACLEN + MACLEN);
@@ -272,6 +373,8 @@ public final class ECIESAEADEngine {
                 if (_log.shouldDebug())
                     _log.debug("State at failure: " + state);
             }
+            // restore original data for subsequent ElG attempt
+            System.arraycopy(tmp, 0, data, 0, KEYLEN);
             return null;
         }
         // bloom filter here based on ephemeral key
@@ -281,7 +384,7 @@ public final class ECIESAEADEngine {
         if (keyManager.isDuplicate(pk)) {
             if (_log.shouldWarn())
                 _log.warn("Dup eph. key in IB NS: " + pk);
-            return null;
+            return NO_CLOVES;
         }
 
         byte[] bobPK = new byte[KEYLEN];
@@ -294,14 +397,14 @@ public final class ECIESAEADEngine {
             // TODO
             if (_log.shouldWarn())
                 _log.warn("Zero static key in IB NS");
-            return null;
+            return NO_CLOVES;
         }
 
         // payload
         if (payloadlen == 0) {
             if (_log.shouldWarn())
                 _log.warn("Zero length payload in NS");
-            return null;
+            return NO_CLOVES;
         }
         PLCallback pc = new PLCallback();
         try {
@@ -317,7 +420,7 @@ public final class ECIESAEADEngine {
         if (pc.datetime == 0) {
             if (_log.shouldWarn())
                 _log.warn("No datetime block in IB NS");
-            return null;
+            return NO_CLOVES;
         }
 
         // tell the SKM
@@ -378,6 +481,7 @@ public final class ECIESAEADEngine {
         }
         if (_log.shouldDebug())
             _log.debug("State before decrypt new session reply: " + state);
+        // rewrite in place, must restore below on failure
         System.arraycopy(k.getData(), 0, data, TAGLEN, KEYLEN);
         state.mixHash(tag, 0, TAGLEN);
         if (_log.shouldDebug())
@@ -390,6 +494,9 @@ public final class ECIESAEADEngine {
                 if (_log.shouldDebug())
                     _log.debug("State at failure: " + state);
             }
+            // restore original data for subsequent ElG attempt
+            // unlikely since we already matched the tag
+            System.arraycopy(yy, 0, data, TAGLEN, KEYLEN);
             return null;
         }
         if (_log.shouldDebug())
@@ -417,12 +524,12 @@ public final class ECIESAEADEngine {
                 if (_log.shouldDebug())
                     _log.debug("State at failure: " + state);
             }
-            return null;
+            return NO_CLOVES;
         }
         if (payload.length == 0) {
             if (_log.shouldWarn())
                 _log.warn("Zero length payload in NSR");
-            return null;
+            return NO_CLOVES;
         }
         PLCallback pc = new PLCallback();
         try {
@@ -443,7 +550,7 @@ public final class ECIESAEADEngine {
             // TODO
             if (_log.shouldWarn())
                 _log.warn("NSR reply to zero static key NS");
-            return null;
+            return NO_CLOVES;
         }
 
         // tell the SKM

router/java/src/net/i2p/router/crypto/ratchet/MuxedEngine.java

@@ -34,31 +34,54 @@ final class MuxedEngine {
             ecKey.getType() != EncType.ECIES_X25519)
             throw new IllegalArgumentException();
         CloveSet rv = null;
-        boolean tryElg = false;
+        // Try in-order from fastest to slowest
-        // See proposal 144
+        // Ratchet Tag
-        if (data.length >= 128) {
+        rv = _context.eciesEngine().decryptFast(data, ecKey, keyManager.getECSKM());
-            int mod = data.length % 16;
+        if (rv != null)
-            if (mod == 0 || mod == 2)
+            return rv;
-                tryElg = true;
+        if (_log.shouldDebug())
-        }
+            _log.debug("Ratchet tag not found");
-        // Always try ElG first, for now
+        // AES Tag
-        if (tryElg) {
+        if (data.length >= 128 && (data.length & 0x0f) == 0) {
-            byte[] dec = _context.elGamalAESEngine().decrypt(data, elgKey, keyManager.getElgSKM());
+            byte[] dec = _context.elGamalAESEngine().decryptFast(data, elgKey, keyManager.getElgSKM());
             if (dec != null) {
                 try {
                     rv = _context.garlicMessageParser().readCloveSet(dec, 0);
+                    if (rv == null && _log.shouldInfo())
+                        _log.info("AES cloveset error");
                 } catch (DataFormatException dfe) {
                     if (_log.shouldInfo())
-                        _log.info("ElG decrypt failed, trying ECIES", dfe);
+                        _log.info("AES cloveset error", dfe);
+                }
+                return rv;
+            } else {
+                if (_log.shouldDebug())
+                    _log.debug("AES tag not found");
+            }
+        }
+        // Ratchet DH
+        rv = _context.eciesEngine().decryptSlow(data, ecKey, keyManager.getECSKM());
+        if (rv != null)
+            return rv;
+        if (_log.shouldDebug())
+            _log.debug("Ratchet NS decrypt failed");
+        // ElG DH
+        if (data.length >= 514 && (data.length & 0x0f) == 2) {
+            byte[] dec = _context.elGamalAESEngine().decryptSlow(data, elgKey, keyManager.getElgSKM());
+            if (dec != null) {
+                try {
+                    rv = _context.garlicMessageParser().readCloveSet(dec, 0);
+                    if (rv == null && _log.shouldInfo())
+                        _log.info("ElG cloveset error");
+                } catch (DataFormatException dfe) {
+                    if (_log.shouldInfo())
+                        _log.info("ElG cloveset error", dfe);
                 }
             } else {
-                //if (_log.shouldDebug())
+                if (_log.shouldInfo())
-                //    _log.debug("ElG decrypt failed, trying ECIES");
+                    _log.info("ElG decrypt failed");
             }
         }
-        if (rv == null) {
-            rv = _context.eciesEngine().decrypt(data, ecKey, keyManager.getECSKM());
-        }
         return rv;
     }
 }

router/java/src/net/i2p/router/crypto/ratchet/SessionKeyAndNonce.java

@@ -86,6 +86,7 @@ class SessionKeyAndNonce extends SessionKey {
         StringBuilder buf = new StringBuilder(64);
         buf.append("[SessionKeyAndNonce: ");
         buf.append(toBase64());
+        buf.append(_state != null ? " NSR" : " ES");
         buf.append(" nonce: ").append(_nonce);
         buf.append(']');
         return buf.toString();