From: AsamK <asamk@gmx.de>
Date: Wed, 29 Dec 2021 08:45:59 +0000 (+0100)
Subject: Add additional logging
X-Git-Tag: v0.10.1~30
X-Git-Url: https://git.nmode.ca/signal-cli/commitdiff_plain/e3fcc9b3baf39a31a9e53ec4cec0a8f699736b77?ds=sidebyside

Add additional logging
---

diff --git a/graalvm-config-dir/reflect-config.json b/graalvm-config-dir/reflect-config.json
index a3edb967..dd5b4156 100644
--- a/graalvm-config-dir/reflect-config.json
+++ b/graalvm-config-dir/reflect-config.json
@@ -184,6 +184,11 @@
   "name":"java.lang.String",
   "allPublicMethods":true}
 ,
+{
+  "name":"java.lang.Throwable",
+  "queryAllPublicMethods":true,
+  "methods":[{"name":"addSuppressed","parameterTypes":["java.lang.Throwable"] }]}
+,
 {
   "name":"java.lang.reflect.Method",
   "methods":[{"name":"isDefault","parameterTypes":[] }]}
diff --git a/lib/src/main/java/org/asamk/signal/manager/storage/SignalAccount.java b/lib/src/main/java/org/asamk/signal/manager/storage/SignalAccount.java
index 67fc2529..8a8fdd3e 100644
--- a/lib/src/main/java/org/asamk/signal/manager/storage/SignalAccount.java
+++ b/lib/src/main/java/org/asamk/signal/manager/storage/SignalAccount.java
@@ -122,11 +122,14 @@ public class SignalAccount implements Closeable {
     public static SignalAccount load(
             File dataPath, String account, boolean waitForLock, final TrustNewIdentity trustNewIdentity
     ) throws IOException {
+        logger.trace("Opening account file");
         final var fileName = getFileName(dataPath, account);
         final var pair = openFileChannel(fileName, waitForLock);
         try {
             var signalAccount = new SignalAccount(pair.first(), pair.second());
+            logger.trace("Loading account file");
             signalAccount.load(dataPath, trustNewIdentity);
+            logger.trace("Migrating legacy parts of account file");
             signalAccount.migrateLegacyConfigs();
 
             if (!account.equals(signalAccount.getAccount())) {
diff --git a/lib/src/main/java/org/asamk/signal/manager/storage/identities/IdentityKeyStore.java b/lib/src/main/java/org/asamk/signal/manager/storage/identities/IdentityKeyStore.java
index 5a651edd..bb4627a2 100644
--- a/lib/src/main/java/org/asamk/signal/manager/storage/identities/IdentityKeyStore.java
+++ b/lib/src/main/java/org/asamk/signal/manager/storage/identities/IdentityKeyStore.java
@@ -84,6 +84,7 @@ public class IdentityKeyStore implements org.whispersystems.libsignal.state.Iden
             final var identityInfo = loadIdentityLocked(recipientId);
             if (identityInfo != null && identityInfo.getIdentityKey().equals(identityKey)) {
                 // Identity already exists, not updating the trust level
+                logger.trace("Not storing new identity for recipient {}, identity already stored", recipientId);
                 return false;
             }
 
@@ -101,18 +102,23 @@ public class IdentityKeyStore implements org.whispersystems.libsignal.state.Iden
         isRetryingDecryption = retryingDecryption;
     }
 
-    public boolean setIdentityTrustLevel(
-            RecipientId recipientId, IdentityKey identityKey, TrustLevel trustLevel
-    ) {
+    public boolean setIdentityTrustLevel(RecipientId recipientId, IdentityKey identityKey, TrustLevel trustLevel) {
         synchronized (cachedIdentities) {
             final var identityInfo = loadIdentityLocked(recipientId);
-            if (identityInfo == null
-                    || !identityInfo.getIdentityKey().equals(identityKey)
-                    || identityInfo.getTrustLevel() == trustLevel) {
-                // Identity not found or trust not changed, not updating the trust level
+            if (identityInfo == null) {
+                logger.debug("Not updating trust level for recipient {}, identity not found", recipientId);
+                return false;
+            }
+            if (!identityInfo.getIdentityKey().equals(identityKey)) {
+                logger.debug("Not updating trust level for recipient {}, different identity found", recipientId);
+                return false;
+            }
+            if (identityInfo.getTrustLevel() == trustLevel) {
+                logger.debug("Not updating trust level for recipient {}, trust level already matches", recipientId);
                 return false;
             }
 
+            logger.debug("Updating trust level for recipient {} with trust {}", recipientId, trustLevel);
             final var newIdentityInfo = new IdentityInfo(recipientId,
                     identityKey,
                     trustLevel,
@@ -134,20 +140,24 @@ public class IdentityKeyStore implements org.whispersystems.libsignal.state.Iden
             // TODO implement possibility for different handling of incoming/outgoing trust decisions
             var identityInfo = loadIdentityLocked(recipientId);
             if (identityInfo == null) {
-                // Identity not found
+                logger.debug("Initial identity found for {}, saving.", recipientId);
                 saveIdentity(address, identityKey);
-                return trustNewIdentity == TrustNewIdentity.ON_FIRST_USE;
-            }
-
-            if (!identityInfo.getIdentityKey().equals(identityKey)) {
+                identityInfo = loadIdentityLocked(recipientId);
+            } else if (!identityInfo.getIdentityKey().equals(identityKey)) {
                 // Identity found, but different
                 if (direction == Direction.SENDING) {
+                    logger.debug("Changed identity found for {}, saving.", recipientId);
                     saveIdentity(address, identityKey);
                     identityInfo = loadIdentityLocked(recipientId);
+                } else {
+                    logger.trace("Trusting identity for {} for {}: {}", recipientId, direction, false);
+                    return false;
                 }
             }
 
-            return identityInfo.isTrusted();
+            final var isTrusted = identityInfo != null && identityInfo.isTrusted();
+            logger.trace("Trusting identity for {} for {}: {}", recipientId, direction, isTrusted);
+            return isTrusted;
         }
     }
 
@@ -239,6 +249,10 @@ public class IdentityKeyStore implements org.whispersystems.libsignal.state.Iden
     }
 
     private void storeIdentityLocked(final RecipientId recipientId, final IdentityInfo identityInfo) {
+        logger.trace("Storing identity info for {}, trust: {}, added: {}",
+                recipientId,
+                identityInfo.getTrustLevel(),
+                identityInfo.getDateAdded());
         cachedIdentities.put(recipientId, identityInfo);
 
         var storage = new IdentityStorage(Base64.getEncoder().encodeToString(identityInfo.getIdentityKey().serialize()),
diff --git a/src/main/java/org/asamk/signal/App.java b/src/main/java/org/asamk/signal/App.java
index f807e8fd..a20b14e3 100644
--- a/src/main/java/org/asamk/signal/App.java
+++ b/src/main/java/org/asamk/signal/App.java
@@ -290,6 +290,7 @@ public class App {
             final TrustNewIdentity trustNewIdentity
     ) throws CommandException {
         Manager manager;
+        logger.trace("Loading account file for {}", account);
         try {
             manager = Manager.init(account, dataPath, serviceEnvironment, BaseConfig.USER_AGENT, trustNewIdentity);
         } catch (NotRegisteredException e) {
@@ -304,6 +305,7 @@ public class App {
                     + ")", e);
         }
 
+        logger.trace("Checking account state");
         try {
             manager.checkAccountState();
         } catch (IOException e) {