OpenBankProject · hongwei1 · Sep 23, 2026
diff --git a/README.md b/README.md
@@ -304,9 +304,12 @@ Note: Your Java environment may need to be set up correctly to use SSL.
 
 Restart OBP-API, if you get an error, check your Java environment can connect to the host over SSL.
 
-Note: You can copy the following example files to prepare your own configurations:
+Note: `/obp-api/src/main/resources/logback.xml` ships ready to use, defaulting to INFO. Set the
+`LOG_LEVEL` environment variable (e.g. `LOG_LEVEL=DEBUG` or `LOG_LEVEL=TRACE`) to override it per
+environment without editing the file.
+
+You can also copy the following example file to prepare your own test-run configuration:
 
-- `/obp-api/src/main/resources/logback.xml.example` -> `/obp-api/src/main/resources/logback.xml` (try TRACE or DEBUG).
 - `/obp-api/src/main/resources/logback-test.xml.example` -> `/obp-api/src/main/resources/logback-test.xml` (try TRACE or DEBUG).
 
 There is a gist/tool which is useful for this. Search the web for SSLPoke. Note this is an external repository.

diff --git a/obp-api/src/main/resources/docs/brief_system_documentation.md b/obp-api/src/main/resources/docs/brief_system_documentation.md
@@ -137,7 +137,7 @@ User ──(has roles/entitlements)──► Bank/System actions
 
 **Logging**
 
-- Copy `logback.xml.example` to `logback.xml`; adjust levels (TRACE/DEBUG/INFO) per environment.
+- `logback.xml` ships ready to use, defaulting to INFO; set `LOG_LEVEL` (TRACE/DEBUG/INFO/...) to override per environment.
 - In Docker/K8s, logs go to stdout/stderr → aggregate with your stack (e.g., Loki/Promtail, EFK).
 
 **Health & metrics**

diff --git a/obp-api/src/main/resources/logback.xml b/obp-api/src/main/resources/logback.xml
@@ -0,0 +1,17 @@
+<configuration>
+
+  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
+    <encoder>
+      <pattern>%d{yyyy-MM-dd HH:mm:ss} %t %c{0} [%p] %m%n</pattern>
+    </encoder>
+  </appender>
+
+  <!-- LOG_LEVEL env var (or -DLOG_LEVEL= system property) overrides this; unset falls back to
+       INFO. Default is intentionally quiet, not DEBUG: DEBUG by default means every deployment
+       silently pays the cost of maximal log volume (including the per-message secret-masking
+       pass in SecureLogging) unless someone remembers to turn it down, an opt-out default that
+       is easy to forget. Verbose logging should be an explicit, per-environment opt-in instead. -->
+  <root level="${LOG_LEVEL:-INFO}">
+    <appender-ref ref="STDOUT"/>
+  </root>
+</configuration>
diff --git a/obp-api/src/main/resources/logback.xml.example b/obp-api/src/main/resources/logback.xml.example
diff --git a/obp-api/src/main/resources/props/sample.props.template b/obp-api/src/main/resources/props/sample.props.template
@@ -1948,6 +1948,13 @@ ethereum.rpc.url=http://127.0.0.1:8545
 ## Enable Redis logging (true/false)
 redis_logging_enabled = false
 
+## Lowest level shipped to Redis when redis_logging_enabled is true (TRACE/DEBUG/INFO/WARNING/ERROR).
+## Defaults to INFO so enabling Redis log shipping doesn't also force every DEBUG/TRACE call site
+## (which can be extremely high-volume) to pay the cost of formatting and masking a message that
+## would otherwise be skipped locally. Set to DEBUG or TRACE only when you actually want that volume
+## shipped, e.g. temporarily while investigating an issue.
+redis_logging_min_level = INFO
+
 ## Batch size for sending logs to Redis
 ## Smaller batch size reduces latency for logging critical messages.
 redis_logging_batch_size = 50
@@ -1978,6 +1985,21 @@ redis_logging_warning_queue_max_entries = 1000   # Max WARNING messages
 redis_logging_error_queue_max_entries = 1000     # Max ERROR messages
 redis_logging_all_queue_max_entries = 1000       # Max ALL messages
 
+
+
+##########################################################
+#                   MDC Logging Dispatch                #
+##########################################################
+## Number of threads used to run secret-masking (SecureLogging.maskSensitive) and the local/
+## Redis log write itself, once a call to logger.debug/info/warn/error/trace has determined
+## the message will actually be consumed. This work used to run inline on whatever thread
+## called the logger, including http4s/cats-effect fiber-managed threads -- CPU-bound work
+## that doesn't yield can trip the runtime's own fiber-starvation detector the same way real
+## blocking I/O would, and its response (spinning up more worker/blocker threads that are
+## never reclaimed) was a contributing factor in a real incident. Keep this small; it's meant
+## to decouple from the calling thread, not to parallelize heavy logging.
+mdc_logging_dispatch_thread_pool_size = 2
+
 ## Optional: Circuit breaker reset interval (ms)
 ## How long before retrying after circuit breaker opens. Default 60s.
 redis_logging_circuit_breaker_reset_ms = 60000

diff --git a/obp-api/src/main/scala/code/api/cache/RedisLogger.scala b/obp-api/src/main/scala/code/api/cache/RedisLogger.scala
@@ -60,6 +60,33 @@ object RedisLogger {
 
   // Performance and reliability improvements
   private val redisLoggingEnabled = APIUtil.getPropsAsBoolValue("redis_logging_enabled", false)
+
+  /**
+   * Whether Redis log shipping is turned on for this instance. Callers that want to skip
+   * building a log message when neither the local logger nor Redis will consume it (e.g.
+   * MdcLoggable) should check this alongside the local logger's isXEnabled.
+   */
+  def isEnabled: Boolean = redisLoggingEnabled
+
+  /**
+   * Floor below which levels are not shipped to Redis even when redis_logging_enabled is
+   * true. Defaults to INFO so that turning Redis log shipping on for a deployment doesn't
+   * silently force every DEBUG/TRACE call site (which can be extremely high-volume) to pay
+   * the cost of formatting and masking a message it would otherwise skip. Set to TRACE to
+   * restore the old "ship everything" behaviour.
+   */
+  private val redisLoggingMinLevel: LogLevel.LogLevel =
+    LogLevel.valueOf(APIUtil.getPropsValue("redis_logging_min_level", "INFO"))
+
+  /**
+   * Whether a message at this level should be shipped to Redis right now. Combines the
+   * on/off switch with the minimum-level floor above. Callers that only want to know "is
+   * Redis shipping on at all" (e.g. to decide whether to enable a config UI) should keep
+   * using `isEnabled`; callers deciding whether to build+ship a specific message should use
+   * this instead.
+   */
+  def shouldShip(level: LogLevel.LogLevel): Boolean =
+    redisLoggingEnabled && level != LogLevel.ALL && level.id >= redisLoggingMinLevel.id
   private val batchSize = APIUtil.getPropsAsIntValue("redis_logging_batch_size", 100)
   private val flushIntervalMs = APIUtil.getPropsAsIntValue("redis_logging_flush_interval_ms", 1000)
   private val maxRetries = APIUtil.getPropsAsIntValue("redis_logging_max_retries", 3)
@@ -175,7 +202,7 @@ object RedisLogger {
    * Returns a Future[Unit], failures are handled gracefully.
    */
   def logAsync(level: LogLevel.LogLevel, message: String): Future[Unit] = {
-    if (!redisLoggingEnabled) {
+    if (!shouldShip(level)) {
       return Future.successful(())
     }
 

diff --git a/obp-api/src/main/scala/code/api/util/JsonSchemaGenerator.scala b/obp-api/src/main/scala/code/api/util/JsonSchemaGenerator.scala
@@ -30,8 +30,10 @@ package code.api.util
 import org.json4s._
 import code.api.util.APIUtil.MessageDoc
 import com.openbankproject.commons.util.ReflectUtils
+import com.tesobe.CacheKeyFromArguments
 import org.json4s.JsonDSL._
 
+import scala.concurrent.duration._
 import scala.reflect.runtime.universe._
 
 /**
@@ -42,9 +44,34 @@ import scala.reflect.runtime.universe._
 object JsonSchemaGenerator {
 
   /**
-   * Convert a list of MessageDoc to a complete JSON Schema document
+   * Convert a list of MessageDoc to a complete JSON Schema document.
+   *
+   * Memoized in-process, keyed by connectorName: for a given connector the message docs
+   * (and therefore the schema) are static for the lifetime of the JVM, but building it
+   * walks every message type's full field tree via Scala runtime reflection (`<:<`/`=:=`
+   * subtype checks), which is expensive and -- unlike a plain field lookup -- leaves behind
+   * long-lived reflection bookkeeping objects (TypeConstraint/UndoPair/Symbol) that don't
+   * get reclaimed promptly. Recomputing this on every request under sustained polling is
+   * what drove a production old-gen heap to exhaustion. The caller (Http4s600) also has a
+   * Redis-backed cache in front of this, but that one silently falls through to a full
+   * recompute if Redis is unreachable or slow -- this in-memory layer doesn't depend on
+   * Redis at all, so it stays a working safety net even when Redis is the one struggling.
    */
   def messageDocsToJsonSchema(messageDocs: List[MessageDoc], connectorName: String): JObject = {
+    // This 3-tuple of random UUIDs is a placeholder only -- CacheKeyFromArguments is a macro
+    // that replaces it at compile time with a real key derived from this method's owner,
+    // name and arguments (regardless of this method's own arity; the convention throughout
+    // this codebase is always a 3-tuple here). See:
+    // https://github.com/OpenBankProject/scala-macros/blob/master/macros/src/main/scala/com/tesobe/CacheKeyFromArgumentsMacro.scala#L49
+    var cacheKey = (java.util.UUID.randomUUID().toString, java.util.UUID.randomUUID().toString, java.util.UUID.randomUUID().toString)
+    CacheKeyFromArguments.buildCacheKey {
+      code.api.cache.Caching.memoizeSyncWithImMemory(Some(cacheKey.toString()))(100000.days) {
+        messageDocsToJsonSchemaUncached(messageDocs, connectorName)
+      }
+    }
+  }
+
+  private def messageDocsToJsonSchemaUncached(messageDocs: List[MessageDoc], connectorName: String): JObject = {
     val allDefinitions = scala.collection.mutable.Map[String, JObject]()
 
     val messages = messageDocs.map { messageDoc =>

diff --git a/obp-api/src/main/scala/code/util/Helper.scala b/obp-api/src/main/scala/code/util/Helper.scala
@@ -286,6 +286,50 @@ object Helper extends Loggable {
 
 
 
+  // Shared across every class mixing in MdcLoggable below -- created once at object-init,
+  // not per mixing instance. Masking (SecureLogging.maskSensitive, ~19 regex passes) and
+  // Redis-shipping serialization are CPU-bound work that used to run inline on whatever
+  // thread called logger.debug/info/etc. On this codebase's http4s/cats-effect request path
+  // that thread is often a fiber-managed worker; running non-yielding CPU work on it directly
+  // is indistinguishable, from the runtime's own fairness/starvation detector, from genuine
+  // blocking I/O -- cats-effect's "your CPU is probably starving" warning fires the same way
+  // either way, and its response is to compensate by spinning up additional worker/blocker
+  // threads that are never reclaimed. Dispatching this work onto a small dedicated pool
+  // instead means the calling thread (fiber or otherwise) returns immediately, regardless of
+  // what kind of thread it happens to be -- this trait is mixed into ~260 classes, many of
+  // them called from contexts (actors, scheduled jobs, Lift-era code) that have no IO runtime
+  // at all, so wrapping in cats.effect.IO.blocking isn't an option here: nothing would ever
+  // run it in those contexts. A plain background ExecutionContext works everywhere the
+  // trait itself is used. Same pattern RedisLogger already uses for its own async shipping.
+  //
+  // Trade-off worth being explicit about: log output for a given logger is no longer
+  // strictly write-ordered relative to other concurrent callers (each dispatched entry lands
+  // whenever its turn on this small pool comes up). That's the same trade-off any async
+  // logging setup makes (Logback's own AsyncAppender, Log4j2's AsyncLogger); this was never a
+  // strict global ordering guarantee to begin with once Redis shipping (already async) was in
+  // the picture.
+  // lazy, not val: Helper's own static initializer transitively touches other objects
+  // (APIUtil/Constant among them) that log during THEIR initialization, which can re-enter
+  // here before a plain val declared at this point in the object body would have run yet --
+  // observed as a NullPointerException on this executor during Helper's own <clinit>, caught
+  // by MdcLoggableDispatchTest. `lazy val` computes on first real use instead of at a fixed
+  // point in top-to-bottom initialization order, which is what this needs given how
+  // entangled this codebase's early object initialization already is (not something
+  // introduced here).
+  private lazy val mdcLoggingExecutor: java.util.concurrent.ExecutorService = {
+    val threadCount = new java.util.concurrent.atomic.AtomicInteger(0)
+    java.util.concurrent.Executors.newFixedThreadPool(
+      APIUtil.getPropsAsIntValue("mdc_logging_dispatch_thread_pool_size", 2),
+      (r: Runnable) => {
+        val t = new Thread(r, s"mdc-log-dispatch-${threadCount.incrementAndGet()}")
+        t.setDaemon(true)
+        t
+      }
+    )
+  }
+  private lazy val mdcLoggingExecutionContext: scala.concurrent.ExecutionContext =
+    scala.concurrent.ExecutionContext.fromExecutor(mdcLoggingExecutor)
+
   trait MdcLoggable extends Loggable {
 
     // Capture the class name of the component mixing in this trait
@@ -311,63 +355,114 @@ object Helper extends Loggable {
           s"[$ts] [$thread] [$clazzName] ${msg.toString}"
         }
 
+      // Every level below builds `maskedMsg` by running the message through ~19 regex
+      // passes in SecureLogging.maskSensitive. That cost must only be paid when the
+      // result is actually going to be consumed (by the local logger and/or Redis
+      // shipping) -- not unconditionally on every call site, which is what made this a
+      // hot path under high request volume with DEBUG enabled. And once it is going to be
+      // paid, it's dispatched onto mdcLoggingExecutionContext (see its own doc comment)
+      // rather than run inline on whatever thread called into this logger.
+      private def dispatch(body: => Unit): Unit = {
+        val future = scala.concurrent.Future(body)(mdcLoggingExecutionContext)
+        future.failed.foreach { e =>
+          System.err.println(s"[$clazzName] background log dispatch failed: ${e.getMessage}")
+        }(mdcLoggingExecutionContext)
+      }
+
       // INFO
       override def info(msg: => AnyRef): Unit = {
-        val maskedMsg = SecureLogging.maskSensitive(msg)
-        underlyingLogger.info(maskedMsg)
-        RedisLogger.logAsync(RedisLogger.LogLevel.INFO, toRedisFormat(maskedMsg))
+        if (underlyingLogger.isInfoEnabled || RedisLogger.shouldShip(RedisLogger.LogLevel.INFO)) {
+          dispatch {
+            val maskedMsg = SecureLogging.maskSensitive(msg)
+            if (underlyingLogger.isInfoEnabled) underlyingLogger.info(maskedMsg)
+            RedisLogger.logAsync(RedisLogger.LogLevel.INFO, toRedisFormat(maskedMsg))
+          }
+        }
       }
 
       override def info(msg: => AnyRef, t: => Throwable): Unit = {
-        val maskedMsg = SecureLogging.maskSensitive(msg)
-        underlyingLogger.info(maskedMsg, t)
-        RedisLogger.logAsync(RedisLogger.LogLevel.INFO, toRedisFormat(maskedMsg) + "\n" + t.toString)
+        if (underlyingLogger.isInfoEnabled || RedisLogger.shouldShip(RedisLogger.LogLevel.INFO)) {
+          dispatch {
+            val maskedMsg = SecureLogging.maskSensitive(msg)
+            val capturedT = t
+            if (underlyingLogger.isInfoEnabled) underlyingLogger.info(maskedMsg, capturedT)
+            RedisLogger.logAsync(RedisLogger.LogLevel.INFO, toRedisFormat(maskedMsg) + "\n" + capturedT.toString)
+          }
+        }
       }
 
       // WARN
       override def warn(msg: => AnyRef): Unit = {
-        val maskedMsg = SecureLogging.maskSensitive(msg)
-        underlyingLogger.warn(maskedMsg)
-        RedisLogger.logAsync(RedisLogger.LogLevel.WARNING, toRedisFormat(maskedMsg))
+        if (underlyingLogger.isWarnEnabled || RedisLogger.shouldShip(RedisLogger.LogLevel.WARNING)) {
+          dispatch {
+            val maskedMsg = SecureLogging.maskSensitive(msg)
+            if (underlyingLogger.isWarnEnabled) underlyingLogger.warn(maskedMsg)
+            RedisLogger.logAsync(RedisLogger.LogLevel.WARNING, toRedisFormat(maskedMsg))
+          }
+        }
       }
 
       override def warn(msg: => AnyRef, t: Throwable): Unit = {
-        val maskedMsg = SecureLogging.maskSensitive(msg)
-        underlyingLogger.warn(maskedMsg, t)
-        RedisLogger.logAsync(RedisLogger.LogLevel.WARNING, toRedisFormat(maskedMsg) + "\n" + t.toString)
+        if (underlyingLogger.isWarnEnabled || RedisLogger.shouldShip(RedisLogger.LogLevel.WARNING)) {
+          dispatch {
+            val maskedMsg = SecureLogging.maskSensitive(msg)
+            if (underlyingLogger.isWarnEnabled) underlyingLogger.warn(maskedMsg, t)
+            RedisLogger.logAsync(RedisLogger.LogLevel.WARNING, toRedisFormat(maskedMsg) + "\n" + t.toString)
+          }
+        }
       }
 
       // ERROR
       override def error(msg: => AnyRef): Unit = {
-        val maskedMsg = SecureLogging.maskSensitive(msg)
-        underlyingLogger.error(maskedMsg)
-        RedisLogger.logAsync(RedisLogger.LogLevel.ERROR, toRedisFormat(maskedMsg))
+        if (underlyingLogger.isErrorEnabled || RedisLogger.shouldShip(RedisLogger.LogLevel.ERROR)) {
+          dispatch {
+            val maskedMsg = SecureLogging.maskSensitive(msg)
+            if (underlyingLogger.isErrorEnabled) underlyingLogger.error(maskedMsg)
+            RedisLogger.logAsync(RedisLogger.LogLevel.ERROR, toRedisFormat(maskedMsg))
+          }
+        }
       }
 
       override def error(msg: => AnyRef, t: Throwable): Unit = {
-        val maskedMsg = SecureLogging.maskSensitive(msg)
-        underlyingLogger.error(maskedMsg, t)
-        RedisLogger.logAsync(RedisLogger.LogLevel.ERROR, toRedisFormat(maskedMsg) + "\n" + t.toString)
+        if (underlyingLogger.isErrorEnabled || RedisLogger.shouldShip(RedisLogger.LogLevel.ERROR)) {
+          dispatch {
+            val maskedMsg = SecureLogging.maskSensitive(msg)
+            if (underlyingLogger.isErrorEnabled) underlyingLogger.error(maskedMsg, t)
+            RedisLogger.logAsync(RedisLogger.LogLevel.ERROR, toRedisFormat(maskedMsg) + "\n" + t.toString)
+          }
+        }
       }
 
       // DEBUG
       override def debug(msg: => AnyRef): Unit = {
-        val maskedMsg = SecureLogging.maskSensitive(msg)
-        underlyingLogger.debug(maskedMsg)
-        RedisLogger.logAsync(RedisLogger.LogLevel.DEBUG, toRedisFormat(maskedMsg))
+        if (underlyingLogger.isDebugEnabled || RedisLogger.shouldShip(RedisLogger.LogLevel.DEBUG)) {
+          dispatch {
+            val maskedMsg = SecureLogging.maskSensitive(msg)
+            if (underlyingLogger.isDebugEnabled) underlyingLogger.debug(maskedMsg)
+            RedisLogger.logAsync(RedisLogger.LogLevel.DEBUG, toRedisFormat(maskedMsg))
+          }
+        }
       }
 
       override def debug(msg: => AnyRef, t: Throwable): Unit = {
-        val maskedMsg = SecureLogging.maskSensitive(msg)
-        underlyingLogger.debug(maskedMsg, t)
-        RedisLogger.logAsync(RedisLogger.LogLevel.DEBUG, toRedisFormat(maskedMsg) + "\n" + t.toString)
+        if (underlyingLogger.isDebugEnabled || RedisLogger.shouldShip(RedisLogger.LogLevel.DEBUG)) {
+          dispatch {
+            val maskedMsg = SecureLogging.maskSensitive(msg)
+            if (underlyingLogger.isDebugEnabled) underlyingLogger.debug(maskedMsg, t)
+            RedisLogger.logAsync(RedisLogger.LogLevel.DEBUG, toRedisFormat(maskedMsg) + "\n" + t.toString)
+          }
+        }
       }
 
       // TRACE
       override def trace(msg: => AnyRef): Unit = {
-        val maskedMsg = SecureLogging.maskSensitive(msg)
-        underlyingLogger.trace(maskedMsg)
-        RedisLogger.logAsync(RedisLogger.LogLevel.TRACE, toRedisFormat(maskedMsg))
+        if (underlyingLogger.isTraceEnabled || RedisLogger.shouldShip(RedisLogger.LogLevel.TRACE)) {
+          dispatch {
+            val maskedMsg = SecureLogging.maskSensitive(msg)
+            if (underlyingLogger.isTraceEnabled) underlyingLogger.trace(maskedMsg)
+            RedisLogger.logAsync(RedisLogger.LogLevel.TRACE, toRedisFormat(maskedMsg))
+          }
+        }
       }
 
       // Delegate enabled checks