[MTCs] add debug logs in VerifyMTC

Bug: 548629159
Change-Id: Id3f21d1f6a6dfca3cc89c25f4cf38bb2acf51de2
Reviewed-on: https://boringssl-review.googlesource.com/c/boringssl/+/101287
Reviewed-by: David Benjamin <davidben@google.com>
Commit-Queue: Matt Mueller <mattm@google.com>
diff --git a/pki/path_builder.h b/pki/path_builder.h
index 981efab..2f8ba5b 100644
--- a/pki/path_builder.h
+++ b/pki/path_builder.h
@@ -122,15 +122,6 @@
   // paths. Delegates can cause path building to stop and return indicating
   // the deadline was exceeded by returning true from this function.
   virtual bool IsDeadlineExpired() = 0;
-
-  // This is called during path building to decide if debug logs will be
-  // sent to the delegate rom the path builder. No calls to DebugLog (below)
-  // will be made unless this returns true.
-  virtual bool IsDebugLogEnabled() = 0;
-
-  // This is called to send a debug log string `msg` to the delegate. These are
-  // only called if IsDebugLogEnabled (above) returns true.
-  virtual void DebugLog(std::string_view msg) = 0;
 };
 
 // Checks whether a certificate is trusted by building candidate paths to trust
diff --git a/pki/trust_store.cc b/pki/trust_store.cc
index 0e2f94a..549b393 100644
--- a/pki/trust_store.cc
+++ b/pki/trust_store.cc
@@ -18,6 +18,7 @@
 #include <cstdint>
 #include <cstring>
 #include <optional>
+#include <string>
 
 #include <openssl/base.h>
 #include <openssl/bytestring.h>
@@ -248,6 +249,31 @@
   return it->hash;
 }
 
+std::string MTCAnchor::TrustedSubtreesDebugString() const {
+  if (trusted_subtrees_.empty()) {
+    return "none";
+  }
+  std::string result;
+
+  for (const auto &[log_number, subtrees] : trusted_subtrees_) {
+    if (!result.empty()) {
+      result += ", ";
+    }
+    result += "log " + std::to_string(log_number) + ":";
+    if (subtrees.empty()) {
+      result += "empty";
+    } else {
+      // Just showing the start of first range to end of last range is an
+      // oversimplification, but showing every single range is probably too
+      // verbose.
+      result += std::to_string(subtrees.size()) + " subtrees(" +
+                std::to_string(subtrees.front().range.start) + ".." +
+                std::to_string(subtrees.back().range.end) + ")";
+    }
+  }
+  return result;
+}
+
 void MTCAnchor::CreateSyntheticCert(bssl::Span<const uint8_t> ca_id) {
   bssl::ScopedCBB cbb;
   CBB cert, tbs_cert, version, validity, subject_seq, subject_set, subject_log,
diff --git a/pki/trust_store.h b/pki/trust_store.h
index d11ed0a..c1ff569 100644
--- a/pki/trust_store.h
+++ b/pki/trust_store.h
@@ -183,6 +183,7 @@
 
   std::optional<TreeHashConstSpan> SubtreeHash(uint16_t log_number,
                                                Subtree target_range) const;
+  std::string TrustedSubtreesDebugString() const;
 
  private:
   void CreateSyntheticCert(Span<const uint8_t> ca_id);
diff --git a/pki/verify_certificate_chain.cc b/pki/verify_certificate_chain.cc
index 71b0716..36edb1b 100644
--- a/pki/verify_certificate_chain.cc
+++ b/pki/verify_certificate_chain.cc
@@ -16,6 +16,7 @@
 
 #include <algorithm>
 #include <cassert>
+#include <string>
 
 #include <inttypes.h>
 
@@ -37,6 +38,7 @@
 #include "parse_certificate.h"
 #include "parse_values.h"
 #include "signature_algorithm.h"
+#include "string_util.h"
 #include "trust_store.h"
 #include "verify_signed_data.h"
 
@@ -1390,15 +1392,6 @@
   }
   std::optional<TreeHashConstSpan> trusted_subtree_hash =
       mtc_anchor->SubtreeHash(log_number, range);
-  if (trusted_subtree_hash) {
-    return CRYPTO_memcmp(expected_subtree_hash->data(),
-                         trusted_subtree_hash->data(),
-                         expected_subtree_hash->size()) == 0;
-  }
-
-  // Step 6: Let log_id be the log ID constructed from the CA ID in issuer and
-  // the log_number.
-  //
   // Use the ca_id from mtc_anchor instead of parsing the id out of issuer. It
   // should be guaranteed to be the same id, otherwise mtc_anchor would not
   // have been selected as the anchor for this cert.
@@ -1407,6 +1400,34 @@
   if (!ca_id_text) {
     return false;
   }
+  if (delegate->IsDebugLogEnabled()) {
+    std::string trusted_subtree_hash_string =
+        trusted_subtree_hash ? string_util::HexEncode(*trusted_subtree_hash)
+                             : "not found";
+    delegate->DebugLog(
+        // clang-format off
+        "VerifyMTC:\n"
+        " ca_id=" + std::string(ca_id_text.get()) + "\n"
+        " log_number=" + std::to_string(log_number) + "\n"
+        " index=" + std::to_string(index) + "\n"
+        " start=" + std::to_string(start) + "\n"
+        " end=" + std::to_string(end) + "\n"
+        " expected_subtree_hash=" +
+            string_util::HexEncode(*expected_subtree_hash) + "\n"
+        " trusted_subtree_hash=" + trusted_subtree_hash_string + "\n"
+        " known_trusted_subtrees=" + mtc_anchor->TrustedSubtreesDebugString()
+            + "\n"
+        // clang-format on
+    );
+  }
+  if (trusted_subtree_hash) {
+    return CRYPTO_memcmp(expected_subtree_hash->data(),
+                         trusted_subtree_hash->data(),
+                         expected_subtree_hash->size()) == 0;
+  }
+
+  // Step 6: Let log_id be the log ID constructed from the CA ID in issuer and
+  // the log_number.
   // Section 5.1: For each positive integer N, the OID {caID logs(0) N}
   // represents the issuance log N (Section 5.2).
   std::string log_id_text = ca_id_text.get();
@@ -1460,10 +1481,14 @@
           expected_subtree_hash.value(), signature,
           mtc_anchor->ca_signature_algorithm(), mtc_anchor->ca_key(),
           delegate->GetVerifyCache());
+
+      if (delegate->IsDebugLogEnabled()) {
+        delegate->DebugLog(std::string("VerifyMTC: CA signature ") +
+                           (found_valid_ca_signature ? "valid" : "invalid"));
+      }
     } else {
       auto cosigner = delegate->GetMTCCosigner(cosigner_id);
-      // TODO(crbug.com/452983502): output debug logs or delegate data or
-      // something for non-success cases?
+      bool this_cosignature_was_valid = false;
       if (cosigner && VerifyMTCProofSignaturePlants04(
                           &cbs_cosigner_id, StringAsBytes(log_id_text), start,
                           end, expected_subtree_hash.value(), signature,
@@ -1471,6 +1496,19 @@
                           delegate->GetVerifyCache())) {
         valid_additional_cosigners.emplace_back(cosigner_id.begin(),
                                                 cosigner_id.end());
+        this_cosignature_was_valid = true;
+      }
+
+      if (delegate->IsDebugLogEnabled()) {
+        UniquePtr<char> cosigner_id_text_buf(
+            CBS_asn1_relative_oid_to_text(&cbs_cosigner_id));
+        const char *cosigner_id_text =
+            cosigner_id_text_buf ? cosigner_id_text_buf.get() : "<invalid ID>";
+        const char *cosignature_result_string =
+            cosigner ? (this_cosignature_was_valid ? "valid" : "invalid")
+                     : "unknown cosigner";
+        delegate->DebugLog(std::string("VerifyMTC: cosignature ") +
+                           cosigner_id_text + " " + cosignature_result_string);
       }
     }
 
diff --git a/pki/verify_certificate_chain.h b/pki/verify_certificate_chain.h
index cdaa646..dbc99a1 100644
--- a/pki/verify_certificate_chain.h
+++ b/pki/verify_certificate_chain.h
@@ -124,6 +124,15 @@
       const MTCAnchor* mtc_anchor,
       std::vector<std::vector<uint8_t>> valid_additional_cosigners) = 0;
 
+  // This is called during verification or path building to decide if debug
+  // logs will be sent to the delegate. No calls to DebugLog (below) will be
+  // made unless this returns true.
+  virtual bool IsDebugLogEnabled() = 0;
+
+  // This is called to send a debug log string `msg` to the delegate. These are
+  // only called if IsDebugLogEnabled (above) returns true.
+  virtual void DebugLog(std::string_view msg) = 0;
+
   virtual ~VerifyCertificateChainDelegate();
 };