What you’ll learn

How logging is used in production systems and how this differs from use of the console for temporary debugging. The SLF4J and logback frameworks will be used.

Why start here?

Software applications in production need to provide ongoing signals as to what they are doing and whether they are operating in a healthy state. Effective logging can also provide an insight into problems that occur and can therefore assist with knowing where to start when debugging.

Self Study

Reading Materials

• SLF4J Framework documentation
• Logback Documentation - Read chapters 1-4
• Baledung logging - Read sections 1, 2, 4, 5
• mapped diagnostic context in logging (MDC) - read sections 1, 2, 5-7
• OWASP cheatsheet - OWASP logging principles
• useful up to section “Network architecture”

Video Materials

• SLF4J usage

Key Concepts

• Logging is the root for system observability, not debug messages.
• Logging provides traceability in a complex system of loosely-coupled services, e.g. via common identifiers transferred across service boundaries.
• Logging can provide auditing and security, but care needs to be taken around sensitive information (e.g. passwords, private customer data)
• Logging should be lightweight and lazily-evaluated whenever possible.
• So that logging does not interfere with the performance of the system.
• Log levels allow us to control the actual logging output from the system at a later point via configuration.
• The order of increasing seriousness is TRACE, DEBUG, INFO, WARN, ERROR.
• INFO level logging is typical for a production system.
• TRACE and DEBUG should be expected only to be used when dealing with an incident or temporarily gathering diagnostics or verifying behaviour.
• Log levels should be used careful to add value and not overwhelm the system operators with noise.
• ERROR applies to unexpected cases only, not e.g. validation of user inputs. A production system should run without generating any ERRORs, we would expect any that do occur to be investigated.
• DEBUG level logging should be specific about the current state and what is being processed.
• Mapped Diagnostic Context (MDC) can be used to elaborate your logging in a cross-cutting fashion.
• This is especially helpful in linking multiple layers of processing together for a single item in a multi-threaded system.

Exercises

<project xmlns="http://maven.apache.org/POM/4.0.0" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd">
  <modelVersion>4.0.0</modelVersion>
  <groupId>com.myname</groupId>
  <artifactId>logging-example</artifactId>
  <name>Example project with logging</name>
  <version>1.0.0</version>
  <dependencies>
   <dependency> 
    <groupId>org.slf4j</groupId>
    <artifactId>slf4j-api</artifactId>
    <version>2.0.17</version>
   </dependency>
   <dependency> 
    <groupId>ch.qos.logback</groupId>
    <artifactId>logback-classic</artifactId>
    <version>1.5.32</version>
   </dependency>
  </dependencies>
</project> 

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
 
public class LoggingDemo {
    private static final Logger log = LoggerFactory.getLogger(LoggingDemo.class);
 
    public static void main(String[] args) {
        log.info("Application starting...");
        log.debug("This is a debug message that you should NOT see yet.");
        log.warn("Low disk space!");
        log.error("Something went wrong.", new RuntimeException("Test error"));
    }
}

<configuration>
    <!-- Add MDC values to log lines -->
    <property name="PATTERN" value="%d{yyyy-MM-dd HH:mm:ss} [%thread] %-5level [%X{requestId}] %logger{36} - %msg%n"/>
 
    <appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>logs/app.log</file>
 
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>logs/app-%d{yyyy-MM-dd}.gz</fileNamePattern>
            <maxHistory>7</maxHistory>
        </rollingPolicy>
 
        <encoder>
            <pattern>${PATTERN}</pattern>
        </encoder>
    </appender>
 
    <root level="info">
        <appender-ref ref="FILE"/>
    </root>
</configuration>

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;
 
import java.util.UUID;
 
public class RequestProcessor {
    private static final Logger log = LoggerFactory.getLogger(RequestProcessor.class);
 
    public static void main(String[] args) {
        for (int i = 1; i <= 3; i++) {
            simulateRequest(i);
        }
    }
 
    private static void simulateRequest(int n) {
        String requestId = UUID.randomUUID().toString();
        MDC.put("requestId", requestId);
 
        log.info("Processing request {}", n);
 
        try {
            if (n == 2) throw new IllegalArgumentException("Bad input!");
        } catch (Exception e) {
            log.error("Error while processing", e);
        } finally {
            MDC.clear();
        }
    }
}

Questions

1. Logging Listener

Consider the following code;

Code block 9 - Logging Question 1

public void listenerLoop() {
  while (keepRunning) {
    logger.atInfo().log("Listener polling...");
    WorkItem workItem = queue.poll();
    if (workItem == null) {
      sleepForOneSecond();
    } else {
      process(workItem);
    }
  }
}

What concerns would you have about the logging? how could it be improved (e.g. by additional information, changing behaviour)?

2. Logging Child Processor

Consider the following code:

Code block 10 Logging Question 1

public process(WorkItem workItem) {
  int childCount = 0;
  for (ChildItem child : workItem.getChildren()) {
    if (logger.isDebugEnabled()) {
      logger.debug("Processing child {}", childCount++);
    }
    if (childProcess(child)) {
      logger.info("Processed child {}", childCount);
    } else {
      logger.warn("Failed to process child {}", childCount);
    }
  }
}

If logging is at info level and the work item has 2 children which are each processed successfully what will be the output;

A) Processing child 0, Processed child 0, Processing child 1, Processed child 1, Processing child 2, Processed child 2 B) Processing child 1, Processed child 1, Processing child 2, Processed child 2, Processing child 3, Processed child 3 C) Processed child 0, Processed child 1, Processed child 2 D) Processed child 0, Processed child 0, Processed child 0

If the processing is repeated with logging at debug level what is the output?

What does this difference tell us about a problem in the way we are logging? What alternative approaches can you think of?

Overview

Debugging a java application effectively is a core skill needed during both development and support of an application. You will learn how to step through, into and over code, evaluating expressions and observing variables/state.

Why start here?

As you develop and refactor software applications things will go wrong and you will need to find the cause.

Self Study

Reading Materials

The main principles are common across all implementations but there will be some IDE specific material

• IntelliJ debugging
• Advanced Debugging - IntelliJ debugging tricks, stream debugging
• VS Code debugging or baeldung eclipse debugging
• Eclipse debugging your programs
• How To Read And Understand A Java Stacktrace

Video Materials

• IntelliJ debugger
• VS Code
• Eclipse
• Stacktraces 1, Stacktraces 2

Key Concepts

• The debugger allows you to step through code in a manner similar to a video-player might allow you to skip between chapters, move forward in steps and pause.
• Variables can be inspected and expressions evaluated during debugging to give insight into the processing and execution paths that will be followed.
• Breakpoints can be applied in advanced ways to enable; conditional-stopping, stopping on exceptions, tracking field-access
• The debugger can be used without specific breakpoints to suspend processing and inspect where current execution is at (e.g. for long-running processes or bugs in loops)
• Stacktraces can be used to track the way an application has executed to reach its current point (e.g. where an exception is thrown) and can be used to locate the root cause or where to set breakpoints to investigate further.

Exercises

import java.util.Arrays;
import java.util.List;
 
public class FaultyCalculator {
 
    public static void main(String[] args) {
        List<Integer> values = Arrays.asList(10, 20, 30, 40);
 
        double average = calculateAverage(values);
        System.out.println("Average = " + average);  // Expected: 25
    }
 
    public static double calculateAverage(List<Integer> numbers) {
        int sum = 0;
        for (int i = 1; i < numbers.size(); i++) {
            Integer currentNumber = numbers.get(i);
            sum += currentNumber;
        }
 
        return (double) sum / numbers.size();
    }
}

public class OrderProcessor {
 
    public static void main(String[] args) {
        Order order = new Order(123);
        process(order);
    }
 
    public static void process(Order order) {
        System.out.println("Customer name: " + order.customer.name.toUpperCase());
    }
}
 
class Order {
    int id;
    Customer customer;
 
    public Order(int id) {
        this.id = id;
        Customer customer = new Customer("Alice");
    }
}
 
class Customer {
    String name;
 
    public Customer(String name) {
        this.name = name;
    }
}

Overview

This is a deeper dive into common industry terminology and testing techniques that will help you write better tests. Why start here?

In larger software applications you will have some services with many dependencies and you need to understand how to write effective isolated tests using mocks as well as the common terminology used. Most software organisations use Test Driven Development, or something closely aligned to it, as part of their software development process and therefore understanding the principles and terminology can be essential to progressing your work.

Mocks make it easy for a test to focus on the processing of a specific service without needing to rely on lots of other services too. For example, by mocking the dependencies used to provide access to external resources (databases, external web services, storage) we can provide tests which are faster, simpler and clearer about what they are assuming and what they are checking.

Self Study

Reading Materials

• Mockito documentation - Read #1 to #33
• Baeldung Mockito Series - follow basics
• JUnit5 assert all vs multiple assertions
• AssertJ documentation (1, 2.1, 2.5-2.8)
• JUnit Parameterised tests
• Baeldung JUnit Parameterised tests
• Test doubles (terminology around mocks) - Test Double
• Test layers - Martin Fowler test-pyramid,
• Google beyond the test pyramid
• Martin Fowler Unit Test
• Martin Fowler Integration Test
• Test Driven Development

Video Materials

• Junit + Mockito (composite - lots of chapters)
• parameterised tests - parameterised tests 1, parameterised tests 2
• Dave Farley (modern software engineering channel) - test types, test driven development, red-green refactoring process
• Automated testing, testability and test-driven development (discussion)

Key Concepts

• There is a rich and meaningful terminology around various types of test double; mock, stub, spy, fake
• Mocking provides a way of simplifying test setup, keeping tests fast and creating separation between components when testing
• Frameworks are available to provide powerful mocking techniques
• Frameworks are available to provide additional assertion patterns and capabilities
• Test layers are used to describe the scope of the test and what real resources (rather than test doubles) it utilises

Exercises

public class PriceService {
    private final ExchangeRateClient client;
 
    PriceService(ExchangeRateClient client) {
        this.client = client;
    }
 
    public double convertTo(double eurPrice, String targetCurrency) {
        return eurPrice * client.getRate("EUR", targetCurrency);
    }
}
 
public interface ExchangeRateClient {
    double getRate(String from, String to);
}

Questions

With the following test what will the output be;

Code block 15 NotificationService

@ParameterizedTest
@CsvSource({"JANUARY, true", "JANUARY, false", "FEBRUARY, true", "FEBRUARY, false", "MARCH, true"})
void months_AreAtLeast29DaysLongCsv(Month month, boolean isALeapYear) {
    assertTrue(month.length(isALeapYear) >= 29);
}

A) The code won’t work as we have strings but need Month and boolean

B) The code won’t work because we can’t provide multiple parameters for each run

C) The code runs and fails for the 3rd input (“FEBRUARY, false”)

D) The code runs and each case passes