rclpy에서 rate.sleep()이 멈추거나 주기가 안 맞을 때: Rate가 타이머 콜백의 이벤트를 기다린다는 점으로 executor 구성과 루프 주기 계산하기
ROS 1에서 rospy.Rate로 고정 주기 루프를 짜던 방식 그대로 ROS 2 Python 노드를 만들면 두 가지 증상 중 하나를 만나기 쉽다. rclpy의 rate.sleep()이 첫 반복 뒤로 영영 돌아오지 않거나, 루프는 도는데 목표한 Hz보다 느리다. Robotics Stack Exchange의 “Rate and sleep function in RCLPY library for ROS2” 같은 질문이 바로 이 상황에서 나온다. 겉으로는 둘 다 “Rate가 이상하다”로 보이지만 원인은 서로 다르다. 멈춤은 executor 구성의 문제이고, 느림은 루프 작업 시간과 주기를 비교하면 풀리는 문제다.
두 증상이 갈리는 이유는 rclpy Jazzy의 Rate.sleep()이 시계를 직접 읽지 않는다는 데 있다. 타이머가 울릴 때 세워지는 깃발 하나를 기다릴 뿐이고, 그 깃발은 executor가 타이머 콜백을 실행해야 올라간다. 아래에서는 rclpy 7.1.12 소스로 이 구조를 확인하고, 8 Hz 예제로 대기 시간·반복 수·실효 주기를 계산한 다음, 같은 예측을 ros:jazzy-ros-base 컨테이너에서 8가지 구성을 5번씩 돌린 실측과 나란히 놓는다. 실측은 소스에서 세운 예측과 모두 맞았다. 읽고 나면 멈춘 루프에서는 어느 스레드가 executor를 돌리는지부터, 느린 루프에서는 rate.sleep() 안에서 보낸 시간부터 확인하게 된다. 컨테이너 안 Python 프로세스에서 잰 값이며 시뮬레이터나 실물 로봇 실험은 아니다.
Python의 while 루프, 스레드(thread, 한 프로그램 안에서 동시에 진행되는 실행 흐름)라는 말, 주기 T = 1/f(초 = 1/Hz) 환산만 알면 따라올 수 있다.
rate.sleep()은 시계 대신 깃발을 기다린다
먼저 용어 몇 개를 맞춰 둔다. 노드(node)는 ROS 2 프로그램의 단위다. 콜백(callback)은 어떤 일이 생기면 대신 불러 달라고 맡겨 둔 함수이고, 타이머(timer)는 정해진 주기마다 그 콜백을 부를 준비가 되는 ROS 객체다. 실행기(executor)는 준비된 콜백을 골라 실제로 호출하는 일꾼이며, rclpy.spin()이나 executor.spin()처럼 이 일꾼을 계속 돌리는 일을 스핀(spin)이라고 부른다.
node.create_rate(8.0)을 부르면 rclpy는 period = 1.0 / frequency를 계산해 콜백이 없는 타이머를 하나 만들고, 그 타이머를 Rate로 감싼다(node.py L1803-L1823). Rate는 만들어지자마자 타이머의 콜백 자리에 threading.Event의 set 메서드를 꽂아 둔다. threading.Event는 스레드 사이에서 쓰는 깃발로, set()이 깃발을 올리고 wait()는 깃발이 올라갈 때까지 기다리며 clear()가 다시 내린다. 흐름을 줄여 옮기면 다음과 같다. 원문 그대로가 아니라 timer.py L118-L177과 node.py의 해당 줄을 읽고 핵심만 남긴 의사 코드다.
# rclpy Jazzy(7.1.12, 커밋 4e607c0) 흐름을 줄인 의사 코드 — 원문 복사가 아님
def create_rate(self, frequency, clock=None):
period = 1.0 / frequency
timer = self.create_timer(period, None, self._rate_group, clock)
return Rate(timer, context=self.context)
class Rate:
def __init__(self, timer, *, context):
self._timer = timer
self._event = threading.Event()
self._num_sleepers = 0
self._timer.callback = self._event.set # 타이머 콜백 = 깃발 올리기
def sleep(self):
self._presleep() # _num_sleepers += 1
try:
self._event.wait() # 타임아웃 없이 깃발을 기다린다
finally:
self._postsleep() # _num_sleepers -= 1, 0이 되면 _event.clear()
sleep() 안에는 “지금 몇 시인가”를 묻는 코드가 없다. 남은 시간 계산은 타이머가 맡고, sleep()은 깃발만 본다. ROS 1의 rospy.Rate.sleep()은 반대로 현재 ROS 시각을 읽고, _remaining()이 계산한 sleep_dur - (curr_time - last_time)만큼 직접 잔다(ros_comm noetic rospy/timer.py L65-L113). 그래서 rospy에서는 콜백을 처리하는 쪽이 무엇을 하든 Rate가 혼자 동작했다. ROS 1에서 되던 루프가 ROS 2에서 멈추는 이유가 여기에 있다.
깃발을 올리는 것은 누구일까. 비유하자면 rclpy의 Rate는 스스로 울리는 알람시계가 아니라, 누군가 눌러 줘야 울리는 초인종이다. 다만 이 비유는 한 단계를 뭉뚱그린다. ROS 2 Jazzy 문서에 따르면 타이머 만료를 알아차리는 것은 wait set(대기 집합, 준비된 타이머·구독을 한꺼번에 기다리는 장치)이고, executor는 그렇게 준비된 콜백을 자기 스레드에서 호출한다(About Executors). 그러니 정확히는 “executor가 wait set에서 Rate 타이머가 준비됐음을 받아 _event.set을 호출해야 sleep()이 돌아온다”가 된다.
멈춤은 깃발을 올릴 스레드가 없을 때 생긴다
이 구조에서 sleep()이 영원히 돌아오지 않는 경로는 둘이다.
첫째, 아무 스레드도 spin하지 않는 경우다. 메인 스레드에서 create_rate() 후 while 루프로 rate.sleep()을 부르기만 하면 타이머는 만료되지만 콜백을 호출할 executor가 없다. 루프 본문은 한 번 실행되고 첫 sleep()에서 멈춘다.
둘째, executor 스레드가 하나뿐인데 그 스레드가 콜백 안에서 rate.sleep()을 부르는 경우다. SingleThreadedExecutor의 타이머나 구독 콜백 안에서 sleep()을 부르면 유일한 스레드가 wait()에 묶여 Rate 타이머 콜백을 실행할 스레드가 남지 않는다. rclpy 소스의 sleep() docstring도 “This may block forever if called in a callback in a SingleThreadedExecutor.”라고 직접 경고한다(timer.py L166-L172).
그렇다면 MultiThreadedExecutor는 왜 해결책이 될 수 있을까. 여기서 콜백 그룹(callback group, 어떤 콜백끼리 동시에 실행해도 되는지 정하는 묶음)이 등장한다. 노드의 기본 그룹은 한 번에 하나만 실행하는 상호 배타(MutuallyExclusive) 그룹이라, 노드의 콜백이 모두 이 그룹에 있으면 스레드가 여럿이어도 사실상 단일 스레드처럼 동작한다(Using Callback Groups). 그런데 rclpy는 Rate 타이머를 기본 그룹이 아닌 노드 전용 ReentrantCallbackGroup(재진입 가능 그룹, 동시 실행 허용)에 넣는다(node.py L178, callback_groups.py L80-L90). create_rate 옆 주석도 “Rates get their own group so timing is not messed up by other callbacks”라고 설명한다. 따라서 스레드가 둘 이상이면, 기본 그룹 콜백 하나가 sleep()에 묶여 있어도 다른 스레드가 Rate 타이머 콜백을 실행할 수 있다. 스레드가 하나뿐인 MultiThreadedExecutor는 단일 스레드와 다를 게 없고, rclpy는 이 구성에 경고를 띄운다(executors.py L951-L983).
여기까지는 소스에서 도출한 예측이다. 컨테이너에서 네 구성을 실제로 돌려 확인했다. 멈추는 구성은 영원히 기다릴 수 없으므로, 실험 스크립트는 2초 뒤 감시용 스레드(워치독)가 node.destroy_rate(rate)를 불러 멈춘 sleep()을 깨우게 했다. Rate는 destroy나 rclpy.shutdown() 때 깃발을 올려 기다리던 스레드를 풀어 준다(rclpy 공식 테스트 test_destroy_wakes_rate, test_shutdown_wakes_rate). 콜백 안 케이스(E·F1·F2)는 노드 기본 그룹에 0.05초 타이머를 걸고, 그 콜백이 한 번 들어와 rate.sleep()을 8번 시도하게 했다.
| 구성 | 소스 기반 예측 | 실측(5회 실행, 5회 모두 같은 판정) |
|---|---|---|
A: spin 없음, 메인 while + 8 Hz Rate |
본문 1회 후 첫 sleep()에서 멈춤 |
본문 1회, 워치독 전 반환 0회. 마지막 sleep()이 2.0003~2.0004 s 막혀 있다가 워치독이 풀어 줌 |
E: SingleThreadedExecutor 콜백 안 rate.sleep() |
반환 0회 | 8번 시도 중 반환 0회, 워치독 없이는 콜백이 끝나지 않음 |
F1: MultiThreadedExecutor(num_threads=1) 콜백 안 |
단일 스레드와 같음, 반환 0회 | 반환 0회, stderr에 MultiThreadedExecutor is used with a single thread. 경고 |
F2: MultiThreadedExecutor(num_threads=2) 콜백 안 |
반환함 | 8번 모두 반환, 워치독 없이 1.0033~1.0036 s에 콜백 종료. 첫 간격을 뺀 평균 간격 0.125 s |
실행 1의 원본 출력 가운데 판정에 쓴 줄이다(5회 출력 전체는 아래 공개 저장소의 results.json에 있다).
{"case": "env", "sched_getaffinity_cpus": 2, "os_cpu_count": 2, "rmw": "default", "ros_distro": "jazzy"}
{"case": "A_no_spin_main_loop", "rate_hz": 8.0, "watchdog_s": 2.0, "loop_bodies_run": 1, "sleep_returns_before_watchdog": 0, "last_sleep_blocked_s": 2.0003, "elapsed_s": 2.0037, "error": null}
{"case": "E_single_threaded_callback", "rate_hz": 8.0, "sleep_attempts": 8, "watchdog_s": 2.0, "callback_entered": true, "sleep_returns_before_watchdog": 0, "finished_without_watchdog": false, "callback_exited": true, "elapsed_s": 2.0035, "error": null, "spin_thread_stopped": true}
{"case": "F2_multi_threaded_2_threads_callback", "rate_hz": 8.0, "sleep_attempts": 8, "watchdog_s": 2.0, "callback_entered": true, "sleep_returns_before_watchdog": 8, "finished_without_watchdog": true, "callback_exited": true, "elapsed_s": 1.0036, "error": null, "spin_thread_stopped": true, "first_interval_s": 0.0753, "n_intervals": 7, "mean_interval_s": 0.125, "median_interval_s": 0.1251, "min_interval_s": 0.1248, "max_interval_s": 0.1251, "stdev_interval_s": 0.0001, "effective_hz": 8.0008}
F2의 첫 간격은 5회 모두 0.0752~0.0753 s로, 나머지 간격(평균 0.125 s)보다 짧았다. 측정값은 여기까지다. 해석하자면 Rate 타이머는 sleep()을 처음 부른 시각이 아니라 create_rate()로 만들어진 시각부터 눈금을 센다. 콜백은 트리거 타이머 주기인 0.05 s쯤에 들어왔고, Rate의 첫 눈금은 생성 후 0.125 s에 왔으니 그 차이만큼 첫 sleep()이 짧아진 것으로 보인다. rclpy 공식 test_rate.py가 첫 sleep을 측정에서 빼는 이유와 같은 현상이다.
env 줄도 하나 짚어 둘 만하다. 하네스는 --cpus 1로 CPU 사용 시간을 제한했지만, 프로세스가 볼 수 있는 CPU 수(os.sched_getaffinity(0))는 2였다. MultiThreadedExecutor()를 인자 없이 만들면 Linux에서 이 값이 기본 스레드 수가 된다(executors.py L951-L983). 이 컨테이너에서는 기본값으로도 F2처럼 동작했겠지만, 볼 수 있는 CPU가 하나인 환경이라면 같은 코드가 F1이 된다. 실험에서 num_threads를 명시한 것도 계획 단계의 시험 실행에서 이 차이를 먼저 봤기 때문이고, 독자 코드에서도 콜백 안에서 Rate를 쓸 거라면 num_threads=2 이상을 명시하는 편이 안전하다.
느림은 작업 시간과 주기 중 긴 쪽이 정한다
executor가 따로 돌고 있다면 sleep()은 반드시 돌아온다. 이제 질문은 “언제 돌아오느냐”다. 직접 구성한 8 Hz 예제로 계산부터 해 보자. 실효 주기(effective period)는 루프가 실제로 한 바퀴 도는 데 걸리는 시간, 작업 시간 w는 루프 본문이 sleep() 전에 쓰는 시간이다.
- 목표 주기 T = 1/8 = 0.125 s.
create_timer는 이 값을int(float(0.125) * 10^9)로 바꿔 125000000 ns 타이머를 만든다(node.py L1750-L1786). - w = 0.0625 s면
sleep()은 다음 눈금까지 0.125 − 0.0625 = 0.0625 s를 기다린다. 5초 동안 5 / 0.125 = 40번 돈다. - w = 0.125 s면 기다릴 시간이 0이다. 여유가 전혀 없어서, 작은 흔들림도 곧바로 주기 초과가 된다.
- w = 0.25 s면 작업 도중에 이미 타이머가 울려 깃발이 서 있다.
sleep()은 즉시 돌아오고 루프는 0.25 s 간격, 즉 4 Hz로 돈다.
위 계산에 “executor가 없으면 본문 1회 뒤 멈춘다”는 반례를 더한 일곱 값은 example.py에 assert 7개로 하나씩 적어 두었다. 계산이 기대는 가정 다섯 가지는 verification.json의 teaching_context에 따로 적었다. 타이머 시계가 벽시계 속도로 흐르고, 타이머가 주기 격자에 맞춰 울리며, 작업 시간이 매번 같고, executor가 별도 스레드에서 지연 없이 콜백을 실행하며, 지터(jitter, 주기가 매번 조금씩 흔들리는 정도)와 GIL(Global Interpreter Lock, 파이썬에서 한 번에 한 스레드만 파이썬 코드를 실행하게 하는 잠금) 경합이 없다는 것이다. 같은 파일에 실행 명령 python3 -I example.py, 종료 코드 0, 출력도 남아 있다. 둘 다 Python 3.12.3으로 돌린 산술 검산이지 ROS 실행이 아니다.
마지막 항목을 일반화하면 실효 주기 ≈ max(T, w)라는 식이 나온다. 근거는 _postsleep()에 있다. 깃발은 sleep()이 끝난 직후에만 내려가므로, w가 T보다 길면 길이 w인 작업 구간 안에 타이머가 적어도 한 번 울리고 다음 sleep()은 서 있는 깃발을 보고 바로 돌아온다. 이 모델이 맞다면 두 가지가 따라 나온다. w = 0.15 s일 때 루프는 다음 눈금인 0.25 s로 밀려 올라가지 않고 0.15 s 간격으로 돈다. 그리고 깃발이 하나뿐이라 작업 중 타이머가 두 번 울려도 쌓이지 않으니, 늦어진 만큼 빠르게 몰아서 도는 “따라잡기”도 없어야 한다.
실측은 executor를 데몬 스레드(daemon thread, 메인 프로그램이 끝나면 함께 끝나는 보조 스레드)에서 spin하고, 메인 루프에서 time.sleep(w)로 작업을 흉내 낸 뒤 rate.sleep()을 부르는 구성이다. 시간은 time.monotonic()(단조 시계, monotonic clock: 시스템 시각을 고쳐도 뒤로 가지 않는 시계)으로 쟀다. 첫 간격은 위에서 본 위상 차가 섞이므로 평균에서 뺐다.
| 작업 w | 계산·모델 예측 | 창 길이 | 예측 루프 수 | 실측 루프 수 | 실측 평균 간격 | 실측 실효 Hz | sleep() 평균 대기 |
|---|---|---|---|---|---|---|---|
| 0.0625 s | 간격 0.125 s, 대기 0.0625 s | 5 s | 40 | 40 | 0.125 s | 8.0~8.0002 | 62.375~62.378 ms |
| 0.125 s (경계) | 간격이 0.125 s보다 아주 조금 김, 대기 ≈ 0 | 3 s | 24 | 24 | 0.1251 s | 7.9919~7.9929 | 0.016~0.021 ms |
| 0.15 s | 간격 ≈ 0.15 s (0.25 s로 올림되지 않음) | 3 s | 20 | 20 | 0.1501 s | 6.6602~6.6606 | 0.024~0.027 ms |
| 0.25 s | 간격 ≈ 0.25 s, 약 4 Hz | 3 s | 12 | 12 | 0.2501~0.2506 s | 3.9909~3.9977 | 0.015~0.017 ms |
범위는 5회 실행의 최소~최대이고, 루프 수와 평균 간격이 한 값이면 5회가 모두 같았다는 뜻이다. 예측과 어긋난 행은 없었다. w = 0.25 s의 실행 2만 최대 간격이 0.2544 s(표준편차 0.0013 s)로 다른 실행보다 한 번 길게 튀었다. 반대 방향, 즉 따라잡느라 짧아진 간격은 보이지 않았다. w = 0.25 s의 최소 간격은 5회 모두 0.2501 s, w = 0.15 s는 5회 모두 0.1501 s였다. 정상 구성인 w = 0.0625 s의 개별 간격은 5회를 통틀어 0.1244~0.1256 s 안에 있었다.
{"case": "B_spin_thread_work_0.0625", "rate_hz": 8.0, "work_s": 0.0625, "window_s": 5.0, "loop_starts_in_window": 40, "first_sleep_wait_ms": 63.05, "mean_sleep_wait_ms": 62.378, "max_sleep_wait_ms": 62.495, "spin_thread_stopped": true, "first_interval_s": 0.1257, "n_intervals": 38, "mean_interval_s": 0.125, "median_interval_s": 0.125, "min_interval_s": 0.1249, "max_interval_s": 0.1251, "stdev_interval_s": 0.0001, "effective_hz": 8.0}
{"case": "D_spin_thread_work_0.15", "rate_hz": 8.0, "work_s": 0.15, "window_s": 3.0, "loop_starts_in_window": 20, "first_sleep_wait_ms": 0.026, "mean_sleep_wait_ms": 0.025, "max_sleep_wait_ms": 0.068, "spin_thread_stopped": true, "first_interval_s": 0.1501, "n_intervals": 18, "mean_interval_s": 0.1501, "median_interval_s": 0.1501, "min_interval_s": 0.1501, "max_interval_s": 0.1502, "stdev_interval_s": 0.0, "effective_hz": 6.6603}
{"case": "C_spin_thread_work_0.25", "rate_hz": 8.0, "work_s": 0.25, "window_s": 3.0, "loop_starts_in_window": 12, "first_sleep_wait_ms": 0.032, "mean_sleep_wait_ms": 0.016, "max_sleep_wait_ms": 0.025, "spin_thread_stopped": true, "first_interval_s": 0.2501, "n_intervals": 10, "mean_interval_s": 0.2501, "median_interval_s": 0.2501, "min_interval_s": 0.2501, "max_interval_s": 0.2504, "stdev_interval_s": 0.0001, "effective_hz": 3.9977}
표에서 가장 쓸모 있는 열은 맨 오른쪽이다. 루프가 정상적으로 Rate에 맞춰 돌 때 sleep() 대기는 T − w 근처의 수십 ms였고, 작업이 주기와 같거나 길어지자 평균 0.03 ms도 안 되는 값으로 떨어졌다. 그러니 “느리다”는 증상을 만나면 rate.sleep() 앞뒤로 time.monotonic()을 찍어 보는 것이 가장 빠른 진단이다. 대기가 0에 붙어 있으면 executor는 멀쩡하고 작업이 주기를 다 먹고 있다. 그때 해야 할 일은 executor 교체가 아니라 작업을 줄이거나 목표 주파수를 낮추는 것이다. 경계 행도 같은 이야기를 한다. 작업이 정확히 T여도 루프 자체의 오버헤드만큼 간격이 길어져 7.99 Hz대로 내려갔다. 여유가 0인 루프는 이미 목표를 지키지 못한다.
루프를 어디에 둘지: 세 가지 구성
멈춤의 원인이 “깃발을 올릴 스레드가 없음”이라면 해법은 결국 그 스레드를 마련하는 방법의 차이다.
spin 데몬 스레드 + 메인 루프의 Rate. 실측 B·경계·D·C가 쓴 구성이다. 공개된 실험 스크립트에서 해당 부분만 발췌했다(...는 생략한 줄, # case_spin_thread() 안은 위치 표시).
def start_spin(executor):
thread = threading.Thread(target=executor.spin, daemon=True)
thread.start()
return thread
# case_spin_thread() 안
node = rclpy.create_node(name.lower().replace(".", "_"))
executor = SingleThreadedExecutor()
executor.add_node(node)
thread = start_spin(executor)
rate = node.create_rate(RATE_HZ)
...
while True:
...
time.sleep(work_s) # 루프 본문(작업) 대역
s = time.monotonic()
rate.sleep()
waits.append(time.monotonic() - s)
ROS 1의 while not rospy.is_shutdown(): ... rate.sleep() 습관을 가장 적게 바꾸는 방법이다. 대신 루프 본문과 spin 스레드의 구독 콜백이 같은 변수를 건드린다면 두 스레드가 동시에 접근하게 되므로, 공유 상태는 잠금 등으로 보호해야 한다. 이 부분은 실험하지 않은 설계상 주의다. “Rate는 메인 스레드에서 쓰면 안 된다”는 설명을 볼 때도 있는데, 조건은 어느 스레드냐가 아니라 다른 스레드에서 executor가 돌고 있느냐다. rclpy 공식 test_rate.py는 거꾸로 Rate를 보조 스레드에 두고 메인에서 spin_once()를 반복한다.
콜백 안에서 Rate를 써야 한다면 MultiThreadedExecutor(num_threads=2) 이상. F2가 이 구성으로 8번 모두 돌아왔다. 다만 sleep() 중인 콜백은 계속 기본 상호 배타 그룹을 붙잡고 있다. 같은 그룹의 다른 콜백, 예를 들어 같은 노드의 구독 콜백은 그동안 실행되지 못한다는 것이 콜백 그룹 문서의 규칙에서 따라 나오는 결론이다. 이 실험은 그 영향을 재지 않았다.
Rate 대신 create_timer(T, callback) 하나에 루프 본문을 넣기. 블록하는 대기 자체가 없으니 위의 두 함정이 생기지 않는다. 새로 짜는 노드라면 가장 단순한 선택이다. 대신 작업이 T보다 길어지면 이 구성은 Rate의 깃발이 아니라 rcl(ROS 2의 C 계층 공통 라이브러리) 타이머가 다음 예정 시각을 정하는 규칙을 따른다. 늦은 콜백 뒤에 rcl이 놓친 주기를 몰아서 실행하지 않고 건너뛴다는 점은 real time factor와 실시간 마감을 구분한 글의 「늦은 콜백 뒤에 rcl 타이머는 주기 하나를 건너뛴다」 절이 rcl timer.c 소스로 설명하고, 같은 글의 다음 절이 컨테이너에서 쟀다. 이번 실험은 create_timer 구성을 재지 않았으니, 콜백이 T보다 길 때의 간격은 그 글에서 확인하면 된다.
직접 확인해 볼 질문
1. 8 Hz Rate, spin 스레드는 정상이고 루프 작업이 매번 0.2초 걸린다. 루프 간격은?
약 0.2초(약 5 Hz)로 예측한다. 0.2 > 0.125이므로 작업 구간마다 타이머가 한 번 이상 울리고, 다음 sleep()은 바로 돌아온다. 다음 눈금인 0.25초까지 기다리지 않는다는 점은 w = 0.15초 실측(간격 0.1501초)이 받쳐 준다. 0.2초 자체는 측정하지 않았으므로 이 답은 모델에 따른 예측이다.
2. 노드 기본 그룹의 타이머 콜백에서 rate.sleep()을 부르고, executor는 MultiThreadedExecutor()를 인자 없이 만들었다. 돌아올까?
환경에 따라 다르다. 기본 스레드 수가 len(os.sched_getaffinity(0))이라 이번 컨테이너처럼 2라면 F2와 같은 구성이 되고, 1이라면 F1처럼 멈춘다. 그래서 답은 “num_threads를 명시하라”다.
3. rate.sleep() 앞뒤 시간을 찍어 보니 매번 0.03 ms 안팎인데 루프는 목표보다 느리다. executor를 바꾸면 해결될까?
아니다. 대기가 0에 붙어 있다는 것은 sleep()이 즉시 돌아오고 있다는 뜻이다. executor는 제 역할을 하고 있고 작업 시간이 주기를 넘었다. 작업을 줄이거나 주파수를 낮춰야 한다.
직접 재현하기와 이 측정의 범위
재현 스크립트, 실행 전에 적은 예측(plan.md), 5회 실행의 원본 출력은 공개 실험 폴더에 있다. 개별 파일은 experiment.py, plan.md, results.json이다. Docker가 설치된 Linux에서 빈 디렉터리를 만들고 다음을 실행하면 된다. 이미지 태그 대신 실측에 쓴 이미지의 digest(내용 해시로 고정한 이미지 주소)를 그대로 지정했다.
mkdir rclpy-rate-check && cd rclpy-rate-check
curl -fsSLO https://raw.githubusercontent.com/sungpyo9053/blog/main/experiments/rclpy-rate-sleep-timer-executor-loop-period/experiment.py
docker run --rm --network none --cpus 1 --memory 1g -v "$PWD":/work ros@sha256:066420e07f60aa18262f2479981def87ebcfcec42eefb0c0c57c4a46098348ca bash -c "source /opt/ros/jazzy/setup.bash && python3 /work/experiment.py"
정상이라면 케이스마다 JSON 한 줄이 나오고 마지막에 {"case": "done", ...}가 찍히며 종료 코드는 0이다. 하네스에서는 한 번에 22초 남짓 걸렸다. F1 케이스는 의도한 구성이라 stderr에 UserWarning: MultiThreadedExecutor is used with a single thread.가 남는다. 판정 기준은 위 표 그대로다. A·E·F1의 sleep_returns_before_watchdog가 0이면 멈춤 재현, F2가 8이면 2스레드 구성 정상, B의 mean_interval_s가 0.125 근처이고 D·C가 각각 작업 시간 근처이면 max(T, w) 모델과 일치한다. 숫자 자체는 CPU와 부하에 따라 달라질 수 있다. 스크립트를 고쳐 쓸 때 하나 걸리기 쉬운 지점이 있다. 계획 단계의 첫 시험 실행은 케이스 이름 B_spin_thread_work_0.0625를 그대로 노드 이름으로 썼다가 InvalidNodeNameException으로 실패했다. 노드 이름에는 영숫자와 _만 쓸 수 있어서, 지금 스크립트는 .을 _로 바꾼다.
측정 환경은 ros:jazzy-ros-base(digest 위와 같음), Python 3.12.3, rclpy 패키지 7.1.12-1noble.20260902.053513, 기본 RMW(ROS Middleware, 노드 사이 통신을 맡는 하부 계층)인 rmw_fastrtps_cpp, 네트워크 없음, CPU 1개 분량과 메모리 1 GiB 제한이며 5회 실행 모두 종료 코드 0이었다. 소스 근거는 rclpy jazzy 브랜치 커밋 4e607c0이고, 2026년 10월 10일 KST에 확인했다. 결론이 달라질 수 있는 조건은 다음과 같다.
- 작업을
time.sleep(w)로 흉내 냈다. 이 대기는 GIL을 놓기 때문에 spin 스레드가 자유롭게 돈다. 실제 계산처럼 GIL을 붙잡는 작업이면 콜백 지연과 지터가 달라질 수 있고, 이는 재지 않았다. - 작업 시간이 일정한 경우만 쟀다. 작업 시간이 들쭉날쭉한 루프는 측정하지 않았다.
use_sim_time은 껐다. 소스상 Rate 타이머는 노드의 ROS 시계를 따르므로use_sim_time을 켜면 /clock 기반 시간을 따르게 되지만, 실행으로 확인하지 않았고 /clock이 아직 발행되지 않았을 때의 동작도 확인하지 않았다. /clock을 받기 전 시각 0이 첫 주기 계산에 끼어드는 문제는 use_sim_time 노드의 첫 dt 스파이크 계산에서 따로 다뤘다.- Jazzy 기준이다. Humble·Rolling 등 다른 배포판의 Rate 구현은 다를 수 있다.
- 시뮬레이터나 실물 로봇이 아니다. 8 Hz를 지켰다는 결과가 실시간 마감 보장을 뜻하지 않는다. 주기를 지키는 것과 마감을 보장하는 것의 차이는 real time factor와 실시간 컴퓨팅의 마감을 숫자로 구분한 글에 정리돼 있다. 이 루프로 실물 로봇에 명령을 보낸다면 주기가 밀릴 때 명령 갱신이 늦어지고,
sleep()이 멈추면 명령이 아예 끊긴다. 명령이 끊겼을 때 로봇이 스스로 멈추는지는 드라이버·제어기 설정에 달린 별도의 확인 항목이며, 이 글은 그 부분을 검증하지 않았다.
멈췄는지, 느린지부터 가른다
rate.sleep()이 의심스러울 때 볼 순서는 짧다. 반복 횟수가 늘지 않으면 멈춤이다. spin하는 스레드가 있는지, sleep()을 executor 콜백 안에서 부르는지, 그 executor의 스레드가 몇 개인지를 차례로 본다. 반복은 되는데 Hz가 모자라면 느림이다. rate.sleep() 안에서 보낸 시간을 재서 0에 붙어 있으면 작업 시간이 주기를 넘은 것이다. ROS 1 코드를 옮기는 중이라면 spin 데몬 스레드 구성이 가장 적은 변경이고, 새로 짜는 노드라면 Rate 없이 create_timer 콜백으로 가는 편이 executor 함정을 처음부터 피한다.
