From 09d22925578c943ac7835206ea9d3be3398a8e7d Mon Sep 17 00:00:00 2001
From: Yarmo Mackenbach <yarmo@yarmo.eu>
Date: Fri, 22 Sep 2023 09:48:55 +0200
Subject: [PATCH] feat: add logging to openpgp profiles

---
 src/index.js                  |  2 +-
 src/server/openpgpProfiles.js | 31 +++++++++++++++++++++++++++++--
 2 files changed, 30 insertions(+), 3 deletions(-)

diff --git a/src/index.js b/src/index.js
index f99b1d4..f583006 100644
--- a/src/index.js
+++ b/src/index.js
@@ -62,7 +62,7 @@ app.use((req, res, next) => {
   httpContext.set('requestPath', req.path)
   httpContext.set('requestIp', req.ip)
 
-  logger.info(`Handle a request`,
+  logger.info('Handle a request',
     { component: 'http_server', action: 'request' })
 
   next()
diff --git a/src/server/openpgpProfiles.js b/src/server/openpgpProfiles.js
index 17a9990..b6605e7 100644
--- a/src/server/openpgpProfiles.js
+++ b/src/server/openpgpProfiles.js
@@ -46,6 +46,9 @@ if (process.env.ENABLE_EXPERIMENTAL_CACHE) {
 const fetchWKD = (id) => {
   return new Promise((resolve, reject) => {
     (async () => {
+      logger.debug('Fetching an OpenPGP profile via WKD',
+        { component: 'wkd_profile_fetcher', action: 'start', profile_id: id })
+
       let publicKey = null
       let profile = null
       let fetchURL = null
@@ -83,7 +86,10 @@ const fetchWKD = (id) => {
               return null
             }
           })
-        } catch (e) {
+        } catch (errorAdvanced) {
+          logger.debug('Failed to fetch an OpenPGP profile via WKD (advanced URL)',
+            { component: 'hkp_profile_fetcher', action: 'failure', profile_id: id, error: errorAdvanced.message })
+
           try {
             plaintext = await got(urlDirect).then((response) => {
               if (response.statusCode === 200) {
@@ -93,7 +99,10 @@ const fetchWKD = (id) => {
                 return null
               }
             })
-          } catch (error) {
+          } catch (errorDirect) {
+            logger.debug('Failed to fetch an OpenPGP profile via WKD (direct URL)',
+              { component: 'hkp_profile_fetcher', action: 'failure', profile_id: id, error: errorDirect.message })
+
             return reject(new Error('No public keys could be fetched using WKD'))
           }
         }
@@ -107,6 +116,9 @@ const fetchWKD = (id) => {
             binaryKey: plaintext
           })
         } catch (error) {
+          logger.debug('Failed to fetch an OpenPGP profile via WKD (reading key)',
+            { component: 'hkp_profile_fetcher', action: 'failure', profile_id: id, error: error.message })
+
           return reject(new Error('No public keys could be read from the data fetched using WKD'))
         }
 
@@ -117,6 +129,9 @@ const fetchWKD = (id) => {
         try {
           profile = await doipjs.openpgp.parsePublicKey(publicKey)
         } catch (error) {
+          logger.debug('Failed to fetch an OpenPGP profile via WKD (parsing key)',
+            { component: 'hkp_profile_fetcher', action: 'failure', profile_id: id, error: error.message })
+
           return reject(new Error('No public keys could be fetched using WKD'))
         }
 
@@ -132,6 +147,9 @@ const fetchWKD = (id) => {
           { component: 'openpgp_cache', action: 'store_wkd' })
       }
 
+      logger.debug('Fetched an OpenPGP profile via WKD',
+        { component: 'wkd_profile_fetcher', action: 'done', profile_id: id })
+
       resolve(profile)
     })()
   })
@@ -140,6 +158,9 @@ const fetchWKD = (id) => {
 const fetchHKP = (id, keyserverDomain) => {
   return new Promise((resolve, reject) => {
     (async () => {
+      logger.debug('Fetching an OpenPGP profile via HKP',
+        { component: 'hkp_profile_fetcher', action: 'start', profile_id: id, keyserver_domain: keyserverDomain || '' })
+
       let profile = null
       let fetchURL = null
 
@@ -174,6 +195,9 @@ const fetchHKP = (id, keyserverDomain) => {
         try {
           profile = await doipjs.openpgp.fetchHKP(query, keyserverDomainNormalized)
         } catch (error) {
+          logger.debug('Failed to fetch an OpenPGP profile via HKP',
+            { component: 'hkp_profile_fetcher', action: 'failure', profile_id: id, keyserver_domain: keyserverDomain || '', error: error.message })
+
           profile = null
         }
       }
@@ -193,6 +217,9 @@ const fetchHKP = (id, keyserverDomain) => {
           { component: 'openpgp_cache', action: 'store_hkp' })
       }
 
+      logger.debug('Fetched an OpenPGP profile via HKP',
+        { component: 'hkp_profile_fetcher', action: 'done', profile_id: id, keyserver_domain: keyserverDomain || '' })
+
       resolve(profile)
     })()
   })