Refactor/logging

SECURITY.md

@@ -26,6 +26,7 @@ When reporting any issue, remove:
 - Real system IDs and account IDs.
 - Private IP addresses when they are sensitive.
 - Phone numbers and message bodies.
+- Raw SMPP PDU, byte, worker message, response, and MO diagnostic logs.
 - Provider names if your agreement requires confidentiality.
 
 ## Supported Versions

SUPPORT.md

@@ -25,6 +25,12 @@ Include:
 - Sanitized `credentials.yml`, `smsg.properties`, or `routingTable.conf` snippets when relevant.
 - Relevant log lines from `smsg.log`, `smppclient.log`, `smppserver.log`, or `httpapi.log`.
 
+Default `httpapi.log` entries omit request query strings. If your deployment uses a custom HTTP access-log pattern, sanitize any `/sendsms` query parameters before sharing logs.
+
+SMPP PDU, byte, message, response, and MO diagnostic logs are opt-in because they can contain credentials, phone numbers, and message bodies. Sanitize `log.pdus`, `log.bytes`, `print.msgs`, `print.resps`, and `print.mos` output before sharing it.
+
+For message-path investigations, prefer `message.*` lifecycle trace lines. `message.trace.mode = necessary` is the default and keeps only `message.accepted`, `message.submitted`, `message.dlr`, and `message.deliver.sent`; use `message.trace.mode = all` when route/enqueue/response detail is needed. These logs include IDs, message type, account/system context, and delivery state without including phone numbers or message bodies.
+
 ## Feature Requests
 
 Use GitHub Discussions for early ideas. Open an issue when the behavior and use case are clear enough to track.

docs/04-smpp-configuration.md

@@ -73,10 +73,15 @@ All properties below should be prefixed with your instance path. For example, if
 
 ## 📊 Logging, Monitoring & JMX
 
+SMPP PDU and byte diagnostics are disabled by default because bind PDUs can include passwords and submit/deliver PDUs can include phone numbers and message bodies. Enable these settings only temporarily in controlled troubleshooting sessions, and treat the resulting logs as sensitive data.
+
+Safe lifecycle trace logs are controlled by global `message.trace.mode`. The default `necessary` mode logs only `message.accepted`, `message.submitted`, `message.dlr`, and `message.deliver.sent`; set it to `off` to disable message-flow logs or `all` to include route/enqueue/response/retry detail.
+
 | Property | Default Value | Description |
 | :--- | :--- | :--- |
-| `log.pdus` | `true` | Log all decoded SMPP Protocol Data Units (PDUs). |
-| `log.bytes` | `false` | Log raw hex bytes for troubleshooting. |
+| `message.trace.mode` | `necessary` | Global `message.*` lifecycle trace mode: `off`, `necessary`, or `all`. |
+| `log.pdus` | `false` | Opt-in logging for decoded SMPP Protocol Data Units (PDUs). May include bind passwords, phone numbers, and message bodies. |
+| `log.bytes` | `false` | Opt-in raw hex byte logging for SMPP troubleshooting. Treat as sensitive. |
 | `log.pdus.exclude` | `21,2147483669` | Comma-separated list of PDU Command IDs to suppress from logs (defaults to EnquireLink & EnquireLinkResp). |
 | `srv.printStatsPeriod` | `300` | Interval (in seconds) to dump server statistics to the logs. |
 | `srv.printRatePeriod` | `60` | Interval (in seconds) to calculate and print message rates. |
@@ -164,10 +169,12 @@ If the worker encounters severe connectivity issues, it can auto-suspend to prev
 
 ### Logging & KPIs
 
+Message printing is disabled by default because worker message objects can include phone numbers, callback URLs, and message bodies. Enable `print.msgs` only for short-lived diagnostics and sanitize logs before sharing them. Use `message.trace.mode` for day-to-day support tracing by IDs, message type, account/system context, and routing state.
+
 | Property | Default Value | Description |
 | :--- | :--- | :--- |
 | `debug` | `false` | Enables deep debug logging for the worker. |
-| `print.msgs` | `true` | Enables printing of message payloads to the log. |
+| `print.msgs` | `false` | Opt-in printing of full worker message objects. Treat output as sensitive. |
 | `kpi.enabled` | `false` |  (KPIs Not supported) Enables tracking of Key Performance Indicators (KPIs) for the vendor route. |
 | `kpi.period.minutes` | `60` | (KPIs Not supported) The rolling time window (in minutes, max 120) for KPI calculations. |
 | `kpi.volume` | `100` | (KPIs Not supported) The volume threshold required before KPI alerts trigger. |
@@ -265,13 +272,15 @@ The SMPP Client worker (`WorkerType: smppclient`) allows the application to conn
 
 ## 📊 Logging & Diagnostics
 
+SMPP client PDU, response, and MO diagnostics are disabled by default. These logs can include bind passwords, phone numbers, provider message IDs, callback data, and message bodies, so enable them only when the log destination is access-controlled and retention is appropriate. Default `message.trace.mode = necessary` preserves submit and DLR milestones without logging payloads; use `all` for submit-response and operator-link details.
+
 | Property | Default Value | Description |
 | :--- | :--- | :--- |
-| `log.pdus` | `true` | Log all decoded SMPP Protocol Data Units (PDUs). |
-| `log.bytes` | `false` | Log raw hex bytes of the SMPP traffic. |
+| `log.pdus` | `false` | Opt-in logging for decoded SMPP Protocol Data Units (PDUs). May include bind passwords, addresses, and message bodies. |
+| `log.bytes` | `false` | Opt-in raw hex byte logging of SMPP traffic. Treat as sensitive. |
 | `log.pdus.exclude` | `21,2147483669` | Exclude specific Command IDs from PDU logs (defaults to EnquireLink/Resp). |
-| `print.resps` | `true` | Log Submit_SM responses. |
-| `print.mos` | `true` | Log incoming Mobile Originated (MO) messages. |
+| `print.resps` | `false` | Opt-in logging for Submit_SM responses with the associated message object. Treat output as sensitive. |
+| `print.mos` | `false` | Opt-in logging for incoming Mobile Originated (MO) messages. Treat output as sensitive. |
 | `counters` | `true` | Enable session monitoring and performance counters. |
 | `connection.healthcheck`| `false` | (Not supported yet) Enable strict connectivity verification before accepting messages. |
 

docs/09-configuration-reference.md

@@ -52,6 +52,14 @@ In the Docker image, the working directory is `/work`, so the default configurat
 | `smppserver.log` | SMPP server bind, session, and message activity. |
 | `httpapi.log` | HTTP API access log when file logging is enabled. |
 
+`httpapi.log` records the HTTP method, request path, protocol, response status, bytes sent, response time, referer, and user agent by default. It intentionally omits the query string because the Kannel-compatible `/sendsms` API carries credentials, phone numbers, callback URLs, and message text in query parameters.
+
+If you customize `quarkus.http.access-log.pattern`, avoid `%r`, `%q`, `%{QUERY_STRING}`, and `%{q,...}` unless the resulting logs are treated as sensitive data.
+
+Worker diagnostic flags such as `log.pdus`, `log.bytes`, `print.msgs`, `print.resps`, and `print.mos` are disabled by default. Enabling them can write SMPP credentials, phone numbers, provider identifiers, callback URLs, and message bodies to logs.
+
+`message.*` lifecycle trace logs are controlled by `message.trace.mode`. The default `necessary` mode keeps `message.accepted`, `message.submitted`, `message.dlr`, and `message.deliver.sent`; use `off` to disable all message-flow logs or `all` to include route/enqueue/response/retry detail.
+
 ## OpenAPI
 
 When the HTTP server is running, Sendium exposes:

docs/10-troubleshooting.md

@@ -42,7 +42,8 @@ Check:
 - The target worker name in `routingTable.conf` matches a configured worker in `smsg.properties`.
 - The SMPP client worker is enabled with `outSms.instance.<name>.enable = true`.
 - The upstream SMPP provider accepted the bind.
-- `smppclient.log` contains submit responses or connection errors.
+- Default `message.trace.mode = necessary` logs `message.accepted`, `message.submitted`, `message.dlr`, and `message.deliver.sent` without exposing addresses or message content. Temporarily set `message.trace.mode = all` to include route/enqueue/submit-response detail.
+- `smppclient.log` contains connection errors. Submit response detail requires temporary `print.resps = true` and should be treated as sensitive.
 
 ## Routing Falls Through Unexpectedly
 
@@ -90,7 +91,7 @@ Check:
 - `forward.mo.format` is set to `JSON` or `FORM`.
 - The callback endpoint is reachable from the Sendium container or host.
 - The receiving endpoint returns an HTTP status from `200` to `399`.
-- `smppclient.log` contains incoming MO activity.
+- Full incoming MO detail requires temporary `print.mos = true` and should be treated as sensitive.
 
 ## Logs Are Missing
 

sendium-app/src/main/resources/application.properties

@@ -52,8 +52,9 @@ quarkus.http.access-log.base-file-name=httpapi
 quarkus.http.access-log.log-suffix=.log
 quarkus.http.access-log.log-directory=${QUARKUS_HTTP_ACCESS_LOG_DIRECTORY:}
 quarkus.http.access-log.rotate=true
-# %a:REMOTE IP %t:DateTime %r:REQUEST_LINE %s:RESPONSE_CODE %b:Bytes sent, more in: https://quarkus.io/guides/http-reference
-quarkus.http.access-log.pattern=%a(%{i,X-Forwarded-For}) %t %{i,X-REROUTE} "%r" %s %b %{RESPONSE_TIME} %{i,Referer} "%{i,User-Agent}"
+# %a:REMOTE IP %t:DateTime %m:METHOD %U:REQUEST URL path %H:PROTOCOL %s:RESPONSE_CODE %b:Bytes sent.
+# Do not use %r or %q by default: /sendsms query parameters can contain credentials, phone numbers, and message text.
+quarkus.http.access-log.pattern=%a(%{i,X-Forwarded-For}) %t %{i,X-REROUTE} "%m %U %H" %s %b %{RESPONSE_TIME} %{i,Referer} "%{i,User-Agent}"
 # record request start time is needed to be enabled for http access logs to be able to record total request time
 quarkus.http.record-request-start-time=true
 

sendium-core/src/main/java/gr/cytech/sendium/auth/CredentialFileParser.java

@@ -33,7 +33,7 @@ public static Map<String, CredentialFileWatcher.Credential> loadAndParse(Path fi
                         cred -> cred,
                         (existing, replacement) -> {
                             // Handle cases where the operator accidentally copy-pasted the same systemId or apiKey twice
-                            logger.warn("Duplicate credential key found for {}. Overwriting with the latest entry.", existing.getLookupKey());
+                            logger.warn("Duplicate credential key found. Overwriting with the latest entry.");
                             return replacement;
                         }
                 ));

sendium-core/src/main/java/gr/cytech/sendium/conf/ConfFileWatcher.java

@@ -1,5 +1,6 @@
 package gr.cytech.sendium.conf;
 
+import gr.cytech.sendium.util.SensitiveLogSanitizer;
 import io.quarkus.runtime.ShutdownEvent;
 import io.quarkus.runtime.StartupEvent;
 import jakarta.annotation.Priority;
@@ -200,16 +201,7 @@ private synchronized void reloadConfiguration(File file) {
 
     /** Simple helper to prevent logging cleartext passwords in production logs. */
     private String maskSecret(String key, String value) {
-        if (value == null) {
-            return "null";
-        }
-        String lowerKey = key.toLowerCase();
-        if (lowerKey.contains("password") ||
-                lowerKey.contains("secret") ||
-                lowerKey.contains("token")) {
-            return "*****";
-        }
-        return value;
+        return SensitiveLogSanitizer.maskValue(key, value);
     }
 
     private Map<String, String> loadPropertiesFromFile(File file) {

sendium-core/src/main/java/gr/cytech/sendium/conf/PropertyChangeEvent.java

@@ -1,5 +1,7 @@
 package gr.cytech.sendium.conf;
 
+import gr.cytech.sendium.util.SensitiveLogSanitizer;
+
 import java.util.EventObject;
 
 public class PropertyChangeEvent extends EventObject {
@@ -37,7 +39,7 @@ public String getOldValue() {
     @Override
     public String toString() {
         return "{\"key\":\"" + key + "\"," +
-                "\"value\":\"" + value + "\"," +
-                "\"oldValue\":\"" + oldValue + "\"}";
+                "\"value\":\"" + SensitiveLogSanitizer.maskValue(key, value) + "\"," +
+                "\"oldValue\":\"" + SensitiveLogSanitizer.maskValue(key, oldValue) + "\"}";
     }
 }

sendium-core/src/main/java/gr/cytech/sendium/conf/SendiumConfigurationHandler.java

@@ -1,6 +1,7 @@
 package gr.cytech.sendium.conf;
 
 import com.google.common.base.Strings;
+import gr.cytech.sendium.util.SensitiveLogSanitizer;
 import io.quarkus.arc.DefaultBean;
 import jakarta.annotation.PostConstruct;
 import jakarta.enterprise.context.ApplicationScoped;
@@ -98,7 +99,7 @@ public String set(String key, String val) {
         try {
             return memoryConfiguration.put(key, val);
         } catch (Exception e) {
-            logger.warn("error setting property {} to {}", key, val, e);
+            logger.warn("error setting property {} to {}", key, SensitiveLogSanitizer.maskValue(key, val), e);
             return null;
         }
     }

sendium-core/src/main/java/gr/cytech/sendium/core/AbstractOutWorker.java

@@ -18,6 +18,7 @@
 import gr.cytech.sendium.external.VendorKpiHandler;
 import gr.cytech.sendium.external.WorkerResourceProvider;
 import gr.cytech.sendium.external.filter.FilterException;
+import gr.cytech.sendium.util.MessageTrace;
 import gr.cytech.sendium.util.Sleeper;
 import gr.cytech.sendium.util.StatsKeeper;
 import gr.cytech.sendium.util.TimeUtils;
@@ -51,7 +52,7 @@ public abstract class AbstractOutWorker<M extends StandardMessage> implements He
             , {"debug", "false"}
             , {"pause", "false"}
             , {"suspend", "false"}
-            , {"print.msgs", "true"}
+            , {"print.msgs", "false"}
             , {"queue.honourPriorities", "false"}
             , {"queue.name", ""}
             , {"tps", "0"} //Transactions Per Second
@@ -530,9 +531,12 @@ public void enqueue(M pMsg) throws InterruptedException {
             return;
         }
         if (!this.keepOnRunning) {
-            throw new IllegalStateException("Worker:" + getFullName() + " is stopped, cannot enqueue msg:" + pMsg);
+            throw new IllegalStateException("Worker:" + getFullName() + " is stopped, cannot enqueue " + MessageTrace.identifiers(pMsg));
         }
         pMsg.outgateway = getFullName();
+        if (MessageTrace.shouldLog(configurationProvider, MessageTrace.EVENT_ENQUEUED)) {
+            logger.info("message.enqueued worker={} {}", getFullName(), MessageTrace.identifiers(pMsg));
+        }
         msgQ.enqueue(pMsg);
     }
 
@@ -689,15 +693,18 @@ public String getQueueName() {
      */
     public final void enqueueToRouter(M msg) throws InterruptedException {
         routerQueue.enqueue(msg);
+        if (MessageTrace.shouldLog(configurationProvider, MessageTrace.EVENT_ENQUEUED)) {
+            logger.info("message.enqueued destination=router {}", MessageTrace.identifiers(msg));
+        }
     }
 
     public void enqueueToRouterNoExceptions(M msg) {
         while (true) {
             try {
-                routerQueue.enqueue(msg);
+                enqueueToRouter(msg);
                 return;
             } catch (Exception e) {
-                logger.warn("exception re-enqueuing to router, will retry:{}", msg, e);
+                logger.warn("exception re-enqueuing to router, will retry {}", MessageTrace.identifiers(msg), e);
                 TimeUtils.sleep(100, TimeUnit.MILLISECONDS);
             }
         }
@@ -1102,15 +1109,19 @@ protected void onMessageFailed(M m, boolean shouldAttemptWorkerRetry) {
 
         if (!shouldAttemptWorkerRetry || m != msg || (internalTries >= getMaxRetries() && getMaxRetries() != 0)) {
             if (m != null) {
-                logger.info("async: failed ({} times) to deliver: {}", internalTries, msg);
+                if (MessageTrace.shouldLog(configurationProvider, MessageTrace.EVENT_DELIVERY_FAILED)) {
+                    logger.info("message.delivery.failed mode=async tries={} {}", internalTries, MessageTrace.identifiers(msg));
+                }
                 handleMessageFailInWorker("async", m, enqueueInstead);
             }
             return;
         }
 
         failedMsgCounter.put(m.msgId, internalTries);
 
-        logger.info("async: failed ({} times) to deliver: {}", internalTries, msg);
+        if (MessageTrace.shouldLog(configurationProvider, MessageTrace.EVENT_DELIVERY_RETRY)) {
+            logger.info("message.delivery.retry mode=async tries={} {}", internalTries, MessageTrace.identifiers(msg));
+        }
 
         m = doFailDelayWorkerRetryPolicyAction(m, internalTries);
 
@@ -1125,7 +1136,7 @@ public void onMessageSuccess(M msg) throws IOException {
             checkAfterDoMessageSuccessFilters(msg);
         } catch (FilterException fe) {
             //after message success, we do not expect to handle any filter exception
-            logger.warn("unexpected filter exception onMessageSuccess for msg:{}", msg, fe);
+            logger.warn("unexpected filter exception onMessageSuccess {}", MessageTrace.identifiers(msg), fe);
         }
     }
 
@@ -1480,7 +1491,10 @@ public void handleMessage() {
                 }
                 if (m == null || m != msg || (internalTries >= getMaxRetries() && getMaxRetries() != 0)) {
                     if (m != null && !enqueueInstead) {
-                        logger.info("{}: failed ({} times) to deliver: {}", id, internalTries, msg);
+                        if (MessageTrace.shouldLog(configurationProvider, MessageTrace.EVENT_DELIVERY_FAILED)) {
+                            logger.info("message.delivery.failed workerThread={} tries={} {}", id, internalTries,
+                                    MessageTrace.identifiers(msg));
+                        }
                     }
                     break; //Stop trying in the worker
                 }
@@ -1494,7 +1508,9 @@ public void handleMessage() {
                     failedMsgCounter.put(m.msgId, tries);
                 } //else we use the current tries
 
-                logger.info("{}: failed ({} times) to deliver: {}", id, tries, msg);
+                if (MessageTrace.shouldLog(configurationProvider, MessageTrace.EVENT_DELIVERY_RETRY)) {
+                    logger.info("message.delivery.retry workerThread={} tries={} {}", id, tries, MessageTrace.identifiers(msg));
+                }
 
                 if (tries >= getMaxRetries() && getMaxRetries() != 0) {
                     //Current retries + previous ones enforce us to break the loop

sendium-core/src/main/java/gr/cytech/sendium/core/http/KannelResource.java

@@ -2,10 +2,12 @@
 
 import com.google.common.base.Strings;
 import gr.cytech.sendium.auth.CredentialFileWatcher;
+import gr.cytech.sendium.conf.SendiumConfigurationHandler;
 import gr.cytech.sendium.core.message.StandardMessage;
 import gr.cytech.sendium.core.queue.InMemoryQueueProvider;
 import gr.cytech.sendium.core.worker.InMemoryDlrService;
 import gr.cytech.sendium.core.worker.MessageState;
+import gr.cytech.sendium.util.MessageTrace;
 import jakarta.annotation.security.PermitAll;
 import jakarta.inject.Inject;
 import jakarta.ws.rs.GET;
@@ -44,6 +46,9 @@ public class KannelResource {
     @Inject
     InMemoryDlrService dlrService;
 
+    @Inject
+    SendiumConfigurationHandler configurationHandler;
+
     @Operation(
             operationId = "sendSms",
             summary = "Send an SMS message",
@@ -205,6 +210,9 @@ public Response receiveSms(
             }
             msg.acked = true;
             msg.serial = UUID.randomUUID().toString();
+            if (MessageTrace.shouldLog(configurationHandler, MessageTrace.EVENT_ACCEPTED)) {
+                logger.info("message.accepted ingress=http {}", MessageTrace.identifiers(msg));
+            }
             queueProvider.getRouterQueue().enqueue(msg);
             MessageState state = new MessageState(msg.serial, usr, msg.from, msg.to, dlrUrl);
             dlrService.saveInitialState(state);
@@ -241,7 +249,7 @@ public void validateKannelAuth(String username, String password) {
         }
 
         if (!password.equals(cred.password())) {
-            logger.warn("Invalid password:{}", password);
+            logger.warn("Invalid password for username:{}", username);
             throw new WebApplicationException(Response.status(Response.Status.UNAUTHORIZED)
                     .entity("Invalid credentials")
                     .build());

sendium-core/src/main/java/gr/cytech/sendium/core/message/StandardMessage.java

@@ -431,6 +431,7 @@ public static String getType(int type) {
             case MSG_HLR: return MSG_TYPE_HLR;
             case MSG_HLR_RSP: return MSG_TYPE_HLR_RSP;
             case MSG_MMS: return MSG_TYPE_MMS;
+            case MSG_VIBER: return MSG_TYPE_VIBER;
             case MSG_DCB: return MSG_TYPE_DCB;
             default: return MSG_TYPE_CUSTOM;
         }
@@ -832,4 +833,4 @@ public enum MarginStatus {
         KNOWN,          // 1 - Calculated successfully
         UNKNOWN         // 2 - Calculation failed (missing data)
     }
-}
+}