From d0db6aa509e1a748474d530928e3dfbe96ec5166 Mon Sep 17 00:00:00 2001 From: Greyson Parrelli Date: Thu, 2 Aug 2018 09:50:36 -0400 Subject: [PATCH] Added more logging around message sending and attachment downloads. --- src/org/thoughtcrime/securesms/ConversationItem.java | 3 +++ .../thoughtcrime/securesms/components/ThumbnailView.java | 3 +++ .../requirements/NetworkBackoffRequirement.java | 6 ++++++ .../securesms/jobs/AttachmentDownloadJob.java | 7 ++++++- src/org/thoughtcrime/securesms/jobs/MmsSendJob.java | 7 ++++++- src/org/thoughtcrime/securesms/jobs/PushGroupSendJob.java | 5 +++++ src/org/thoughtcrime/securesms/jobs/PushMediaSendJob.java | 6 +++++- src/org/thoughtcrime/securesms/jobs/PushSendJob.java | 4 ++++ src/org/thoughtcrime/securesms/jobs/PushTextSendJob.java | 6 +++++- src/org/thoughtcrime/securesms/jobs/SendJob.java | 3 +++ .../securesms/jobs/ServiceOutageDetectionJob.java | 2 ++ src/org/thoughtcrime/securesms/jobs/SmsSendJob.java | 8 +++++--- 12 files changed, 53 insertions(+), 7 deletions(-) diff --git a/src/org/thoughtcrime/securesms/ConversationItem.java b/src/org/thoughtcrime/securesms/ConversationItem.java index ffcae68be9..f038c17809 100644 --- a/src/org/thoughtcrime/securesms/ConversationItem.java +++ b/src/org/thoughtcrime/securesms/ConversationItem.java @@ -856,12 +856,15 @@ public class ConversationItem extends LinearLayout private class AttachmentDownloadClickListener implements SlideClickListener { @Override public void onClick(View v, final Slide slide) { + Log.i(TAG, "onClick() for attachment download"); if (messageRecord.isMmsNotification()) { + Log.i(TAG, "Scheduling MMS attachment download"); ApplicationContext.getInstance(context) .getJobManager() .add(new MmsDownloadJob(context, messageRecord.getId(), messageRecord.getThreadId(), false)); } else { + Log.i(TAG, "Scheduling push attachment download"); DatabaseFactory.getAttachmentDatabase(context).setTransferState(messageRecord.getId(), slide.asAttachment(), AttachmentDatabase.TRANSFER_PROGRESS_STARTED); diff --git a/src/org/thoughtcrime/securesms/components/ThumbnailView.java b/src/org/thoughtcrime/securesms/components/ThumbnailView.java index 3541823e5d..ad8273cd8d 100644 --- a/src/org/thoughtcrime/securesms/components/ThumbnailView.java +++ b/src/org/thoughtcrime/securesms/components/ThumbnailView.java @@ -380,8 +380,11 @@ public class ThumbnailView extends FrameLayout { private class DownloadClickDispatcher implements View.OnClickListener { @Override public void onClick(View view) { + Log.i(TAG, "onClick() for download button"); if (downloadClickListener != null && slide != null) { downloadClickListener.onClick(view, slide); + } else { + Log.w(TAG, "Received a download button click, but unable to execute it. slide: " + String.valueOf(slide) + " downloadClickListener: " + String.valueOf(downloadClickListener)); } } } diff --git a/src/org/thoughtcrime/securesms/jobmanager/requirements/NetworkBackoffRequirement.java b/src/org/thoughtcrime/securesms/jobmanager/requirements/NetworkBackoffRequirement.java index f0ef170f93..5c5667cbc2 100644 --- a/src/org/thoughtcrime/securesms/jobmanager/requirements/NetworkBackoffRequirement.java +++ b/src/org/thoughtcrime/securesms/jobmanager/requirements/NetworkBackoffRequirement.java @@ -5,6 +5,7 @@ import android.support.annotation.NonNull; import org.thoughtcrime.securesms.jobmanager.Job; import org.thoughtcrime.securesms.jobmanager.dependencies.ContextDependent; +import org.thoughtcrime.securesms.logging.Log; import java.util.concurrent.TimeUnit; @@ -13,6 +14,8 @@ import java.util.concurrent.TimeUnit; */ public class NetworkBackoffRequirement implements Requirement, ContextDependent { + private static final String TAG = NetworkBackoffRequirement.class.getSimpleName(); + private static final long MAX_WAIT = TimeUnit.SECONDS.toMillis(30); private transient Context context; @@ -28,7 +31,10 @@ public class NetworkBackoffRequirement implements Requirement, ContextDependent @Override public void onRetry(@NonNull Job job) { + Log.i(TAG, "onRetry()"); + if (!(new NetworkRequirement(context).isPresent())) { + Log.i(TAG, "No network. Resetting run stats."); job.resetRunStats(); return; } diff --git a/src/org/thoughtcrime/securesms/jobs/AttachmentDownloadJob.java b/src/org/thoughtcrime/securesms/jobs/AttachmentDownloadJob.java index e3333145e8..6099abad0b 100644 --- a/src/org/thoughtcrime/securesms/jobs/AttachmentDownloadJob.java +++ b/src/org/thoughtcrime/securesms/jobs/AttachmentDownloadJob.java @@ -64,10 +64,13 @@ public class AttachmentDownloadJob extends MasterSecretJob implements Injectable @Override public void onAdded() { + Log.i(TAG, "onAdded() messageId: " + messageId + " partRowId: " + partRowId + " partUniqueId: " + partUniqueId + " manual: " + manual); } @Override public void onRun(MasterSecret masterSecret) throws IOException { + Log.i(TAG, "onRun() messageId: " + messageId + " partRowId: " + partRowId + " partUniqueId: " + partUniqueId + " manual: " + manual); + final AttachmentDatabase database = DatabaseFactory.getAttachmentDatabase(context); final AttachmentId attachmentId = new AttachmentId(partRowId, partUniqueId); final DatabaseAttachment attachment = database.getAttachment(attachmentId); @@ -96,6 +99,8 @@ public class AttachmentDownloadJob extends MasterSecretJob implements Injectable @Override public void onCanceled() { + Log.w(TAG, "onCanceled() messageId: " + messageId + " partRowId: " + partRowId + " partUniqueId: " + partUniqueId + " manual: " + manual); + final AttachmentId attachmentId = new AttachmentId(partRowId, partUniqueId); markFailed(messageId, attachmentId); } @@ -122,7 +127,7 @@ public class AttachmentDownloadJob extends MasterSecretJob implements Injectable database.insertAttachmentsForPlaceholder(messageId, attachmentId, stream); } catch (InvalidPartException | NonSuccessfulResponseCodeException | InvalidMessageException | MmsException e) { - Log.w(TAG, e); + Log.w(TAG, "Experienced exception while trying to download an attachment.", e); markFailed(messageId, attachmentId); } finally { if (attachmentFile != null) { diff --git a/src/org/thoughtcrime/securesms/jobs/MmsSendJob.java b/src/org/thoughtcrime/securesms/jobs/MmsSendJob.java index 25e7efc005..c203237efa 100644 --- a/src/org/thoughtcrime/securesms/jobs/MmsSendJob.java +++ b/src/org/thoughtcrime/securesms/jobs/MmsSendJob.java @@ -70,7 +70,7 @@ public class MmsSendJob extends SendJob { @Override public void onAdded() { - + Log.i(TAG, "onAdded() messageId: " + messageId); } @Override @@ -79,6 +79,8 @@ public class MmsSendJob extends SendJob { OutgoingMediaMessage message = database.getOutgoingMessage(messageId); try { + Log.i(TAG, "Sending message: " + messageId); + SendReq pdu = constructSendPdu(message); validateDestinations(message, pdu); @@ -89,6 +91,8 @@ public class MmsSendJob extends SendJob { database.markAsSent(messageId, false); markAttachmentsUploaded(messageId, message.getAttachments()); + + Log.i(TAG, "Sent message: " + messageId); } catch (UndeliverableMessageException | IOException e) { Log.w(TAG, e); database.markAsSentFailed(messageId); @@ -107,6 +111,7 @@ public class MmsSendJob extends SendJob { @Override public void onCanceled() { + Log.i(TAG, "onCanceled() messageId: " + messageId); DatabaseFactory.getMmsDatabase(context).markAsSentFailed(messageId); notifyMediaMessageDeliveryFailed(context, messageId); } diff --git a/src/org/thoughtcrime/securesms/jobs/PushGroupSendJob.java b/src/org/thoughtcrime/securesms/jobs/PushGroupSendJob.java index 3dccc7809b..77ef8fa1e6 100644 --- a/src/org/thoughtcrime/securesms/jobs/PushGroupSendJob.java +++ b/src/org/thoughtcrime/securesms/jobs/PushGroupSendJob.java @@ -76,6 +76,7 @@ public class PushGroupSendJob extends PushSendJob implements InjectableType { @Override public void onAdded() { + Log.i(TAG, "onAdded() messageId: " + messageId); } @Override @@ -86,6 +87,8 @@ public class PushGroupSendJob extends PushSendJob implements InjectableType { OutgoingMediaMessage message = database.getOutgoingMessage(messageId); try { + Log.i(TAG, "Sending message: " + messageId); + deliver(message, filterAddress == null ? null : Address.fromSerialized(filterAddress)); database.markAsSent(messageId, true); @@ -97,6 +100,8 @@ public class PushGroupSendJob extends PushSendJob implements InjectableType { .getExpiringMessageManager() .scheduleDeletion(messageId, true, message.getExpiresIn()); } + + Log.i(TAG, "Sent message: " + messageId); } catch (InvalidNumberException | RecipientFormattingException | UndeliverableMessageException e) { Log.w(TAG, e); database.markAsSentFailed(messageId); diff --git a/src/org/thoughtcrime/securesms/jobs/PushMediaSendJob.java b/src/org/thoughtcrime/securesms/jobs/PushMediaSendJob.java index d33de03be7..94473aa5da 100644 --- a/src/org/thoughtcrime/securesms/jobs/PushMediaSendJob.java +++ b/src/org/thoughtcrime/securesms/jobs/PushMediaSendJob.java @@ -49,7 +49,7 @@ public class PushMediaSendJob extends PushSendJob implements InjectableType { @Override public void onAdded() { - + Log.i(TAG, "onAdded() messageId: " + messageId); } @Override @@ -62,6 +62,8 @@ public class PushMediaSendJob extends PushSendJob implements InjectableType { OutgoingMediaMessage message = database.getOutgoingMessage(messageId); try { + Log.i(TAG, "Sending message: " + messageId); + deliver(message); database.markAsSent(messageId, true); markAttachmentsUploaded(messageId, message.getAttachments()); @@ -71,6 +73,8 @@ public class PushMediaSendJob extends PushSendJob implements InjectableType { expirationManager.scheduleDeletion(messageId, true, message.getExpiresIn()); } + Log.i(TAG, "Sent message: " + messageId); + } catch (InsecureFallbackApprovalException ifae) { Log.w(TAG, ifae); database.markAsPendingInsecureSmsFallback(messageId); diff --git a/src/org/thoughtcrime/securesms/jobs/PushSendJob.java b/src/org/thoughtcrime/securesms/jobs/PushSendJob.java index 5eb48179ac..97088d9a71 100644 --- a/src/org/thoughtcrime/securesms/jobs/PushSendJob.java +++ b/src/org/thoughtcrime/securesms/jobs/PushSendJob.java @@ -70,14 +70,18 @@ public abstract class PushSendJob extends SendJob { throw new TextSecureExpiredException("Too many signed prekey rotation failures"); } + Log.i(TAG, "Starting message send attempt"); onPushSend(); + Log.i(TAG, "Message send completed"); } @Override public void onRetry() { super.onRetry(); + Log.i(TAG, "onRetry()"); if (getRunIteration() > 1) { + Log.i(TAG, "Scheduling service outage detection job."); ApplicationContext.getInstance(context).getJobManager().add(new ServiceOutageDetectionJob(context)); } } diff --git a/src/org/thoughtcrime/securesms/jobs/PushTextSendJob.java b/src/org/thoughtcrime/securesms/jobs/PushTextSendJob.java index 7dc134ae37..1b880aa132 100644 --- a/src/org/thoughtcrime/securesms/jobs/PushTextSendJob.java +++ b/src/org/thoughtcrime/securesms/jobs/PushTextSendJob.java @@ -42,7 +42,9 @@ public class PushTextSendJob extends PushSendJob implements InjectableType { } @Override - public void onAdded() {} + public void onAdded() { + Log.i(TAG, "onAdded() messageId: " + messageId); + } @Override public void onPushSend() throws NoSuchMessageException, RetryLaterException { @@ -61,6 +63,8 @@ public class PushTextSendJob extends PushSendJob implements InjectableType { expirationManager.scheduleDeletion(record.getId(), record.isMms(), record.getExpiresIn()); } + Log.i(TAG, "Sent message: " + messageId); + } catch (InsecureFallbackApprovalException e) { Log.w(TAG, e); database.markAsPendingInsecureSmsFallback(record.getId()); diff --git a/src/org/thoughtcrime/securesms/jobs/SendJob.java b/src/org/thoughtcrime/securesms/jobs/SendJob.java index e5bf9c4aa0..70e807e2a3 100644 --- a/src/org/thoughtcrime/securesms/jobs/SendJob.java +++ b/src/org/thoughtcrime/securesms/jobs/SendJob.java @@ -10,6 +10,7 @@ import org.thoughtcrime.securesms.crypto.MasterSecret; import org.thoughtcrime.securesms.database.AttachmentDatabase; import org.thoughtcrime.securesms.database.DatabaseFactory; import org.thoughtcrime.securesms.jobmanager.JobParameters; +import org.thoughtcrime.securesms.logging.Log; import org.thoughtcrime.securesms.mms.MediaConstraints; import org.thoughtcrime.securesms.mms.MediaStream; import org.thoughtcrime.securesms.mms.MmsException; @@ -38,7 +39,9 @@ public abstract class SendJob extends MasterSecretJob { System.currentTimeMillis())); } + Log.i(TAG, "Starting message send attempt"); onSend(masterSecret); + Log.i(TAG, "Message send completed"); } protected abstract void onSend(MasterSecret masterSecret) throws Exception; diff --git a/src/org/thoughtcrime/securesms/jobs/ServiceOutageDetectionJob.java b/src/org/thoughtcrime/securesms/jobs/ServiceOutageDetectionJob.java index a22be361a1..4735669127 100644 --- a/src/org/thoughtcrime/securesms/jobs/ServiceOutageDetectionJob.java +++ b/src/org/thoughtcrime/securesms/jobs/ServiceOutageDetectionJob.java @@ -36,6 +36,8 @@ public class ServiceOutageDetectionJob extends ContextJob { @Override public void onRun() throws RetryLaterException { + Log.i(TAG, "onRun()"); + long timeSinceLastCheck = System.currentTimeMillis() - TextSecurePreferences.getLastOutageCheckTime(context); if (timeSinceLastCheck < CHECK_TIME) { Log.w(TAG, "Skipping service outage check. Too soon."); diff --git a/src/org/thoughtcrime/securesms/jobs/SmsSendJob.java b/src/org/thoughtcrime/securesms/jobs/SmsSendJob.java index d3ffec6896..f01d613056 100644 --- a/src/org/thoughtcrime/securesms/jobs/SmsSendJob.java +++ b/src/org/thoughtcrime/securesms/jobs/SmsSendJob.java @@ -40,7 +40,9 @@ public class SmsSendJob extends SendJob { } @Override - public void onAdded() {} + public void onAdded() { + Log.i(TAG, "onAdded() messageId: " + messageId); + } @Override public void onSend(MasterSecret masterSecret) throws NoSuchMessageException { @@ -49,8 +51,8 @@ public class SmsSendJob extends SendJob { try { Log.i(TAG, "Sending message: " + messageId); - deliver(record); + Log.i(TAG, "Sent message: " + messageId); } catch (UndeliverableMessageException ude) { Log.w(TAG, ude); DatabaseFactory.getSmsDatabase(context).markAsSentFailed(record.getId()); @@ -65,7 +67,7 @@ public class SmsSendJob extends SendJob { @Override public void onCanceled() { - Log.w(TAG, "onCanceled()"); + Log.w(TAG, "onCanceled() messageId: " + messageId); long threadId = DatabaseFactory.getSmsDatabase(context).getThreadIdForMessage(messageId); Recipient recipient = DatabaseFactory.getThreadDatabase(context).getRecipientForThreadId(threadId);