chore: clean up logging

Winston handles .error(message, err) okay, but not .error(err) by itself. For reability we also
want to make sure the provided message ends with a space so that the concatenated message from the
error is separate.

Due to a winston regression introduced in 3.x, we cannot pass other meta information after the error
without passing error.message and error.stack explicitly. This means we may lose additional error
properties. We cannot destructure the error either (non-iterable properties).

A better fix would be to write a custom log formatter that is error-aware. There are a few examples
on GitHub, but none that looked straightforward. We don't want to break JSON logging and parsing.

src/server/api/lib/nexmo.js

@@ -191,7 +191,7 @@ async function handleIncomingMessage(message) {
     !message.hasOwnProperty("text") ||
     !message.hasOwnProperty("messageId")
   ) {
-    logger.error(`This is not an incoming message: ${JSON.stringify(message)}`);
+    logger.error("This is not an incoming message", { payload: message });
   }
 
   const { to, msisdn, concat } = message;

src/server/api/lib/twilio.js

@@ -175,8 +175,8 @@ async function sendMessage(message, organizationId, trx = r.knex) {
 
   if (!twilio) {
     logger.error(
-      "cannot actually send SMS message -- twilio is not fully configured:",
-      message.id
+      "cannot actually send SMS message -- twilio is not fully configured",
+      { messageId: message.id }
     );
     if (message.id) {
       await trx("message")
@@ -242,7 +242,7 @@ async function sendMessage(message, organizationId, trx = r.knex) {
       let hasError = false;
       if (err) {
         hasError = true;
-        logger.error(`Error sending message ${message.id}`, err);
+        logger.error(`Error sending message ${message.id}: `, err);
         const jsonErr = typeof err === "object" ? err : { error: err };
         messageToSave.service_response = appendServiceResponse(
           messageToSave.service_response,
@@ -352,7 +352,7 @@ async function handleIncomingMessage(message) {
     !message.hasOwnProperty("Body") ||
     !message.hasOwnProperty("MessageSid")
   ) {
-    logger.error(`This is not an incoming message: ${JSON.stringify(message)}`);
+    logger.error("This is not an incoming message", { payload: message });
   }
 
   const { From, To, MessageSid } = message;

src/server/models/cacheable_queries/opt-out.js

@@ -102,7 +102,7 @@ export const optOutCache = {
         cell
       });
     } catch (error) {
-      logger.error("Error creating opt-out", error);
+      logger.error("Error creating opt-out: ", error);
     }
 
     // update all organization's active campaigns as well

src/server/routes/assemble-numbers.js

@@ -13,8 +13,11 @@ router.post(
       await assembleNumbers.handleIncomingMessage(req.body);
       return res.status(200).send({ success: true });
     } catch (err) {
-      logger.error("Error handling incoming assemble numbers message", {
-        err,
+      logger.error({
+        message: `Error handling incoming assemble numbers message: ${
+          err.message
+        }`,
+        stack: err.stack,
         body: req.body
       });
       res.status(500).send({ error: err.message });
@@ -31,7 +34,7 @@ router.post(
       await assembleNumbers.handleDeliveryReport(req.body);
       return res.status(200).send({ success: true });
     } catch (err) {
-      logger.error("Error handling assemble numbers message report", err);
+      logger.error("Error handling assemble numbers message report: ", err);
       res.status(500).send({ error: err.message });
     }
   }

src/server/routes/twilio.js

@@ -14,7 +14,7 @@ router.post("/twilio", headerValidator, async (req, res) => {
     res.writeHead(200, { "Content-Type": "text/xml" });
     res.end(resp.toString());
   } catch (ex) {
-    logger.error("Error handling incoming twilio message", ex);
+    logger.error("Error handling incoming twilio message: ", ex);
     res.status(500).send(ex.message);
   }
 });
@@ -26,7 +26,7 @@ router.post("/twilio-message-report", headerValidator, async (req, res) => {
     res.writeHead(200, { "Content-Type": "text/xml" });
     return res.end(resp.toString());
   } catch (exc) {
-    logger.error("Error handling twilio message report", exc);
+    logger.error("Error handling twilio message report: ", exc);
     res.status(500).send(exc.message);
   }
 });

src/workers/cron/deliverability-report.js

@@ -267,6 +267,6 @@ main()
     process.exit(0);
   })
   .catch(error => {
-    logger.error(error);
+    logger.error("Error creating deliverability report: ", error);
     process.exit(1);
   });

src/workers/cron/release-old-unsent-messages.js

@@ -40,6 +40,6 @@ main()
     process.exit(0);
   })
   .catch(error => {
-    logger.error(error);
+    logger.error("Error releasing old unsent messages: ", error);
     process.exit(1);
   });

src/workers/cron/slack-teams-update.js

@@ -99,6 +99,6 @@ const fetchAllChannels = async (acc = [], next_cursor) => {
 main()
   .then(() => process.exit(0))
   .catch(error => {
-    logger.error(error);
+    logger.error("Error updating Slack teams: ", error);
     process.exit(1);
   });

src/workers/job-processes.js

@@ -49,7 +49,7 @@ export async function processJobs() {
       // clear out stuck jobs
       await clearOldJobs(twoMinutesAgo);
     } catch (ex) {
-      logger.error("Error processing jobs", ex);
+      logger.error("Error processing jobs: ", ex);
     }
   }
 }
@@ -65,7 +65,7 @@ export async function checkMessageQueue() {
       await sleep(10000);
       processSqsMessages();
     } catch (ex) {
-      logger.error("Error checking message queue", ex);
+      logger.error("Error checking message queue: ", ex);
     }
   }
 }
@@ -84,7 +84,7 @@ const messageSenderCreator = (subQuery, defaultStatus) => {
         await sleep(delay);
         await sendMessages(subQuery, defaultStatus);
       } catch (ex) {
-        logger.error("Error sending messages from messageSender", ex);
+        logger.error("Error sending messages from messageSender: ", ex);
       }
     }
   };
@@ -168,7 +168,7 @@ export async function handleIncomingMessages() {
         await handleIncomingMessageParts();
       }
     } catch (ex) {
-      logger.error("Error at handleIncomingMessages", ex);
+      logger.error("Error at handleIncomingMessages: ", ex);
     }
   }
 }