core: Improve SEP-1, SEP-10 logging

core/src/main/java/org/stellar/anchor/config/AppConfig.java

@@ -9,6 +9,7 @@ public interface AppConfig {
 
   String getHorizonUrl();
 
+  @Secret
   String getJwtSecretKey();
 
   String getAssets();

core/src/main/java/org/stellar/anchor/config/PII.java

@@ -0,0 +1,10 @@
+package org.stellar.anchor.config;
+
+import java.lang.annotation.*;
+
+/** Annotate that a method/field is personal identifiable information */
+@Documented
+@Target({ElementType.FIELD, ElementType.METHOD})
+@Inherited
+@Retention(RetentionPolicy.RUNTIME)
+public @interface PII {}

core/src/main/java/org/stellar/anchor/config/Secret.java

@@ -0,0 +1,10 @@
+package org.stellar.anchor.config;
+
+import java.lang.annotation.*;
+
+/** To annotate if a method returns secret information. */
+@Documented
+@Target({ElementType.METHOD})
+@Inherited
+@Retention(RetentionPolicy.RUNTIME)
+public @interface Secret {}

core/src/main/java/org/stellar/anchor/config/Sep10Config.java

@@ -9,6 +9,7 @@ public interface Sep10Config {
 
   Boolean getEnabled();
 
+  @Secret
   String getSigningSeed();
 
   Integer getAuthTimeout();

core/src/main/java/org/stellar/anchor/sep1/Sep1Service.java

@@ -1,5 +1,7 @@
 package org.stellar.anchor.sep1;
 
+import static org.stellar.anchor.util.Log.*;
+
 import java.io.IOException;
 import org.stellar.anchor.api.exception.SepNotFoundException;
 import org.stellar.anchor.config.Sep1Config;
@@ -31,10 +33,16 @@ public Sep1Service(Sep1Config sep1Config, ResourceReader resourceReader) {
   }
 
   public String getStellarToml() throws IOException, SepNotFoundException {
+    infoF("reading SEP1 TOML: {}", sep1Config.getStellarFile());
     if (resourceReader == null) {
+      debugF("reading SEP1 TOML from file system. path={}", sep1Config.getStellarFile());
       return FileUtil.getResourceFileAsString(sep1Config.getStellarFile());
     }
 
+    debugF(
+        "reading SEP1 TOML from resource reader({}). path={}",
+        resourceReader.getClass().getSimpleName(),
+        sep1Config.getStellarFile());
     return resourceReader.readResourceAsString(sep1Config.getStellarFile());
   }
 }

core/src/main/java/org/stellar/anchor/sep10/Sep10Service.java

@@ -1,13 +1,5 @@
 package org.stellar.anchor.sep10;
 
-import static org.stellar.anchor.util.Log.infoF;
-import static org.stellar.anchor.util.Log.shorter;
-
-import java.io.IOException;
-import java.net.URI;
-import java.net.URISyntaxException;
-import java.util.*;
-import java.util.stream.Collectors;
 import org.stellar.anchor.api.exception.SepException;
 import org.stellar.anchor.api.exception.SepValidationException;
 import org.stellar.anchor.api.sep.sep10.ChallengeRequest;
@@ -17,13 +9,20 @@
 import org.stellar.anchor.config.AppConfig;
 import org.stellar.anchor.config.Sep10Config;
 import org.stellar.anchor.horizon.Horizon;
-import org.stellar.anchor.util.Log;
 import org.stellar.anchor.util.Sep1Helper;
 import org.stellar.anchor.util.Sep1Helper.TomlContent;
 import org.stellar.sdk.*;
 import org.stellar.sdk.requests.ErrorResponse;
 import org.stellar.sdk.responses.AccountResponse;
 
+import java.io.IOException;
+import java.net.URI;
+import java.net.URISyntaxException;
+import java.util.*;
+import java.util.stream.Collectors;
+
+import static org.stellar.anchor.util.Log.*;
+
 /** The Sep-10 protocol service. */
 public class Sep10Service {
   final AppConfig appConfig;
@@ -34,27 +33,35 @@ public class Sep10Service {
 
   public Sep10Service(
       AppConfig appConfig, Sep10Config sep10Config, Horizon horizon, JwtService jwtService) {
+    infoF("Creating Sep10Service");
+    infoConfig("appConfig:", appConfig, AppConfig.class);
     this.appConfig = appConfig;
+
+    infoConfig("sep10Config:", sep10Config, Sep10Config.class);
     this.sep10Config = sep10Config;
+
     this.horizon = horizon;
     this.jwtService = jwtService;
     this.serverAccountId = KeyPair.fromSecretSeed(sep10Config.getSigningSeed()).getAccountId();
   }
 
   public ChallengeResponse createChallenge(ChallengeRequest challengeRequest) throws SepException {
+    info("Creating challenge");
     //
     // Validations
     //
     if (challengeRequest.getHomeDomain() == null) {
+      infoF("home_domain is not specified. Use {}", sep10Config.getHomeDomain());
       challengeRequest.setHomeDomain(sep10Config.getHomeDomain());
     } else if (!sep10Config.getHomeDomain().equalsIgnoreCase(challengeRequest.getHomeDomain())) {
+      infoF("Bad home_domain: {}", challengeRequest.getHomeDomain());
       throw new SepValidationException(
           String.format("home_domain [%s] is not supported.", challengeRequest.getHomeDomain()));
     }
 
     if (sep10Config.isClientAttributionRequired()) {
       if (challengeRequest.getClientDomain() == null) {
-        infoF("ALERT: client domain required and not provided");
+        info("client_domain is required but not provided");
         throw new SepValidationException("client_domain is required");
       }
 
@@ -63,7 +70,7 @@ public ChallengeResponse createChallenge(ChallengeRequest challengeRequest) thro
           && denyList.size() > 0
           && denyList.contains(challengeRequest.getClientDomain())) {
         infoF(
-            "ALERT: client domain provided is in configured deny list - {} ",
+            "client_domain({}) provided is in the configured deny list",
             challengeRequest.getClientDomain());
         throw new SepValidationException("unable to process.");
       }
@@ -73,7 +80,7 @@ public ChallengeResponse createChallenge(ChallengeRequest challengeRequest) thro
           && allowList.size() > 0
           && !allowList.contains(challengeRequest.getClientDomain())) {
         infoF(
-            "ALERT: client domain provided is not in configured allow list - {} ",
+            "client_domain provided ({}) is not in configured allow list",
             challengeRequest.getClientDomain());
         throw new SepValidationException("unable to process");
       }
@@ -82,7 +89,7 @@ public ChallengeResponse createChallenge(ChallengeRequest challengeRequest) thro
     try {
       KeyPair.fromAccountId(challengeRequest.getAccount());
     } catch (Exception ex) {
-      infoF("ALERT: client wallet account is invalid - {}", challengeRequest.getAccount());
+      infoF("client wallet account ({}) is invalid", challengeRequest.getAccount());
       throw new SepValidationException("Invalid account.");
     }
 
@@ -91,11 +98,13 @@ public ChallengeResponse createChallenge(ChallengeRequest challengeRequest) thro
       if (challengeRequest.getMemo() != null) {
         int memoInt = Integer.parseInt(challengeRequest.getMemo());
         if (memoInt <= 0) {
+          infoF("Invalid memo value: {}", challengeRequest.getMemo());
           throw new SepValidationException(
               String.format("Invalid memo value: %s", challengeRequest.getMemo()));
         }
       }
     } catch (NumberFormatException e) {
+      infoF("invalid memo format: {}. Only MEMO_INT is supported", challengeRequest.getMemo());
       throw new SepValidationException(
           String.format("Invalid memo format: %s", challengeRequest.getMemo()));
     }
@@ -106,7 +115,9 @@ public ChallengeResponse createChallenge(ChallengeRequest challengeRequest) thro
     try {
       String clientSigningKey = null;
       if (!Objects.toString(challengeRequest.getClientDomain(), "").isEmpty()) {
+        infoF("Fetching SIGNING_KEY from client_domain: {}", challengeRequest.getClientDomain());
         clientSigningKey = getClientAccountId(challengeRequest.getClientDomain());
+        debugF("SIGNING_KEY from client_domain fetched: {}", clientSigningKey);
       }
 
       KeyPair signer = KeyPair.fromSecretSeed(sep10Config.getSigningSeed());
@@ -124,12 +135,17 @@ public ChallengeResponse createChallenge(ChallengeRequest challengeRequest) thro
                   : challengeRequest.getClientDomain(),
               (clientSigningKey == null) ? "" : clientSigningKey);
       // Convert the challenge to response
-      return ChallengeResponse.of(
-          txn.toEnvelopeXdrBase64(), appConfig.getStellarNetworkPassphrase());
+      traceB("SEP-10 challenge txn:", txn);
+      ChallengeResponse challengeResponse =
+          ChallengeResponse.of(txn.toEnvelopeXdrBase64(), appConfig.getStellarNetworkPassphrase());
+      traceB("challengeResponse:", challengeResponse);
+      return challengeResponse;
     } catch (URISyntaxException e) {
+      warnF("Invalid HOST_URL: {}", appConfig.getHostUrl());
       throw new SepException(
           String.format("Invalid HOST_URL [%s} is used.", appConfig.getHostUrl()));
     } catch (InvalidSep10ChallengeException ex) {
+      warnEx(ex);
       throw new SepException("Failed to create the sep-10 challenge.", ex);
     }
   }
@@ -148,7 +164,7 @@ public ValidationResponse validateChallenge(ValidationRequest validationRequest)
 
   public String validateChallenge(String challengeXdr)
       throws IOException, InvalidSep10ChallengeException, URISyntaxException {
-    Log.info("Parse challenge string.");
+    debug("Parse challenge string.");
     Sep10Challenge.ChallengeTransaction challenge =
         Sep10Challenge.readChallengeTransaction(
             challengeXdr,
@@ -157,11 +173,13 @@ public String validateChallenge(String challengeXdr)
             sep10Config.getHomeDomain(),
             getDomainFromURI(appConfig.getHostUrl()));
 
-    infoF(
+    debugF(
         "Challenge parsed. account={}, home_domain={}",
         shorter(challenge.getClientAccountId()),
         challenge.getMatchedHomeDomain());
 
+    traceB("challenge:", challenge);
+
     String clientDomain = null;
     Operation operation =
         Arrays.stream(challenge.getTransaction().getOperations())
@@ -172,15 +190,20 @@ public String validateChallenge(String challengeXdr)
             .findFirst()
             .orElse(null);
 
+    traceB("Challenge operation:", operation);
     if (operation != null) {
       clientDomain = new String(((ManageDataOperation) operation).getValue());
     }
+    debugF("client_domain: {}", clientDomain);
 
     // Check the client's account
     AccountResponse account;
     try {
+      infoF("Checking if {} exists in the Stellar network", challenge.getClientAccountId());
       account = horizon.getServer().accounts().account(challenge.getClientAccountId());
+      traceF("challenge account: {}", account);
     } catch (ErrorResponse ex) {
+      infoF("Account {} does not exist in the Stellar Network");
       // account not found
       // The client account does not exist, using the client's master key to verify.
       Set<String> signers = new HashSet<>();
@@ -194,11 +217,12 @@ public String validateChallenge(String challengeXdr)
       if ((clientDomain != null && challenge.getTransaction().getSignatures().size() != 3)
           || (clientDomain == null && challenge.getTransaction().getSignatures().size() != 2)) {
         infoF(
-            "ALERT: Invalid SEP 10 challenge exception, there is more than one client signer on challenge transaction for an account that doesn't exist");
+            "Invalid SEP 10 challenge exception, there is more than one client signer on challenge transaction for an account that doesn't exist");
         throw new InvalidSep10ChallengeException(
             "There is more than one client signer on challenge transaction for an account that doesn't exist");
       }
 
+      debug("Calling Sep10Challenge.verifyChallengeTransactionSigners");
       Sep10Challenge.verifyChallengeTransactionSigners(
           challengeXdr,
           serverAccountId,
@@ -219,12 +243,12 @@ public String validateChallenge(String challengeXdr)
 
     // the signatures must be greater than the medium threshold of the account.
     int threshold = account.getThresholds().getMedThreshold();
+
     infoF(
         "Verifying challenge threshold. server_account={}, threshold={}, signers={}",
         shorter(serverAccountId),
         threshold,
         signers.size());
-
     Sep10Challenge.verifyChallengeTransactionThreshold(
         challengeXdr,
         serverAccountId,
@@ -241,32 +265,39 @@ String getClientAccountId(String clientDomain) throws SepException {
     String clientSigningKey = "";
     String url = "https://" + clientDomain + "/.well-known/stellar.toml";
     try {
+      debugF("Fetching {}", url);
       TomlContent toml = Sep1Helper.readToml(url);
       clientSigningKey = toml.getString("SIGNING_KEY");
       if (clientSigningKey == null) {
+        infoF("SIGNING_KEY not present in 'client_domain' TOML.");
         throw new SepException("SIGNING_KEY not present in 'client_domain' TOML");
       }
 
       // client key validation
+      debugF("Validating client_domain signing key: {}", clientSigningKey);
       KeyPair.fromAccountId(clientSigningKey);
       return clientSigningKey;
     } catch (IllegalArgumentException | FormatException ex) {
+      infoF("SIGNING_KEY {} is not a valid Stellar account Id.", clientSigningKey);
       throw new SepException(
           String.format("SIGNING_KEY %s is not a valid Stellar account Id.", clientSigningKey));
     } catch (IOException ioex) {
+      infoF("Unable to read from {}", url);
       throw new SepException(String.format("Unable to read from %s", url), ioex);
     }
   }
 
   String generateSep10Jwt(String challengeXdr, String clientDomain)
       throws InvalidSep10ChallengeException, IOException, URISyntaxException {
+    infoF("Creating SEP-10 challenge.");
     Sep10Challenge.ChallengeTransaction challenge =
         Sep10Challenge.readChallengeTransaction(
             challengeXdr,
             serverAccountId,
             new Network(appConfig.getStellarNetworkPassphrase()),
             sep10Config.getHomeDomain(),
             getDomainFromURI(appConfig.getHostUrl()));
+    debugB("challenge:", challenge);
     long issuedAt = challenge.getTransaction().getTimeBounds().getMinTime();
     JwtToken jwtToken =
         JwtToken.of(
@@ -276,6 +307,7 @@ String generateSep10Jwt(String challengeXdr, String clientDomain)
             issuedAt + sep10Config.getJwtTimeout(),
             challenge.getTransaction().hashHex(),
             clientDomain);
+    debugB("jwtToken:", jwtToken);
     return jwtService.encode(jwtToken);
   }
 

core/src/main/java/org/stellar/anchor/util/FileUtil.java

@@ -1,5 +1,7 @@
 package org.stellar.anchor.util;
 
+import static org.stellar.anchor.util.Log.errorF;
+
 import java.io.BufferedReader;
 import java.io.IOException;
 import java.io.InputStream;
@@ -12,8 +14,10 @@ public static String getResourceFileAsString(String fileName)
       throws IOException, SepNotFoundException {
     ClassLoader classLoader = FileUtil.class.getClassLoader();
     try (InputStream is = classLoader.getResourceAsStream(fileName)) {
-      if (is == null)
+      if (is == null) {
+        errorF("{} was not found in class path.", fileName);
         throw new SepNotFoundException(String.format("%s was not found in classpath.", fileName));
+      }
       try (InputStreamReader isr = new InputStreamReader(is);
           BufferedReader reader = new BufferedReader(isr)) {
         return reader.lines().collect(Collectors.joining(System.lineSeparator()));