Add more logging around attachment queueing

js/background.js

@@ -398,6 +398,7 @@
       },
 
       shutdown: async () => {
+        window.log.info('background/shutdown');
         // Stop background processing
         window.Signal.AttachmentDownloads.stop();
         if (idleDetector) {

js/models/messages.js

@@ -1722,12 +1722,19 @@
 
     // Receive logic
     async queueAttachmentDownloads() {
+      const attachmentsToQueue = this.get('attachments') || [];
       const messageId = this.id;
       let count = 0;
       let bodyPending;
 
+      window.log.info(
+        `Queueing ${
+          attachmentsToQueue.length
+        } attachment downloads for message ${this.idForLogging()}`
+      );
+
       const [longMessageAttachments, normalAttachments] = _.partition(
-        this.get('attachments') || [],
+        attachmentsToQueue,
         attachment =>
           attachment.contentType === Whisper.Message.LONG_MESSAGE_CONTENT_TYPE
       );
@@ -1737,6 +1744,13 @@
           `Received more than one long message attachment in message ${this.idForLogging()}`
         );
       }
+
+      window.log.info(
+        `Queueing ${
+          longMessageAttachments.length
+        } long message attachment downloads for message ${this.idForLogging()}`
+      );
+
       if (longMessageAttachments.length > 0) {
         count += 1;
         bodyPending = true;
@@ -1750,6 +1764,11 @@
         );
       }
 
+      window.log.info(
+        `Queueing ${
+          normalAttachments.length
+        } normal attachment downloads for message ${this.idForLogging()}`
+      );
       const attachments = await Promise.all(
         normalAttachments.map((attachment, index) => {
           count += 1;
@@ -1761,8 +1780,14 @@
         })
       );
 
+      const previewsToQueue = this.get('preview') || [];
+      window.log.info(
+        `Queueing ${
+          previewsToQueue.length
+        } preview attachment downloads for message ${this.idForLogging()}`
+      );
       const preview = await Promise.all(
-        (this.get('preview') || []).map(async (item, index) => {
+        previewsToQueue.map(async (item, index) => {
           if (!item.image) {
             return item;
           }
@@ -1779,8 +1804,14 @@
         })
       );
 
+      const contactsToQueue = this.get('contact') || [];
+      window.log.info(
+        `Queueing ${
+          contactsToQueue.length
+        } contact attachment downloads for message ${this.idForLogging()}`
+      );
       const contact = await Promise.all(
-        (this.get('contact') || []).map(async (item, index) => {
+        contactsToQueue.map(async (item, index) => {
           if (!item.avatar || !item.avatar.avatar) {
             return item;
           }
@@ -1804,7 +1835,14 @@
       );
 
       let quote = this.get('quote');
-      if (quote && quote.attachments && quote.attachments.length) {
+      const quoteAttachmentsToQueue =
+        quote && quote.attachments ? quote.attachments : [];
+      window.log.info(
+        `Queueing ${
+          quoteAttachmentsToQueue.length
+        } quote attachment downloads for message ${this.idForLogging()}`
+      );
+      if (quoteAttachmentsToQueue.length > 0) {
         quote = {
           ...quote,
           attachments: await Promise.all(
@@ -1834,6 +1872,9 @@
 
       let group = this.get('group_update');
       if (group && group.avatar) {
+        window.log.info(
+          `Queueing group avatar download for message ${this.idForLogging()}`
+        );
         count += 1;
         group = {
           ...group,
@@ -1847,6 +1888,9 @@
 
       let sticker = this.get('sticker');
       if (sticker) {
+        window.log.info(
+          `Queueing sticker download for message ${this.idForLogging()}`
+        );
         count += 1;
         const { packId, stickerId, packKey } = sticker;
 
@@ -1891,6 +1935,10 @@
         };
       }
 
+      window.log.info(
+        `Queued ${count} total attachment downloads for message ${this.idForLogging()}`
+      );
+
       if (count > 0) {
         this.set({
           bodyPending,

js/modules/attachment_downloads.js

@@ -57,6 +57,7 @@ async function start(options = {}) {
     throw new Error('attachment_downloads/start: logger must be provided!');
   }
 
+  logger.info('attachment_downloads/start: enabling');
   enabled = true;
   await resetAttachmentDownloadPending();
 
@@ -64,6 +65,7 @@ async function start(options = {}) {
 }
 
 async function stop() {
+  logger.info('attachment_downloads/stop: disabling');
   enabled = false;
   if (timeout) {
     clearTimeout(timeout);
@@ -121,6 +123,7 @@ async function _tick() {
 
 async function _maybeStartJob() {
   if (!enabled) {
+    logger.info('attachment_downloads/_maybeStartJob: not enabled, returning');
     return;
   }
 
@@ -166,6 +169,8 @@ async function _runJob(job) {
       );
     }
 
+    logger.info(`attachment_downloads/_runJob for job id ${id}`);
+
     const found =
       MessageController.getById(messageId) ||
       (await getMessageById(messageId, {
@@ -261,6 +266,7 @@ async function _runJob(job) {
 
 async function _finishJob(message, id) {
   if (message) {
+    logger.info(`attachment_downloads/_finishJob for job id: ${id}`);
     await saveMessage(message.attributes, {
       Message: Whisper.Message,
     });