diff --git a/SECURITY.md b/SECURITY.md index 50094a2..b6e51d3 100644 --- a/SECURITY.md +++ b/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 diff --git a/SUPPORT.md b/SUPPORT.md index 5cb1f73..bd95c18 100644 --- a/SUPPORT.md +++ b/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. diff --git a/docs/04-smpp-configuration.md b/docs/04-smpp-configuration.md index ab45f31..ddf4e31 100644 --- a/docs/04-smpp-configuration.md +++ b/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. | diff --git a/docs/09-configuration-reference.md b/docs/09-configuration-reference.md index e29579f..dc00230 100644 --- a/docs/09-configuration-reference.md +++ b/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: diff --git a/docs/10-troubleshooting.md b/docs/10-troubleshooting.md index 2e9405d..074b475 100644 --- a/docs/10-troubleshooting.md +++ b/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..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 diff --git a/sendium-app/src/main/resources/application.properties b/sendium-app/src/main/resources/application.properties index 1fdf986..71cb063 100644 --- a/sendium-app/src/main/resources/application.properties +++ b/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 diff --git a/sendium-core/src/main/java/gr/cytech/sendium/auth/CredentialFileParser.java b/sendium-core/src/main/java/gr/cytech/sendium/auth/CredentialFileParser.java index 5ea5750..e3699cf 100644 --- a/sendium-core/src/main/java/gr/cytech/sendium/auth/CredentialFileParser.java +++ b/sendium-core/src/main/java/gr/cytech/sendium/auth/CredentialFileParser.java @@ -33,7 +33,7 @@ public static Map 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; } )); diff --git a/sendium-core/src/main/java/gr/cytech/sendium/conf/ConfFileWatcher.java b/sendium-core/src/main/java/gr/cytech/sendium/conf/ConfFileWatcher.java index c0be32a..f34c3bd 100644 --- a/sendium-core/src/main/java/gr/cytech/sendium/conf/ConfFileWatcher.java +++ b/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 loadPropertiesFromFile(File file) { diff --git a/sendium-core/src/main/java/gr/cytech/sendium/conf/PropertyChangeEvent.java b/sendium-core/src/main/java/gr/cytech/sendium/conf/PropertyChangeEvent.java index 4629eae..6e90c27 100644 --- a/sendium-core/src/main/java/gr/cytech/sendium/conf/PropertyChangeEvent.java +++ b/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) + "\"}"; } } \ No newline at end of file diff --git a/sendium-core/src/main/java/gr/cytech/sendium/conf/SendiumConfigurationHandler.java b/sendium-core/src/main/java/gr/cytech/sendium/conf/SendiumConfigurationHandler.java index d37176a..789e3b1 100644 --- a/sendium-core/src/main/java/gr/cytech/sendium/conf/SendiumConfigurationHandler.java +++ b/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; } } diff --git a/sendium-core/src/main/java/gr/cytech/sendium/core/AbstractOutWorker.java b/sendium-core/src/main/java/gr/cytech/sendium/core/AbstractOutWorker.java index cb70a58..2608daf 100644 --- a/sendium-core/src/main/java/gr/cytech/sendium/core/AbstractOutWorker.java +++ b/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 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,7 +1109,9 @@ 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; @@ -1110,7 +1119,9 @@ protected void onMessageFailed(M m, boolean shouldAttemptWorkerRetry) { 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 diff --git a/sendium-core/src/main/java/gr/cytech/sendium/core/http/KannelResource.java b/sendium-core/src/main/java/gr/cytech/sendium/core/http/KannelResource.java index 778031c..8d05962 100644 --- a/sendium-core/src/main/java/gr/cytech/sendium/core/http/KannelResource.java +++ b/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()); diff --git a/sendium-core/src/main/java/gr/cytech/sendium/core/message/StandardMessage.java b/sendium-core/src/main/java/gr/cytech/sendium/core/message/StandardMessage.java index 3f450b8..da1e48b 100644 --- a/sendium-core/src/main/java/gr/cytech/sendium/core/message/StandardMessage.java +++ b/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) } -} \ No newline at end of file +} diff --git a/sendium-core/src/main/java/gr/cytech/sendium/core/smpp/client/SmppClientSessionHandler.java b/sendium-core/src/main/java/gr/cytech/sendium/core/smpp/client/SmppClientSessionHandler.java index 1fc262b..0f737e8 100644 --- a/sendium-core/src/main/java/gr/cytech/sendium/core/smpp/client/SmppClientSessionHandler.java +++ b/sendium-core/src/main/java/gr/cytech/sendium/core/smpp/client/SmppClientSessionHandler.java @@ -18,6 +18,7 @@ import gr.cytech.sendium.core.message.StandardMessage; import gr.cytech.sendium.core.smpp.SmsgSmppSessionHandler; import gr.cytech.sendium.core.smpp.util.SmppServerUtil; +import gr.cytech.sendium.util.MessageTrace; import org.slf4j.Logger; import org.slf4j.LoggerFactory; @@ -125,7 +126,7 @@ public PduResponse firePduRequestReceived(PduRequest pduRequest) { //removeConnectionAndReconnect(this); resp = pduRequest.createResponse(); resp.setReferenceObject(this); - logger.info("responding to unbind request:{} with resp:{}", pduRequest, resp); + logger.info("responding to unbind request {} with resp {}", MessageTrace.pdu(pduRequest), MessageTrace.pdu(resp)); break; default: logger.debug("{}: received (invalid/not handled) pdu request: {}", this, pduRequest); @@ -144,7 +145,7 @@ public PduResponse firePduRequestReceived(PduRequest pduRequest) { * @param pduRequest The request PDU received on this session */ public void firePduRequestExpired(PduRequest pduRequest) { - logger.info("{}: received expired request PDU: {}", this, pduRequest); + logger.info("{}: received expired request PDU {}", this, MessageTrace.pdu(pduRequest)); switch (pduRequest.getCommandId()) { case SmppConstants.CMD_ID_SUBMIT_SM: @@ -155,7 +156,7 @@ public void firePduRequestExpired(PduRequest pduRequest) { smppClientWorker.handleResponse(this, SmppConstants.STATUS_DELIVERYFAILURE, null, msg); } else { - logger.warn("Pdu response with no object reference received, do nothing: {}", pduRequest); + logger.warn("Pdu response with no object reference received, do nothing {}", MessageTrace.pdu(pduRequest)); return; } break; @@ -209,7 +210,8 @@ public void fireExpectedPduResponseReceived(PduAsyncResponse pduAsyncResponse) { // ask worker to handle response String respMessageId = resp.getMessageId(); if (msg == null) { - logger.warn("{} no attached message for submit: {} with response:{}", this, submit, resp); + logger.warn("{} no attached message for submit {} with response {}", this, + MessageTrace.pdu(submit), MessageTrace.pdu(resp)); return; } smppClientWorker.handleResponse(this, statusCode, respMessageId, msg); @@ -240,7 +242,7 @@ public void fireExpectedPduResponseReceived(PduAsyncResponse pduAsyncResponse) { * @param pduResponse The "unexpected" response PDU received on this session */ public void fireUnexpectedPduResponseReceived(PduResponse pduResponse) { - logger.warn("{}: received unexpected response PDU (it will be ignored): {}", this, pduResponse); + logger.warn("{}: received unexpected response PDU (it will be ignored) {}", this, MessageTrace.pdu(pduResponse)); } /** @@ -284,7 +286,7 @@ public void fireRecoverablePduException(RecoverablePduException e) { try { this.session.sendResponsePdu(resp); } catch (Exception ex) { - logger.warn("received further exception while trying to send back generic nack for request:{}", partialPdu, ex); + logger.warn("received further exception while trying to send back generic nack for partial PDU", ex); } } } diff --git a/sendium-core/src/main/java/gr/cytech/sendium/core/smpp/client/SmppClientWorker.java b/sendium-core/src/main/java/gr/cytech/sendium/core/smpp/client/SmppClientWorker.java index ae25f87..75c639f 100644 --- a/sendium-core/src/main/java/gr/cytech/sendium/core/smpp/client/SmppClientWorker.java +++ b/sendium-core/src/main/java/gr/cytech/sendium/core/smpp/client/SmppClientWorker.java @@ -38,6 +38,7 @@ import gr.cytech.sendium.external.HealthCheckReport; import gr.cytech.sendium.external.WorkerResourceProvider; import gr.cytech.sendium.util.MessageFlexValue; +import gr.cytech.sendium.util.MessageTrace; import gr.cytech.sendium.util.SecurityUtils; import gr.cytech.sendium.util.TimeUtils; import jakarta.enterprise.context.Dependent; @@ -110,10 +111,10 @@ public class SmppClientWorker extends AbstractOutWork , {"unbind.timeout.millis", "5000"} , {"counters", "true"} , {"log.bytes", "false"} - , {"log.pdus", "true"} + , {"log.pdus", "false"} , {"log.pdus.exclude", SmppConstants.CMD_ID_ENQUIRE_LINK + "," + SmppConstants.CMD_ID_ENQUIRE_LINK_RESP} - , {"print.resps", "true"} - , {"print.mos", "true"} + , {"print.resps", "false"} + , {"print.mos", "false"} , {"systemType", ""} , {"addressRangeTon", ""} , {"addressRangeNpi", ""} @@ -502,7 +503,7 @@ public M doMessage(int pThreadIndex, M pMsg) throws IOException { try { requests = generateSubmitRequest(pMsg); } catch (Exception e) { - logger.warn("Caught exception while generating SMPP request(s) for msg:{}", pMsg, e); + logger.warn("Caught exception while generating SMPP request(s) {}", MessageTrace.identifiers(pMsg), e); return pMsg; } SmppClientSessionHandler handler = getAvailableHandlerForSending(); @@ -510,15 +511,21 @@ public M doMessage(int pThreadIndex, M pMsg) throws IOException { SubmitSm submitSm = requests.get(i); try { handler.getSession().sendRequestPdu(submitSm, configurationProvider.getLongPrpt(_requestTout), false); + StandardMessage submittedMsg = submitSm.getReferenceObject() instanceof StandardMessage ? + (StandardMessage) submitSm.getReferenceObject() : pMsg; + if (MessageTrace.shouldLog(configurationProvider, MessageTrace.EVENT_SUBMITTED)) { + logger.info("message.submitted worker={} part={}/{} {}", getFullName(), i + 1, requests.size(), + MessageTrace.identifiers(submittedMsg)); + } } catch (Exception e) { if (i == 0) { - logger.warn("Caught exception while sending 1st of {} parts for msg. Cancelling msg to be retried: {}", - requests.size(), pMsg); + logger.warn("Caught exception while sending 1st of {} parts. Cancelling message to be retried {}", + requests.size(), MessageTrace.identifiers(pMsg), e); return pMsg; } else { StandardMessage msgPart = (StandardMessage) submitSm.getReferenceObject(); - logger.warn("Caught exception while sending {} of {} parts for msg. It is re-enqueued as: {}", - i, requests.size(), msgPart); + logger.warn("Caught exception while sending {} of {} parts. Part is re-enqueued {}", + i, requests.size(), MessageTrace.identifiers(msgPart), e); enqueueNoExceptions((M) msgPart); } } @@ -965,7 +972,7 @@ public PduResponse parseDlrAndCreateResponse(DeliverSm deliverSm) { dlrBody = gsmBody; } } catch (Exception e) { - logger.warn("error trying to re-parse dlr with gsm charset: {}", deliverSm, e); + logger.warn("error trying to re-parse dlr with gsm charset {}", MessageTrace.pdu(deliverSm), e); } } if (Strings.isNullOrEmpty(dlrBody)) { @@ -983,7 +990,7 @@ public PduResponse parseDlrAndCreateResponse(DeliverSm deliverSm) { } String smscid = decodeMessageID(true, receipt.getMessageId()); if (Strings.isNullOrEmpty(smscid)) { - logger.warn("Invalid smscid: null or empty, skipping unknown dlr: {}", deliverSm); + logger.warn("Invalid smscid: null or empty, skipping unknown dlr {}", MessageTrace.pdu(deliverSm)); return deliverSm.createGenericNack(SmppConstants.STATUS_SYSERR); } HashMap tlvs = extractTlvs(this.tlvsDlrs, deliverSm); @@ -991,7 +998,7 @@ public PduResponse parseDlrAndCreateResponse(DeliverSm deliverSm) { } catch (Exception e) { //our own extended delivery receipt parsing method will not throw exception for dlr field validation //so this means that something else went really wrong - logger.warn("caught exception while parsing dlr: {}", deliverSm, e); + logger.warn("caught exception while parsing dlr {}", MessageTrace.pdu(deliverSm), e); PduResponse resp = deliverSm.createResponse(); resp.setCommandStatus(SmppConstants.STATUS_SYSERR); return resp; @@ -1125,6 +1132,7 @@ public void handleResponse(SmppClientSessionHandler handler, int statusCode, Str switch (policy) { case RETRY_WORKER: + logSubmitResponse(statusCode, respMessageId, msg); onMessageTemporaryFailed(msg); break; case RETRY_ROUTER: @@ -1134,6 +1142,7 @@ public void handleResponse(SmppClientSessionHandler handler, int statusCode, Str msg.outgateway = ""; } } + logSubmitResponse(statusCode, respMessageId, msg); onMessageFailed(msg); break; case FAIL: @@ -1158,11 +1167,12 @@ public NackHandlePolicy findPolicyForStatusCode(int statusCode) { } protected void successMessage(String respMessageId, M msg) { - updateSendStatusAndSmscId(respMessageId, msg); + String smscid = updateSendStatusAndSmscId(respMessageId, msg); + logSubmitResponse(SmppConstants.STATUS_OK, smscid, msg); try { onMessageSuccess(msg); } catch (Exception e) { - logger.warn("exception on message success callback for msg:{}", msg, e); + logger.warn("exception on message success callback {}", MessageTrace.identifiers(msg), e); } } @@ -1173,6 +1183,7 @@ public void failMessage(int commandStatus, String respMessageId, M msg) { } String smscid = updateSendStatusAndSmscId(respMessageId, msg); + logSubmitResponse(commandStatus, smscid, msg); String smsid = getHashedMessageID(smscid); String errorCode; @@ -1187,6 +1198,13 @@ public void failMessage(int commandStatus, String respMessageId, M msg) { StandardMessage.DLR_STAT_FAILED, errorCode, null); } + protected void logSubmitResponse(int statusCode, String operatorMsgId, M msg) { + if (MessageTrace.shouldLog(configurationProvider, MessageTrace.EVENT_SUBMIT_RESPONSE)) { + logger.info("message.submit.response worker={} status={} operatorMsgId={} {}", getFullName(), statusCode, + MessageTrace.value(operatorMsgId), MessageTrace.identifiers(msg)); + } + } + public String updateSendStatusAndSmscId(String respMessageId, M msg) { if (msg.msgId < 0) { return null; @@ -1866,4 +1884,3 @@ public String toString() { } } } - diff --git a/sendium-core/src/main/java/gr/cytech/sendium/core/smpp/server/InMemorySmppServerMessageStore.java b/sendium-core/src/main/java/gr/cytech/sendium/core/smpp/server/InMemorySmppServerMessageStore.java index efad50e..e0e4e02 100644 --- a/sendium-core/src/main/java/gr/cytech/sendium/core/smpp/server/InMemorySmppServerMessageStore.java +++ b/sendium-core/src/main/java/gr/cytech/sendium/core/smpp/server/InMemorySmppServerMessageStore.java @@ -3,6 +3,8 @@ import gr.cytech.sendium.core.message.StandardMessage; import gr.cytech.sendium.core.worker.InMemoryDlrService; import gr.cytech.sendium.core.worker.MessageState; +import gr.cytech.sendium.util.MessageTrace; +import gr.cytech.sendium.util.SensitiveLogSanitizer; import jakarta.inject.Inject; import org.slf4j.Logger; import org.slf4j.LoggerFactory; @@ -62,11 +64,11 @@ public boolean markAsUnpushed(StandardMessage msg) { try { boolean saved = getDlrService().saveUnpushedDlr(msg); if (!saved) { - logger.warn("Failed to save unpushed DLR: {}", msg); + logger.warn("Failed to save unpushed DLR {}", MessageTrace.identifiers(msg)); } return saved; } catch (Exception e) { - logger.warn("Exception while saving unpushed DLR: {}", msg, e); + logger.warn("Exception while saving unpushed DLR {}", MessageTrace.identifiers(msg), e); return false; } } @@ -90,7 +92,7 @@ public void onClientConnected(String systemId) { } } catch (Exception e) { dlrService.releaseUnpushedDlrClaim(msg); - logger.warn("Failed to re-enqueue unpushed DLR: {}", msg, e); + logger.warn("Failed to re-enqueue unpushed DLR {}", MessageTrace.identifiers(msg), e); } } } @@ -106,7 +108,10 @@ public int getMaxAttempts(boolean isDlr) { @Override public void configure(String key, String newValue, String oldValue) { - logger.debug("Configure: key={}, newValue={}, oldValue={}", key, newValue, oldValue); + logger.debug("Configure: key={}, newValue={}, oldValue={}", + key, + SensitiveLogSanitizer.maskValue(key, newValue), + SensitiveLogSanitizer.maskValue(key, oldValue)); } @Override diff --git a/sendium-core/src/main/java/gr/cytech/sendium/core/smpp/server/SmppServerBindHandler.java b/sendium-core/src/main/java/gr/cytech/sendium/core/smpp/server/SmppServerBindHandler.java index 8eae093..29f0821 100644 --- a/sendium-core/src/main/java/gr/cytech/sendium/core/smpp/server/SmppServerBindHandler.java +++ b/sendium-core/src/main/java/gr/cytech/sendium/core/smpp/server/SmppServerBindHandler.java @@ -36,7 +36,7 @@ public void sessionBindRequested( SmppSessionConfiguration sessionConfiguration, final BaseBind bindRequest ) throws SmppProcessingException { - logger.info("new bind request: {}", bindRequest); + logger.info("new bind request from ip:{} systemId:{}", sessionConfiguration.getHost(), sessionConfiguration.getSystemId()); checkIfConnectionFromIpIsOverLimit(sessionConfiguration.getHost()); SmppSessionContext context = authProvider.authenticate( sessionConfiguration.getSystemId(), diff --git a/sendium-core/src/main/java/gr/cytech/sendium/core/smpp/server/SmppServerSessionHandler.java b/sendium-core/src/main/java/gr/cytech/sendium/core/smpp/server/SmppServerSessionHandler.java index 014db49..68131fd 100644 --- a/sendium-core/src/main/java/gr/cytech/sendium/core/smpp/server/SmppServerSessionHandler.java +++ b/sendium-core/src/main/java/gr/cytech/sendium/core/smpp/server/SmppServerSessionHandler.java @@ -22,6 +22,7 @@ import gr.cytech.sendium.core.smpp.SmsgSmppSessionHandler; import gr.cytech.sendium.core.smpp.util.SmppServerUtil; import gr.cytech.sendium.util.Constants; +import gr.cytech.sendium.util.MessageTrace; import gr.cytech.sendium.util.MessageUtil; import org.slf4j.Logger; import org.slf4j.LoggerFactory; @@ -98,7 +99,7 @@ public PduResponse firePduRequestReceived(PduRequest pduRequest) { try { handleSubmitSm(submitSm); } catch (Exception e) { - logger.error("{}: handling of submit sm caused exception: {}", this, pduRequest, e); + logger.error("{}: handling of submit sm caused exception {}", this, MessageTrace.pdu(pduRequest), e); resp = SmppServerUtil.createSubmitRsp(submitSm, SmppConstants.STATUS_SYSERR, null); worker.enqueueOut(resp); } @@ -130,7 +131,7 @@ public PduResponse firePduRequestReceived(PduRequest pduRequest) { * @param pduRequest The request PDU received on this session */ public void firePduRequestExpired(PduRequest pduRequest) { - logger.info("{}: received expired request PDU: {}", this, pduRequest); + logger.info("{}: received expired request PDU {}", this, MessageTrace.pdu(pduRequest)); if (pduRequest.getCommandId() == SmppConstants.CMD_ID_DELIVER_SM) { try { @@ -139,7 +140,7 @@ public void firePduRequestExpired(PduRequest pduRequest) { worker.markAsUnpushed(original); } catch (Exception e) { - logger.warn("{}: error while handling expired pdu request {}", this, pduRequest, e); + logger.warn("{}: error while handling expired pdu request {}", this, MessageTrace.pdu(pduRequest), e); } } } @@ -177,7 +178,7 @@ public void fireExpectedPduResponseReceived(PduAsyncResponse pduAsyncResponse) { * be returned by the remote endpoint in response to a PDU. */ if (pduAsyncResponse.getResponse().getCommandStatus() != SmppConstants.STATUS_OK) { - logger.warn("{}: pdu response with error status received: {}", this, pduAsyncResponse.getResponse()); + logger.warn("{}: pdu response with error status received {}", this, MessageTrace.pdu(pduAsyncResponse.getResponse())); } } @@ -192,7 +193,7 @@ public void fireExpectedPduResponseReceived(PduAsyncResponse pduAsyncResponse) { * @param pduResponse The "unexpected" response PDU received on this session */ public void fireUnexpectedPduResponseReceived(PduResponse pduResponse) { - logger.warn("{}: received unexpected response PDU: {}", this, pduResponse); + logger.warn("{}: received unexpected response PDU {}", this, MessageTrace.pdu(pduResponse)); } /** @@ -219,7 +220,7 @@ public void fireUnrecoverablePduException(UnrecoverablePduException e) { public void fireRecoverablePduException(RecoverablePduException e) { PartialPdu partialPdu = (PartialPdu) e.getPartialPdu(); - logger.warn("{}: received: {}", this, partialPdu, e); + logger.warn("{}: received malformed partial PDU", this, e); if (partialPdu.getReferenceObject() == null) { partialPdu.setReferenceObject(new Object[]{this, System.currentTimeMillis()}); @@ -292,7 +293,7 @@ public boolean firePduReceived(Pdu pdu) { ) { if (!rateController.tryAcquire()) { pdu.setReferenceObject(new Object[]{this, System.currentTimeMillis()}); - logger.warn("{}: PDU throttled (rate={}): {}", this, rateController.getRate(), pdu); + logger.warn("{}: PDU throttled rate={} {}", this, rateController.getRate(), MessageTrace.pdu(pdu)); GenericNack nack = SmppServerUtil.createGenericNack((PduRequest) pdu, SmppConstants.STATUS_THROTTLED); worker.enqueueOut(nack); return false; @@ -389,11 +390,11 @@ public void handleSubmitSm(SubmitSm submitSm) { InEvent ine = submitProcessor.processSubmitSm(submitSm, sessionContext, validatedMessageBody, tstamp); worker.enqueueIn(ine); } catch (SmppProcessingException e) { - logger.warn("{} error processing submit sm: {}", this, submitSm, e); + logger.warn("{} error processing submit sm {}", this, MessageTrace.pdu(submitSm), e); SubmitSmResp resp = SmppServerUtil.createSubmitRsp(submitSm, e.getErrorCode(), null); worker.enqueueOut(resp); } catch (Exception e) { - logger.error("{}: unexpected error processing submit sm: {}", this, submitSm, e); + logger.error("{}: unexpected error processing submit sm {}", this, MessageTrace.pdu(submitSm), e); SubmitSmResp resp = SmppServerUtil.createSubmitRsp(submitSm, SmppConstants.STATUS_SYSERR, null); worker.enqueueOut(resp); } diff --git a/sendium-core/src/main/java/gr/cytech/sendium/core/smpp/server/SmppServerWorker.java b/sendium-core/src/main/java/gr/cytech/sendium/core/smpp/server/SmppServerWorker.java index 2296a9b..5e41100 100644 --- a/sendium-core/src/main/java/gr/cytech/sendium/core/smpp/server/SmppServerWorker.java +++ b/sendium-core/src/main/java/gr/cytech/sendium/core/smpp/server/SmppServerWorker.java @@ -32,6 +32,7 @@ import gr.cytech.sendium.external.filter.FilterException; import gr.cytech.sendium.external.filter.FilterStatusCodes; import gr.cytech.sendium.external.filter.InMessageFiltering; +import gr.cytech.sendium.util.MessageTrace; import io.netty.channel.EventLoopGroup; import io.netty.channel.epoll.Epoll; import io.netty.channel.epoll.EpollEventLoopGroup; @@ -78,7 +79,7 @@ public class SmppServerWorker extends AbstractOutWork public final String[] _srvMonitorThreads = {"srv.monitor.threads", "1"}; public final String[] _srvOutThreads = {"srv.out.threads", "10"}; public final String[] _logBytes = {"log.bytes", "false"}; - public final String[] _logPdus = {"log.pdus", "true"}; + public final String[] _logPdus = {"log.pdus", "false"}; protected final String[] _srvEnabled = {"srv.enabled", "true"}; protected final String[] _srvPort = {"srv.port", "0"}; @@ -616,7 +617,7 @@ public M doMessage(int pThreadIndex, M pMsg) throws IOException { try { requests = isDlr ? generateDeliverSmForDLR(pMsg) : generateDeliverSmForMO(pMsg); } catch (Exception e) { - logger.warn("Caught exception while generating SMPP request(s) for msg:{}", pMsg, e); + logger.warn("Caught exception while generating SMPP request(s) {}", MessageTrace.identifiers(pMsg), e); return isDlr ? null : pMsg; } @@ -627,6 +628,9 @@ public M doMessage(int pThreadIndex, M pMsg) throws IOException { for (DeliverSm deliverSm : requests) { deliverSm.setReferenceObject(new Object[]{handler, pMsg}); enqueueOut(deliverSm); + if (MessageTrace.shouldLog(configurationProvider, MessageTrace.EVENT_DELIVER_ENQUEUED)) { + logger.info("message.deliver.enqueued worker={} {}", getFullName(), MessageTrace.identifiers(pMsg)); + } } return null; } @@ -800,9 +804,12 @@ public boolean markAsUnpushed(M msg) { public void outTaskFailed(Pdu pdu, M message) { if (pdu != null && pdu.isRequest() && pdu.getCommandId() == SmppConstants.CMD_ID_DELIVER_SM) { if (message == null) { - logger.warn("no message found for the failed out pdu:{}", pdu); + logger.warn("no message found for the failed out pdu {}", MessageTrace.pdu(pdu)); return; } + if (MessageTrace.shouldLog(configurationProvider, MessageTrace.EVENT_DELIVER_FAILED)) { + logger.warn("message.deliver.failed worker={} {}", getFullName(), MessageTrace.identifiers(message)); + } if (!markAsUnpushed(message)) { enqueueNoExceptions(message); } @@ -821,6 +828,9 @@ public void enqueueIn(InEvent ine) { return; } filtered.pMsg.serial = UUID.randomUUID().toString(); + if (MessageTrace.shouldLog(configurationProvider, MessageTrace.EVENT_ACCEPTED)) { + logger.info("message.accepted ingress=smppserver worker={} {}", getFullName(), MessageTrace.identifiers(filtered.pMsg)); + } filtered.waitingForResponse = false; filtered.pMsg.ctstamp = ine.localTimestamp.getTime(); filtered.pMsg.onetwork = ine.mpid; @@ -866,13 +876,13 @@ public InEvent handleBeforeInsertMessageFiltering(InEvent ine) { filter.doFilter(FilterLifecyclePhase.BEFORE_INSERT, ine.pMsg); } catch (FilterException fe) { if (fe.getStatusCode() == FilterStatusCodes.DROP) { - logger.debug("Dropping message {} after filtering (before insert)", ine); + logger.debug("Dropping message after filtering (before insert) {}", MessageTrace.identifiers(ine.pMsg)); enqueueOut(SmppServerUtil.createSubmitRsp(ine.submitSm, VendorSpecificConstants.STATUS_NUMBLOCKED, null)); return null; } } catch (Exception e) { logger.warn("exception caught while trying to apply filter:{} before inserting message {}. " + - "ignoring filter and continuing", filter.getFullName(), ine, e); + "ignoring filter and continuing", filter.getFullName(), MessageTrace.identifiers(ine.pMsg), e); } } @@ -1208,4 +1218,4 @@ private FailDelayPolicyAction onWorkerEndRetry(StandardMessage msg, int trial) { return reEnqueueRouter; } } -} \ No newline at end of file +} diff --git a/sendium-core/src/main/java/gr/cytech/sendium/core/smpp/server/tasks/InTask.java b/sendium-core/src/main/java/gr/cytech/sendium/core/smpp/server/tasks/InTask.java index 36f2be2..8e42ba4 100644 --- a/sendium-core/src/main/java/gr/cytech/sendium/core/smpp/server/tasks/InTask.java +++ b/sendium-core/src/main/java/gr/cytech/sendium/core/smpp/server/tasks/InTask.java @@ -6,6 +6,7 @@ import gr.cytech.sendium.core.smpp.server.InEvent; import gr.cytech.sendium.core.smpp.server.SmppServerWorker; import gr.cytech.sendium.core.smpp.util.SmppServerUtil; +import gr.cytech.sendium.util.MessageTrace; import gr.cytech.sendium.util.TimeUtils; import org.slf4j.Logger; import org.slf4j.LoggerFactory; @@ -87,7 +88,7 @@ public void processEvents() { currentBatchSize++; } } catch (InterruptedException e) { - logger.warn("Exception caught while waiting for in event {}", ine, e); + logger.warn("Exception caught while waiting for in event {}", MessageTrace.identifiers(ine == null ? null : ine.pMsg), e); } } while (currentBatchSize < maxBatchSize && remainingTime >= 0); diff --git a/sendium-core/src/main/java/gr/cytech/sendium/core/smpp/server/tasks/OutTask.java b/sendium-core/src/main/java/gr/cytech/sendium/core/smpp/server/tasks/OutTask.java index deb108f..b865d79 100644 --- a/sendium-core/src/main/java/gr/cytech/sendium/core/smpp/server/tasks/OutTask.java +++ b/sendium-core/src/main/java/gr/cytech/sendium/core/smpp/server/tasks/OutTask.java @@ -6,6 +6,7 @@ import gr.cytech.sendium.core.message.StandardMessage; import gr.cytech.sendium.core.smpp.server.SmppServerSessionHandler; import gr.cytech.sendium.core.smpp.server.SmppServerWorker; +import gr.cytech.sendium.util.MessageTrace; import org.slf4j.Logger; import org.slf4j.LoggerFactory; @@ -50,6 +51,10 @@ public void run() { if (!success) { worker.outTaskFailed(pdu, msg); + } else if (!pdu.isResponse() && msg != null) { + if (MessageTrace.shouldLog(worker.getConfigurationProvider(), MessageTrace.EVENT_DELIVER_SENT)) { + logger.info("message.deliver.sent worker={} {}", worker.getFullName(), MessageTrace.identifiers(msg)); + } } } diff --git a/sendium-core/src/main/java/gr/cytech/sendium/core/worker/InMemoryDlrService.java b/sendium-core/src/main/java/gr/cytech/sendium/core/worker/InMemoryDlrService.java index 96bdea1..e9ae9c3 100644 --- a/sendium-core/src/main/java/gr/cytech/sendium/core/worker/InMemoryDlrService.java +++ b/sendium-core/src/main/java/gr/cytech/sendium/core/worker/InMemoryDlrService.java @@ -168,7 +168,6 @@ public void saveInitialState(MessageState context) { String json = mapper.writeValueAsString(context); primaryStore.put(context.getGatewayMsgId(), json); primaryTimestamps.put(context.getGatewayMsgId(), System.currentTimeMillis()); - logger.info("Saved initial state on primaryStore for gatewayMsgId: {}", context.getGatewayMsgId()); } catch (JsonProcessingException e) { logger.error("Failed to serialize MessageState for gatewayMsgId: {}", context.getGatewayMsgId(), e); } @@ -215,7 +214,6 @@ public void linkOperatorId(String gatewayMsgId, String operatorMsgId) { primaryStore.put(gatewayMsgId, mapper.writeValueAsString(state)); correlationIndex.put(operatorMsgId, gatewayMsgId); correlationTimestamps.put(operatorMsgId, System.currentTimeMillis()); - logger.warn("Linked operatorMsgId: {} to gatewayMsgId: {}", operatorMsgId, gatewayMsgId); } catch (JsonProcessingException e) { logger.error("Failed to serialize updated MessageState", e); } diff --git a/sendium-core/src/main/java/gr/cytech/sendium/core/worker/InMemoryMessageTracker.java b/sendium-core/src/main/java/gr/cytech/sendium/core/worker/InMemoryMessageTracker.java index fb65081..056e3ed 100644 --- a/sendium-core/src/main/java/gr/cytech/sendium/core/worker/InMemoryMessageTracker.java +++ b/sendium-core/src/main/java/gr/cytech/sendium/core/worker/InMemoryMessageTracker.java @@ -2,7 +2,9 @@ import gr.cytech.sendium.core.AbstractOutWorker; import gr.cytech.sendium.core.message.StandardMessage; +import gr.cytech.sendium.util.MessageTrace; import gr.cytech.sendium.util.SecurityUtils; +import gr.cytech.sendium.util.SensitiveLogSanitizer; import org.slf4j.Logger; import org.slf4j.LoggerFactory; @@ -33,7 +35,10 @@ public boolean stop() { @Override public void configure(String key, String newValue, String oldValue) { - logger.debug("Configure: key={}, newValue={}, oldValue={}", key, newValue, oldValue); + logger.debug("Configure: key={}, newValue={}, oldValue={}", + key, + SensitiveLogSanitizer.maskValue(key, newValue), + SensitiveLogSanitizer.maskValue(key, oldValue)); } @Override @@ -41,7 +46,9 @@ public int updateSendStatusAndExtID(String smsid, StandardMessage pMsg, String s smsid = pMsg.serial; //in our case no hash needed if (smsid != null && !smsid.isEmpty() && smscid != null && !smscid.isEmpty()) { outWorker.getWorkerResources().getDlrService().linkOperatorId(smsid, smscid); - logger.debug("Linked gatewayMsgId={} to operatorMsgId={}", smsid, smscid); + if (MessageTrace.shouldLog(outWorker.getConfigurationProvider(), MessageTrace.EVENT_OPERATOR_LINKED)) { + logger.info("message.operator.linked operatorMsgId={} {}", MessageTrace.value(smscid), MessageTrace.identifiers(pMsg)); + } return 1; } logger.warn("Invalid parameters: smsid={}, smscid={}", smsid, smscid); @@ -85,7 +92,9 @@ public void createAndEnqueueDLR(int mqid, String smscid, String smsid, String fr } catch (InterruptedException ie) { outWorker.handleException(ie); } - logger.debug("DLR enqueued for gatewayMsgId: {}, status: {}", msgState.getGatewayMsgId(), state); + if (MessageTrace.shouldLog(outWorker.getConfigurationProvider(), MessageTrace.EVENT_DLR)) { + logger.info("message.dlr status={} operatorMsgId={} {}", state, MessageTrace.value(smscid), MessageTrace.identifiers(dlrMsg)); + } } else { logger.warn("DLR received for unknown/expired message: smsid={}", smsid); } diff --git a/sendium-core/src/main/java/gr/cytech/sendium/routing/AbstractRoutingManager.java b/sendium-core/src/main/java/gr/cytech/sendium/routing/AbstractRoutingManager.java index c8a2265..e18add6 100644 --- a/sendium-core/src/main/java/gr/cytech/sendium/routing/AbstractRoutingManager.java +++ b/sendium-core/src/main/java/gr/cytech/sendium/routing/AbstractRoutingManager.java @@ -5,6 +5,7 @@ import gr.cytech.sendium.core.AbstractOutWorker; import gr.cytech.sendium.core.message.StandardMessage; import gr.cytech.sendium.external.filter.FilterException; +import gr.cytech.sendium.util.MessageTrace; import gr.cytech.sendium.util.TimeUtils; import io.quarkus.arc.Arc; import org.slf4j.Logger; @@ -58,6 +59,8 @@ public abstract class AbstractRoutingManager implemen protected abstract int getConfigInt(String[] prop); + protected abstract String getConfigString(String[] prop); + @Override public void propertyChange(PropertyChangeEvent evt) { String key = evt.getKey(); @@ -158,15 +161,20 @@ public void getNextMessageInQueueAndRoute() { if (sent) { msg = null; //Avoid further handling in finally block; } else { - logger.warn("No route for: ({}), requeuing it", msg); + if (MessageTrace.shouldLog(getConfigString(MessageTrace.TRACE_MODE), MessageTrace.EVENT_ROUTING_MISS)) { + logger.warn("message.routing.miss action=requeue {}", MessageTrace.identifiers(msg)); + } TimeUtils.sleep(100, TimeUnit.MILLISECONDS); } } catch (InterruptedException ie) { - logger.warn("Interrupted while processing msg:{}", msg, ie); + logger.warn("Interrupted while processing message {}", MessageTrace.identifiers(msg), ie); } catch (FilterException fe) { switch (fe.getStatusCode()) { case DROP: - logger.info("DROP {} {} {}", fe.getFilter().getFullName(), fe.getMessage(), msg); + if (MessageTrace.shouldLog(getConfigString(MessageTrace.TRACE_MODE), MessageTrace.EVENT_DROPPED)) { + logger.info("message.dropped filter={} reason={} {}", fe.getFilter().getFullName(), fe.getMessage(), + MessageTrace.identifiers(msg)); + } msg = null; break; case RESCHEDULE: @@ -208,6 +216,9 @@ public boolean sendMessageToTargets(M msg, RoutingLookupResult result) throws In logger.info("Message: ({}) has target: ({})", msg, target); } // Suppressing unchecked cast since we know workers take StandardMessage + if (MessageTrace.shouldLog(getConfigString(MessageTrace.TRACE_MODE), MessageTrace.EVENT_ROUTED)) { + logger.info("message.routed target={} {}", target.getFullName(), MessageTrace.identifiers(msg)); + } ((AbstractOutWorker) target).enqueue(msg); } return true; @@ -222,7 +233,7 @@ private void handleMessageFailure(M msg, Exception e) { } msg.rtxCnt++; } - logger.error("Error processing msg {}", msg, e); + logger.error("Error processing message {}", MessageTrace.identifiers(msg), e); } public static class RoutingTargets { diff --git a/sendium-core/src/main/java/gr/cytech/sendium/routing/StandardRoutingManager.java b/sendium-core/src/main/java/gr/cytech/sendium/routing/StandardRoutingManager.java index d691153..8e983c4 100644 --- a/sendium-core/src/main/java/gr/cytech/sendium/routing/StandardRoutingManager.java +++ b/sendium-core/src/main/java/gr/cytech/sendium/routing/StandardRoutingManager.java @@ -6,6 +6,7 @@ import gr.cytech.sendium.core.message.StandardMessage; import gr.cytech.sendium.core.queue.InMemoryQueueProvider; import gr.cytech.sendium.external.filter.FilterException; +import gr.cytech.sendium.util.MessageTrace; import gr.cytech.sendium.util.TimeUtils; import io.quarkus.arc.DefaultBean; import io.quarkus.runtime.StartupEvent; @@ -73,6 +74,11 @@ protected int getConfigInt(String[] prop) { return sendiumConfigurationHandler.getIntPrpt(prop); } + @Override + protected String getConfigString(String[] prop) { + return sendiumConfigurationHandler.getPrpt(prop); + } + public void beforeWorkerStop(AbstractOutWorker worker) { if (!areWorkersStarted) { return; @@ -172,7 +178,7 @@ private void handleMessageFailure(StandardMessage msg, Exception e) { } msg.rtxCnt++; } - logger.error("Error processing msg {}", msg, e); + logger.error("Error processing message {}", MessageTrace.identifiers(msg), e); } @Override @@ -184,7 +190,7 @@ protected void handleMessageUnexpectedFailure(StandardMessage msg, Throwable e) "Adding it to failed queue! " + "You must address the error and then re-enqueue the messages, " + "by setting the property: {} equal to true!", - msg, e, _enqueueFailedRouting[0]); + MessageTrace.identifiers(msg), e, _enqueueFailedRouting[0]); //sent error to external system ideally } } @@ -211,7 +217,8 @@ protected RoutingLookupResult lookupRoutingForMessage(StandardMessage pMsg, Rout if (result.hasReachedLast()) { if (pMsg.rtxCnt == 0 && !Strings.isNullOrEmpty(pMsg.nextTarget) && pMsg.nextTarget.equals(Strings.nullToEmpty(originalNextTarget))) { - logger.warn("Message has exact same next target as before routing. Switching it to noMoreTargets to avoid possible looping: {}", pMsg); + logger.warn("Message has exact same next target as before routing. Switching it to noMoreTargets {}", + MessageTrace.identifiers(pMsg)); pMsg.nextTarget = NO_MORE_TARGETS; } return result; diff --git a/sendium-core/src/main/java/gr/cytech/sendium/util/MessageTrace.java b/sendium-core/src/main/java/gr/cytech/sendium/util/MessageTrace.java new file mode 100644 index 0000000..f79353e --- /dev/null +++ b/sendium-core/src/main/java/gr/cytech/sendium/util/MessageTrace.java @@ -0,0 +1,146 @@ +package gr.cytech.sendium.util; + +import com.cloudhopper.smpp.pdu.Pdu; +import gr.cytech.sendium.conf.SendiumConfigurationProvider; +import gr.cytech.sendium.core.message.StandardMessage; + +import java.util.Collection; +import java.util.Map; + +public final class MessageTrace { + public static final String EVENT_ACCEPTED = "message.accepted"; + public static final String EVENT_DELIVER_SENT = "message.deliver.sent"; + public static final String EVENT_DELIVER_ENQUEUED = "message.deliver.enqueued"; + public static final String EVENT_DELIVER_FAILED = "message.deliver.failed"; + public static final String EVENT_DLR = "message.dlr"; + public static final String EVENT_DROPPED = "message.dropped"; + public static final String EVENT_DELIVERY_FAILED = "message.delivery.failed"; + public static final String EVENT_DELIVERY_RETRY = "message.delivery.retry"; + public static final String EVENT_ENQUEUED = "message.enqueued"; + public static final String EVENT_OPERATOR_LINKED = "message.operator.linked"; + public static final String EVENT_ROUTED = "message.routed"; + public static final String EVENT_ROUTING_MISS = "message.routing.miss"; + public static final String EVENT_SUBMITTED = "message.submitted"; + public static final String EVENT_SUBMIT_RESPONSE = "message.submit.response"; + public static final String[] TRACE_MODE = {"message.trace.mode", TraceMode.NECESSARY.value}; + + private static final String MISSING = "-"; + + private MessageTrace() { + } + + public static String identifiers(StandardMessage msg) { + if (msg == null) { + return "serial=- msgId=- extrid=-"; + } + + String serial = value(msg.serial); + return "serial=" + serial + + " msgId=" + msg.msgId + + " extrid=" + value(msg.extrid) + + " type=" + value(StandardMessage.getType(msg.type)) + + " typeId=" + msg.type + + " priority=" + msg.priority + + " acked=" + msg.acked + + " dcs=" + msg.dcs + + " mclass=" + msg.mclass + + " ttl=" + msg.ttl + + " ddt=" + msg.ddt + + " state=" + msg.state + + " errcode=" + value(msg.errcode) + + " rtxCnt=" + msg.rtxCnt + + " accountId=" + value(msg.owner_id) + + " systemId=" + value(msg.systemId) + + " messageCenter=" + value(msg.message_center) + + " ingateway=" + value(msg.ingateway) + + " outgateway=" + value(msg.outgateway) + + " nextTarget=" + value(msg.nextTarget) + + " onetwork=" + msg.onetwork + + " cnetwork=" + msg.cnetwork + + " smsCnt=" + msg.smsCnt + + " submitParts=" + msg.smsSubmitCnt + + " reassembledParts=" + size(msg.reassembledParts) + + " hasUdh=" + hasValue(msg.binheader) + + " tlvCount=" + size(msg.tlvs); + } + + public static String pdu(Pdu pdu) { + if (pdu == null) { + return "pduCommandId=- pduSequence=- pduStatus=-"; + } + + return "pduCommandId=" + pdu.getCommandId() + + " pduSequence=" + pdu.getSequenceNumber() + + " pduStatus=" + pdu.getCommandStatus(); + } + + public static String value(String value) { + if (value == null || value.isBlank()) { + return MISSING; + } + + return value.replace('\r', '_') + .replace('\n', '_') + .replace('\t', '_') + .replace(' ', '_'); + } + + public static boolean shouldLog(SendiumConfigurationProvider configurationProvider, String eventName) { + String mode = configurationProvider == null ? TRACE_MODE[1] : configurationProvider.getPrpt(TRACE_MODE); + return shouldLog(mode, eventName); + } + + public static boolean shouldLog(String mode, String eventName) { + return TraceMode.from(mode).allows(eventName); + } + + private static boolean hasValue(String value) { + return value != null && !value.isBlank(); + } + + private static int size(Collection values) { + return values == null ? 0 : values.size(); + } + + private static int size(Map values) { + return values == null ? 0 : values.size(); + } + + private enum TraceMode { + OFF("off"), + NECESSARY("necessary"), + ALL("all"); + + private final String value; + + TraceMode(String value) { + this.value = value; + } + + private static TraceMode from(String value) { + String normalized = value == null ? "" : value.trim(); + if (OFF.value.equalsIgnoreCase(normalized)) { + return OFF; + } else if (ALL.value.equalsIgnoreCase(normalized)) { + return ALL; + } else { + return NECESSARY; + } + } + + private boolean allows(String eventName) { + return switch (this) { + case OFF -> false; + case NECESSARY -> isNecessaryEvent(eventName); + case ALL -> true; + }; + } + + private boolean isNecessaryEvent(String eventName) { + return switch (eventName) { + case EVENT_ACCEPTED, EVENT_SUBMITTED, EVENT_DLR, EVENT_DELIVER_SENT -> true; + default -> false; + }; + } + } +} diff --git a/sendium-core/src/main/java/gr/cytech/sendium/util/SensitiveLogSanitizer.java b/sendium-core/src/main/java/gr/cytech/sendium/util/SensitiveLogSanitizer.java new file mode 100644 index 0000000..11a58eb --- /dev/null +++ b/sendium-core/src/main/java/gr/cytech/sendium/util/SensitiveLogSanitizer.java @@ -0,0 +1,36 @@ +package gr.cytech.sendium.util; + +import java.util.Locale; + +public final class SensitiveLogSanitizer { + public static final String REDACTED = "*****"; + + private SensitiveLogSanitizer() { + } + + public static String maskValue(String key, String value) { + if (value == null) { + return "null"; + } + return isSensitiveKey(key) ? REDACTED : value; + } + + public static boolean isSensitiveKey(String key) { + if (key == null) { + return false; + } + + String lowerKey = key.toLowerCase(Locale.ROOT); + return lowerKey.contains("password") || + lowerKey.contains("secret") || + lowerKey.contains("token") || + lowerKey.contains("apikey") || + lowerKey.contains("api_key") || + lowerKey.contains("api-key") || + lowerKey.contains("api.key") || + lowerKey.contains("privatekey") || + lowerKey.contains("private_key") || + lowerKey.contains("private-key") || + lowerKey.contains("private.key"); + } +} diff --git a/sendium-core/src/test/java/gr/cytech/sendium/conf/ConfFileWatcherTest.java b/sendium-core/src/test/java/gr/cytech/sendium/conf/ConfFileWatcherTest.java index 1d1e40b..dc5c3f2 100644 --- a/sendium-core/src/test/java/gr/cytech/sendium/conf/ConfFileWatcherTest.java +++ b/sendium-core/src/test/java/gr/cytech/sendium/conf/ConfFileWatcherTest.java @@ -92,6 +92,7 @@ void maskSecretMasksSensitiveKeysOnly() throws Exception { assertThat(method.invoke(watcher, "db.password", "secret")).isEqualTo("*****"); assertThat(method.invoke(watcher, "api.token", "token")).isEqualTo("*****"); + assertThat(method.invoke(watcher, "http.apiKey", "api-key")).isEqualTo("*****"); assertThat(method.invoke(watcher, "plain.key", "value")).isEqualTo("value"); assertThat(method.invoke(watcher, "plain.key", null)).isEqualTo("null"); } diff --git a/sendium-core/src/test/java/gr/cytech/sendium/conf/SendiumConfigurationHandlerTest.java b/sendium-core/src/test/java/gr/cytech/sendium/conf/SendiumConfigurationHandlerTest.java index 6248272..c9b33d1 100644 --- a/sendium-core/src/test/java/gr/cytech/sendium/conf/SendiumConfigurationHandlerTest.java +++ b/sendium-core/src/test/java/gr/cytech/sendium/conf/SendiumConfigurationHandlerTest.java @@ -90,6 +90,21 @@ void firePropertyChangeContinuesWhenOneListenerThrows() { assertThat(events.getFirst().getOldValue()).isEqualTo("old"); } + @Test + void propertyChangeEventToStringMasksSensitiveValuesOnly() { + var sensitive = new PropertyChangeEvent("db.password", "secret", "old-secret"); + var plain = new PropertyChangeEvent("plain.key", "value", "old-value"); + + assertThat(sensitive.toString()) + .contains("\"value\":\"*****\"") + .contains("\"oldValue\":\"*****\"") + .doesNotContain("secret") + .doesNotContain("old-secret"); + assertThat(plain.toString()) + .contains("\"value\":\"value\"") + .contains("\"oldValue\":\"old-value\""); + } + @Test void loadDefaultParamsPrefixesKeysOnlyOnce() { String[][] params = {{"host", "localhost"}, {"outSms.instance.worker.port", "2775"}}; diff --git a/sendium-core/src/test/java/gr/cytech/sendium/core/smpp/client/SmppClientWorkerTest.java b/sendium-core/src/test/java/gr/cytech/sendium/core/smpp/client/SmppClientWorkerTest.java index ef774e0..3a60f63 100644 --- a/sendium-core/src/test/java/gr/cytech/sendium/core/smpp/client/SmppClientWorkerTest.java +++ b/sendium-core/src/test/java/gr/cytech/sendium/core/smpp/client/SmppClientWorkerTest.java @@ -25,6 +25,18 @@ class SmppClientWorkerTest { + @Test + void defaultsSensitiveDiagnosticLoggingOff() { + TestConfigurationProvider config = new TestConfigurationProvider(); + TestSmppClientWorker worker = new TestSmppClientWorker(config, new Queue<>(), new CapturingTracker()); + + assertThat(worker.isPrintMsgs()).isFalse(); + assertThat(config.getBlnPrpt(worker._logPdus)).isFalse(); + assertThat(config.getBlnPrpt(worker._logBytes)).isFalse(); + assertThat(config.getBlnPrpt(worker._printResps)).isFalse(); + assertThat(config.getBlnPrpt(worker._printMos)).isFalse(); + } + @Test void parseDlrAndCreateResponse_whenReceiptIsValid_enqueuesDlrWithRegisteredTlvs() throws Exception { TestConfigurationProvider config = new TestConfigurationProvider(Map.of( diff --git a/sendium-core/src/test/java/gr/cytech/sendium/routing/AbstractRoutingManagerTest.java b/sendium-core/src/test/java/gr/cytech/sendium/routing/AbstractRoutingManagerTest.java index 4273294..0789bc3 100644 --- a/sendium-core/src/test/java/gr/cytech/sendium/routing/AbstractRoutingManagerTest.java +++ b/sendium-core/src/test/java/gr/cytech/sendium/routing/AbstractRoutingManagerTest.java @@ -164,5 +164,10 @@ protected boolean getConfigBoolean(String[] prop) { protected int getConfigInt(String[] prop) { return 1; } + + @Override + protected String getConfigString(String[] prop) { + return prop[1]; + } } } diff --git a/sendium-core/src/test/java/gr/cytech/sendium/util/MessageTraceTest.java b/sendium-core/src/test/java/gr/cytech/sendium/util/MessageTraceTest.java new file mode 100644 index 0000000..1b16bbe --- /dev/null +++ b/sendium-core/src/test/java/gr/cytech/sendium/util/MessageTraceTest.java @@ -0,0 +1,139 @@ +package gr.cytech.sendium.util; + +import gr.cytech.sendium.core.message.StandardMessage; +import org.junit.jupiter.api.Test; + +import java.util.ArrayList; +import java.util.HashMap; +import java.util.List; +import java.util.Map; + +import static org.assertj.core.api.Assertions.assertThat; + +class MessageTraceTest { + + @Test + void identifiersIncludeSafeSupportContext() { + StandardMessage message = new StandardMessage(); + message.serial = "gw-1"; + message.msgId = 17; + message.extrid = "operator-1"; + message.type = StandardMessage.MSG_DLR; + message.priority = StandardMessage.HIGH_PRIORITY; + message.acked = true; + message.dcs = StandardMessage.DCS_16BIT; + message.mclass = 2; + message.ttl = 60; + message.ddt = 10; + message.state = StandardMessage.DLR_STAT_DELIVRD; + message.errcode = "0"; + message.rtxCnt = 2; + message.owner_id = "account-1"; + message.systemId = "system-1"; + message.message_center = "smsc-1"; + message.ingateway = "smpp.in"; + message.outgateway = "smpp.out"; + message.nextTarget = "fallback"; + message.onetwork = 20201; + message.cnetwork = 20205; + message.smsCnt = 2; + message.smsSubmitCnt = 3; + message.reassembledParts = new ArrayList<>(List.of("part-1", "part-2")); + message.binheader = "UDH-SECRET"; + message.tlvs = new HashMap<>(Map.of("carrier_tag", "TLV-SECRET")); + + String trace = MessageTrace.identifiers(message); + + assertThat(trace).contains( + "serial=gw-1", + "msgId=17", + "extrid=operator-1", + "type=l", + "typeId=18", + "priority=3", + "acked=true", + "dcs=8", + "mclass=2", + "ttl=60", + "ddt=10", + "state=1", + "errcode=0", + "rtxCnt=2", + "accountId=account-1", + "systemId=system-1", + "messageCenter=smsc-1", + "ingateway=smpp.in", + "outgateway=smpp.out", + "nextTarget=fallback", + "onetwork=20201", + "cnetwork=20205", + "smsCnt=2", + "submitParts=3", + "reassembledParts=2", + "hasUdh=true", + "tlvCount=1"); + } + + @Test + void identifiersDoNotIncludePayloadAddressesOrArbitraryFields() { + StandardMessage message = new StandardMessage(); + message.from = "FROM-SECRET"; + message.to = "TO-SECRET"; + message.body = "BODY-SECRET"; + message.binbody = "BINBODY-SECRET"; + message.binheader = "BINHEADER-SECRET"; + message.metadata = "METADATA-SECRET"; + message.field1 = "FIELD-SECRET"; + message.attrs = new HashMap<>(Map.of("attr", "ATTR-SECRET")); + message.tlvs = new HashMap<>(Map.of("tlv", "TLV-SECRET")); + + String trace = MessageTrace.identifiers(message); + + assertThat(trace).doesNotContain( + "FROM-SECRET", + "TO-SECRET", + "BODY-SECRET", + "BINBODY-SECRET", + "BINHEADER-SECRET", + "METADATA-SECRET", + "FIELD-SECRET", + "ATTR-SECRET", + "TLV-SECRET"); + } + + @Test + void identifiersUseNamedViberType() { + StandardMessage message = new StandardMessage(); + message.type = StandardMessage.MSG_VIBER; + + assertThat(MessageTrace.identifiers(message)).contains("type=v", "typeId=22"); + } + + @Test + void shouldLogDisablesAllMessageFlowEventsWhenModeIsOff() { + assertThat(MessageTrace.shouldLog("off", MessageTrace.EVENT_ACCEPTED)).isFalse(); + assertThat(MessageTrace.shouldLog("off", MessageTrace.EVENT_SUBMITTED)).isFalse(); + assertThat(MessageTrace.shouldLog("off", MessageTrace.EVENT_DLR)).isFalse(); + assertThat(MessageTrace.shouldLog("off", MessageTrace.EVENT_DELIVER_SENT)).isFalse(); + assertThat(MessageTrace.shouldLog("off", MessageTrace.EVENT_ROUTED)).isFalse(); + } + + @Test + void shouldLogAllowsOnlyNecessaryMessageFlowEventsByDefault() { + assertThat(MessageTrace.shouldLog((String) null, MessageTrace.EVENT_ACCEPTED)).isTrue(); + assertThat(MessageTrace.shouldLog("necessary", MessageTrace.EVENT_SUBMITTED)).isTrue(); + assertThat(MessageTrace.shouldLog(" necessary ", MessageTrace.EVENT_DLR)).isTrue(); + assertThat(MessageTrace.shouldLog("invalid", MessageTrace.EVENT_DELIVER_SENT)).isTrue(); + assertThat(MessageTrace.shouldLog("necessary", MessageTrace.EVENT_ENQUEUED)).isFalse(); + assertThat(MessageTrace.shouldLog("necessary", MessageTrace.EVENT_ROUTED)).isFalse(); + assertThat(MessageTrace.shouldLog("necessary", MessageTrace.EVENT_SUBMIT_RESPONSE)).isFalse(); + } + + @Test + void shouldLogAllowsEveryMessageFlowEventWhenModeIsAll() { + assertThat(MessageTrace.shouldLog("all", MessageTrace.EVENT_ACCEPTED)).isTrue(); + assertThat(MessageTrace.shouldLog("all", MessageTrace.EVENT_ENQUEUED)).isTrue(); + assertThat(MessageTrace.shouldLog("all", MessageTrace.EVENT_ROUTED)).isTrue(); + assertThat(MessageTrace.shouldLog("all", MessageTrace.EVENT_SUBMIT_RESPONSE)).isTrue(); + } +} diff --git a/sendium-core/src/test/java/utils/NativeE2eSmoke.java b/sendium-core/src/test/java/utils/NativeE2eSmoke.java index 3439736..8a585f4 100644 --- a/sendium-core/src/test/java/utils/NativeE2eSmoke.java +++ b/sendium-core/src/test/java/utils/NativeE2eSmoke.java @@ -226,12 +226,12 @@ private static void writeRuntimeConfig(Path workDir) throws IOException { outSms.instance.route.tps = 0 outSms.instance.route.connections.transceivers = 1 outSms.instance.route.connection.healthcheck = true - outSms.instance.route.print.msgs = true + outSms.instance.route.print.msgs = false outSms.instance.smpp.enable = true outSms.instance.smpp.type = smppserver outSms.instance.smpp.tps = 0 - outSms.instance.smpp.print.msgs = true + outSms.instance.smpp.print.msgs = false outSms.instance.smpp.srv.host = 0.0.0.0 outSms.instance.smpp.srv.port = 27777 outSms.instance.smpp.srv.bindTimeout = 5000 diff --git a/sendium-core/src/test/resources/smsg.properties b/sendium-core/src/test/resources/smsg.properties index f61dfa8..5d9695e 100644 --- a/sendium-core/src/test/resources/smsg.properties +++ b/sendium-core/src/test/resources/smsg.properties @@ -14,13 +14,13 @@ outSms.instance.route.tps = 0 outSms.instance.route.connections.transceivers = 1 outSms.instance.route.log.bytes = false outSms.instance.route.log.pdus = false -outSms.instance.route.print.msgs = truef +outSms.instance.route.print.msgs = false outSms.instance.smpp.enable = truef outSms.instance.smpp.type = smppserver outSms.instance.smpp.pause = false outSms.instance.smpp.tps = 0 -outSms.instance.smpp.print.msgs = true +outSms.instance.smpp.print.msgs = false outSms.instance.smpp.srv.host = 0.0.0.0 outSms.instance.smpp.srv.port = 27777 outSms.instance.smpp.srv.bindTimeout = 5000 @@ -33,4 +33,4 @@ outSms.instance.smpp.srv.printRateCount = 0 outSms.instance.smpp.srv.printRatePeriod = 0 outSms.instance.smpp.srv.printStatsPeriod = 0 outSms.instance.smpp.conf.maxConnectionsPerUser.default = 4 -outSms.instance.smpp.conf.maxRate.default = 0 \ No newline at end of file +outSms.instance.smpp.conf.maxRate.default = 0