Log request, response and linked data 39/314439/7
authorKrzysztof Malysa <k.malysa@samsung.com>
Thu, 11 Jul 2024 13:15:05 +0000 (15:15 +0200)
committerKrzysztof Malysa <k.malysa@samsung.com>
Tue, 16 Jul 2024 14:59:02 +0000 (16:59 +0200)
Change-Id: Ibd69c54d781bb50792fab7af26a83de8c4676b03

srcs/request_handler.cpp
srcs/request_handler.h

index ecae4c40dfa104fe567a26654c127bc05ba5ee06..928d4e42a4d1d83db8957c1a11157ee95ce4ec71 100644 (file)
@@ -15,6 +15,7 @@
  */
 
 #include "log/log.h"
+#include "lowercase_hex_string_of.h"
 #include "request_handler.h"
 
 #include <chrono>
 #include <future>
 #include <pthread.h>
 
+namespace {
+
+#ifdef BUILD_TYPE_DEBUG
+std::string ToStr(const char *str)
+{
+    if (!str)
+        return "null";
+    std::string res = "\"";
+    res += str;
+    res += '"';
+    return res;
+}
+
+std::string ToStr(wauthn_const_buffer_s *wcb)
+{
+    if (!wcb)
+        return "null";
+
+    std::string str = "\"";
+    str.append(wcb->data, wcb->data + wcb->size);
+    str += '"';
+    return str;
+}
+
+std::string ToHexStr(wauthn_const_buffer_s *wcb)
+{
+    return wcb ? LowercaseHexStringOf(BufferView{wcb->data, wcb->size}) : "null";
+}
+
+std::string ToStr(wauthn_cose_algorithm_e alg)
+{
+    switch (alg) {
+    case WAUTHN_COSE_ALGORITHM_ECDSA_P256_WITH_SHA256: return "ES256";
+    case WAUTHN_COSE_ALGORITHM_ECDSA_P384_WITH_SHA384: return "ES384";
+    case WAUTHN_COSE_ALGORITHM_ECDSA_P521_WITH_SHA512: return "ES512";
+    case WAUTHN_COSE_ALGORITHM_EDDSA: return "EdDSA";
+    case WAUTHN_COSE_ALGORITHM_RSA_PSS_WITH_SHA256: return "PS256";
+    case WAUTHN_COSE_ALGORITHM_RSA_PSS_WITH_SHA384: return "PS384";
+    case WAUTHN_COSE_ALGORITHM_RSA_PSS_WITH_SHA512: return "PS512";
+    case WAUTHN_COSE_ALGORITHM_RSASSA_PKCS1_V1_5_WITH_SHA256: return "RS256";
+    case WAUTHN_COSE_ALGORITHM_RSASSA_PKCS1_V1_5_WITH_SHA384: return "RS384";
+    case WAUTHN_COSE_ALGORITHM_RSASSA_PKCS1_V1_5_WITH_SHA512: return "RS512";
+    }
+    return std::to_string(alg);
+}
+
+std::string ToStr(wauthn_pubkey_cred_type_e pct)
+{
+    switch (pct) {
+    case PCT_PUBLIC_KEY: return "public-key";
+    }
+    return std::to_string(pct);
+}
+
+std::string ToStr(wauthn_authenticator_attachment_e authenticatorAttachment)
+{
+    switch (authenticatorAttachment) {
+    case AA_NONE: return "none";
+    case AA_PLATFORM: return "platform";
+    case AA_CROSS_PLATFORM: return "cross-platform";
+    }
+    return std::to_string(authenticatorAttachment);
+}
+
+std::string ToStr(wauthn_resident_key_requirement_e residentKeyRequirement)
+{
+    switch (residentKeyRequirement) {
+    case RKR_NONE: return "none";
+    case RKR_DISCOURAGED: return "discouraged";
+    case RKR_PREFERRED: return "preferred";
+    case RKR_REQUIRED: return "required";
+    }
+    return std::to_string(residentKeyRequirement);
+}
+
+std::string ToStr(wauthn_user_verification_requirement_e userVerificationRequirement)
+{
+    switch (userVerificationRequirement) {
+    case UVR_NONE: return "none";
+    case UVR_REQUIRED: return "required";
+    case UVR_PREFERRED: return "preferred";
+    case UVR_DISCOURAGED: return "discouraged";
+    }
+    return std::to_string(userVerificationRequirement);
+}
+
+std::string ToStr(wauthn_pubkey_cred_hint_e credHint)
+{
+    switch (credHint) {
+    case PCH_NONE: return "none";
+    case PCH_SECURITY_KEY: return "security-key";
+    case PCH_CLIENT_DEVICE: return "client-device";
+    case PCH_HYBRID: return "hybrid";
+    }
+    return std::to_string(credHint);
+}
+
+std::string ToStr(wauthn_attestation_pref_e attestationPref)
+{
+    switch (attestationPref) {
+    case AP_NONE: return "none";
+    case AP_INDIRECT: return "indirect";
+    case AP_DIRECT: return "direct";
+    case AP_ENTERPRISE: return "enterprise";
+    }
+    return std::to_string(attestationPref);
+}
+
+std::string TransportsToStr(unsigned int transports)
+{
+    if (transports == WAUTHN_TRANSPORT_NONE)
+        return "none";
+
+    struct TransportInfo {
+        wauthn_authenticator_transport_e mask;
+        const char *name;
+    };
+
+    static constexpr auto TRANSPORTS = std::array{
+        TransportInfo{WAUTHN_TRANSPORT_USB,       "usb"       },
+        TransportInfo{WAUTHN_TRANSPORT_NFC,       "nfc"       },
+        TransportInfo{WAUTHN_TRANSPORT_BLE,       "ble"       },
+        TransportInfo{WAUTHN_TRANSPORT_SMARTCARD, "smart-card"},
+        TransportInfo{WAUTHN_TRANSPORT_HYBRID,    "hybrid"    },
+        TransportInfo{WAUTHN_TRANSPORT_INTERNAL,  "internal"  },
+    };
+
+    std::string transportsStr;
+    auto transportsLeft = transports;
+    constexpr auto SEPARATOR = std::string_view{" | "};
+    for (const auto &ti : TRANSPORTS) {
+        if (transports & ti.mask) {
+            transportsStr += ti.name;
+            transportsStr += SEPARATOR;
+            transportsLeft &= ~ti.mask;
+        }
+    }
+    if (transportsLeft != 0)
+        transportsStr += std::to_string(transportsLeft);
+    else
+        transportsStr.resize(transportsStr.size() - SEPARATOR.size());
+
+    return transportsStr;
+}
+
+void LogExtensions(const char *prefix1,
+                   const char *prefix2,
+                   const wauthn_authentication_exts_s *extensions)
+{
+    if (!extensions)
+        LogDebug(prefix1 << prefix2 << "->extensions: null");
+    else {
+        LogDebug(prefix1 << prefix2 << "->extensions->size: " << extensions->size);
+        for (size_t i = 0; i < extensions->size; ++i) {
+            LogDebug(prefix1 << prefix2 << "->extensions[" << i
+                             << "]: " << ToStr(extensions->extensions[i].extension_id) << " -> "
+                             << ToHexStr(extensions->extensions[i].extension_value));
+        }
+    }
+}
+#endif
+
+} // namespace
+
 RequestHandler &RequestHandler::Instance() noexcept
 {
     static RequestHandler handler;
@@ -76,6 +241,240 @@ void RequestHandler::StopTimeoutThread(std::thread &&timeoutThread,
     }
 }
 
+template <RequestKind REQUEST_KIND>
+void RequestHandler::LogRequest(
+    const wauthn_client_data_s &clientData,
+    const std::conditional_t<REQUEST_KIND == RequestKind::MC,
+                             wauthn_pubkey_cred_creation_options_s,
+                             wauthn_pubkey_cred_request_options_s> &options)
+
+{
+#ifdef BUILD_TYPE_DEBUG
+    static constexpr const char *REQUEST_KIND_PREFIX =
+        REQUEST_KIND == RequestKind::MC ? "MC: " : "GA: ";
+    if (!clientData.client_data_json)
+        LogDebug(REQUEST_KIND_PREFIX << "client_data->client_data_json: null");
+    else {
+        LogDebug(REQUEST_KIND_PREFIX
+                 << "client_data->client_data_json: " << ToHexStr(clientData.client_data_json)
+                 << " == " << ToStr(clientData.client_data_json));
+    }
+
+    LogDebug(REQUEST_KIND_PREFIX << "client_data->hash_alg: " << [&]() -> std::string {
+        switch (clientData.hash_alg) {
+        case WAUTHN_HASH_ALGORITHM_SHA_256: return "SHA-256";
+        }
+        return std::to_string(clientData.hash_alg);
+    }());
+
+    if constexpr (REQUEST_KIND == RequestKind::MC) {
+        if (!options.rp)
+            LogDebug(REQUEST_KIND_PREFIX << "options->rp: null");
+        else {
+            LogDebug(REQUEST_KIND_PREFIX << "options->rp->name: " << ToStr(options.rp->name));
+            LogDebug(REQUEST_KIND_PREFIX << "options->rp->id: " << ToStr(options.rp->id));
+        }
+
+        if (!options.user)
+            LogDebug(REQUEST_KIND_PREFIX << "options->user: null");
+        else {
+            LogDebug(REQUEST_KIND_PREFIX << "options->user->name: " << ToStr(options.user->name));
+            LogDebug(REQUEST_KIND_PREFIX << "options->user->id: " << ToHexStr(options.user->id));
+            LogDebug(REQUEST_KIND_PREFIX << "options->user->display_name: "
+                                         << ToStr(options.user->display_name));
+        }
+
+        if (!options.pubkey_cred_params)
+            LogDebug(REQUEST_KIND_PREFIX << "options->pubkey_cred_params: null");
+        else {
+            LogDebug(REQUEST_KIND_PREFIX << "options->pubkey_cred_params->size: "
+                                         << options.pubkey_cred_params->size);
+            for (size_t i = 0; i < options.pubkey_cred_params->size; ++i) {
+                LogDebug(REQUEST_KIND_PREFIX
+                         << "options->pubkey_cred_params->params[" << i
+                         << "]: {type: " << ToStr(options.pubkey_cred_params->params[i].type)
+                         << ", alg: " << ToStr(options.pubkey_cred_params->params[i].alg) << "}");
+            }
+        }
+    }
+
+    LogDebug(REQUEST_KIND_PREFIX << "options->timeout: " << options.timeout << " ms");
+
+    static constexpr auto logCredDescriptors =
+        [](const char *fieldName, wauthn_pubkey_cred_descriptors_s *credDescriptors) {
+            if (!credDescriptors)
+                LogDebug(REQUEST_KIND_PREFIX << "options->" << fieldName << ": null");
+            else {
+                LogDebug(REQUEST_KIND_PREFIX << "options->" << fieldName
+                                             << "->size: " << credDescriptors->size);
+                for (size_t i = 0; i < credDescriptors->size; ++i) {
+                    LogDebug(REQUEST_KIND_PREFIX
+                             << "options->" << fieldName << "->descriptors[" << i
+                             << "].type: " << ToStr(credDescriptors->descriptors[i].type));
+                    LogDebug(REQUEST_KIND_PREFIX
+                             << "options->" << fieldName << "->descriptors[" << i
+                             << "].id: " << ToHexStr(credDescriptors->descriptors[i].id));
+                    LogDebug(REQUEST_KIND_PREFIX
+                             << "options->" << fieldName << "->descriptors[" << i
+                             << "].transports: "
+                             << TransportsToStr(credDescriptors->descriptors[i].transports));
+                }
+            }
+        };
+
+    if constexpr (REQUEST_KIND == RequestKind::MC) {
+        logCredDescriptors("exclude_credentials", options.exclude_credentials);
+        if (!options.authenticator_selection)
+            LogDebug(REQUEST_KIND_PREFIX << "options->authenticator_selection: null");
+        else {
+            LogDebug(REQUEST_KIND_PREFIX << "options->authenticator_selection->attachment: "
+                                         << ToStr(options.authenticator_selection->attachment));
+            LogDebug(REQUEST_KIND_PREFIX << "options->authenticator_selection->resident_key: "
+                                         << ToStr(options.authenticator_selection->resident_key));
+            LogDebug(REQUEST_KIND_PREFIX
+                     << "options->authenticator_selection->require_resident_key: "
+                     << (options.authenticator_selection->require_resident_key ? "true" : "false"));
+            LogDebug(REQUEST_KIND_PREFIX
+                     << "options->authenticator_selection->user_verification: "
+                     << ToStr(options.authenticator_selection->user_verification));
+        }
+    } else {
+        LogDebug(REQUEST_KIND_PREFIX << "options->rpId: " << ToStr(options.rpId));
+        logCredDescriptors("allow_credentials", options.allow_credentials);
+        LogDebug(REQUEST_KIND_PREFIX << "options->user_verification: "
+                                     << ToStr(options.user_verification));
+    }
+
+    if (!options.hints)
+        LogDebug(REQUEST_KIND_PREFIX << "options->hints: null");
+    else {
+        LogDebug(REQUEST_KIND_PREFIX << "options->hints->size: " << options.hints->size);
+        for (size_t i = 0; i < options.hints->size; ++i)
+            LogDebug(REQUEST_KIND_PREFIX << "options->hints->hints[" << i
+                                         << "]: " << ToStr(options.hints->hints[i]));
+    }
+
+    LogDebug(REQUEST_KIND_PREFIX << "options->attestation: " << ToStr(options.attestation));
+
+    if (!options.attestation_formats)
+        LogDebug(REQUEST_KIND_PREFIX << "options->attestation_formats: null");
+    else {
+        LogDebug(REQUEST_KIND_PREFIX << "options->attestation_formats->size: "
+                                     << options.attestation_formats->size);
+        for (size_t i = 0; i < options.attestation_formats->size; ++i)
+            LogDebug(REQUEST_KIND_PREFIX
+                     << "options->attestation_formats->attestation_formats[" << i
+                     << "]: " << ToHexStr(options.attestation_formats->attestation_formats + i)
+                     << " == " << ToStr(options.attestation_formats->attestation_formats + i));
+    }
+
+    LogExtensions(REQUEST_KIND_PREFIX, "options", options.extensions);
+    LogLinkedDevice(REQUEST_KIND_PREFIX, "options->", options.linked_device);
+#else
+    (void)clientData;
+    (void)options;
+#endif // BUILD_TYPE_DEBUG
+}
+
+template void
+RequestHandler::LogRequest<RequestKind::MC>(const wauthn_client_data_s &clientData,
+                                            const wauthn_pubkey_cred_creation_options_s &options);
+
+template void
+RequestHandler::LogRequest<RequestKind::GA>(const wauthn_client_data_s &clientData,
+                                            const wauthn_pubkey_cred_request_options_s &options);
+
+template <RequestKind REQUEST_KIND>
+void RequestHandler::LogResponse(const decltype(ForCallbacks<REQUEST_KIND>::ca) &ca)
+{
+#ifdef BUILD_TYPE_DEBUG
+    static constexpr const char *RESPONSE_KIND_NAME =
+        REQUEST_KIND == RequestKind::MC ? "creation" : "assertion";
+
+    LogDebug(RESPONSE_KIND_NAME << "->id: " << ToStr(ca.id));
+    LogDebug(RESPONSE_KIND_NAME << "->type: " << ToStr(ca.type));
+    LogDebug(RESPONSE_KIND_NAME << "->rawId: " << ToHexStr(ca.rawId));
+
+    if (!ca.response)
+        LogDebug(RESPONSE_KIND_NAME << "->response: null");
+    else {
+        LogDebug(RESPONSE_KIND_NAME
+                 << "->response->client_data_json: " << ToHexStr(ca.response->client_data_json)
+                 << " == " << ToStr(ca.response->client_data_json));
+        if constexpr (REQUEST_KIND == RequestKind::MC) {
+            LogDebug(RESPONSE_KIND_NAME << "->response->attestation_object: "
+                                        << ToHexStr(ca.response->attestation_object));
+            LogDebug(RESPONSE_KIND_NAME << "->response->transports: "
+                                        << TransportsToStr(ca.response->transports));
+        }
+
+        LogDebug(RESPONSE_KIND_NAME << "->response->authenticator_data: "
+                                    << ToHexStr(ca.response->authenticator_data));
+
+        if constexpr (REQUEST_KIND == RequestKind::MC) {
+            LogDebug(RESPONSE_KIND_NAME << "->response->subject_pubkey_info: "
+                                        << ToHexStr(ca.response->subject_pubkey_info));
+            LogDebug(RESPONSE_KIND_NAME << "->response->pubkey_alg: "
+                                        << ToStr(ca.response->pubkey_alg));
+        } else {
+            LogDebug(RESPONSE_KIND_NAME << "->response->signature: "
+                                        << ToHexStr(ca.response->signature));
+            LogDebug(RESPONSE_KIND_NAME << "->response->user_handle: "
+                                        << ToHexStr(ca.response->user_handle));
+            LogDebug(RESPONSE_KIND_NAME << "->response->attestation_object: "
+                                        << ToHexStr(ca.response->attestation_object));
+        }
+    }
+
+    LogDebug(RESPONSE_KIND_NAME << "->authenticator_attachment: "
+                                << ToStr(ca.authenticator_attachment));
+    LogExtensions(RESPONSE_KIND_NAME, "", ca.extensions);
+    LogLinkedDevice(RESPONSE_KIND_NAME, "->", ca.linked_device);
+#else
+    (void)ca;
+#endif // BUILD_TYPE_DEBUG
+}
+
+template void
+RequestHandler::LogResponse<RequestKind::MC>(const decltype(ForCallbacks<RequestKind::MC>::ca) &);
+
+template void
+RequestHandler::LogResponse<RequestKind::GA>(const decltype(ForCallbacks<RequestKind::GA>::ca) &);
+
+void RequestHandler::LogLinkedDevice(const char *prefix1,
+                                     const char *prefix2,
+                                     const wauthn_hybrid_linked_data_s *linkedDevice)
+{
+#ifdef BUILD_TYPE_DEBUG
+    if (!linkedDevice)
+        LogDebug(prefix1 << prefix2 << "linked_device: null");
+    else {
+        LogDebug(prefix1 << prefix2
+                         << "linked_device->contact_id: " << ToHexStr(linkedDevice->contact_id));
+        LogDebug(prefix1 << prefix2
+                         << "linked_device->link_id: " << ToHexStr(linkedDevice->link_id));
+        LogDebug(prefix1 << prefix2
+                         << "linked_device->link_secret: " << ToHexStr(linkedDevice->link_secret));
+        LogDebug(prefix1 << prefix2 << "linked_device->authenticator_pubkey: "
+                         << ToHexStr(linkedDevice->authenticator_pubkey));
+        LogDebug(prefix1 << prefix2 << "linked_device->authenticator_name: "
+                         << ToHexStr(linkedDevice->authenticator_name)
+                         << " == " << ToStr(linkedDevice->authenticator_name));
+        LogDebug(prefix1 << prefix2
+                         << "linked_device->signature: " << ToHexStr(linkedDevice->signature));
+        LogDebug(prefix1 << prefix2 << "linked_device->tunnel_server_domain: "
+                         << ToHexStr(linkedDevice->tunnel_server_domain)
+                         << " == " << ToStr(linkedDevice->tunnel_server_domain));
+        LogDebug(prefix1 << prefix2 << "linked_device->identity_key: "
+                         << ToHexStr(linkedDevice->identity_key));
+    }
+#else
+    (void)prefix1;
+    (void)prefix2;
+    (void)linkedDevice;
+#endif // BUILD_TYPE_DEBUG
+}
+
 wauthn_hybrid_linked_data_s *
 RequestHandler::AssignAndGetLinkedData(ForCallbacksCommon &forCallbacks) noexcept
 {
index 70fc3b9118d8499a438a1ab3846ed4c48e3746fb..e3969115873ef697ae93cebfb79ec2c337cfc3fd 100644 (file)
@@ -19,6 +19,7 @@
 #include "base64.h"
 #include "common.h"
 #include "exception.h"
+#include "log/log.h"
 #include "qr_transaction.h"
 #include "state_assisted_transaction.h"
 #include "to_wauthn_const_buff.h"
@@ -28,7 +29,9 @@
 #include <exception>
 #include <future>
 #include <mutex>
+#include <string>
 #include <thread>
+#include <type_traits>
 #include <webauthn-types.h>
 
 enum class RequestKind {
@@ -163,6 +166,7 @@ public:
             result = WAUTHN_ERROR_NOT_SUPPORTED; // CTAP 2.2 does not specify any field for this
         } else {
             try {
+                LogRequest<REQUEST_KIND>(*clientData, *request.options);
                 if (request.options->linked_device) {
                     transaction = &stateAssistedTransaction;
                     stateAssistedTransaction.Initialize(Hint{Request<REQUEST_KIND>::HINT});
@@ -251,10 +255,10 @@ public:
                 transaction->ProcessFollowingUpdateMsgs([&](UpdateMessage &&upMsg) {
                     forCallbacks.upMsg = std::move(upMsg);
                     try {
+                        auto linkedData = AssignAndGetLinkedData(forCallbacks);
+                        LogLinkedDevice("", "", linkedData);
                         request.callbacks->linked_data_callback(
-                            AssignAndGetLinkedData(forCallbacks),
-                            WAUTHN_ERROR_NONE_AND_WAIT,
-                            request.callbacks->user_data);
+                            linkedData, WAUTHN_ERROR_NONE_AND_WAIT, request.callbacks->user_data);
                     } catch (const std::exception &e) {
                         TRY_LOG_ERROR("linked_data_callback has thrown an exception: " << e.what());
                         throw; // safe - it will be caught below
@@ -309,9 +313,9 @@ private:
     }
 
     template <RequestKind REQUEST_KIND, class TransactionResult>
-    void ProcessTransactionResult(wauthn_const_buffer_s *clientDataJson,
-                                  ForCallbacks<REQUEST_KIND> &forCallbacks,
-                                  TransactionResult &&transactionRes) // NOLINT
+    static void ProcessTransactionResult(wauthn_const_buffer_s *clientDataJson,
+                                         ForCallbacks<REQUEST_KIND> &forCallbacks,
+                                         TransactionResult &&transactionRes) // NOLINT
     {
         forCallbacks.upMsg = std::move(transactionRes.ctapResult.upMsg);
         forCallbacks.clientPlatformPrivKey = std::move(transactionRes.clientPlatformPrivKey);
@@ -375,16 +379,33 @@ private:
         forCallbacks.ca.authenticator_attachment = AA_CROSS_PLATFORM;
         forCallbacks.ca.extensions = nullptr;
         forCallbacks.ca.linked_device = AssignAndGetLinkedData(forCallbacks);
+
+        LogResponse<REQUEST_KIND>(forCallbacks.ca);
     }
 
+    template <RequestKind REQUEST_KIND>
+    static void LogRequest(const wauthn_client_data_s &clientData,
+                           const std::conditional_t<REQUEST_KIND == RequestKind::MC,
+                                                    wauthn_pubkey_cred_creation_options_s,
+                                                    wauthn_pubkey_cred_request_options_s> &options);
+
+    template <RequestKind REQUEST_KIND>
+    static void LogResponse(const decltype(ForCallbacks<REQUEST_KIND>::ca) &ca);
+
+    static void LogLinkedDevice(const char *prefix1,
+                                const char *prefix2,
+                                const wauthn_hybrid_linked_data_s *linkedDevice);
+
     template <class T>
-    void Assign(wauthn_const_buffer_s *&dest, wauthn_const_buffer_s &storageVar, T &&value) noexcept
+    static void
+    Assign(wauthn_const_buffer_s *&dest, wauthn_const_buffer_s &storageVar, T &&value) noexcept
     {
         storageVar = ToWauthnConstBuff(std::forward<T>(value));
         dest = &storageVar;
     }
 
-    wauthn_hybrid_linked_data_s *AssignAndGetLinkedData(ForCallbacksCommon &forCallbacks) noexcept;
+    static wauthn_hybrid_linked_data_s *
+    AssignAndGetLinkedData(ForCallbacksCommon &forCallbacks) noexcept;
 
     RequestHandler() noexcept;