Log4j: nó có được đồng bộ hóa cho các cuộc gọi đa luồng không?

Question

Chúng tôi đang chạy vào một vấn đề thú vị mà chúng tôi nhận thấy trong khi thực hiện kiểm tra căng thẳng của hệ thống của chúng tôi. Chúng tôi đang sử dụng log4j (trong JBOSS) rất nhiều cho việc đăng nhập của chúng tôi. Đây là một ví dụ ngây thơ của một số khai thác gỗ, chúng tôi ave

void someFunction() 
{ 
Log.info("entered some function"); 
... 

Log.info("existed some function"); 
} 

Bây giờ điều thú vị chúng tôi nhận thấy là nếu chúng tôi khởi động 100 chủ đề chống lại chức năng này; các cuộc gọi Log.info() đang chặn trên mỗi chuỗi .. có nghĩa là thread 2 đang chờ thread1 để kết thúc cuộc gọi "Log.info". Trường hợp chủ đề 100; nó kết thúc chờ đợi khá lâu. Chúng tôi đang sử dụng một tập tin bản ghi logger.

Đây có phải là sự cố đã biết không?

Answer 1

Những gì bạn có thể muốn là không đồng bộ khai thác gỗ, xem bài viết này về cách đạt được điều đó:

Asynchronous logging with log4j

Ngoài ra, xem xét sử dụng các mức log đúng. Các câu lệnh entered... và exi(s)ted... thường phải được ghi ở mức TRACE, có thể hữu ích khi gỡ lỗi (sau đó đặt cấu hình log4j để đăng nhập ở mức TRACE). Trong cài đặt sản xuất, bạn có thể muốn yêu cầu log4j chỉ đăng nhập từ mức INFO hoặc DEBUG, do đó tránh các hành động nhật ký không cần thiết.

cũng Xem câu hỏi này về việc thực hiện của log4j:

log4j performance

Answer 2

Log4J phải được đồng bộ, nếu không bạn sẽ nhìn thấy thông điệp log xen kẽ và bị cắt xén trong tập tin của bạn. Nhưng ít nhất trong Logback chỉ appenders được đồng bộ, không phải là toàn bộ thông điệp đăng nhập (vì vậy tính toán mức độ đăng nhập hiệu quả, thông điệp tường trình, vv là đa luồng).

Tuy nhiên ngay cả khi đồng bộ hóa đã bị xóa, I/O sẽ là nút cổ chai vì nó vốn dĩ là đơn luồng. Vì vậy, hãy xem xét giảm số lượng đăng nhập, vì nó là truy cập tập tin đó là chậm, không Log4J.

Bạn cũng có thể quan tâm AsyncAppender để xếp hàng các thông điệp ghi nhật ký trong một chuỗi khác nhau.

Answer 3

Những người khác đã gợi ý bạn lựa chọn thay thế, tôi đã đào bới trong mã nguồn và thực sự có một phần synchronized:

public void info(Object message) { 
    if(repository.isDisabled(Level.INFO_INT)) 
     return; 
    if(Level.INFO.isGreaterOrEqual(this.getEffectiveLevel())) 
     forcedLog(FQCN, Level.INFO, message, null); 
} 

... 

protected void forcedLog(String fqcn, Priority level, Object message, Throwable t) { 
    callAppenders(new LoggingEvent(fqcn, this, level, message, t)); 
} 

... 

public void callAppenders(LoggingEvent event) { 
    int writes = 0; 

    for(Category c = this; c != null; c=c.parent) { 
     // Protected against simultaneous call to addAppender, removeAppender,... 
     synchronized(c) { 
      if(c.aai != null) { 
       writes += c.aai.appendLoopOnAppenders(event); 
      } 
      if(!c.additive) { 
       break; 
      } 
     } 
    } 

    if(writes == 0) { 
     repository.emitNoAppenderWarning(this); 
    } 
} 

Answer 4

Vâng, log4j sử dụng multithread syncronyzation. Và không hoàn hảo, đôi khi.

Chúng tôi đã trải qua một số sự xuống cấp hiệu suất gây ra bởi tranh chấp cho các khóa log4j và thậm chí deadlocks với việc sử dụng phương thức toString() phức tạp. Ví dụ:

Xem https://issues.apache.org/bugzilla/show_bug.cgi?id=24159 và https://issues.apache.org/bugzilla/show_bug.cgi?id=41214#c38.

Xem thêm chi tiết trong câu trả lời của tôi khác: Production settings file for log4j?

Tôi đoán đây là một trong những lý do của sự tồn tại logback và chuyển sang logmanager tùy chỉnh từ JBoss AS 6.

Answer 5

Đồng ý với câu trả lời trước. Một trong những bước cải thiện hiệu suất đầu tiên trong bất kỳ ứng dụng nào là giảm cấp độ nhật ký và cho phép kết xuất ít nhật ký hơn. Các nhà phát triển ứng dụng cần phải siêng năng trong việc sử dụng các mức ghi đúng. Việc ghi nhật ký có tác động rất lớn đến hiệu suất vì I/O cũng như đồng bộ hóa đặc biệt là khi các đối tượng logger là tĩnh và được chia sẻ giữa các luồng khác nhau.