Hello world!

• 서론

다수의 서버를 사용하는 실시간 분산 시스템(Apache Kafka, Apache Storm 등)에서 시간 성능을 측정할 일이 생겼다.

성능 측정을 위해 A서버가 B서버에게 메시지를 전송할 때, A서버에서 송신시간을 측정하고 B서버에서 수신시간을 측정하여 {수신시간 - 송신시간}으로 전송시간을 계산하려고 하였다.

이때, 실시간 시스템이 워낙 빠르게 데이터를 주고 받으니 Java의 System.nanoTime()으로 송신시간과 수신시간을 측정했다.

그런데 측정된 시간으로 전송시간({수신시간 - 송신시간})을 계산해보니 음수가 나오는 문제가 발생했다.

즉, 이는 송신시간이 수신시간보다 더 느리다는 뜻이다.

어디서 이런 문제가 발생했을까?

• 본론

혹시 다른 프로세스에서 System.nanoTime()을 출력하면 다른 값이 나오는걸까?

먼저 아래와 같이 10ms(0.01초)마다 System.nanoTime()을 출력하는 간단한 프로그램을 작성해보았다.

이 프로그램을 두 개의 프로세스로 동작시켰더니 아래와 같은 결과가 나왔다.

실험 결과, test01 프로세스와 test02 프로세스가 출력하는 System.nanoTime()은 서로 반복적으로 교차하지만 선형적으로 증가함을 확인하였다.

즉, 서버 내에서 동작하는 서로 다른 프로세스에서는 System.nanoTime()이 꼬이지 않고 정상적으로 측정된다.

이제 두 개의 서버에서 위의 프로세스를 하나씩 동작시켜보자.

실험은 MobaXterm의 Multi-execution mode를 사용하여 동시에 실행하였다.

실험 결과는 아래와 같다.

실험 결과를 보면, 쉘의 입출력 시간과 터미널이 결과를 보여주는 시간을 고려하더라도 큰 차이가 있음을 알 수 있다.

예를 들어, 각 2번 라인을 보면 test01이 test02에 비해 3,827,747,357이 더 크다.

System.nanoTime()은 나노 초(10^-9 초)를 측정하므로, test01이 test02에 비해 약 3.8초 정도 느린 시간을 측정한다는 것이다.

이로써 System.nanoTime()을 서버 간의 시간 성능 측정에 사용할 경우 수 초 정도의 오차가 발생함을 확인하였다.

이러한 문제의 원인은 System 클래스의 Java doc을 통해 확인할 수 있었다.

Java doc의 nanoTime() 메서드 설명을 보면 아래의 설명이 있었다.

Returns the current value of the running Java Virtual Machine's high-resolution time source, in nanoseconds.

(중략)

The same origin is used by all invocations of this method in an instance of a Java virtual machine; other virtual machine instances are likely to use a different origin.

즉, System.nanoTime() 메서드는 JVM을 기준으로 나노초를 측정하며, 다른 JVM에서는 기준이 다르다는 뜻이다.

이러한 이유로 서로 다른 서버에서 측정한 나노초는 오차가 발생하는 것이다.

• 결론

Java의 System.nanoTime()은 같은 서버에서 서로 다른 프로세스로 동작시킬 경우에는 결과가 꼬이는 문제가 발생하지 않는다.

하지만 서로 다른 서버에서 시간 성능 측정으로 사용할 경우에는 수 초 정도의 오차가 발생할 수 있다.

따라서 서로 다른 서버에서는 단위가 조금 크더라도 System.currentTimeMillis()를 사용해야 한다.

System.currentTimeMillis() 함수는 운영체제로부터 시간을 가져오므로 서버들의 시간 동기화를 잘 맞춰준다면 초 단위의 오차를 없앨 수 있다.

(시간 동기화 후에 추가로 실험해보니 System.currentTimeMillis()은 초 단위의 오차가 발생하지 않았다.)

• 실험 환경

OS: CentOS 7

JVM: 1.8