Merge pull request #8180 from metabase/check-before-decrypting

Don't decrypt obviously not encrypted strings

src/metabase/util/encryption.clj

@@ -6,6 +6,7 @@
              [crypto :as crypto]
              [kdf :as kdf]
              [nonce :as nonce]]
+            [clojure.string :as str]
             [clojure.tools.logging :as log]
             [environ.core :as env]
             [metabase.util :as u]
@@ -73,21 +74,37 @@
        (encrypt secret-key s))
      s)))
 
+(def ^:private ^:const aes256-tag-length 32)
+(def ^:private ^:const aes256-block-size 16)
+
+(defn- possibly-encrypted-string?
+  "Returns true if it's likely that `s` is an encrypted string. Specifically we need `s` to be a non-blank, base64
+  encoded string of the correct length. The correct length is determined by the cipher's type tag and the cipher's
+  block size (AES+CBC). To compute this, we need the number of bytes in the input, subtract the bytes used by the
+  cipher type tag (`aes256-tag-length`) and what is left should be divisible by the cipher's block size
+  (`aes256-block-size`). If it's not divisible by that number it is either not encrypted or it has been corrupted as
+  it must always have a multiple of the block size or it won't decrypt."
+  [s]
+  (when-let [str-byte-length (and (not (str/blank? s))
+                                  (u/base64-string? s)
+                                  (alength ^bytes (codec/base64-decode s)))]
+    (zero? (mod (- str-byte-length aes256-tag-length)
+                aes256-block-size))))
+
 (defn maybe-decrypt
   "If `MB_ENCRYPTION_SECRET_KEY` is set and `s` is encrypted, decrypt `s`; otherwise return `s` as-is."
   (^String [^String s]
    (maybe-decrypt default-secret-key s))
   (^String [secret-key, ^String s]
-   (if (and secret-key (seq s))
+   (if (and secret-key (possibly-encrypted-string? s))
      (try
        (decrypt secret-key s)
        (catch Throwable e
-         (if (u/base64-string? s)
-           ;; if we can't decrypt `s`, but it *is* encrypted, log an error message and return `nil`
-           (log/error
-            (trs "Cannot decrypt encrypted credentials. Have you changed or forgot to set MB_ENCRYPTION_SECRET_KEY?")
-            (.getMessage e)
-            (u/pprint-to-str (u/filtered-stacktrace e)))
-           ;; otherwise return S without decrypting. It's probably not decrypted in the first place
-           s)))
+         ;; if we can't decrypt `s`, but it *is* probably encrypted, log a warning
+         (log/warn
+          (trs "Cannot decrypt encrypted string. Have you changed or forgot to set MB_ENCRYPTION_SECRET_KEY?")
+          (.getMessage e)
+          (u/pprint-to-str (u/filtered-stacktrace e)))
+         s))
+     ;; otherwise return `s` without decrypting. It's probably not decrypted in the first place
      s)))

test/metabase/test/util.clj

@@ -40,6 +40,7 @@
             [toucan.util.test :as test])
   (:import com.mchange.v2.c3p0.PooledDataSource
            java.util.TimeZone
+           org.apache.log4j.Logger
            org.joda.time.DateTimeZone
            [org.quartz CronTrigger JobDetail JobKey Scheduler Trigger]))
 
@@ -340,6 +341,36 @@
   [& body]
   `(do-with-log-messages (fn [] ~@body)))
 
+(def level-kwd->level
+  "Conversion from a keyword log level to the Log4J constance mapped to that log level.
+   Not intended for use outside of the `with-mb-log-messages-at-level` macro."
+  {:error org.apache.log4j.Level/ERROR
+   :warn  org.apache.log4j.Level/WARN
+   :info  org.apache.log4j.Level/INFO
+   :debug org.apache.log4j.Level/DEBUG
+   :trace org.apache.log4j.Level/TRACE})
+
+(defn ^Logger metabase-logger
+  "Gets the root logger for all metabase namespaces. Not intended for use outside of the
+  `with-mb-log-messages-at-level` macro."
+  []
+  (Logger/getLogger "metabase"))
+
+(defmacro with-mb-log-messages-at-level
+  "Executes `body` with the metabase logging level set to `level-kwd`. This is needed when the logging level is set at
+  a higher threshold than the log messages you're wanting to example. As an example if the metabase logging level is
+  set to `ERROR` in the log4j.properties file and you are looking for a `WARN` message, it won't show up in the
+  `with-log-messages` call as there's a guard around the log invocation, if it's not enabled (it is set to `ERROR`)
+  the log function will never be invoked. This macro will temporarily set the logging level to `level-kwd`, then
+  invoke `with-log-messages`, then set the level back to what it was before the invocation. This allows testing log
+  messages even if the threshold is higher than the message you are looking for."
+  [level-kwd & body]
+  `(let  [orig-log-level# (.getLevel (metabase-logger))]
+     (try
+       (.setLevel (metabase-logger) (get level-kwd->level ~level-kwd))
+       (with-log-messages ~@body)
+       (finally
+         (.setLevel (metabase-logger) orig-log-level#)))))
 
 (defn vectorize-byte-arrays
   "Walk form X and convert any byte arrays in the results to standard Clojure vectors. This is useful when writing

test/metabase/util/encryption_test.clj

@@ -54,14 +54,49 @@
   "{\"a\":100}"
   (encryption/maybe-decrypt secret "{\"a\":100}"))
 
-;; trying to decrypt something that is encrypted with the wrong key with `maybe-decrypt` should return `nil`...
+;; trying to decrypt something that is encrypted with the wrong key with `maybe-decrypt` should return the ciphertext...
+(let [original-ciphertext (encryption/encrypt secret "WOW")]
+  (expect
+    original-ciphertext
+    (encryption/maybe-decrypt secret-2 original-ciphertext)))
+
+(defn- includes-encryption-warning? [log-messages]
+  (some (fn [[level _ message]]
+          (and (= level :warn)
+               (str/includes? message (str "Cannot decrypt encrypted string. Have you changed or forgot to set "
+                                           "MB_ENCRYPTION_SECRET_KEY? Message seems corrupt or manipulated."))))
+        log-messages))
+
+(expect
+  (includes-encryption-warning?
+   (tu/with-mb-log-messages-at-level :warn
+     (encryption/maybe-decrypt secret-2 (encryption/encrypt secret "WOW")))))
+
+;; Something obviously not encrypted should avoiding trying to decrypt it (and thus not log an error)
+(expect
+  []
+  (tu/with-mb-log-messages-at-level :warn
+    (encryption/maybe-decrypt secret "abc")))
+
+;; Something obviously not encrypted should return the original string
+(expect
+  "abc"
+  (encryption/maybe-decrypt secret "abc"))
+
+(def ^:private fake-ciphertext
+  "AES+CBC's block size is 16 bytes and the tag length is 32 bytes. This is a string of characters that is the same
+  length as would be expected for something that has been encrypted, but it is not encrypted, just unlucky enough to
+  have the same size"
+  (apply str (repeat 64 "a")))
+
+;; Something that is not encrypted, but might be (is the correct shape etc) should attempt to be decrypted. If unable
+;; to decrypt it, log a warning.
 (expect
-  nil
-  (encryption/maybe-decrypt secret-2 (encryption/encrypt secret "WOW")))
+  (includes-encryption-warning?
+   (tu/with-mb-log-messages-at-level :warn
+     (encryption/maybe-decrypt secret fake-ciphertext))))
 
+;; Something that is not encrypted, but might be should return the original text
 (expect
-  (some (fn [[_ _ message]]
-          (str/includes? message (str "Cannot decrypt encrypted credentials. Have you changed or forgot to set "
-                                      "MB_ENCRYPTION_SECRET_KEY? Message seems corrupt or manipulated.")))
-        (tu/with-log-messages
-          (encryption/maybe-decrypt secret-2 (encryption/encrypt secret "WOW")))))
+  fake-ciphertext
+  (encryption/maybe-decrypt secret fake-ciphertext))