2. Туториалы
  3. Логирование
Последнее обновление: 8 февраля 2026
Автор: Антон Козицкий

Уровни логирования

Зачем нам уровни логирования

Итак, логи нужны нам для того, чтобы видеть, что происходит во время выполнения в программе. И это очень хорошо, но есть одна проблема: происходящие в программе события могут отличаться по своей важности. Например, мы можем логировать ошибку и мы можем логировать вход в метод.

В первом случае это лог, от которого зависит дальнейшее выполнение программы. Чаще всего во время ошибки программа останавливает свое выполнение, либо продолжает выполняться, но некорректно. И здесь нужна реакция от разработчика, чтобы выяснить проблему и устранить как можно скорей.

Во втором же случае речь идет от трейс-логе, который просто дает нам информацию о том, что мы вошли в какой-то метод в коде во время выполнения. Такие логи могут оказаться полезными, если нам нужно отладить сложную проблему в коде. Сейчас я описал два крайних случая и, соответственно, два разных по уровни важности лога - ERROR и TRACE.

Уровни важности логов от наименее важного до самого критичного ниже на картинке:

Рассмотрим каждый уровень логирования детально

Сейчас пройдемся по каждому уровню логирования и разберем его детали для лучшего понимания.

TRACE

TRACE логи нужны для вывода самой подробной информации в тех кусочках кода, где это может нам оказать помощь в отладке. Это самый низкий уровень логирования, когда мы логируем самую детальную и самую подробную информацию о выполнении программы. Ниже привожу примеры таких логов для лучшего понимания:

  • "Вошли в метод purchase()"
  • "Параметры метода: userId=42, productId=10, quantity=2"
  • "Executing SQL: SELECT * FROM products WHERE id=10"
  • "Mapping result set to Product entity"

Ниже пример реальных логов из приложения интернет-магазина.

2026-02-05 10:30:45.123 TRACE 12345 --- [http-nio-8080-exec-3] c.e.shop.controller.OrderController      : Entering method: createOrder(customerId=42, productId=10, quantity=2)
2026-02-05 10:30:45.124 TRACE 12345 --- [http-nio-8080-exec-3] c.e.shop.controller.OrderController      : Method parameters: OrderRequest[customerId=42, productId=10, quantity=2, paymentMethod=CREDIT_CARD]
2026-02-05 10:30:45.125 TRACE 12345 --- [http-nio-8080-exec-3] c.e.shop.service.OrderService            : Entering method: processOrder(OrderRequest)
2026-02-05 10:30:45.126 TRACE 12345 --- [http-nio-8080-exec-3] c.e.shop.service.OrderService            : Validating order request...
2026-02-05 10:30:45.127 TRACE 12345 --- [http-nio-8080-exec-3] c.e.shop.service.OrderService            : Order request validation passed
2026-02-05 10:30:45.128 TRACE 12345 --- [http-nio-8080-exec-3] c.e.shop.service.ProductService          : Entering method: getProductById(productId=10)
2026-02-05 10:30:45.129 TRACE 12345 --- [http-nio-8080-exec-3] c.e.shop.repository.ProductRepository    : Entering method: findById(10)
2026-02-05 10:30:45.130 TRACE 12345 --- [http-nio-8080-exec-3] o.h.SQL                                  : Executing SQL query
2026-02-05 10:30:45.131 TRACE 12345 --- [http-nio-8080-exec-3] o.h.SQL                                  : 
    select
        p1_0.id,
        p1_0.name,
        p1_0.description,
        p1_0.price,
        p1_0.created_at,
        p1_0.updated_at 
    from
        products p1_0 
    where
        p1_0.id=?
2026-02-05 10:30:45.132 TRACE 12345 --- [http-nio-8080-exec-3] o.h.orm.jdbc.bind                        : Binding parameter [1] as [BIGINT] - [10]
2026-02-05 10:30:45.145 TRACE 12345 --- [http-nio-8080-exec-3] o.h.type.descriptor.sql.BasicExtractor   : Extracted value ([id] : [BIGINT]) - [10]
2026-02-05 10:30:45.146 TRACE 12345 --- [http-nio-8080-exec-3] o.h.type.descriptor.sql.BasicExtractor   : Extracted value ([name] : [VARCHAR]) - [Wireless Mouse]
2026-02-05 10:30:45.147 TRACE 12345 --- [http-nio-8080-exec-3] o.h.type.descriptor.sql.BasicExtractor   : Extracted value ([description] : [VARCHAR]) - [Ergonomic wireless mouse with USB receiver]
2026-02-05 10:30:45.148 TRACE 12345 --- [http-nio-8080-exec-3] o.h.type.descriptor.sql.BasicExtractor   : Extracted value ([price] : [DECIMAL]) - [29.99]
2026-02-05 10:30:45.149 TRACE 12345 --- [http-nio-8080-exec-3] o.h.type.descriptor.sql.BasicExtractor   : Extracted value ([created_at] : [TIMESTAMP]) - [2026-01-15 10:23:45.0]
2026-02-05 10:30:45.150 TRACE 12345 --- [http-nio-8080-exec-3] o.h.type.descriptor.sql.BasicExtractor   : Extracted value ([updated_at] : [TIMESTAMP]) - [2026-02-01 14:30:22.0]
2026-02-05 10:30:45.151 TRACE 12345 --- [http-nio-8080-exec-3] c.e.shop.repository.ProductRepository    : Mapping result set to Product entity
2026-02-05 10:30:45.152 TRACE 12345 --- [http-nio-8080-exec-3] c.e.shop.repository.ProductRepository    : Product entity created: Product[id=10, name='Wireless Mouse', price=29.99]
2026-02-05 10:30:45.153 TRACE 12345 --- [http-nio-8080-exec-3] c.e.shop.repository.ProductRepository    : Exiting method: findById() - returning Product[id=10]
2026-02-05 10:30:45.154 TRACE 12345 --- [http-nio-8080-exec-3] c.e.shop.service.ProductService          : Exiting method: getProductById() - Product found
2026-02-05 10:30:45.155 TRACE 12345 --- [http-nio-8080-exec-3] c.e.shop.service.InventoryService        : Entering method: checkAvailability(productId=10, quantity=2)
2026-02-05 10:30:45.156 TRACE 12345 --- [http-nio-8080-exec-3] o.h.SQL                                  : 
    select
        i1_0.id,
        i1_0.product_id,
        i1_0.available_quantity,
        i1_0.reserved_quantity 
    from
        inventory i1_0 
    where
        i1_0.product_id=?
2026-02-05 10:30:45.157 TRACE 12345 --- [http-nio-8080-exec-3] o.h.orm.jdbc.bind                        : Binding parameter [1] as [BIGINT] - [10]
2026-02-05 10:30:45.162 TRACE 12345 --- [http-nio-8080-exec-3] o.h.type.descriptor.sql.BasicExtractor   : Extracted value ([available_quantity] : [INTEGER]) - [150]
2026-02-05 10:30:45.163 TRACE 12345 --- [http-nio-8080-exec-3] c.e.shop.service.InventoryService        : Available quantity: 150, Requested quantity: 2
2026-02-05 10:30:45.164 TRACE 12345 --- [http-nio-8080-exec-3] c.e.shop.service.InventoryService        : Stock availability check passed
2026-02-05 10:30:45.165 TRACE 12345 --- [http-nio-8080-exec-3] c.e.shop.service.InventoryService        : Exiting method: checkAvailability() - returning true
2026-02-05 10:30:45.166 TRACE 12345 --- [http-nio-8080-exec-3] c.e.shop.service.CustomerService         : Entering method: getCustomerById(customerId=42)
2026-02-05 10:30:45.167 TRACE 12345 --- [http-nio-8080-exec-3] o.h.SQL                                  : 
    select
        c1_0.id,
        c1_0.email,
        c1_0.first_name,
        c1_0.last_name,
        c1_0.balance 
    from
        customers c1_0 
    where
        c1_0.id=?
2026-02-05 10:30:45.168 TRACE 12345 --- [http-nio-8080-exec-3] o.h.orm.jdbc.bind                        : Binding parameter [1] as [BIGINT] - [42]
2026-02-05 10:30:45.173 TRACE 12345 --- [http-nio-8080-exec-3] o.h.type.descriptor.sql.BasicExtractor   : Extracted value ([email] : [VARCHAR]) - [[email protected]]
2026-02-05 10:30:45.174 TRACE 12345 --- [http-nio-8080-exec-3] o.h.type.descriptor.sql.BasicExtractor   : Extracted value ([first_name] : [VARCHAR]) - [John]
2026-02-05 10:30:45.175 TRACE 12345 --- [http-nio-8080-exec-3] o.h.type.descriptor.sql.BasicExtractor   : Extracted value ([last_name] : [VARCHAR]) - [Doe]
2026-02-05 10:30:45.176 TRACE 12345 --- [http-nio-8080-exec-3] o.h.type.descriptor.sql.BasicExtractor   : Extracted value ([balance] : [DECIMAL]) - [500.00]
2026-02-05 10:30:45.177 TRACE 12345 --- [http-nio-8080-exec-3] c.e.shop.service.CustomerService         : Exiting method: getCustomerById() - Customer[id=42, [email protected]]
2026-02-05 10:30:45.178 TRACE 12345 --- [http-nio-8080-exec-3] c.e.shop.service.PriceCalculator         : Entering method: calculateTotal(price=29.99, quantity=2)
2026-02-05 10:30:45.179 TRACE 12345 --- [http-nio-8080-exec-3] c.e.shop.service.PriceCalculator         : Calculating subtotal: 29.99 * 2 = 59.98
2026-02-05 10:30:45.180 TRACE 12345 --- [http-nio-8080-exec-3] c.e.shop.service.PriceCalculator         : Applying tax rate: 0.0%
2026-02-05 10:30:45.181 TRACE 12345 --- [http-nio-8080-exec-3] c.e.shop.service.PriceCalculator         : Tax amount: 0.00
2026-02-05 10:30:45.182 TRACE 12345 --- [http-nio-8080-exec-3] c.e.shop.service.PriceCalculator         : Total amount: 59.98
2026-02-05 10:30:45.183 TRACE 12345 --- [http-nio-8080-exec-3] c.e.shop.service.PriceCalculator         : Exiting method: calculateTotal() - returning 59.98
2026-02-05 10:30:45.184 TRACE 12345 --- [http-nio-8080-exec-3] c.e.shop.service.PaymentService          : Entering method: processPayment(customerId=42, amount=59.98, method=CREDIT_CARD)
2026-02-05 10:30:45.185 TRACE 12345 --- [http-nio-8080-exec-3] c.e.shop.service.PaymentService          : Building payment gateway request
2026-02-05 10:30:45.186 TRACE 12345 --- [http-nio-8080-exec-3] c.e.shop.service.PaymentService          : Request payload: {"customerId":42,"amount":59.98,"currency":"USD","method":"CREDIT_CARD"}
2026-02-05 10:30:45.187 TRACE 12345 --- [http-nio-8080-exec-3] c.e.shop.client.PaymentGatewayClient     : Sending HTTP POST request to: https://payment-gateway.example.com/api/v1/charge
2026-02-05 10:30:45.188 TRACE 12345 --- [http-nio-8080-exec-3] c.e.shop.client.PaymentGatewayClient     : Request headers: {Content-Type=application/json, Authorization=Bearer *****, X-Request-ID=req_abc123}
2026-02-05 10:30:45.456 TRACE 12345 --- [http-nio-8080-exec-3] c.e.shop.client.PaymentGatewayClient     : Received response: HTTP 200 OK
2026-02-05 10:30:45.457 TRACE 12345 --- [http-nio-8080-exec-3] c.e.shop.client.PaymentGatewayClient     : Response body: {"transactionId":"txn_xyz789","status":"SUCCESS","authCode":"456789","timestamp":1738767045457}
2026-02-05 10:30:45.458 TRACE 12345 --- [http-nio-8080-exec-3] c.e.shop.service.PaymentService          : Payment processed successfully: txn_xyz789
2026-02-05 10:30:45.459 TRACE 12345 --- [http-nio-8080-exec-3] c.e.shop.service.PaymentService          : Exiting method: processPayment() - returning PaymentResult[transactionId=txn_xyz789, status=SUCCESS]
2026-02-05 10:30:45.460 TRACE 12345 --- [http-nio-8080-exec-3] c.e.shop.service.InventoryService        : Entering method: reserveStock(productId=10, quantity=2)
2026-02-05 10:30:45.461 TRACE 12345 --- [http-nio-8080-exec-3] o.h.SQL                                  : 
    update
        inventory 
    set
        available_quantity=available_quantity-?,
        reserved_quantity=reserved_quantity+? 
    where
        product_id=?
2026-02-05 10:30:45.462 TRACE 12345 --- [http-nio-8080-exec-3] o.h.orm.jdbc.bind                        : Binding parameter [1] as [INTEGER] - [2]
2026-02-05 10:30:45.463 TRACE 12345 --- [http-nio-8080-exec-3] o.h.orm.jdbc.bind                        : Binding parameter [2] as [INTEGER] - [2]
2026-02-05 10:30:45.464 TRACE 12345 --- [http-nio-8080-exec-3] o.h.orm.jdbc.bind                        : Binding parameter [3] as [BIGINT] - [10]
2026-02-05 10:30:45.470 TRACE 12345 --- [http-nio-8080-exec-3] c.e.shop.service.InventoryService        : Stock reserved successfully. Rows affected: 1
2026-02-05 10:30:45.471 TRACE 12345 --- [http-nio-8080-exec-3] c.e.shop.service.InventoryService        : Exiting method: reserveStock() - success
2026-02-05 10:30:45.472 TRACE 12345 --- [http-nio-8080-exec-3] c.e.shop.repository.OrderRepository      : Entering method: save(Order)
2026-02-05 10:30:45.473 TRACE 12345 --- [http-nio-8080-exec-3] o.h.SQL                                  : 
    insert 
    into
        orders
        (customer_id, product_id, quantity, total_amount, status, transaction_id, created_at) 
    values
        (?, ?, ?, ?, ?, ?, ?)
2026-02-05 10:30:45.474 TRACE 12345 --- [http-nio-8080-exec-3] o.h.orm.jdbc.bind                        : Binding parameter [1] as [BIGINT] - [42]
2026-02-05 10:30:45.475 TRACE 12345 --- [http-nio-8080-exec-3] o.h.orm.jdbc.bind                        : Binding parameter [2] as [BIGINT] - [10]
2026-02-05 10:30:45.476 TRACE 12345 --- [http-nio-8080-exec-3] o.h.orm.jdbc.bind                        : Binding parameter [3] as [INTEGER] - [2]
2026-02-05 10:30:45.477 TRACE 12345 --- [http-nio-8080-exec-3] o.h.orm.jdbc.bind                        : Binding parameter [4] as [DECIMAL] - [59.98]
2026-02-05 10:30:45.478 TRACE 12345 --- [http-nio-8080-exec-3] o.h.orm.jdbc.bind                        : Binding parameter [5] as [VARCHAR] - [COMPLETED]
2026-02-05 10:30:45.479 TRACE 12345 --- [http-nio-8080-exec-3] o.h.orm.jdbc.bind                        : Binding parameter [6] as [VARCHAR] - [txn_xyz789]
2026-02-05 10:30:45.480 TRACE 12345 --- [http-nio-8080-exec-3] o.h.orm.jdbc.bind                        : Binding parameter [7] as [TIMESTAMP] - [2026-02-05 10:30:45.480]
2026-02-05 10:30:45.487 TRACE 12345 --- [http-nio-8080-exec-3] c.e.shop.repository.OrderRepository      : Order saved with generated ID: 9876
2026-02-05 10:30:45.488 TRACE 12345 --- [http-nio-8080-exec-3] c.e.shop.repository.OrderRepository      : Exiting method: save() - Order[id=9876]
2026-02-05 10:30:45.489 TRACE 12345 --- [http-nio-8080-exec-3] c.e.shop.service.OrderService            : Order created successfully: Order[id=9876, customerId=42, productId=10, status=COMPLETED]
2026-02-05 10:30:45.490 TRACE 12345 --- [http-nio-8080-exec-3] c.e.shop.service.OrderService            : Exiting method: processOrder() - returning OrderResponse[orderId=9876, status=COMPLETED]
2026-02-05 10:30:45.491 TRACE 12345 --- [http-nio-8080-exec-3] c.e.shop.controller.OrderController      : Preparing HTTP response
2026-02-05 10:30:45.492 TRACE 12345 --- [http-nio-8080-exec-3] c.e.shop.controller.OrderController      : Response status: 201 CREATED
2026-02-05 10:30:45.493 TRACE 12345 --- [http-nio-8080-exec-3] c.e.shop.controller.OrderController      : Response body: {"orderId":9876,"status":"COMPLETED","message":"Order created successfully"}
2026-02-05 10:30:45.494 TRACE 12345 --- [http-nio-8080-exec-3] c.e.shop.controller.OrderController      : Exiting method: createOrder() - execution time: 371ms

Как видите из примера выше, в TRACE-логи попадает самая детальная информация о ходе исполнения кода. Иногда еще это называется "протрейсить код" - то есть пройтись по нему, заглядывая в самые мелкие детали. И делают это тогда, когда ищут проблему.

DEBUG

Как можно догадаться из названия, DEBUG-логи мы используем для того, чтобы добавить в лог информацию, которая сможет быть полезной во время отладки. Напомню, что отладку (или дебаггинг/debugging) мы делаем тогда, когда у нас что-то не работает так, как ожидалось и мы не можем быстро разобраться в проблеме. В этом случае мы обычно запускаем нашу программу в режиме отладки в нашей IDE (как правило, это кнопка в виде ), ставим точки останова (брекпоинты/breakpoints) и пошагово проходим по коду, заглядывая в значения каждой переменной в тот или иной момент времени, пытаясь понять что у нас идет не так.

Так вот DEBUG-логи - это первый уровень отладки:

  • Когда мы еще не хотим запускать наш код в debug mode,
  • Но хотим попытаться понять что происходит в программе по логам.

Как правило, этот уровень логирования включен во время локальной разработки и включается лишь при необходимости и на строго определенное время на продакшн. Это связано с тем, что DEBUG-логи сильно "забивают" остальные логи своим большим количеством и могут помешать увидеть более важные логи на продакшн. Еще одна причина, почему DEBUG-логи не держат постоянно включенными на продакшн - системы агрегации логов, которые могут сильно переполняться, если у нас надолго были включены DEBUG-логи. Это также может влиять на стоимость использования таких систем, если они тарифицируют по количеству обработанных логов.

Примеры таких логов:

  • "Был получен продукт из базы данных: {детали продукта}"
  • "Делаем запрос на шлюз оплаты с такими параметрами: {параметры запроса}"
  • "Был получен ответ от шлюза оплаты: {детали ответа}"
  • "Общая стоимость заказа составляет: {общая сумма}"
  • "Сохраняем в базу данных заказ {детали заказа} для клиента {детали клиента}"

А вот как эти логи выглядят в реальных Java-приложениях:

2026-02-05 14:23:45.123 [http-nio-8080-exec-1] DEBUG c.e.shop.service.OrderService - Retrieved product from database: Product[id=12345, name='Wireless Mouse', price=29.99, stock=150]
2026-02-05 14:23:45.145 [http-nio-8080-exec-1] DEBUG c.e.shop.service.PaymentService - Making request to payment gateway with parameters: {amount=29.99, currency=USD, customerId=987, cardLast4=4242}
2026-02-05 14:23:45.892 [http-nio-8080-exec-1] DEBUG c.e.shop.service.PaymentService - Received response from payment gateway: {transactionId='txn_1a2b3c4d', status='SUCCESS', authCode='123456', timestamp=1738768425892}
2026-02-05 14:23:45.910 [http-nio-8080-exec-1] DEBUG c.e.shop.service.OrderService - Total order cost calculated: $29.99 (product: $29.99, tax: $0.00, shipping: $0.00)
2026-02-05 14:23:45.925 [http-nio-8080-exec-1] DEBUG c.e.shop.repository.OrderRepository - Saving order to database: Order[id=null, productId=12345, quantity=1, totalAmount=29.99] for customer: Customer[id=987, email='[email protected]', name='John Doe']

INFO

Как следует из названия, INFO - это информационные логи. Обычно, это уровень логирования по умолчанию на продакшн. Эти логи нужны нам, чтобы сообщать об основных событиях, происходящих в нашей программе. Посмотрите на пример ниже и вы поймете назначение этих логов лучше, чем из моих объяснений:

  • "Пользователь X добавил продукт Y в корзину"
  • "Начался процесс оплаты..."
  • "Была выбрана оплата картой VISA/MASTERCARD"
  • "Пользователь X успешно добавил биллинг-адрес"
  • "Оплата картой прошла успешно"
  • "Продукт был успешно зарезервирован на складе"

Если покрытие INFO-логами нашего программного кода было выполнено правильно, то эти логи читаются как повествование. То есть прочитав эти логи можно составить цепочку событий.

Пример логов, который я привел выше - это процесс покупки и оплаты продукта в интернет-магазине. Эти логи пишутся в момент, когда пользователь решает совершить покупку на сайте. На самом деле, самые первые INFO-логи мы можем увидеть в момент старта приложения. Например, если говорить о Spring Boot, то это может выглядеть так:

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::                (v4.0.2)

2026-02-05 10:15:23.456  INFO 12345 --- [           main] c.e.shop.ShopApplication                 : Starting ShopApplication using Java 21.0.2 with PID 12345 (C:\Users\Anton\projects\shop\target\classes started by Anton in C:\Users\Anton\projects\shop)
2026-02-05 10:15:23.460  INFO 12345 --- [           main] c.e.shop.ShopApplication                 : No active profile set, falling back to 1 default profile: "default"
2026-02-05 10:15:24.125  INFO 12345 --- [           main] .s.d.r.c.RepositoryConfigurationDelegate : Bootstrapping Spring Data JPA repositories in DEFAULT mode.
2026-02-05 10:15:24.201  INFO 12345 --- [           main] .s.d.r.c.RepositoryConfigurationDelegate : Finished Spring Data repository scanning in 68 ms. Found 5 JPA repository interfaces.
2026-02-05 10:15:24.890  INFO 12345 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port 8080 (http)
2026-02-05 10:15:24.903  INFO 12345 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2026-02-05 10:15:24.904  INFO 12345 --- [           main] o.apache.catalina.core.StandardEngine    : Starting Servlet engine: [Apache Tomcat/11.0.1]
2026-02-05 10:15:25.012  INFO 12345 --- [           main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2026-02-05 10:15:25.013  INFO 12345 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 1493 ms
2026-02-05 10:15:25.234  INFO 12345 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Starting...
2026-02-05 10:15:25.456  INFO 12345 --- [           main] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - Added connection org.postgresql.jdbc.PgConnection@7b3a299d
2026-02-05 10:15:25.458  INFO 12345 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Start completed.
2026-02-05 10:15:25.523  INFO 12345 --- [           main] o.hibernate.jpa.internal.util.LogHelper  : HHH000204: Processing PersistenceUnitInfo [name: default]
2026-02-05 10:15:25.589  INFO 12345 --- [           main] org.hibernate.Version                    : HHH000412: Hibernate ORM core version 7.0.0.Final
2026-02-05 10:15:25.623  INFO 12345 --- [           main] o.h.c.internal.RegionFactoryInitiator    : HHH000026: Second-level cache disabled
2026-02-05 10:15:25.912  INFO 12345 --- [           main] o.s.o.j.p.SpringPersistenceUnitInfo      : No LoadTimeWeaver setup: ignoring JPA class transformer
2026-02-05 10:15:26.234  INFO 12345 --- [           main] o.h.e.t.j.p.i.JtaPlatformInitiator       : HHH000489: No JTA platform available (set 'hibernate.transaction.jta.platform' to enable JTA platform integration)
2026-02-05 10:15:26.237  INFO 12345 --- [           main] j.LocalContainerEntityManagerFactoryBean : Initialized JPA EntityManagerFactory for persistence unit 'default'
2026-02-05 10:15:26.678  INFO 12345 --- [           main] o.s.b.a.e.web.EndpointLinksResolver      : Exposing 13 endpoint(s) beneath base path '/actuator'
2026-02-05 10:15:26.834  INFO 12345 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port 8080 (http) with context path ''
2026-02-05 10:15:26.849  INFO 12345 --- [           main] c.e.shop.ShopApplication                 : Started ShopApplication in 3.654 seconds (process running for 4.123)

Логи в примере - это те логи, который пишет сам Spring Boot в коде своего фреймворка. Как вы видите, эти информационные логи показывают нам цепочку загрузки основных компонентов фреймворка от самого старта и до момента, когда приложение полностью готово к работе.

WARN

Этот уровень лога предназначен для обозначения событий в программе, которые пошли не по плану, но в то же время еще не являются критичными и программа может продолжить свою работу в штатном режиме.

Эти логи, как правило, нужны, чтобы позже, когда мы будем просматривать логи нашей программы, мы смогли найти в них события, которые заслуживают нашего внимания, так как чаще всего требуют какой-то реакции. Давайте сразу посмотрим на примеры таких логов:

  • "Продукт Y не найден"
  • "На складе недостаточное количество продукта Y"

Давайте начнем с первого "Продукт Y не найден". Чаще всего такая проблема может возникать, когда существует рассинхронизация между тем, что мы показываем на UI (на странице нашего сайта) и тем, что у нас реально есть в базе данных (на сервере). В этом случае может возникать ситуация, что пользователь пытается купить несуществующий продукт (например, продукт был удален, но на UI еще не убран со страницы). Такая проблема не сломает весь сайт, но не позволит пользователю купить продукт. Когда администратор сайта будет просматривать логи, он заметит эту проблему и она будет исправлена.

2026-02-05 14:45:12.123  INFO 12345 --- [http-nio-8080-exec-5] c.e.shop.controller.OrderController      : Received purchase request for productId=54321, customerId=987, quantity=1
2026-02-05 14:45:12.145  WARN 12345 --- [http-nio-8080-exec-5] c.e.shop.service.ProductService          : Product not found in database: productId=54321
2026-02-05 14:45:12.147  WARN 12345 --- [http-nio-8080-exec-5] c.e.shop.service.OrderService            : Cannot create order: Product with id=54321 does not exist. Possible UI cache issue.
2026-02-05 14:45:12.150  INFO 12345 --- [http-nio-8080-exec-5] c.e.shop.controller.OrderController      : Purchase request failed: Product not found (productId=54321)

2026-02-05 15:22:34.567  INFO 12345 --- [http-nio-8080-exec-8] c.e.shop.controller.OrderController      : Received purchase request for productId=12890, customerId=456, quantity=2
2026-02-05 14:45:12.590  WARN 12345 --- [http-nio-8080-exec-8] c.e.shop.service.InventoryService        : Insufficient stock for productId=12890. Requested: 2, Available: 0
2026-02-05 14:45:12.592  WARN 12345 --- [http-nio-8080-exec-8] c.e.shop.service.OrderService            : Cannot fulfill order: Product 12890 is out of stock. Consider updating UI to reflect availability.
2026-02-05 14:45:12.595  INFO 12345 --- [http-nio-8080-exec-8] c.e.shop.controller.OrderController      : Purchase request failed: Product out of stock (productId=12890)

2026-02-05 16:10:45.890  INFO 12345 --- [http-nio-8080-exec-12] c.e.shop.controller.PaymentController    : Processing payment for orderId=99876, amount=149.99
2026-02-05 16:10:46.234  WARN 12345 --- [http-nio-8080-exec-12] c.e.shop.service.PaymentService          : Payment gateway response delayed. Waiting for confirmation... (attempt 1/3)
2026-02-05 16:10:48.567  WARN 12345 --- [http-nio-8080-exec-12] c.e.shop.service.PaymentService          : Payment gateway response delayed. Waiting for confirmation... (attempt 2/3)
2026-02-05 16:10:49.123  INFO 12345 --- [http-nio-8080-exec-12] c.e.shop.service.PaymentService          : Payment confirmed: transactionId=txn_9x8y7z6w, status=SUCCESS

ERROR

Уровень логирования ERROR используют для логирования ошибок, после которых дальнейшее штатное выполнение программы невозможно. Если после WARN мы можем продолжить, но с ограничениями, либо без них, то ERROR - это когда что-то пошло не так и после этого "не так" уже нельзя продолжить нормальный поток выполнения программы.

Обычно просмотр логов начинают с этого типа, чтобы сразу увидеть все самые существенные проблемы в программе, которые прямо влияют на стабильность ее работы. И исправить их как можно скорее.

Примеры ERROR-логов:

  • "Не удалось получить продукт Y, база данных недоступна"
  • "Не удалось получить оплату, платежный шлюз вернул ошибку"
  • "Не удалось зарезервировать продукт, inventory-service недоступен в данный момент"

Разберем пару логов.

"Не удалось получить продукт Y, база данных недоступна"

Как правило, данные мы храним в базе данных. Из кода наших программ мы делаем запросы к базе данных, чтобы получить требуемые данные. В нашем случае мы пытаемся получить продукт, который пользователь хочет купить на сайте. И не можем получить. Причин здесь может быть несколько:

  • База данные недоступна, так как сервер, на котором она "крутится" недоступен. Это может произойти по самым разным причинам;
  • Сам сервер баз данных не отвечает - например, перегружен;
  • Учетные данные (credentials) не подходят. Например, администратор БД изменил, но приложение еще об этом не знает.

Получив такую ошибку в логах мы сразу начинаем проверять доступ к базе и оперативно решать проблему.

"Не удалось получить оплату, платежный шлюз вернул ошибку"

Как правило, для обработки платежей мы используем платежные шлюзы. Один из популярных примеров такого шлюза - Stripe. Может быть так, что шлюз временно недоступен и приложение не может до него "достучаться". А может быть так, что изменилась конфигурация подключения к шлюзу и в этом случае мы со своей стороны должны обновить эту конфигурацию на стороне приложения, чтобы снова все заработало. То есть логирование здесь помогает нам быстро идентифицировать проблему еще до того, как к нам в службу поддержки придет жалоба от потенциального покупателя о том, что он не смог совершить заказ. О том, как настроить уведомления (алерты) на случай таких ошибок, мы поговорим в других частях этого туториала.

2026-02-05 18:30:12.456  INFO 12345 --- [http-nio-8080-exec-15] c.e.shop.controller.OrderController      : Received purchase request for productId=67890, customerId=123, quantity=1
2026-02-05 18:30:12.478  INFO 12345 --- [http-nio-8080-exec-15] c.e.shop.service.ProductService          : Fetching product with id=67890 from database
2026-02-05 18:30:12.512 ERROR 12345 --- [http-nio-8080-exec-15] c.e.shop.repository.ProductRepository    : Failed to execute database query

org.postgresql.util.PSQLException: Connection to database failed
	at org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:342)
	at org.postgresql.core.ConnectionFactory.openConnection(ConnectionFactory.java:54)
	at org.postgresql.jdbc.PgConnection.<init>(PgConnection.java:263)
	at org.postgresql.Driver.makeConnection(Driver.java:443)
	at org.postgresql.Driver.connect(Driver.java:297)
	at com.zaxxer.hikari.pool.PoolBase.newConnection(PoolBase.java:359)
	at com.zaxxer.hikari.pool.PoolBase.newPoolEntry(PoolBase.java:201)
	at com.zaxxer.hikari.pool.HikariPool.createPoolEntry(HikariPool.java:470)
	at com.example.shop.repository.ProductRepository.findById(ProductRepository.java:45)
	at com.example.shop.service.ProductService.getProduct(ProductService.java:78)
	at com.example.shop.controller.OrderController.createOrder(OrderController.java:123)
Caused by: java.net.ConnectException: Connection refused
	at java.net.PlainSocketImpl.socketConnect(Native Method)
	at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:476)
	at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:218)
	... 11 more

2026-02-05 18:30:12.520 ERROR 12345 --- [http-nio-8080-exec-15] c.e.shop.service.OrderService            : Cannot process order: Database unavailable
2026-02-05 18:30:12.523 ERROR 12345 --- [http-nio-8080-exec-15] c.e.shop.controller.OrderController      : Order creation failed for customer 123
2026-02-05 18:30:12.525  INFO 12345 --- [http-nio-8080-exec-15] c.e.shop.controller.OrderController      : Returning error response to client: HTTP 500 - Internal Server Error

2026-02-05 19:15:45.123  INFO 12345 --- [http-nio-8080-exec-22] c.e.shop.controller.PaymentController    : Processing payment for orderId=45678, amount=299.99, customerId=456
2026-02-05 19:15:45.245  INFO 12345 --- [http-nio-8080-exec-22] c.e.shop.service.PaymentService          : Sending payment request to gateway: amount=299.99
2026-02-05 19:15:47.890 ERROR 12345 --- [http-nio-8080-exec-22] c.e.shop.service.PaymentService          : Payment gateway returned error response

com.example.shop.exception.PaymentGatewayException: Payment declined: Insufficient funds
	at com.example.shop.service.PaymentService.processPayment(PaymentService.java:156)
	at com.example.shop.controller.PaymentController.handlePayment(PaymentController.java:89)
	at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
	at java.base/java.lang.reflect.Method.invoke(Method.java:580)
Response: {"error": "INSUFFICIENT_FUNDS", "message": "Card has insufficient funds for this transaction", "transactionId": "txn_failed_abc123"}

2026-02-05 19:15:47.895 ERROR 12345 --- [http-nio-8080-exec-22] c.e.shop.controller.PaymentController    : Payment failed for order 45678: Customer 456 - Insufficient funds
2026-02-05 19:15:47.897  INFO 12345 --- [http-nio-8080-exec-22] c.e.shop.service.OrderService            : Order status updated to PAYMENT_FAILED for orderId=45678

2026-02-05 20:45:30.567  INFO 12345 --- [http-nio-8080-exec-30] c.e.shop.controller.OrderController      : Received purchase request for productId=11111, customerId=789, quantity=5
2026-02-05 20:45:30.590  INFO 12345 --- [http-nio-8080-exec-30] c.e.shop.service.InventoryService        : Reserving inventory: productId=11111, quantity=5
2026-02-05 20:45:30.612 ERROR 12345 --- [http-nio-8080-exec-30] c.e.shop.service.InventoryService        : Failed to reserve inventory

java.lang.NullPointerException: Cannot invoke "com.example.shop.entity.Inventory.getAvailableQuantity()" because "inventory" is null
	at com.example.shop.service.InventoryService.reserveStock(InventoryService.java:134)
	at com.example.shop.service.OrderService.processOrder(OrderService.java:201)
	at com.example.shop.controller.OrderController.createOrder(OrderController.java:145)
	at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
	at java.base/java.lang.reflect.Method.invoke(Method.java:580)

2026-02-05 20:45:30.615 ERROR 12345 --- [http-nio-8080-exec-30] c.e.shop.controller.OrderController      : Critical error during order processing
2026-02-05 20:45:30.617 ERROR 12345 --- [http-nio-8080-exec-30] o.s.web.servlet.HandlerExceptionResolver : Unhandled exception in request handler

FATAL

Этот уровень логирования на самом деле присутствует не во всех системах логирования. И это неспроста - на это есть своя причина. Дело в том, что FATAL логи довольно редко пишутся в бизнес-коде (коде, который мы, разработчики, пишем в своих приложениях). Фатальные ошибки и фатальные логи чаще всего выбрасывает инструменты, которые мы используем в разработке. Другими словами, FATAL - это чаще всего ошибки инфраструктурного уровня. Один из примеров таких ошибок и логов в Java - это старт Spring Boot. Если по какой-то причине приложение не смогло запуститься, оно "падает" и в консоли мы можем видеть FATAL логи:

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::                (v4.0.2)

2026-02-05 21:30:12.456  INFO 23456 --- [           main] c.e.shop.ShopApplication                 : Starting ShopApplication using Java 21.0.2 with PID 23456
2026-02-05 21:30:12.460  INFO 23456 --- [           main] c.e.shop.ShopApplication                 : No active profile set, falling back to 1 default profile: "default"
2026-02-05 21:30:13.234  INFO 23456 --- [           main] .s.d.r.c.RepositoryConfigurationDelegate : Bootstrapping Spring Data JPA repositories in DEFAULT mode.
2026-02-05 21:30:13.312  INFO 23456 --- [           main] .s.d.r.c.RepositoryConfigurationDelegate : Finished Spring Data repository scanning in 72 ms. Found 5 JPA repository interfaces.
2026-02-05 21:30:13.890  INFO 23456 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port 8080 (http)
2026-02-05 21:30:13.903  INFO 23456 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2026-02-05 21:30:13.904  INFO 23456 --- [           main] o.apache.catalina.core.StandardEngine    : Starting Servlet engine: [Apache Tomcat/11.0.1]
2026-02-05 21:30:14.123  INFO 23456 --- [           main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2026-02-05 21:30:14.124  INFO 23456 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 1604 ms
2026-02-05 21:30:14.345  INFO 23456 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Starting...
2026-02-05 21:30:14.567 ERROR 23456 --- [           main] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - Exception during pool initialization.

org.postgresql.util.PSQLException: FATAL: password authentication failed for user "shop_user"
	at org.postgresql.core.v3.ConnectionFactoryImpl.doAuthentication(ConnectionFactoryImpl.java:654)
	at org.postgresql.core.v3.ConnectionFactoryImpl.tryConnect(ConnectionFactoryImpl.java:174)
	at org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:235)
	at org.postgresql.core.ConnectionFactory.openConnection(ConnectionFactory.java:54)
	at org.postgresql.jdbc.PgConnection.<init>(PgConnection.java:263)
	at org.postgresql.Driver.makeConnection(Driver.java:443)
	at org.postgresql.Driver.connect(Driver.java:297)
	at com.zaxxer.hikari.util.DriverDataSource.getConnection(DriverDataSource.java:138)
	at com.zaxxer.hikari.pool.PoolBase.newConnection(PoolBase.java:359)
	at com.zaxxer.hikari.pool.PoolBase.newPoolEntry(PoolBase.java:201)
	at com.zaxxer.hikari.pool.HikariPool.createPoolEntry(HikariPool.java:470)
	at com.zaxxer.hikari.pool.HikariPool.checkFailFast(HikariPool.java:561)
	at com.zaxxer.hikari.pool.HikariPool.<init>(HikariPool.java:100)
	at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:112)
	at org.springframework.boot.autoconfigure.jdbc.DataSourceInitializerInvoker.initSchema(DataSourceInitializerInvoker.java:62)
	... 42 common frames omitted

2026-02-05 21:30:14.570  WARN 23456 --- [           main] o.s.b.a.orm.jpa.DatabaseLookup           : Unable to determine database type - no connection available
2026-02-05 21:30:14.572 ERROR 23456 --- [           main] o.s.boot.SpringApplication               : Application run failed

org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'dataSource' defined in class path resource [org/springframework/boot/autoconfigure/jdbc/DataSourceConfiguration$Hikari.class]: Failed to instantiate [com.zaxxer.hikari.HikariDataSource]: Factory method 'dataSource' threw exception with message: HikariPool-1 - Exception during pool initialization.
	at org.springframework.beans.factory.support.ConstructorResolver.instantiate(ConstructorResolver.java:655)
	at org.springframework.beans.factory.support.ConstructorResolver.instantiateUsingFactoryMethod(ConstructorResolver.java:638)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.instantiateUsingFactoryMethod(AbstractAutowireCapableBeanFactory.java:1355)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBeanInstance(AbstractAutowireCapableBeanFactory.java:1185)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:582)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:542)
	at org.springframework.beans.factory.support.AbstractBeanFactory.lambda$doGetBean$0(AbstractBeanFactory.java:335)
	at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:234)
	at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:333)
	at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:208)
	at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:584)
	at org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext.refresh(ServletWebServerApplicationContext.java:146)
	at org.springframework.boot.SpringApplication.refresh(SpringApplication.java:754)
	at org.springframework.boot.SpringApplication.refreshContext(SpringApplication.java:456)
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:335)
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:1363)
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:1352)
	at com.example.shop.ShopApplication.main(ShopApplication.java:15)
Caused by: org.postgresql.util.PSQLException: FATAL: password authentication failed for user "shop_user"
	at org.postgresql.core.v3.ConnectionFactoryImpl.doAuthentication(ConnectionFactoryImpl.java:654)
	... 53 common frames omitted

2026-02-05 21:30:14.578 FATAL 23456 --- [           main] o.s.boot.SpringApplication               : Application startup failed

java.lang.IllegalStateException: Failed to execute ApplicationRunner
	at org.springframework.boot.SpringApplication.callRunner(SpringApplication.java:780)
	at org.springframework.boot.SpringApplication.callRunners(SpringApplication.java:761)
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:340)
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:1363)
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:1352)
	at com.example.shop.ShopApplication.main(ShopApplication.java:15)
Caused by: org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'dataSource'
	... 67 common frames omitted
Caused by: org.postgresql.util.PSQLException: FATAL: password authentication failed for user "shop_user"
	... 89 common frames omitted

2026-02-05 21:30:14.580  INFO 23456 --- [           main] o.apache.catalina.core.StandardService   : Stopping service [Tomcat]
2026-02-05 21:30:14.585  INFO 23456 --- [           main] .s.b.a.l.ConditionEvaluationReportLogger : 

Error starting ApplicationContext. To display the condition evaluation report re-run your application with 'debug' enabled.
2026-02-05 21:30:14.590 ERROR 23456 --- [           main] o.s.b.d.LoggingFailureAnalysisReporter   : 

***************************
APPLICATION FAILED TO START
***************************

Description:

Failed to configure a DataSource: 'password authentication failed for user "shop_user"'

Reason: Database authentication failed

Action:

Check your database credentials in application.properties:
  spring.datasource.username=shop_user
  spring.datasource.password=<your-password>

Verify that the database user exists and the password is correct.


2026-02-05 21:30:14.592  INFO 23456 --- [           main] c.e.shop.ShopApplication                 : Application context shutdown completed

Process finished with exit code 1