diff --git a/app/src/main/java/org/thoughtcrime/securesms/database/LogDatabase.kt b/app/src/main/java/org/thoughtcrime/securesms/database/LogDatabase.kt index 3dc5743b3..704e47188 100644 --- a/app/src/main/java/org/thoughtcrime/securesms/database/LogDatabase.kt +++ b/app/src/main/java/org/thoughtcrime/securesms/database/LogDatabase.kt @@ -23,8 +23,7 @@ import java.util.concurrent.TimeUnit * Logs are very performance critical. Even though this database is written to on a low-priority background thread, we want to keep throughput high and ensure * that we aren't creating excess garbage. * - * This is it's own separate physical database, so it cannot do joins or queries with any other - * tables. + * This is it's own separate physical database, so it cannot do joins or queries with any other tables. */ class LogDatabase private constructor( application: Application, @@ -46,7 +45,7 @@ class LogDatabase private constructor( private val MAX_FILE_SIZE = ByteUnit.MEGABYTES.toBytes(15) private val DEFAULT_LIFESPAN = TimeUnit.DAYS.toMillis(2) - private val LONGER_LIFESPAN = TimeUnit.DAYS.toMillis(7) + private val LONGER_LIFESPAN = TimeUnit.DAYS.toMillis(14) private const val DATABASE_VERSION = 2 private const val DATABASE_NAME = "signal-logs.db" diff --git a/app/src/main/java/org/thoughtcrime/securesms/messages/MessageContentProcessor.java b/app/src/main/java/org/thoughtcrime/securesms/messages/MessageContentProcessor.java index f71c8e48a..4867a77be 100644 --- a/app/src/main/java/org/thoughtcrime/securesms/messages/MessageContentProcessor.java +++ b/app/src/main/java/org/thoughtcrime/securesms/messages/MessageContentProcessor.java @@ -238,7 +238,7 @@ public final class MessageContentProcessor { PendingRetryReceiptModel pending = ApplicationDependencies.getPendingRetryReceiptCache().get(senderRecipient.getId(), content.getTimestamp()); long receivedTime = handlePendingRetry(pending, content, threadRecipient); - log(String.valueOf(content.getTimestamp()), "Beginning message processing."); + log(String.valueOf(content.getTimestamp()), "Beginning message processing. Sender: " + senderRecipient.getId() + " | " + senderRecipient.requireServiceId()); if (content.getDataMessage().isPresent()) { GroupDatabase groupDatabase = DatabaseFactory.getGroupDatabase(context); @@ -439,7 +439,7 @@ public final class MessageContentProcessor { Optional groupRecord = groupDatabase.getGroup(groupId); if (groupRecord.isPresent() && !groupRecord.get().getMembers().contains(senderRecipient.getId())) { - log(String.valueOf(content.getTimestamp()), "Ignoring GV2 message from member not in group " + groupId); + log(String.valueOf(content.getTimestamp()), "Ignoring GV2 message from member not in group " + groupId + ". Sender: " + senderRecipient.getId() + " | " + senderRecipient.requireServiceId()); return true; } @@ -1769,7 +1769,7 @@ public final class MessageContentProcessor { GroupId.Push groupId = GroupId.push(typingMessage.getGroupId().get()); if (!DatabaseFactory.getGroupDatabase(context).isCurrentMember(groupId, senderRecipient.getId())) { - warn(String.valueOf(content.getTimestamp()), "Seen typing indicator for non-member"); + warn(String.valueOf(content.getTimestamp()), "Seen typing indicator for non-member " + senderRecipient.getId()); return; } diff --git a/libsignal/service/src/main/java/org/whispersystems/signalservice/api/SignalServiceMessageSender.java b/libsignal/service/src/main/java/org/whispersystems/signalservice/api/SignalServiceMessageSender.java index 4d3fcd7fa..f9f9c2976 100644 --- a/libsignal/service/src/main/java/org/whispersystems/signalservice/api/SignalServiceMessageSender.java +++ b/libsignal/service/src/main/java/org/whispersystems/signalservice/api/SignalServiceMessageSender.java @@ -385,6 +385,7 @@ public class SignalServiceMessageSender { EnvelopeContent envelopeContent = EnvelopeContent.encrypted(content, ContentHint.IMPLICIT, Optional.of(groupId)); long timestamp = System.currentTimeMillis(); + Log.d(TAG, "[" + timestamp + "] Sending SKDM to " + recipients.size() + " recipients."); return sendMessage(recipients, getTargetUnidentifiedAccess(unidentifiedAccess), timestamp, envelopeContent, false, null, null); } @@ -1520,6 +1521,7 @@ public class SignalServiceMessageSender { CancelationSignal cancelationSignal) throws IOException { + Log.d(TAG, "[" + timestamp + "] Sending to " + recipients.size() + " recipients."); enforceMaxContentSize(content); long startTime = System.currentTimeMillis(); @@ -1551,7 +1553,7 @@ public class SignalServiceMessageSender { Log.w(TAG, e); results.add(SendMessageResult.identityFailure(recipient, ((UntrustedIdentityException) e.getCause()).getIdentityKey())); } else if (e.getCause() instanceof UnregisteredUserException) { - Log.w(TAG, "Found unregistered user."); + Log.w(TAG, "[" + timestamp + "] Found unregistered user."); results.add(SendMessageResult.unregisteredFailure(recipient)); } else if (e.getCause() instanceof PushNetworkException) { Log.w(TAG, e); @@ -1586,7 +1588,7 @@ public class SignalServiceMessageSender { } } - Log.d(TAG, "Completed send to " + recipients.size() + " recipients in " + (System.currentTimeMillis() - startTime) + " ms, with an average time of " + Math.round(average) + " ms per send."); + Log.d(TAG, "[" + timestamp + "] Completed send to " + recipients.size() + " recipients in " + (System.currentTimeMillis() - startTime) + " ms, with an average time of " + Math.round(average) + " ms per send."); return results; } @@ -1611,7 +1613,7 @@ public class SignalServiceMessageSender { OutgoingPushMessageList messages = getEncryptedMessages(socket, recipient, unidentifiedAccess, timestamp, content, online); if (content.getContent().isPresent() && content.getContent().get().getSyncMessage() != null && content.getContent().get().getSyncMessage().hasSent()) { - Log.d(TAG, "[" + timestamp + "] Sending a sent sync message to devices: " + messages.getDevices()); + Log.d(TAG, "[sendMessage][" + timestamp + "] Sending a sent sync message to devices: " + messages.getDevices()); } if (cancelationSignal != null && cancelationSignal.isCanceled()) { @@ -1623,20 +1625,20 @@ public class SignalServiceMessageSender { SendMessageResponse response = new MessagingService.SendResponseProcessor<>(messagingService.send(messages, Optional.absent()).blockingGet()).getResultOrThrow(); return SendMessageResult.success(recipient, messages.getDevices(), false, response.getNeedsSync() || store.isMultiDevice(), System.currentTimeMillis() - startTime, content.getContent()); } catch (WebSocketUnavailableException e) { - Log.i(TAG, "[sendMessage] Pipe unavailable, falling back... (" + e.getClass().getSimpleName() + ": " + e.getMessage() + ")"); + Log.i(TAG, "[sendMessage][" + timestamp + "] Pipe unavailable, falling back... (" + e.getClass().getSimpleName() + ": " + e.getMessage() + ")"); } catch (IOException e) { Log.w(TAG, e); - Log.w(TAG, "[sendMessage] Pipe failed, falling back... (" + e.getClass().getSimpleName() + ": " + e.getMessage() + ")"); + Log.w(TAG, "[sendMessage][" + timestamp + "] Pipe failed, falling back... (" + e.getClass().getSimpleName() + ": " + e.getMessage() + ")"); } } else if (unidentifiedAccess.isPresent()) { try { SendMessageResponse response = new MessagingService.SendResponseProcessor<>(messagingService.send(messages, unidentifiedAccess).blockingGet()).getResultOrThrow(); return SendMessageResult.success(recipient, messages.getDevices(), true, response.getNeedsSync() || store.isMultiDevice(), System.currentTimeMillis() - startTime, content.getContent()); } catch (WebSocketUnavailableException e) { - Log.i(TAG, "[sendMessage] Unidentified pipe unavailable, falling back... (" + e.getClass().getSimpleName() + ": " + e.getMessage() + ")"); + Log.i(TAG, "[sendMessage][" + timestamp + "] Unidentified pipe unavailable, falling back... (" + e.getClass().getSimpleName() + ": " + e.getMessage() + ")"); } catch (IOException e) { Log.w(TAG, e); - Log.w(TAG, "[sendMessage] Unidentified pipe failed, falling back..."); + Log.w(TAG, "[sendMessage][" + timestamp + "] Unidentified pipe failed, falling back..."); } } @@ -1688,11 +1690,11 @@ public class SignalServiceMessageSender { throws IOException, UntrustedIdentityException, NoSessionException, InvalidKeyException, InvalidRegistrationIdException { if (recipients.isEmpty()) { - Log.w(TAG, "[sendGroupMessage] Empty recipient list!"); + Log.w(TAG, "[sendGroupMessage][" + timestamp + "] Empty recipient list!"); return Collections.emptyList(); } - Preconditions.checkArgument(recipients.size() == unidentifiedAccess.size(), "Unidentified access mismatch!"); + Preconditions.checkArgument(recipients.size() == unidentifiedAccess.size(), "[" + timestamp + "] Unidentified access mismatch!"); Map accessByUuid = new HashMap<>(); Iterator addressIterator = recipients.iterator(); @@ -1712,7 +1714,7 @@ public class SignalServiceMessageSender { .map(SignalServiceAddress::new) .collect(Collectors.toList()); if (needsSenderKey.size() > 0) { - Log.i(TAG, "[sendGroupMessage] Need to send the distribution message to " + needsSenderKey.size() + " addresses."); + Log.i(TAG, "[sendGroupMessage][" + timestamp + "] Need to send the distribution message to " + needsSenderKey.size() + " addresses."); SenderKeyDistributionMessage message = getOrCreateNewGroupSession(distributionId); List> access = needsSenderKey.stream() .map(r -> { @@ -1733,11 +1735,11 @@ public class SignalServiceMessageSender { store.markSenderKeySharedWith(distributionId, successAddresses); - Log.i(TAG, "[sendGroupMessage] Successfully sent sender keys to " + successes.size() + "/" + needsSenderKey.size() + " recipients."); + Log.i(TAG, "[sendGroupMessage][" + timestamp + "] Successfully sent sender keys to " + successes.size() + "/" + needsSenderKey.size() + " recipients."); int failureCount = results.size() - successes.size(); if (failureCount > 0) { - Log.w(TAG, "[sendGroupMessage] Failed to send sender keys to " + failureCount + " recipients. Sending back failed results now."); + Log.w(TAG, "[sendGroupMessage][" + timestamp + "] Failed to send sender keys to " + failureCount + " recipients. Sending back failed results now."); List trueFailures = results.stream() .filter(r -> !r.isSuccess()) @@ -1785,29 +1787,29 @@ public class SignalServiceMessageSender { SendGroupMessageResponse response = new MessagingService.SendResponseProcessor<>(messagingService.sendToGroup(ciphertext, joinedUnidentifiedAccess, timestamp, online).blockingGet()).getResultOrThrow(); return transformGroupResponseToMessageResults(targetInfo.devices, response, content); } catch (WebSocketUnavailableException e) { - Log.i(TAG, "[sendGroupMessage] Pipe unavailable, falling back... (" + e.getClass().getSimpleName() + ": " + e.getMessage() + ")"); + Log.i(TAG, "[sendGroupMessage][" + timestamp + "] Pipe unavailable, falling back... (" + e.getClass().getSimpleName() + ": " + e.getMessage() + ")"); } catch (IOException e) { - Log.w(TAG, "[sendGroupMessage] Pipe failed, falling back... (" + e.getClass().getSimpleName() + ": " + e.getMessage() + ")"); + Log.w(TAG, "[sendGroupMessage][" + timestamp + "] Pipe failed, falling back... (" + e.getClass().getSimpleName() + ": " + e.getMessage() + ")"); } try { SendGroupMessageResponse response = socket.sendGroupMessage(ciphertext, joinedUnidentifiedAccess, timestamp, online); return transformGroupResponseToMessageResults(targetInfo.devices, response, content); } catch (GroupMismatchedDevicesException e) { - Log.w(TAG, "[sendGroupMessage] Handling mismatched devices.", e); + Log.w(TAG, "[sendGroupMessage][" + timestamp + "] Handling mismatched devices.", e); for (GroupMismatchedDevices mismatched : e.getMismatchedDevices()) { SignalServiceAddress address = new SignalServiceAddress(UuidUtil.parseOrThrow(mismatched.getUuid()), Optional.absent()); handleMismatchedDevices(socket, address, mismatched.getDevices()); } } catch (GroupStaleDevicesException e) { - Log.w(TAG, "[sendGroupMessage] Handling stale devices.", e); + Log.w(TAG, "[sendGroupMessage][" + timestamp + "] Handling stale devices.", e); for (GroupStaleDevices stale : e.getStaleDevices()) { SignalServiceAddress address = new SignalServiceAddress(UuidUtil.parseOrThrow(stale.getUuid()), Optional.absent()); handleStaleDevices(address, stale.getDevices()); } } - Log.w(TAG, "[sendGroupMessage] Attempt failed (i = " + i + ")"); + Log.w(TAG, "[sendGroupMessage][" + timestamp + "] Attempt failed (i = " + i + ")"); } throw new IOException("Failed to resolve conflicts after " + RETRY_COUNT + " attempts!");