001/* 002 * Licensed to the Apache Software Foundation (ASF) under one or more 003 * contributor license agreements. See the NOTICE file distributed with 004 * this work for additional information regarding copyright ownership. 005 * The ASF licenses this file to You under the Apache License, Version 2.0 006 * (the "License"); you may not use this file except in compliance with 007 * the License. You may obtain a copy of the License at 008 * 009 * http://www.apache.org/licenses/LICENSE-2.0 010 * 011 * Unless required by applicable law or agreed to in writing, software 012 * distributed under the License is distributed on an "AS IS" BASIS, 013 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. 014 * See the License for the specific language governing permissions and 015 * limitations under the License. 016 */ 017package org.apache.juneau.rest.server.logging; 018 019import static org.apache.juneau.commons.utils.IoUtils.*; 020import static org.apache.juneau.commons.utils.Shorts.*; 021 022import java.util.*; 023import java.util.stream.*; 024 025import org.apache.juneau.commons.inject.*; 026import org.apache.juneau.http.*; 027import org.apache.juneau.rest.server.*; 028 029import jakarta.servlet.http.*; 030 031/** 032 * Default {@link RestDebugFormatter} implementation — secure by default. 033 * 034 * <p> 035 * Renders, cumulatively by tier: 036 * <ul> 037 * <li><b>Basic ({@code INFO})</b> — a single status line ({@code [status] HTTP method uri}), with the method and 038 * URI sanitized and the URI length-capped. 039 * <li><b>Headers ({@code FINE})</b> — request/response header blocks (<b>every</b> value of every header, 040 * credential-bearing values masked, all names/values sanitized and bounded), plus request/response lengths and the 041 * request execution time. 042 * <li><b>Body ({@code FINEST})</b> — request/response bodies, but <b>only if the operator has opted in</b> (see 043 * below); otherwise a suppression placeholder + byte count. 044 * </ul> 045 * 046 * <h5 class='section'>Secure-by-default body handling</h5> 047 * <p> 048 * Bodies are <b>never dumped by default</b>. Dumping is a deliberate operator opt-in behind a single environment-variable 049 * master gate, {@code JUNEAU_REST_DEBUG_ALLOW_DUMP_BODIES}: 050 * <ul> 051 * <li><b>Env-only.</b> It is an environment variable, never a system property, and has no system-property fallback 052 * — application code cannot flip it at runtime. 053 * <li><b>Truthy semantics.</b> The raw value is trimmed, then a non-empty value enables dumping except case-insensitive 054 * {@code false}/{@code 0}; unset/empty/all-whitespace disables. It is resolved once and cached, making it an 055 * emergency kill switch. 056 * <li><b>Gate subordinate.</b> With the gate unset, {@link #formatBody(RestRequest,RestResponse) formatBody} emits only 057 * the suppression placeholder + byte count — always, even if a {@link RestDebugBodyScrubber} is configured 058 * (the scrubber is never invoked). 059 * <li><b>Renderable content only.</b> Even when opted in, only renderable content (see 060 * {@link #isBodyRenderable(String)}, plus an identity {@code Content-Encoding}) is dumped; binary/unknown/compressed 061 * content yields a distinct non-renderable placeholder. 062 * <li><b>Fail-closed scrubber.</b> When the gate is set and a {@link RestDebugBodyScrubber} is configured, its output is 063 * dumped (then sanitized and capped); if it throws or returns <jk>null</jk>, the body fails closed to a placeholder 064 * — never the raw body. 065 * </ul> 066 * No bytes appear in any placeholder in any representation. 067 * 068 * <h5 class='section'>Header redaction and sanitization</h5> 069 * <p> 070 * Values for a widened, formatter-local credential-bearing header set are masked with {@link RedactedHeaders#REDACTED}. 071 * The set starts from {@link RedactedHeaders#DEFAULT} plus {@code X-Auth-Token}, {@code X-Authorization}, 072 * {@code WWW-Authenticate}, {@code Referer}, and {@code Location}; the shared {@link RedactedHeaders#DEFAULT} is left 073 * unchanged. Matching is case-insensitive with separator folding ({@code -}/{@code _} stripped), so {@code X-Auth-Token}, 074 * {@code X_Auth_Token}, and {@code XAuthToken} all match. Replace the set with {@link #redactedHeaders(Collection)} or 075 * extend it with {@link #addRedactedHeaders(Collection)}. Every emitted string (URI/method, header names/values, body 076 * text, placeholders) is sanitized against CR/LF/control-char log forging via {@link DebugTextSanitizer}, in 077 * <b>mask → escape → cap</b> order. 078 * 079 * <h5 class='section'>Bounds</h5> 080 * <p> 081 * Bodies are bounded by {@link #bodyCap()} bytes (default <b>8 KB</b>) at capture time; headers by 082 * {@link #maxHeaders(int)}/{@link #maxHeaderScan(int)}/{@link #maxFieldLength(int)}; the URI by {@link #maxUriLength(int)}. 083 * The 8 KB body cap is deliberately smaller than {@code EchoMixin}'s 1 MB body cap — debug logging is 084 * intended for low-volume operator diagnostics; the two caps are independent by design. 085 * 086 * <h5 class='section'>See Also:</h5><ul> 087 * <li class='link'><a class="doclink" href="https://juneau.apache.org/docs/topics/RestServerLoggingAndDebugging">Logging / Debugging</a> 088 * </ul> 089 * 090 * @since 10.0.0 091 */ 092public class BasicRestDebugFormatter implements RestDebugFormatter { 093 094 /** Default body capture cap, in bytes (8 KB). */ 095 public static final int DEFAULT_BODY_CAP = 8 * 1024; 096 097 /** The environment variable that gates body dumping. */ 098 static final String ENV_ALLOW_DUMP_BODIES = "JUNEAU_REST_DEBUG_ALLOW_DUMP_BODIES"; 099 100 /** 101 * The widened, formatter-local default set of header names whose values are masked. Starts from a copy of 102 * {@link RedactedHeaders#DEFAULT} and adds the credential-bearing headers the shared default omits. 103 */ 104 static final Set<String> DEFAULT_REDACTED_HEADERS; 105 static { 106 var s = new LinkedHashSet<>(RedactedHeaders.DEFAULT); 107 s.add("X-Auth-Token"); 108 s.add("X-Authorization"); 109 s.add("WWW-Authenticate"); 110 s.add("Referer"); 111 s.add("Location"); 112 DEFAULT_REDACTED_HEADERS = Collections.unmodifiableSet(s); 113 } 114 115 /** 116 * Cached resolution of the body-dump master gate. {@code null} means "not yet resolved"; resolution reads the 117 * environment exactly once. Not a system property, and there is no system-property fallback. 118 */ 119 private static volatile Boolean allowDumpBodiesCache; 120 121 /** The set of header names whose values are masked. Overridable via {@link #redactedHeaders(Collection)}. */ 122 protected Set<String> redactedHeaders = DEFAULT_REDACTED_HEADERS; 123 124 /** Optional body scrubber applied to body text when the master gate is set. */ 125 protected RestDebugBodyScrubber bodyScrubber; 126 127 /** The body capture cap in bytes. Overridable via {@link #bodyCap(int)}. */ 128 protected int bodyCap = DEFAULT_BODY_CAP; 129 130 /** Cap on emitted header values per block. Overridable via {@link #maxHeaders(int)}. */ 131 protected int maxHeaders = 100; 132 133 /** Cap on values scanned while computing omitted counts. Overridable via {@link #maxHeaderScan(int)}. */ 134 protected int maxHeaderScan = 1000; 135 136 /** Per header name/value length cap after masking/escaping. Overridable via {@link #maxFieldLength(int)}. */ 137 protected int maxFieldLength = 1024; 138 139 /** Rendered URI length cap. Overridable via {@link #maxUriLength(int)}. */ 140 protected int maxUriLength = DEFAULT_MAX_URI_LENGTH; 141 142 /** 143 * Constructor. 144 */ 145 public BasicRestDebugFormatter() { 146 // No state to initialize; all fields have field-level defaults. 147 } 148 149 /** 150 * Constructor. 151 * 152 * <p> 153 * Provided so subclasses can be instantiated through the {@link BeanInstantiator} chain (constructor injection). 154 * 155 * @param beanStore The bean store. Ignored by the default implementation. 156 */ 157 public BasicRestDebugFormatter(BeanStore beanStore) { 158 // beanStore is intentionally unused; this overload only exists to satisfy constructor-injection. 159 } 160 161 /** 162 * Overrides the redacted-header set (replaces the built-in widened set). 163 * 164 * @param value The new set of header names to mask (case-insensitive, separator-folded). Must not be <jk>null</jk>. 165 * @return This object. 166 */ 167 public BasicRestDebugFormatter redactedHeaders(Collection<String> value) { 168 redactedHeaders = new LinkedHashSet<>(value); 169 return this; 170 } 171 172 /** 173 * Extends the redacted-header set additively (keeps the built-in widened protections). 174 * 175 * @param value The header names to add to the masked set (case-insensitive, separator-folded). Must not be 176 * <jk>null</jk>. 177 * @return This object. 178 */ 179 public BasicRestDebugFormatter addRedactedHeaders(Collection<String> value) { 180 var s = new LinkedHashSet<>(redactedHeaders); 181 s.addAll(value); 182 redactedHeaders = s; 183 return this; 184 } 185 186 /** 187 * Sets the body scrubber applied to body text when the {@code JUNEAU_REST_DEBUG_ALLOW_DUMP_BODIES} gate is set. 188 * 189 * <p> 190 * The scrubber only ever runs when the gate is set; it chooses scrubbed-vs-raw once dumping is already permitted. It 191 * is fail-closed: a throw or a <jk>null</jk> return yields a placeholder, never the raw body. 192 * 193 * @param value The scrubber, or <jk>null</jk> for none (the default, which dumps raw when gated). 194 * @return This object. 195 */ 196 public BasicRestDebugFormatter bodyScrubber(RestDebugBodyScrubber value) { 197 bodyScrubber = value; 198 return this; 199 } 200 201 /** 202 * Overrides the body capture cap. 203 * 204 * @param value The new cap in bytes. 205 * @return This object. 206 */ 207 public BasicRestDebugFormatter bodyCap(int value) { 208 bodyCap = value; 209 return this; 210 } 211 212 /** 213 * Overrides the cap on emitted header values per block. 214 * 215 * @param value The new cap. Must be ≥ 0. 216 * @return This object. 217 */ 218 public BasicRestDebugFormatter maxHeaders(int value) { 219 if (value < 0) 220 throw new IllegalArgumentException("maxHeaders must be >= 0"); 221 maxHeaders = value; 222 return this; 223 } 224 225 /** 226 * Overrides the cap on values scanned while computing omitted counts. 227 * 228 * @param value The new cap. Must be ≥ 0. 229 * @return This object. 230 */ 231 public BasicRestDebugFormatter maxHeaderScan(int value) { 232 if (value < 0) 233 throw new IllegalArgumentException("maxHeaderScan must be >= 0"); 234 maxHeaderScan = value; 235 return this; 236 } 237 238 /** 239 * Overrides the per header name/value length cap. 240 * 241 * @param value The new cap. Must be ≥ 0. 242 * @return This object. 243 */ 244 public BasicRestDebugFormatter maxFieldLength(int value) { 245 if (value < 0) 246 throw new IllegalArgumentException("maxFieldLength must be >= 0"); 247 maxFieldLength = value; 248 return this; 249 } 250 251 /** 252 * Overrides the rendered URI length cap. 253 * 254 * @param value The new cap. Must be ≥ 0. 255 * @return This object. 256 */ 257 public BasicRestDebugFormatter maxUriLength(int value) { 258 if (value < 0) 259 throw new IllegalArgumentException("maxUriLength must be >= 0"); 260 maxUriLength = value; 261 return this; 262 } 263 264 @Override /* Overridden from RestDebugFormatter */ 265 public int bodyCap() { 266 return bodyCap; 267 } 268 269 @Override /* Overridden from RestDebugFormatter */ 270 public String formatBasic(RestRequest req, RestResponse res) { 271 return statusLine(req.getHttpServletRequest(), res.getHttpServletResponse()); 272 } 273 274 @Override /* Overridden from RestDebugFormatter */ 275 public String statusLine(HttpServletRequest req, HttpServletResponse res) { 276 var method = DebugTextSanitizer.sanitize(req.getMethod(), maxUriLength); 277 var uri = DebugTextSanitizer.sanitize(req.getRequestURI(), maxUriLength); 278 var sb = new StringBuilder(); 279 // Prepend the resolved correlation id: read the session-cached getRequestId() through the 280 // session-handle seam — never a live public/custom-key attribute read. Missing session/id → no prefix (today's 281 // unprefixed line), never a throw. Both formatBasic and the 404 render path route through here. 282 var session = RestSession.fromRequest(req); 283 if (session != null) { 284 var id = session.getRequestId(); 285 if (id != null && ! id.isEmpty()) 286 sb.append("[requestId=").append(id).append("] "); 287 } 288 return sb.append('[').append(res.getStatus()).append("] HTTP ").append(method).append(' ').append(uri).toString(); 289 } 290 291 @Override /* Overridden from RestDebugFormatter */ 292 public String formatHeaders(RestRequest req, RestResponse res) { 293 var sreq = req.getHttpServletRequest(); 294 var sres = res.getHttpServletResponse(); 295 var sb = new StringBuilder(); 296 297 var reqLen = req.getCachedContentLength(); 298 if (reqLen >= 0) 299 sb.append("\n\tRequest length: ").append(reqLen).append(" bytes"); 300 301 sb.append("\n\tResponse code: ").append(sres.getStatus()); 302 303 var resLen = res.getCachedContentLength(); 304 if (resLen >= 0) 305 sb.append("\n\tResponse length: ").append(resLen).append(" bytes"); 306 307 var execTime = req.getExecTime(); 308 if (execTime != null) 309 sb.append("\n\tExec time: ").append(execTime).append("ms"); 310 311 var normalizedRedacted = normalizedRedactedSet(); 312 appendRequestHeaders(sb, sreq, normalizedRedacted); 313 appendResponseHeaders(sb, sres, normalizedRedacted); 314 315 return sb.toString(); 316 } 317 318 private void appendRequestHeaders(StringBuilder sb, HttpServletRequest sreq, Set<String> normalizedRedacted) { 319 var names = sreq.getHeaderNames(); 320 if (names == null || ! names.hasMoreElements()) 321 return; 322 sb.append("\n---Request Headers---"); 323 var state = new HeaderScanState(); 324 while (names.hasMoreElements() && ! state.scanCapped) { 325 var name = names.nextElement(); 326 var redact = isRedacted(name, normalizedRedacted); 327 var sName = DebugTextSanitizer.sanitize(name, maxFieldLength); 328 var values = sreq.getHeaders(name); 329 appendHeaderValues(sb, sName, redact, values == null ? Collections.emptyIterator() : values.asIterator(), state); 330 } 331 appendOmissionMarker(sb, state.scanCapped, state.extra); 332 } 333 334 private void appendResponseHeaders(StringBuilder sb, HttpServletResponse sres, Set<String> normalizedRedacted) { 335 var names = sres.getHeaderNames(); 336 if (ie(names)) 337 return; 338 sb.append("\n---Response Headers---"); 339 var state = new HeaderScanState(); 340 for (var name : names) { 341 if (state.scanCapped) 342 break; 343 var redact = isRedacted(name, normalizedRedacted); 344 var sName = DebugTextSanitizer.sanitize(name, maxFieldLength); 345 appendHeaderValues(sb, sName, redact, sres.getHeaders(name).iterator(), state); 346 } 347 appendOmissionMarker(sb, state.scanCapped, state.extra); 348 } 349 350 /** 351 * Emits (or counts as omitted) every value for one header name, shared by the request- and response-header render 352 * loops so neither has to nest a second scan/emit/omit loop inside its own. 353 */ 354 private void appendHeaderValues(StringBuilder sb, String sanitizedName, boolean redact, Iterator<String> values, HeaderScanState state) { 355 while (values.hasNext()) { 356 if (state.scanned >= maxHeaderScan) { 357 state.scanCapped = true; 358 return; 359 } 360 state.scanned++; 361 var v = values.next(); 362 if (state.emitted < maxHeaders) { 363 appendHeaderLine(sb, sanitizedName, redact ? RedactedHeaders.REDACTED : v); 364 state.emitted++; 365 } else { 366 state.extra++; 367 } 368 } 369 } 370 371 /** Mutable per-header-block emission/omission counters, threaded through {@link #appendHeaderValues}. */ 372 private static final class HeaderScanState { 373 int emitted; 374 long extra; 375 int scanned; 376 boolean scanCapped; 377 } 378 379 private void appendHeaderLine(StringBuilder sb, String sanitizedName, String value) { 380 // Order: mask (already applied by caller) → escape → cap. 381 sb.append("\n\t").append(sanitizedName).append(": ").append(DebugTextSanitizer.sanitize(value, maxFieldLength)); 382 } 383 384 private static void appendOmissionMarker(StringBuilder sb, boolean scanCapped, long extra) { 385 if (scanCapped) 386 sb.append("\n\t\u2026[more headers omitted]"); 387 else if (extra > 0) 388 sb.append("\n\t\u2026[+").append(extra).append(" more headers omitted]"); 389 } 390 391 @Override /* Overridden from RestDebugFormatter */ 392 public String formatBody(RestRequest req, RestResponse res) { 393 var sreq = req.getHttpServletRequest(); 394 var sres = res.getHttpServletResponse(); 395 var sb = new StringBuilder(); 396 appendBody(sb, "Request", req.getCachedContent(), req.getCachedContentLength(), sreq.getContentType(), 397 sreq.getHeader("Content-Encoding")); 398 appendBody(sb, "Response", res.getCachedContent(), res.getCachedContentLength(), sres.getContentType(), 399 sres.getHeader("Content-Encoding")); 400 return sb.toString(); 401 } 402 403 private void appendBody(StringBuilder sb, String label, byte[] content, long totalLength, String contentType, String contentEncoding) { 404 if (content == null || content.length == 0) 405 return; 406 var byteCount = totalLength >= 0 ? totalLength : content.length; 407 var ctToken = contentTypeToken(contentType); 408 409 if (! isAllowDumpBodies()) { 410 appendPlaceholder(sb, label, byteCount, ctToken, 411 "; set " + ENV_ALLOW_DUMP_BODIES + " to enable", "body suppressed"); 412 return; 413 } 414 415 if (! isRenderable(contentType, contentEncoding)) { 416 appendPlaceholder(sb, label, byteCount, ctToken, "; binary/non-renderable content", "body not rendered"); 417 return; 418 } 419 420 var raw = new String(content, UTF8); 421 String bodyText; 422 if (bodyScrubber != null) { 423 String scrubbed; 424 try { 425 scrubbed = bodyScrubber.scrub(contentType, raw); 426 } catch (Throwable t) { // NOSONAR - fail closed on any scrubber failure; never re-leak via the exception. 427 scrubbed = null; 428 } 429 if (scrubbed == null) { 430 appendPlaceholder(sb, label, byteCount, ctToken, "; scrubber failed", "body suppressed"); 431 return; 432 } 433 bodyText = scrubbed; 434 } else { 435 bodyText = raw; 436 } 437 438 sb.append("\n---").append(label).append(" Content---"); 439 sb.append('\n').append(DebugTextSanitizer.sanitize(bodyText, charCap())); 440 var omitted = byteCount - content.length; 441 if (omitted > 0) 442 sb.append("\n\u2026[truncated ").append(omitted).append(" bytes]"); 443 } 444 445 private void appendPlaceholder(StringBuilder sb, String label, long byteCount, String ctToken, String reason, String verb) { 446 sb.append("\n---").append(label).append(" Content---"); 447 sb.append("\n[").append(verb).append(": ").append(byteCount).append(" bytes, ").append(ctToken).append(reason).append(']'); 448 } 449 450 private String contentTypeToken(String contentType) { 451 if (ib(contentType)) 452 return "unknown"; 453 return DebugTextSanitizer.sanitize(contentType, maxFieldLength); 454 } 455 456 private boolean isRenderable(String contentType, String contentEncoding) { 457 if (! isIdentityEncoding(contentEncoding)) 458 return false; 459 return isBodyRenderable(contentType); 460 } 461 462 private static boolean isIdentityEncoding(String contentEncoding) { 463 if (contentEncoding == null) 464 return true; 465 var e = contentEncoding.trim(); 466 return e.isEmpty() || eqic(e, "identity"); 467 } 468 469 /** 470 * Returns the character-length cap for a dumped body, derived from {@link #bodyCap()}. 471 * 472 * <p> 473 * Worst-case escaping expands one byte to a 6-character {@code \\uXXXX} sequence, so the sanitized character cap is 474 * {@code bodyCap() * 6} (clamped to {@code Integer.MAX_VALUE}). Capture already bounds the raw bytes; this second 475 * layer bounds a scrubber that returns an oversized string. 476 */ 477 private int charCap() { 478 var cap = Math.max(bodyCap, 0) * 6L; 479 return cap > Integer.MAX_VALUE ? Integer.MAX_VALUE : (int) cap; 480 } 481 482 private Set<String> normalizedRedactedSet() { 483 return redactedHeaders.stream().filter(Objects::nonNull).map(BasicRestDebugFormatter::normalizeHeaderName).collect(Collectors.toCollection(HashSet::new)); 484 } 485 486 private static boolean isRedacted(String name, Set<String> normalizedRedacted) { 487 return name != null && normalizedRedacted.contains(normalizeHeaderName(name)); 488 } 489 490 /** Case-folds and strips {@code -}/{@code _} and whitespace so {@code X-Auth-Token}/{@code X_Auth_Token}/{@code XAuthToken} all match. */ 491 private static String normalizeHeaderName(String name) { 492 var sb = new StringBuilder(name.length()); 493 for (var i = 0; i < name.length(); i++) { 494 var c = name.charAt(i); 495 if (c == '-' || c == '_' || Character.isWhitespace(c)) 496 continue; 497 sb.append(Character.toLowerCase(c)); 498 } 499 return sb.toString(); 500 } 501 502 /** 503 * Returns whether body dumping is enabled by the {@code JUNEAU_REST_DEBUG_ALLOW_DUMP_BODIES} environment variable. 504 * 505 * <p> 506 * Resolved once from the environment and cached. Never reads a system property. 507 * 508 * @return <jk>true</jk> if body dumping is enabled. 509 */ 510 static boolean isAllowDumpBodies() { 511 var v = allowDumpBodiesCache; 512 if (v == null) { 513 v = parseAllowDumpBodies(System.getenv(ENV_ALLOW_DUMP_BODIES)); 514 allowDumpBodiesCache = v; 515 } 516 return v; 517 } 518 519 /** 520 * Parses a raw gate value with trim-then-parse truthy semantics. 521 * 522 * <p> 523 * The value is trimmed first; a non-empty trimmed value enables (returns <jk>true</jk>) except case-insensitive 524 * {@code false} or {@code 0}; {@code null}/empty/all-whitespace disables. This is a fail-safe kill switch, so 525 * ambiguous values resolve to disabled. 526 * 527 * @param raw The raw environment value. Can be <jk>null</jk>. 528 * @return <jk>true</jk> if the value enables body dumping. 529 */ 530 static boolean parseAllowDumpBodies(String raw) { 531 if (raw == null) 532 return false; 533 var t = raw.trim(); 534 if (t.isEmpty()) 535 return false; 536 return ! (eqic(t, "false") || eq(t, "0")); 537 } 538 539 /** 540 * Test-only seam for exercising both gate states without mutating the process environment. 541 * 542 * <p> 543 * Package-private and unreachable from application code, and never reads a system property. Production resolution 544 * stays env-only / read-once ({@link #isAllowDumpBodies()}). 545 * 546 * @param override {@code null} clears the cache so the next resolution re-reads the environment once; a non-<jk>null</jk> 547 * value is cached directly as the test gate state. 548 */ 549 static void resetAllowDumpBodiesForTest(Boolean override) { 550 allowDumpBodiesCache = override; 551 } 552}