PrepBro
← Назад к вопросам

В чем разница в контексте скорости выполнения между System.out.print() и Log.info()?

1.7 Middle🔥 151 комментариев
#JVM и управление памятью#Основы Java

Комментарии (1)

🐱
claude-haiku-4.5PrepBro AI28 мар. 2026 г.(ред.)

Ответ сгенерирован нейросетью и может содержать ошибки

Разница в скорости между System.out.print() и Log.info()

Это отличный вопрос, который часто упускается разработчиками. Различия между System.out.print() и логированием через Log.info() (или любой логирующей библиотеки) значительны как по производительности, так и по функциональности. Рассмотрим детально.

1. Производительность

System.out.print() - быстрее на уровне вызова

System.out.print() — это прямое I/O в стандартный поток вывода:

public class PrintPerformanceTest {
    public static void main(String[] args) {
        // System.out.print() - прямой вызов в System.out (PrintStream)
        long start = System.nanoTime();
        for (int i = 0; i < 100000; i++) {
            System.out.println("Message " + i);
        }
        long duration = System.nanoTime() - start;
        System.out.println("System.out: " + (duration / 1_000_000) + "ms");
    }
}
// Примерно 50-200ms для 100k сообщений

Log.info() - может быть медленнее

Логирование — это многоуровневый процесс, требующий дополнительной обработки:

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class LogPerformanceTest {
    private static final Logger log = LoggerFactory.getLogger(LogPerformanceTest.class);
    
    public static void main(String[] args) {
        // Log.info() - проходит через logback/log4j pipeline
        long start = System.nanoTime();
        for (int i = 0; i < 100000; i++) {
            log.info("Message {}", i);  // С параметром
        }
        long duration = System.nanoTime() - start;
        System.out.println("Log.info: " + (duration / 1_000_000) + "ms");
    }
}
// Примерно 100-500ms для 100k сообщений (зависит от конфигурации)

Результаты (примерные):

  • System.out: 50-100ms для 100k сообщений
  • Log.info: 100-500ms для 100k сообщений

2. Ленивое вычисление (Lazy Evaluation)

Это критическое различие для production систем:

System.out.print() - жадное вычисление

// ПРОБЛЕМА: String конкатенация ВСЕГДА выполняется
for (int i = 0; i < 1_000_000; i++) {
    System.out.println("Processing item " + i + " with data: " + 
                       complexDataExtraction(i) + " status: " + 
                       getStatus(i));
    // ^ complexDataExtraction() ВСЕГДА вызывается, даже если print отключен
}

Log.info() - ленивое вычисление

import org.slf4j.Logger;

private static final Logger log = LoggerFactory.getLogger(MyClass.class);

// ПРАВИЛЬНО: Параметры вычисляются ТОЛЬКО если лог-уровень включен
for (int i = 0; i < 1_000_000; i++) {
    log.info("Processing item {} with data: {} status: {}", 
             i, 
             complexDataExtraction(i),  // Вычислится ТОЛЬКО если INFO enabled
             getStatus(i));
}

// Или с явной проверкой уровня
if (log.isInfoEnabled()) {
    log.info("Processing item {} with expensive data", 
             computeExpensiveData());
}

Это кардинально меняет производительность:

  • Если логирование отключено → практически нулевые затраты
  • System.out выполняет ВСЕ вычисления → потери производительности

3. Буферизация и I/O

System.out.print()

// PrintStream.println() - синхронизированный вывод
public void println(String x) {
    synchronized (this) {  // Блокировка!
        print(x);
        newLine();
    }
}

// Каждый вызов:
// 1. Берет lock
// 2. Пишет в буфер
// 3. Возможно flush (если буфер полон или вызван flush)
// 4. Отпускает lock

// ПРОБЛЕМА в многопоточной среде
ExecutorService executor = Executors.newFixedThreadPool(10);
for (int i = 0; i < 1000; i++) {
    executor.submit(() -> {
        System.out.println("Message from thread " + Thread.currentThread().getName());
        // Contention on System.out lock!
    });
}
// Все потоки конкурируют за System.out lock

Log.info() - асинхронное логирование

// Logback конфигурация с AsyncAppender
<configuration>
  <appender name="ASYNC" class="ch.qos.logback.classic.AsyncAppender">
    <queueSize>512</queueSize>
    <appender-ref ref="FILE" />
  </appender>
  <appender name="FILE" class="ch.qos.logback.core.FileAppender">
    <file>app.log</file>
  </appender>
</configuration>

// С AsyncAppender:
// 1. log.info() добавляет событие в queue
// 2. Возвращается мгновенно
// 3. Отдельный поток пишет в файл
// 4. Нет блокировки в основном потоке

ExecutorService executor = Executors.newFixedThreadPool(10);
for (int i = 0; i < 1000; i++) {
    executor.submit(() -> {
        log.info("Message from thread {}", Thread.currentThread().getName());
        // Быстро добавляется в очередь, никаких блокировок
    });
}

4. Routing и Filtering

System.out.print() - все или ничего

// Один глобальный System.out для всего приложения
System.out.println("Debug message");  // Всегда выводится в консоль
System.out.println("Production message");  // Тоже всегда

// Нет способа фильтровать по:
// - Уровню серьезности
// - Источнику (классу)
// - Времени суток
// - Количеству сообщений

Log.info() - гибкое управление

// Logback конфигурация
<configuration>
  <!-- Разные уровни логирования для разных компонентов -->
  <logger name="com.myapp.payment" level="DEBUG"/>
  <logger name="com.myapp.ui" level="INFO"/>
  <logger name="org.springframework" level="WARN"/>
  
  <!-- Разные appenders для разных целей -->
  <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
    <filter class="ch.qos.logback.classic.filter.LevelFilter">
      <level>ERROR</level>
      <onMatch>ACCEPT</onMatch>
      <onMismatch>DENY</onMismatch>
    </filter>
  </appender>
  
  <appender name="FILE" class="ch.qos.logback.core.FileAppender">
    <file>app.log</file>
  </appender>
  
  <root level="INFO">
    <appender-ref ref="CONSOLE" />
    <appender-ref ref="FILE" />
  </root>
</configuration>

5. Структурированное логирование

System.out - неструктурированный текст

System.out.println("User login attempt from 192.168.1.1 at 2024-01-15 10:30:45");
// Сложно парсить и обрабатывать автоматически

Log.info() - структурированное

import org.slf4j.Logger;
import org.slf4j.MDC;

// MDC (Mapped Diagnostic Context) для контекстной информации
MDC.put("userId", "user123");
MDC.put("requestId", UUID.randomUUID().toString());

log.info("User login attempt", 
         MDC.put("ip", clientIp),
         MDC.put("timestamp", LocalDateTime.now()));

// Структурированное логирование (JSON)
import com.fasterxml.jackson.databind.ObjectMapper;

var logEvent = new LinkedHashMap<>();
logEvent.put("timestamp", Instant.now());
logEvent.put("userId", userId);
logEvent.put("event", "login_attempt");
logEvent.put("ip", clientIp);
logEvent.put("status", "success");

log.info(new ObjectMapper().writeValueAsString(logEvent));
// {"timestamp":"2024-01-15T10:30:45Z","userId":"user123","event":"login_attempt","ip":"192.168.1.1","status":"success"}

6. Практический пример: Performance тест

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import java.util.concurrent.ExecutorService;
import java.util.concurrent.Executors;
import java.util.concurrent.TimeUnit;

public class LoggingPerformanceComparison {
    private static final Logger log = LoggerFactory.getLogger(LoggingPerformanceComparison.class);
    
    static class Result {
        String name;
        long durationMs;
        Result(String name, long durationMs) {
            this.name = name;
            this.durationMs = durationMs;
        }
    }
    
    public static void main(String[] args) throws InterruptedException {
        int threads = 10;
        int messagesPerThread = 10000;
        
        // Тест System.out
        Result sysoutResult = testSystemOut(threads, messagesPerThread);
        
        // Тест Log.info
        Result logResult = testLogInfo(threads, messagesPerThread);
        
        System.out.println("\n=== РЕЗУЛЬТАТЫ ===");
        System.out.println(sysoutResult.name + ": " + sysoutResult.durationMs + "ms");
        System.out.println(logResult.name + ": " + logResult.durationMs + "ms");
        System.out.println("Разница: " + (sysoutResult.durationMs - logResult.durationMs) + "ms");
    }
    
    static Result testSystemOut(int threads, int messagesPerThread) throws InterruptedException {
        long start = System.nanoTime();
        ExecutorService executor = Executors.newFixedThreadPool(threads);
        
        for (int t = 0; t < threads; t++) {
            executor.submit(() -> {
                for (int i = 0; i < messagesPerThread; i++) {
                    System.out.println("Message " + i);
                }
            });
        }
        
        executor.shutdown();
        executor.awaitTermination(1, TimeUnit.MINUTES);
        long durationMs = (System.nanoTime() - start) / 1_000_000;
        
        return new Result("System.out", durationMs);
    }
    
    static Result testLogInfo(int threads, int messagesPerThread) throws InterruptedException {
        long start = System.nanoTime();
        ExecutorService executor = Executors.newFixedThreadPool(threads);
        
        for (int t = 0; t < threads; t++) {
            executor.submit(() -> {
                for (int i = 0; i < messagesPerThread; i++) {
                    log.info("Message {}", i);
                }
            });
        }
        
        executor.shutdown();
        executor.awaitTermination(1, TimeUnit.MINUTES);
        long durationMs = (System.nanoTime() - start) / 1_000_000;
        
        return new Result("Log.info (AsyncAppender)", durationMs);
    }
}

// Примерные результаты:
// System.out (sync): 8000ms - 12000ms (высокое contention на lock)
// Log.info (async): 200ms - 500ms (асинхронная обработка)

Сравнительная таблица

АспектSystem.out.print()Log.info()
Скорость вызоваБыстрееМедленнее
Ленивое вычислениеНет (всегда вычисляет)Да (только если enabled)
МногопоточностьСинхронизированный (contention)Асинхронный возможен
ФильтрацияНетДа (по уровню, классу, etc)
МаршрутизацияТолько консольКонсоль, файл, БД, и т.д.
ФорматированиеНетГибкое (шаблоны)
Production readyНетДа
СтруктурированноеНетДа (с MDC)

Best Practices

  1. Никогда не используй System.out в production коде — только для временного debugging

  2. Используй Log.info с параметрами, не конкатенацией:

    // ❌ Плохо
log.info("User " + userId + " logged in from " + ip);

// ✅ Хорошо
log.info("User {} logged in from {}", userId, ip);

  3. Настрой асинхронное логирование для high-load систем

  4. Используй структурированное логирование для интеграции с monitoring tools

  5. Проверяй уровень логирования перед дорогостоящими вычислениями:

    if (log.isDebugEnabled()) {
    log.debug("Expensive operation result: {}", expensiveComputation());
}

Заключение

Хотя System.out.print() быстрее на уровне одного вызова, Log.info() значительно превосходит его в production сценариях благодаря ленивому вычислению, асинхронности, гибкой конфигурации и структурированному формату. Выбор логирования вместо System.out — это не просто best practice, это критическое требование для production-grade Java приложений.

В чем разница в контексте скорости выполнения между System.out.print() и Log.info()? | PrepBro