[C#][Serilog] Serilog 멀티스레드

Serilog는 멀티스레드 환경에서 별도 lock 컨트롤 없어도 괜찮은지 확인해보려고 한다.
(기본적으로 Serilog는 thread-safe 하다고 한다.)

 

10개의 쓰레드 생성

각 쓰레드 마다 1000개의 로그 기록

=> 총 n값이 10000까지 출력이 되어야 하고 n 값이 중복되서는 안된다.

 

다음 함수를 쓰레드로 실행시킬 것이다.

n은 static으로 선언해서 별도의 lock 처리 없이 Information (및 Verbose, Debug, Error, Fatal)에서 ++n이 잘 실행되는지도 확인해보겠다.

추가적으로 운좋게(?) 경합이 일어나지 않아 예상대로 출력될 수도 있으니 3번씩은 실행시켜보았다.

static int n = 0;

static void Thread1()
{
    for (int i = 0; i < 1000; i++)
    {
        Log.Logger.Information("This is {i} message on Thread [n={n}]", i, ++n);
    }
}

static void Main()
{
    // logger 생성
    
    List<Action> list = new();
    for(int i=0; i<10; i++)
    {
        int t = i;
        list.Add(() => Thread1());
    }
    Parallel.Invoke(list.ToArray());

    Log.Logger.Information("All threads are completed.");
    Console.WriteLine("End");
    while (true)
    {
        string c = Console.ReadLine();
        if (c.Equals("stop")) break;
    }
}

---

Serilog.Sinks.Console

 

다음과 같이 Logger를 생성하여 Console에 출력을 해보았다.

Log.Logger = new LoggerConfiguration().WriteTo.Console().CreateLogger();

예상대로 전부 깔끔하게 출력이 되는 것을 확인하였다. 

---

Serilog.Sinks.Async (Console)

 

로깅을 Async으로 처리하면 어떻게 될까?

Log.Logger = new LoggerConfiguration().WriteTo.Async(a => a.Console()).CreateLogger();

이번에는 완전하게 예상대로 출력되지 못했다. 총 10000줄이 출력되었는지는 일일히 확인해보지는 않아서 알 수 없었다. (File에서 확인)

---

Serilog.Sinks.File

Log.Logger = new LoggerConfiguration().WriteTo.File("logs.txt").CreateLogger();

n=10000이 출력된 줄에 Ln 10000이 표시된 걸로 보아 제대로 출력이 된 것을 확인할 수 있었다. (커서가 현재 마지막 줄이 나닌 n=10000에 가 있다.)

---

Serilog.Sinks.Async (File)

Log.Logger = new LoggerConfiguration().WriteTo.Async(a => a.File("logs-async.txt")).CreateLogger();

 

n 값은 10000이 나오지 않았다. => n에 대한 연산은 async로 했을 때, thread-safe 하지 않았다.

총 10000줄이 출력되었다. => 로깅 자체는 thread-safe하다.

추가적으로, n값이 동일하게 출력되는 부분도 있었다.

---

결과

 

Serilog에서 Sync이든 Async이든 콘솔과 파일에 로깅을 하는 것은 Thread-Safe하므로 여러 스레드에서 동시에 접근해도 Serilog가 알아서 안전하게 처리해주기 때문에 상관이 없다는 것을 알았다.

 

하지만, Async(비동기) 로깅에서는  Logging 함수 (Verbose, Debug, Information, Error, Fatal) 내에서 어떤 연산을 하거나, 어떤 값을 출력할 때는 주의가 필요할 수 있다고 느꼈다. 확실하지 않다는 것이다. 값 변화가 매우 심한 오브젝트를 출력할 때는 고려를 해야 할 것 같다. (매우 심한 경우!)

 

 

 

(위에서 확인했듯이, ++n 연산을 Information 함수에 포함시켰는데 이는 async-logging을 하였을 경우 연산이 Serilog에서 처리되는 것이 아니라 연산이 된 결과 값이 async하게 로깅되는 것처럼 보인다. 하지만 10000과 크게 차이가 나지 않는 것으로 보아, 이러한 생각도 정확하지 않은 것같다... 실제로 로깅을 하지 않고 ++n만 했을 때, n 값이 10000과 크게 차이가 났다.)