Loading content...
You're investigating a payment failure that affected 47 customers last night. The ERROR log says:
2024-01-15 03:47:23 ERROR PaymentProcessor - Payment failed
That's it. No transaction ID. No user ID. No amount. No error code. No indication of which payment gateway was involved or what stage of processing failed.
This log is almost worse than no log at all—it tells you something happened without giving you any way to understand what happened or how to fix it.
Compare this to a well-crafted log:
{
"timestamp": "2024-01-15T03:47:23.847Z",
"level": "ERROR",
"event": "PAYMENT_PROCESSING_FAILED",
"transactionId": "txn_a1b2c3d4e5",
"orderId": "ord_f6g7h8i9j0",
"userId": "usr_k1l2m3n4o5",
"amount": 149.99,
"currency": "USD",
"gateway": "stripe",
"stage": "CHARGE",
"errorCode": "card_declined",
"errorMessage": "Your card was declined due to insufficient funds.",
"declineCode": "insufficient_funds",
"cardLast4": "4242",
"processingTimeMs": 847,
"correlationId": "req_p6q7r8s9t0",
"serviceVersion": "2.4.1"
}
With this log, you can immediately identify the affected customers, understand the failure reason, and know exactly where in the process it failed. The difference is not volume—it's precision.
By the end of this page, you will know exactly what information to capture in your logs: identifiers for correlation, context for understanding, metadata for analysis, and timing for performance. You'll learn to balance completeness with conciseness, and you'll understand what to never log.
Every log entry should answer one question: "When I'm investigating an issue at 3 AM with incomplete information, what will I need to know?"
This principle guides all decisions about what to log. You're not logging for yourself right now—you're logging for a stressed engineer (possibly yourself) in the future who has:
Good logs provide self-contained context. Someone unfamiliar with the code should be able to read the logs and understand what the system was trying to do, what state it was in, and what went wrong.
Before writing any log statement, ask: 'If this is the only log I see, what else would I need to know?' Then include that information. Logs should minimize the need to check other sources.
Identifiers are the glue that connects related log entries. Without them, logs are scattered puzzle pieces; with them, you can reconstruct the complete picture of any operation.
123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263
public class OrderController { private static final Logger logger = LoggerFactory.getLogger(OrderController.class); @PostMapping("/orders") public ResponseEntity<OrderResponse> createOrder( @RequestBody CreateOrderRequest request, @RequestHeader("X-Correlation-Id") String correlationId, @AuthenticationPrincipal User user) { // MDC (Mapped Diagnostic Context) adds these to ALL logs in this thread MDC.put("correlationId", correlationId); MDC.put("userId", user.getId()); MDC.put("sessionId", user.getSessionId()); try { // All subsequent logs automatically include correlation context logger.info("ORDER_CREATE_STARTED: itemCount={}, totalAmount={}", request.getItems().size(), request.getTotalAmount()); Order order = orderService.createOrder(request); // Add order ID to context for remaining operations MDC.put("orderId", order.getId()); logger.info("ORDER_CREATED: status={}", order.getStatus()); // All these identifiers help correlate: // - This request with requests from the same user session // - This order with all subsequent operations on it // - This request with calls to downstream services return ResponseEntity.ok(OrderResponse.from(order)); } finally { MDC.clear(); } }} public class OrderService { private static final Logger logger = LoggerFactory.getLogger(OrderService.class); public Order createOrder(CreateOrderRequest request) { // MDC values (correlationId, userId, sessionId) are automatically included String orderId = generateOrderId(); MDC.put("orderId", orderId); logger.debug("Validating order items"); validateItems(request.getItems()); logger.debug("Checking inventory"); InventoryResult inventory = inventoryService.checkAvailability(request.getItems()); logger.debug("Processing payment"); PaymentResult payment = paymentService.charge(request.getPaymentDetails()); // Every log from every service can be correlated by correlationId // Every log about this order can be found by orderId // Every log from this user can be found by userId return orderRepository.save(new Order(orderId, request, payment)); }}Most logging frameworks support Mapped Diagnostic Context (MDC) or similar mechanisms. Use them! Setting identifiers in MDC means every log statement automatically includes them without cluttering your code.
Beyond identifiers, logs need operational context—information about the environment and infrastructure that helps you understand where and how something happened.
| Category | Fields | Why It Matters |
|---|---|---|
| Service Identity | serviceName, serviceVersion, instanceId | Know which exact version of which service produced this log |
| Environment | environment (prod/staging/dev), region, datacenter, cluster | Distinguish production issues from dev noise; localize regional problems |
| Host Information | hostname, containerIdeventId, pod name (K8s) | Identify specific instances; correlate with infrastructure metrics |
| Deployment | deploymentId, buildNumber, gitCommit | Link behavior to specific deployments; identify regression sources |
| Thread/Process | threadName, processId | Debug concurrency issues; understand parallel execution |
12345678910111213141516171819202122232425262728293031323334353637383940414243444546474849505152535455565758596061626364656667
/** * Startup configuration that sets up operational context * in MDC for all logging throughout the application lifecycle. */@Componentpublic class LoggingContextInitializer implements ApplicationListener<ContextRefreshedEvent> { @Value("${spring.application.name}") private String serviceName; @Value("${app.version}") private String serviceVersion; @Value("${app.environment}") private String environment; @Value("${app.instance-id:${random.uuid}}") private String instanceId; @Override public void onApplicationEvent(ContextRefreshedEvent event) { // These will be included in every log entry MDC.put("serviceName", serviceName); MDC.put("serviceVersion", serviceVersion); MDC.put("environment", environment); MDC.put("instanceId", instanceId); MDC.put("hostname", getHostname()); // Git commit if available (set during build) String gitCommit = System.getenv("GIT_COMMIT"); if (gitCommit != null) { MDC.put("gitCommit", gitCommit.substring(0, 7)); // Short SHA } logger.info("LOGGING_CONTEXT_INITIALIZED: Operational context set for all logs"); } private String getHostname() { try { return InetAddress.getLocalHost().getHostName(); } catch (UnknownHostException e) { return System.getenv("HOSTNAME"); } }} /** * Example log output with full operational context: * * { * "timestamp": "2024-01-15T10:30:45.123Z", * "level": "INFO", * "logger": "com.example.OrderService", * "message": "ORDER_CREATED", * "serviceName": "order-service", * "serviceVersion": "2.4.1", * "environment": "production", * "instanceId": "i-0abc123def456", * "hostname": "order-service-5f7b8c9d-xyz", * "gitCommit": "a1b2c3d", * "correlationId": "req-123-456-789", * "userId": "usr-abc-123", * "orderId": "ord-xyz-789", * "orderAmount": 149.99, * "itemCount": 3 * } */Why Operational Context Matters:
Imagine you're investigating an intermittent error. Without operational context:
With operational context, you can immediately narrow down:
Identifiers and operational context are metadata. The substance of your logs is business and domain data—the specific information about what your application is actually doing.
1234567891011121314151617181920212223242526272829303132333435
public class OrderProcessor { private static final Logger logger = LoggerFactory.getLogger(OrderProcessor.class); public OrderResult process(Order order) { logger.info("ORDER_PROCESSING_STARTED: orderId={}, status={}, itemCount={}, totalAmount={}, currency={}", order.getId(), order.getStatus(), order.getItems().size(), order.getTotalAmount(), order.getCurrency()); // Log decision point: which pricing rules applied PricingResult pricing = pricingEngine.calculate(order); logger.info("PRICING_CALCULATED: orderId={}, subtotal={}, discount={}, discountReason={}, tax={}, total={}", order.getId(), pricing.getSubtotal(), pricing.getDiscount(), pricing.getDiscountReason(), pricing.getTax(), pricing.getTotal()); // Log state transition OrderStatus previousStatus = order.getStatus(); order.setStatus(OrderStatus.PROCESSING); logger.info("ORDER_STATUS_CHANGED: orderId={}, previousStatus={}, newStatus={}, reason=PROCESSING_STARTED", order.getId(), previousStatus, order.getStatus()); // Log external interaction PaymentResult payment = paymentGateway.charge(order); logger.info("PAYMENT_CHARGED: orderId={}, transactionId={}, gateway={}, amount={}, currency={}, responseCode={}", order.getId(), payment.getTransactionId(), payment.getGateway(), payment.getAmount(), payment.getCurrency(), payment.getResponseCode()); // Log final state order.setStatus(OrderStatus.CONFIRMED); logger.info("ORDER_CONFIRMED: orderId={}, transactionId={}, processingTimeMs={}", order.getId(), payment.getTransactionId(), System.currentTimeMillis() - startTime); return new OrderResult(order, payment); }}Don't log every field of every object. Focus on the fields that are: (1) useful for investigation, (2) useful for business metrics, or (3) needed for audit. Logging entire objects is verbose and often includes sensitive data accidentally.
Timing information transforms logs from a debugging tool into a performance analysis platform. By logging durations, you can identify bottlenecks, track performance over time, and detect degradation before it becomes critical.
123456789101112131415161718192021222324252627282930313233343536373839404142434445464748
public class PerformanceAwareService { private static final Logger logger = LoggerFactory.getLogger(PerformanceAwareService.class); public SearchResult search(SearchRequest request) { long startTime = System.currentTimeMillis(); // Phase 1: Parse and validate long parseStart = System.currentTimeMillis(); ParsedQuery query = queryParser.parse(request.getQuery()); long parseMs = System.currentTimeMillis() - parseStart; // Phase 2: Execute search long searchStart = System.currentTimeMillis(); List<Document> results = searchIndex.search(query); long searchMs = System.currentTimeMillis() - searchStart; // Phase 3: Rank results long rankStart = System.currentTimeMillis(); List<RankedDocument> ranked = ranker.rank(results, query); long rankMs = System.currentTimeMillis() - rankStart; // Phase 4: Fetch metadata long metadataStart = System.currentTimeMillis(); List<EnrichedDocument> enriched = metadataService.enrich(ranked); long metadataMs = System.currentTimeMillis() - metadataStart; long totalMs = System.currentTimeMillis() - startTime; // Log with full timing breakdown logger.info("SEARCH_COMPLETED: query={}, resultCount={}, totalMs={}, " + "parseMs={}, searchMs={}, rankMs={}, metadataMs={}, " + "percentSearch={}, percentMetadata={}", request.getQuery(), enriched.size(), totalMs, parseMs, searchMs, rankMs, metadataMs, (searchMs * 100.0 / totalMs), (metadataMs * 100.0 / totalMs)); // Alert if performance degrades if (totalMs > PERFORMANCE_THRESHOLD_MS) { logger.warn("SEARCH_SLOW: query={}, totalMs={}, threshold={}, " + "slowestPhase={}, slowestPhaseMs={}", request.getQuery(), totalMs, PERFORMANCE_THRESHOLD_MS, getSlowestPhase(parseMs, searchMs, rankMs, metadataMs), Math.max(Math.max(parseMs, searchMs), Math.max(rankMs, metadataMs))); } return new SearchResult(enriched, totalMs); }}With timing data in logs, you can build dashboards showing p50/p95/p99 latencies, breakdown by phase, trends over time, and automatic anomaly detection. This is often cheaper and faster than dedicated APM tools.
When things go wrong, the quality of your error logs determines how quickly you can diagnose and fix the issue. Error logs need to be complete and actionable.
12345678910111213
// ❌ USELESS ERROR LOGtry { processOrder(order);} catch (Exception e) { logger.error("Error processing order"); // No context, no exception, nothing useful} // Or even worse:} catch (Exception e) { logger.error(e.getMessage()); // Just "null" or cryptic message, no stack trace}12345678910111213
// ✅ ACTIONABLE ERROR LOGtry { processOrder(order);} catch (PaymentException e) { logger.error("PAYMENT_FAILED: orderId={}, userId={}, " + "amount={}, gateway={}, stage={}, " + "errorCode={}, errorMessage={}, retryable={}", order.getId(), order.getUserId(), order.getAmount(), paymentGateway.getName(), e.getStage(), e.getErrorCode(), e.getMessage(), e.isRetryable(), e); // Full context + exception with stack trace}1234567891011121314151617181920212223242526272829303132333435363738394041424344454647484950515253545556575859
public class RobustDataProcessor { private static final Logger logger = LoggerFactory.getLogger(RobustDataProcessor.class); public ProcessResult processRecord(DataRecord record) { try { // Attempt processing validateRecord(record); TransformResult transformed = transform(record); return persist(transformed); } catch (ValidationException e) { // Expected error - data quality issue logger.warn("RECORD_VALIDATION_FAILED: recordId={}, source={}, " + "validationErrors={}, fieldsFailed={}, action=SKIPPED", record.getId(), record.getSource(), e.getErrors(), e.getFailedFields()); return ProcessResult.skipped(e.getErrors()); } catch (TransformException e) { // Processing logic failed - might be a bug or edge case logger.error("RECORD_TRANSFORM_FAILED: recordId={}, source={}, " + "transformStage={}, inputValue={}, error={}, " + "action=SENT_TO_DLQ", record.getId(), record.getSource(), e.getStage(), sanitize(e.getInputValue()), e.getMessage(), e); deadLetterQueue.send(record, e); return ProcessResult.failed(e); } catch (DatabaseException e) { // Infrastructure failure - might need intervention logger.error("RECORD_PERSIST_FAILED: recordId={}, source={}, " + "database={}, operation={}, sqlState={}, " + "error={}, retryable={}, action=RETRY_QUEUED", record.getId(), record.getSource(), dbConfig.getHost(), e.getOperation(), e.getSqlState(), e.getMessage(), e.isRetryable(), e); if (e.isRetryable()) { retryQueue.enqueue(record, e); return ProcessResult.willRetry(); } else { deadLetterQueue.send(record, e); return ProcessResult.failed(e); } } catch (Exception e) { // Unexpected error - definitely needs investigation logger.error("RECORD_PROCESSING_UNEXPECTED_ERROR: recordId={}, " + "source={}, recordType={}, recordSize={}, " + "exceptionType={}, error={}, action=SENT_TO_DLQ_FOR_INVESTIGATION", record.getId(), record.getSource(), record.getType(), record.getSize(), e.getClass().getName(), e.getMessage(), e); deadLetterQueue.send(record, e); return ProcessResult.failed(e); } }}Equally important as what to log is what not to log. Logging sensitive data creates security vulnerabilities, compliance violations, and privacy breaches. This isn't optional—it's a critical security practice.
12345678910111213141516171819202122232425262728293031323334353637383940414243444546474849
public class SafeLoggingExamples { private static final Logger logger = LoggerFactory.getLogger(SafeLoggingExamples.class); // ❌ DANGEROUS - NEVER DO THIS public void dangerousLogging(PaymentRequest request) { logger.info("Processing payment: cardNumber={}, cvv={}, expiry={}", request.getCardNumber(), // Full card number! request.getCvv(), // CVV! request.getExpiry()); // Could be sensitive } // ✅ SAFE - Masked/truncated sensitive data public void safeLogging(PaymentRequest request) { logger.info("Processing payment: cardLast4={}, cardType={}, expiryMonth={}", maskCard(request.getCardNumber()), detectCardType(request.getCardNumber()), request.getExpiryMonth()); } // ❌ DANGEROUS - Logging full request bodies public void dangerousRequestLogging(HttpRequest request) { logger.debug("Received request: body={}", request.getBody()); // Body might contain passwords, tokens, or other secrets! } // ✅ SAFE - Sanitized logging public void safeRequestLogging(HttpRequest request) { logger.debug("Received request: path={}, method={}, contentType={}, contentLength={}", request.getPath(), request.getMethod(), request.getContentType(), request.getContentLength()); } // Utility methods for safe logging private String maskCard(String cardNumber) { if (cardNumber == null || cardNumber.length() < 4) return "****"; return "****" + cardNumber.substring(cardNumber.length() - 4); } private String maskEmail(String email) { if (email == null || !email.contains("@")) return "***@***"; String[] parts = email.split("@"); return parts[0].charAt(0) + "***@" + parts[1]; } private String maskToken(String token) { if (token == null || token.length() < 8) return "***"; return token.substring(0, 4) + "..." + token.substring(token.length() - 4); }}Logging sensitive data can violate GDPR, HIPAA, PCI-DSS, SOX, and other regulations. Violations can result in fines in the millions, lawsuits, and criminal liability. Implement automated scanning for sensitive data in logs.
System boundaries—where your code interacts with external systems, receives requests, or sends data out—are the most important places to log. These are where issues most often occur and where visibility is most valuable.
1234567891011121314151617181920212223242526272829303132333435363738394041424344454647484950515253545556575859606162636465666768697071727374757677787980818283848586878889909192939495969798
@Aspect@Componentpublic class BoundaryLoggingAspect { private static final Logger logger = LoggerFactory.getLogger(BoundaryLoggingAspect.class); /** * Log all inbound API requests */ @Around("@annotation(org.springframework.web.bind.annotation.RequestMapping) || " + "@annotation(org.springframework.web.bind.annotation.GetMapping) || " + "@annotation(org.springframework.web.bind.annotation.PostMapping)") public Object logInboundRequest(ProceedingJoinPoint joinPoint) throws Throwable { HttpServletRequest request = getCurrentRequest(); long startTime = System.currentTimeMillis(); logger.info("HTTP_REQUEST_RECEIVED: method={}, path={}, remoteAddr={}, userAgent={}", request.getMethod(), request.getRequestURI(), request.getRemoteAddr(), request.getHeader("User-Agent")); try { Object result = joinPoint.proceed(); long duration = System.currentTimeMillis() - startTime; logger.info("HTTP_REQUEST_COMPLETED: method={}, path={}, status=200, durationMs={}", request.getMethod(), request.getRequestURI(), duration); return result; } catch (Exception e) { long duration = System.currentTimeMillis() - startTime; logger.error("HTTP_REQUEST_FAILED: method={}, path={}, error={}, durationMs={}", request.getMethod(), request.getRequestURI(), e.getMessage(), duration, e); throw e; } } /** * Log all outbound HTTP calls */ @Around("execution(* org.springframework.web.client.RestTemplate.*(..))") public Object logOutboundHttp(ProceedingJoinPoint joinPoint) throws Throwable { Object[] args = joinPoint.getArgs(); String url = extractUrl(args); String method = extractMethod(joinPoint); long startTime = System.currentTimeMillis(); logger.debug("HTTP_OUTBOUND_STARTED: method={}, url={}", method, url); try { Object result = joinPoint.proceed(); long duration = System.currentTimeMillis() - startTime; logger.info("HTTP_OUTBOUND_COMPLETED: method={}, url={}, durationMs={}", method, url, duration); return result; } catch (Exception e) { long duration = System.currentTimeMillis() - startTime; logger.error("HTTP_OUTBOUND_FAILED: method={}, url={}, error={}, durationMs={}", method, url, e.getMessage(), duration); throw e; } } /** * Log database queries (be careful with query content - may contain PII) */ @Around("execution(* javax.persistence.EntityManager.*(..)) || " + "execution(* org.springframework.data.repository.CrudRepository.*(..))") public Object logDatabaseOperation(ProceedingJoinPoint joinPoint) throws Throwable { String operation = joinPoint.getSignature().getName(); long startTime = System.currentTimeMillis(); try { Object result = joinPoint.proceed(); long duration = System.currentTimeMillis() - startTime; // Log slow queries at WARN level if (duration > 100) { logger.warn("DATABASE_SLOW_QUERY: operation={}, durationMs={}, threshold=100", operation, duration); } else { logger.debug("DATABASE_QUERY: operation={}, durationMs={}", operation, duration); } return result; } catch (Exception e) { long duration = System.currentTimeMillis() - startTime; logger.error("DATABASE_ERROR: operation={}, error={}, durationMs={}", operation, e.getMessage(), duration, e); throw e; } }}Let's consolidate the key insights about what to include in your logs:
What's Next:
Now that we know what information to capture, the next page covers structured logging—how to format logs for machine parsing, analysis, and efficient querying at scale.
You now understand what information to capture in your logs. Good logs tell a complete story with identifiers, context, business data, timing, and actionable error information—all while protecting sensitive data. Next, we'll explore structured logging for efficient analysis at scale.