Introduction
Effective log message formatting is crucial for debugging, monitoring, and maintaining applications. Template-based logging provides structured, consistent, and performant log messages that are easily parsable by logging systems and humans alike.
Basic String Formatting Approaches
Traditional String Concatenation
public class BasicLogFormatting { public void traditionalConcatenation(String user, int attempts, String status) { // Inefficient - creates multiple string objects logger.info("User: " + user + " made " + attempts + " attempts. Status: " + status); } public void stringFormat(String user, int attempts, String status) { // Better - single string creation logger.info(String.format("User: %s made %d attempts. Status: %s", user, attempts, status)); } public void messageFormat(String user, int attempts, String status) { // More flexible formatting String pattern = "User: {0} made {1} attempts. Status: {2}"; logger.info(MessageFormat.format(pattern, user, attempts, status)); } } Template-Based Logging Frameworks
SLF4J with Parameterized Messages
import org.slf4j.Logger; import org.slf4j.LoggerFactory; public class SLF4JTemplateLogging { private static final Logger logger = LoggerFactory.getLogger(SLF4JTemplateLogging.class); public void basicParameterizedLogging(String userId, String action, int duration) { // SLF4J parameterized logging - efficient and clean logger.info("User {} performed action {} in {} ms", userId, action, duration); // With exception logging try { processUserAction(userId, action); } catch (Exception e) { logger.error("Failed to process action {} for user {}", action, userId, e); } } public void complexParameterizedLogging(User user, Order order, double amount) { logger.debug( "Processing order {} for user {} with amount ${:.2f}", order.getId(), user.getUsername(), amount ); } // Conditional logging with templates public void conditionalLogging(String transactionId, boolean isHighValue) { if (logger.isDebugEnabled()) { logger.debug("Processing transaction {} - high value: {}", transactionId, isHighValue); } // More efficient - parameter evaluation is lazy logger.debug("Processing transaction {} - high value: {}", transactionId, isHighValue); } private void processUserAction(String userId, String action) { // Simulate business logic } } Logback Configuration with Templates
<!-- logback.xml --> <configuration> <!-- Custom pattern with structured data --> <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender"> <encoder> <pattern>%d{yyyy-MM-dd HH:mm:ss} [%thread] %-5level %logger{36} - [user:%X{userId}] [session:%X{sessionId}] %msg%n</pattern> </encoder> </appender> <!-- JSON layout for structured logging --> <appender name="JSON" class="ch.qos.logback.core.ConsoleAppender"> <encoder class="net.logstash.logback.encoder.LogstashEncoder"> <template> { "timestamp": "%d{yyyy-MM-dd HH:mm:ss.SSS}", "level": "%level", "thread": "%thread", "logger": "%logger{40}", "message": "#asJson{%message}", "user_id": "%mdc{userId}", "session_id": "%mdc{sessionId}", "exception": "%exception" } </template> </encoder> </appender> <root level="INFO"> <appender-ref ref="CONSOLE" /> <appender-ref ref="JSON" /> </root> </configuration> Advanced Template Systems
Custom Template Engine with StringTemplate
import org.stringtemplate.v4.ST; public class StringTemplateLogging { private static final Map<String, String> LOG_TEMPLATES = Map.of( "USER_LOGIN", "User <username> logged in from IP <ip> at <timestamp>", "ORDER_CREATED", "Order <orderId> created by user <userId> with <itemCount> items totaling $<amount>", "API_CALL", "API <method> <endpoint> called by <client> - Status: <status>, Duration: <duration>ms", "ERROR", "Error <errorCode> in <component>: <message> - Context: <context>" ); public void logWithTemplate(String templateKey, Map<String, Object> parameters) { String template = LOG_TEMPLATES.get(templateKey); if (template != null) { ST st = new ST(template); parameters.forEach(st::add); logger.info(st.render()); } } public void demonstrateTemplateUsage() { // User login event logWithTemplate("USER_LOGIN", Map.of( "username", "john_doe", "ip", "192.168.1.100", "timestamp", Instant.now().toString() )); // Order creation event logWithTemplate("ORDER_CREATED", Map.of( "orderId", "ORD-12345", "userId", "user-67890", "itemCount", 5, "amount", "99.99" )); // API call event logWithTemplate("API_CALL", Map.of( "method", "POST", "endpoint", "/api/orders", "client", "web-app", "status", 201, "duration", 150 )); } } Mustache Template Engine for Logging
import com.github.mustachejava.Mustache; import com.github.mustachejava.MustacheFactory; public class MustacheTemplateLogging { private final MustacheFactory mustacheFactory; private final Map<String, Mustache> templateCache; public MustacheTemplateLogging() { this.mustacheFactory = new DefaultMustacheFactory(); this.templateCache = new ConcurrentHashMap<>(); } private Mustache getTemplate(String templateName) { return templateCache.computeIfAbsent(templateName, key -> mustacheFactory.compile("templates/" + key + ".mustache")); } public void logWithMustache(String templateName, Object context) { Mustache template = getTemplate(templateName); StringWriter writer = new StringWriter(); template.execute(writer, context); logger.info(writer.toString()); } // Template context classes public static class LoginContext { public String username; public String ip; public String timestamp; public boolean success; public LoginContext(String username, String ip, String timestamp, boolean success) { this.username = username; this.ip = ip; this.timestamp = timestamp; this.success = success; } } public static class OrderContext { public String orderId; public String userId; public int itemCount; public double amount; public List<String> items; public OrderContext(String orderId, String userId, int itemCount, double amount, List<String> items) { this.orderId = orderId; this.userId = userId; this.itemCount = itemCount; this.amount = amount; this.items = items; } } public void demonstrateMustacheLogging() { // Login event LoginContext login = new LoginContext("alice", "10.0.1.50", Instant.now().toString(), true); logWithMustache("login", login); // Order event OrderContext order = new OrderContext("ORD-67890", "user-12345", 3, 149.99, List.of("Laptop", "Mouse", "Keyboard")); logWithMustache("order", order); } } Structured Logging with JSON
JSON Template Logging
import com.fasterxml.jackson.databind.ObjectMapper; import com.fasterxml.jackson.core.JsonProcessingException; public class JSONTemplateLogging { private static final ObjectMapper mapper = new ObjectMapper(); private static final Logger logger = LoggerFactory.getLogger(JSONTemplateLogging.class); // JSON log event templates public static class LogEvent { public final String timestamp; public final String level; public final String logger; public final String message; public final Map<String, Object> context; public LogEvent(String level, String logger, String message, Map<String, Object> context) { this.timestamp = Instant.now().toString(); this.level = level; this.logger = logger; this.message = message; this.context = context; } } public void logJSON(String level, String message, Map<String, Object> context) { LogEvent event = new LogEvent(level, this.getClass().getSimpleName(), message, context); try { String json = mapper.writeValueAsString(event); switch (level) { case "INFO" -> logger.info(json); case "WARN" -> logger.warn(json); case "ERROR" -> logger.error(json); case "DEBUG" -> logger.debug(json); default -> logger.info(json); } } catch (JsonProcessingException e) { logger.error("Failed to serialize log event to JSON", e); } } public void demonstrateJSONLogging() { // User activity logJSON("INFO", "User login successful", Map.of( "user_id", "user-123", "ip_address", "192.168.1.100", "user_agent", "Mozilla/5.0...", "session_duration_sec", 3600 )); // Business transaction logJSON("INFO", "Order processed", Map.of( "order_id", "ORD-98765", "customer_id", "CUST-54321", "total_amount", 199.99, "currency", "USD", "payment_method", "credit_card", "items_count", 2 )); // Error with context logJSON("ERROR", "Payment processing failed", Map.of( "transaction_id", "TXN-11111", "error_code", "INSUFFICIENT_FUNDS", "amount_attempted", 150.00, "available_balance", 100.00, "retry_count", 3 )); } // Fluent API for JSON logging public JSONLogger withContext(String key, Object value) { return new JSONLogger().withContext(key, value); } public static class JSONLogger { private final Map<String, Object> context = new HashMap<>(); public JSONLogger withContext(String key, Object value) { context.put(key, value); return this; } public void info(String message) { logJSON("INFO", message, context); } public void error(String message) { logJSON("ERROR", message, context); } public void warn(String message) { logJSON("WARN", message, context); } } public void demonstrateFluentJSONLogging() { withContext("user_id", "user-999") .withContext("action", "profile_update") .withContext("changes_count", 3) .info("User profile updated successfully"); withContext("api_endpoint", "/api/v1/payments") .withContext("response_time_ms", 245) .withContext("status_code", 500) .error("Internal server error in payment API"); } } Performance-Optimized Template Logging
Cached Message Templates
public class CachedTemplateLogging { private static final Logger logger = LoggerFactory.getLogger(CachedTemplateLogging.class); // Template cache for performance private static final Map<String, MessageFormat> templateCache = new ConcurrentHashMap<>(); private MessageFormat getCachedTemplate(String pattern) { return templateCache.computeIfAbsent(pattern, MessageFormat::new); } public void logWithCachedTemplate(String pattern, Object... args) { if (logger.isInfoEnabled()) { MessageFormat formatter = getCachedTemplate(pattern); String message = formatter.format(args); logger.info(message); } } // Pre-compiled templates for common log messages private static final MessageFormat USER_LOGIN_TEMPLATE = new MessageFormat("User {0} logged in from {1} at {2}"); private static final MessageFormat ORDER_TEMPLATE = new MessageFormat("Order {0} created for {1} with {2} items"); private static final MessageFormat ERROR_TEMPLATE = new MessageFormat("Error in {0}: {1} (Code: {2})"); public void logUserLogin(String username, String ip, Instant timestamp) { if (logger.isInfoEnabled()) { String message = USER_LOGIN_TEMPLATE.format(new Object[]{username, ip, timestamp}); logger.info(message); } } public void logOrderCreation(String orderId, String customer, int itemCount) { if (logger.isInfoEnabled()) { String message = ORDER_TEMPLATE.format(new Object[]{orderId, customer, itemCount}); logger.info(message); } } public void logError(String component, String message, String errorCode) { if (logger.isErrorEnabled()) { String formattedMessage = ERROR_TEMPLATE.format(new Object[]{component, message, errorCode}); logger.error(formattedMessage); } } } Lazy Evaluation for Expensive Operations
public class LazyTemplateLogging { private static final Logger logger = LoggerFactory.getLogger(LazyTemplateLogging.class); @FunctionalInterface public interface LazyMessageSupplier { String get(); } // Lazy message evaluation for expensive operations public void logDebug(LazyMessageSupplier messageSupplier) { if (logger.isDebugEnabled()) { logger.debug(messageSupplier.get()); } } public void logInfo(LazyMessageSupplier messageSupplier) { if (logger.isInfoEnabled()) { logger.info(messageSupplier.get()); } } public void demonstrateLazyLogging() { String userId = "user-123"; String action = "complex_operation"; // Expensive operation only executed if debug is enabled logDebug(() -> { String expensiveData = generateExpensiveDebugInfo(userId, action); return String.format("User %s performed %s: %s", userId, action, expensiveData); }); // Complex context building only if info is enabled logInfo(() -> { Map<String, Object> context = buildComplexContext(userId); return String.format("Processing user %s with context: %s", userId, context); }); } private String generateExpensiveDebugInfo(String userId, String action) { // Simulate expensive operation try { Thread.sleep(100); } catch (InterruptedException e) { Thread.currentThread().interrupt(); } return "Expensive debug data for " + userId; } private Map<String, Object> buildComplexContext(String userId) { // Simulate complex context building Map<String, Object> context = new HashMap<>(); context.put("user_profile", loadUserProfile(userId)); context.put("permissions", loadUserPermissions(userId)); context.put("preferences", loadUserPreferences(userId)); return context; } // Mock methods private Object loadUserProfile(String userId) { return "Profile"; } private Object loadUserPermissions(String userId) { return "Permissions"; } private Object loadUserPreferences(String userId) { return "Preferences"; } } Domain-Specific Logging Templates
E-Commerce Logging Templates
public class ECommerceLoggingTemplates { private static final Logger logger = LoggerFactory.getLogger(ECommerceLoggingTemplates.class); public static class ECommerceLogger { private final String component; public ECommerceLogger(String component) { this.component = component; } public void logProductView(String productId, String userId, String sessionId) { logger.info("[PRODUCT_VIEW] component={} product_id={} user_id={} session_id={}", component, productId, userId, sessionId); } public void logAddToCart(String productId, String userId, int quantity, double price) { logger.info("[ADD_TO_CART] component={} product_id={} user_id={} quantity={} price={}", component, productId, userId, quantity, price); } public void logCheckoutStart(String orderId, String userId, int itemCount, double total) { logger.info("[CHECKOUT_START] component={} order_id={} user_id={} items={} total={}", component, orderId, userId, itemCount, total); } public void logPaymentProcessed(String orderId, String paymentId, String status, double amount) { logger.info("[PAYMENT_PROCESSED] component={} order_id={} payment_id={} status={} amount={}", component, orderId, paymentId, status, amount); } public void logInventoryUpdate(String productId, int oldStock, int newStock, String reason) { logger.info("[INVENTORY_UPDATE] component={} product_id={} old_stock={} new_stock={} reason={}", component, productId, oldStock, newStock, reason); } } public void demonstrateECommerceLogging() { ECommerceLogger catalogLogger = new ECommerceLogger("catalog"); ECommerceLogger cartLogger = new ECommerceLogger("shopping_cart"); ECommerceLogger paymentLogger = new ECommerceLogger("payment"); // Product browsing catalogLogger.logProductView("PROD-123", "USER-456", "SESS-789"); // Shopping cart actions cartLogger.logAddToCart("PROD-123", "USER-456", 2, 29.99); // Checkout process cartLogger.logCheckoutStart("ORDER-111", "USER-456", 3, 89.97); paymentLogger.logPaymentProcessed("ORDER-111", "PAY-222", "SUCCESS", 89.97); // Inventory management catalogLogger.logInventoryUpdate("PROD-123", 50, 48, "SALE"); } } API Request/Response Logging Templates
public class APILoggingTemplates { private static final Logger logger = LoggerFactory.getLogger(APILoggingTemplates.class); public static class APIRequestLog { public String method; public String path; public String clientIp; public String userAgent; public Map<String, String> headers; public String queryParams; public String requestBody; public long timestamp; public void log() { logger.info("[API_REQUEST] method={} path={} client_ip={} user_agent={} query_params={}", method, path, clientIp, userAgent, queryParams); if (logger.isDebugEnabled() && requestBody != null && !requestBody.isEmpty()) { logger.debug("[API_REQUEST_BODY] body={}", requestBody); } } } public static class APIResponseLog { public String method; public String path; public int statusCode; public long durationMs; public String responseBody; public Map<String, String> headers; public void log() { String level = statusCode >= 400 ? "ERROR" : "INFO"; if ("ERROR".equals(level)) { logger.error("[API_RESPONSE] method={} path={} status={} duration_ms={}", method, path, statusCode, durationMs); } else { logger.info("[API_RESPONSE] method={} path={} status={} duration_ms={}", method, path, statusCode, durationMs); } } } public void demonstrateAPILogging() { // Request logging APIRequestLog requestLog = new APIRequestLog(); requestLog.method = "POST"; requestLog.path = "/api/v1/orders"; requestLog.clientIp = "192.168.1.100"; requestLog.userAgent = "Mozilla/5.0..."; requestLog.queryParams = "expand=items"; requestLog.requestBody = "{\"items\": [{\"id\": \"PROD-1\", \"qty\": 2}]}"; requestLog.log(); // Response logging APIResponseLog responseLog = new APIResponseLog(); responseLog.method = "POST"; responseLog.path = "/api/v1/orders"; responseLog.statusCode = 201; responseLog.durationMs = 150; responseLog.log(); } // HTTP filter for automatic API logging @Component public class APILoggingFilter implements WebFilter { @Override public Mono<Void> filter(ServerWebExchange exchange, WebFilterChain chain) { long startTime = System.currentTimeMillis(); ServerHttpRequest request = exchange.getRequest(); // Log request APIRequestLog requestLog = new APIRequestLog(); requestLog.method = request.getMethodValue(); requestLog.path = request.getPath().value(); requestLog.clientIp = getClientIp(request); requestLog.timestamp = System.currentTimeMillis(); requestLog.log(); return chain.filter(exchange).doOnSuccessOrError((result, error) -> { long duration = System.currentTimeMillis() - startTime; ServerHttpResponse response = exchange.getResponse(); // Log response APIResponseLog responseLog = new APIResponseLog(); responseLog.method = request.getMethodValue(); responseLog.path = request.getPath().value(); responseLog.statusCode = response.getStatusCode() != null ? response.getStatusCode().value() : 500; responseLog.durationMs = duration; responseLog.log(); }); } private String getClientIp(ServerHttpRequest request) { String xForwardedFor = request.getHeaders().getFirst("X-Forwarded-For"); if (xForwardedFor != null && !xForwardedFor.isEmpty()) { return xForwardedFor.split(",")[0].trim(); } return request.getRemoteAddress() != null ? request.getRemoteAddress().getAddress().getHostAddress() : "unknown"; } } } Configuration and Best Practices
Logback Configuration with Custom Patterns
<!-- logback-spring.xml --> <configuration> <!-- Environment-specific templates --> <springProfile name="dev"> <property name="LOG_PATTERN" value="%d{HH:mm:ss.SSS} [%thread] %highlight(%-5level) %cyan(%logger{36}) - %msg%n"/> </springProfile> <springProfile name="prod"> <property name="LOG_PATTERN" value="%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{36} - [traceId:%X{traceId}] [spanId:%X{spanId}] %msg%n"/> </springProfile> <!-- Structured logging for production --> <springProfile name="prod & json"> <appender name="JSON" class="ch.qos.logback.core.ConsoleAppender"> <encoder class="net.logstash.logback.encoder.LoggingEventCompositeJsonEncoder"> <providers> <timestamp/> <logLevel/> <loggerName/> <message/> <mdc/> <stackTrace/> </providers> </encoder> </appender> </springProfile> <root level="INFO"> <appender-ref ref="CONSOLE" /> </root> </configuration> Best Practices Class
public class LoggingBestPractices { private static final Logger logger = LoggerFactory.getLogger(LoggingBestPractices.class); // 1. Use parameterized logging public void goodParameterizedLogging(String userId, String action, int count) { logger.info("User {} performed action {} {} times", userId, action, count); } // 2. Avoid string concatenation in log messages public void badLogging(String userId, String action) { // Bad - creates unnecessary strings logger.info("User " + userId + " performed " + action); } // 3. Use lazy evaluation for expensive operations public void goodLazyLogging(Supplier<String> expensiveOperation) { if (logger.isDebugEnabled()) { logger.debug("Expensive data: {}", expensiveOperation.get()); } } // 4. Include context in log messages public void logWithContext(String transactionId, String component, String operation) { MDC.put("transactionId", transactionId); try { logger.info("Processing {} in {}", operation, component); } finally { MDC.clear(); } } // 5. Use consistent log formats public void consistentFormatting(String eventType, String entityId, String action) { logger.info("[{}] entity_id={} action={}", eventType, entityId, action); } // 6. Template for different log levels public void logWithLevel(Level level, String template, Object... args) { switch (level) { case DEBUG -> logger.debug(template, args); case INFO -> logger.info(template, args); case WARN -> logger.warn(template, args); case ERROR -> logger.error(template, args); } } // 7. Structured logging for machine parsing public void structuredLog(String event, Map<String, Object> fields) { StringBuilder sb = new StringBuilder(); sb.append("event=").append(event); fields.forEach((key, value) -> sb.append(" ").append(key).append("=").append(value)); logger.info(sb.toString()); } public enum Level { DEBUG, INFO, WARN, ERROR } } Conclusion
Effective log message formatting with templates provides:
- Consistency - Uniform log format across the application
- Performance - Reduced string creation and better memory usage
- Maintainability - Easy to update log formats across the codebase
- Parsability - Structured logs that are easy to parse and analyze
- Context - Rich contextual information for debugging and monitoring
By implementing template-based logging strategies, developers can create more maintainable, performant, and useful logging systems that scale with application complexity and provide valuable insights during development and production operations.