Linux Kernel(4.19) Hacks

rousalome.egloos.com

포토로그 Kernel Crash


통계 위젯 (화이트)

5112
737
82115


[라즈베리파이] 커널 타이머 - jiffies란 값은 누가 언제 증가하나 7장. 타이머관리

jiffies에 대해 조금 더 깊이 알아보겠습니다. jiffies는 커널 시스템 타이머가 동적 타이머를 처리하는 횟수입니다. 그럼, jiffies란 값은 누가 언제 증가시킬까요? 이 변수는 타이머 인터럽트가 발생하고 난 후 do_timer() 함수에서 jiffies를 업데이트합니다. 

소스 코드를 보면 이 내용을 더 쉽게 이해할 수 있으니 바로 코드 분석으로 들어가겠습니다.
[kernel/time/timekeeping.c]
1 void do_timer(unsigned long ticks)
2 {
3 jiffies_64 += ticks;
4 calc_global_load(ticks);
5}

3번 줄 코드를 보면 ticks이란 인자를 jiffies_64이란 jiffies 변수에 증감합니다.

여기서 do_timer() 함수는 누가 호출할까요? do_timer() 함수는 tick_do_update_jiffies64 () 함수에서 tick이란 변수를 1만큼 증감시키고 do_timer() 함수 인자로 전달합니다.

이 내용은 다음 7번 줄 코드를 보면 알 수 있습니다.
1 static void tick_do_update_jiffies64(ktime_t now)
2 {
...
3 if (delta >= tick_period) {
4
5 delta = ktime_sub(delta, tick_period);
6 last_jiffies_update = ktime_add(last_jiffies_update,
...
7 do_timer(++ticks);

이론으로 라즈베리파이에서 HZ가 100이니 jiffies는 1초에 100번 증감합니다.

이번에는 jiffies란 값이 실제 1초 안에 얼마나 증감하는지 확인하겠습니다. 이를 위해 다음 패치를 적용할 필요가 있습니다.
diff --git a/kernel/time/timekeeping.c b/kernel/time/timekeeping.c
--- a/kernel/time/timekeeping.c
+++ b/kernel/time/timekeeping.c
@@ -2194,11 +2194,17 @@ struct timespec64 get_monotonic_coarse64(void)
 }
 EXPORT_SYMBOL(get_monotonic_coarse64);
 
/*
  * Must hold jiffies_lock
  */
 void do_timer(unsigned long ticks)
 {
+ trace_printk("[+]jiffies_64: %llu, caller:%pS \n", 
+ jiffies_64, (void *)__builtin_return_address(0)); 
+
  jiffies_64 += ticks;
  calc_global_load(ticks);
 }

위 코드에서 + 기호는 새롭게 추가하는 코드를 표현합니다. 그러니 do_timer() 함수 앞단에 코드 2줄을 입력하면 됩니다.

패치 코드는 trace_printk()이란 함수를 써서 do_timer() 함수가 호출될 때 ftrace 로그를 출력합니다. jiffies_64 변수를 출력하고 __builtin_return_address(0) 빌트인 매크로를 써서 자신을 호출한 함수 정보를 출력합니다.

위 코드를 컴파일해서 라즈베리파이에 설치 후 리부팅을 시켜봅시다. 기존에 했던 방식으로 ftrace 로그를 받아 봅시다. 

이제 ftrace 로그를 볼 시간입니다.
1 <idle>-0     [000] d...   228.989960: do_timer: [+]jiffies_64: 4294960195, caller:tick_do_update_jiffies64.part.0+0xa0/0x180 
2 <idle>-0     [000] d...   229.000074: do_timer: [+]jiffies_64: 4294960196, caller:tick_do_update_jiffies64.part.0+0xa0/0x180
...
3 ibus-x11-706   [003] d.h.   229.989991: do_timer: [+]jiffies_64: 4294960295, caller:tick_do_update_jiffies64.part.0+0xa0/0x180 
4 <idle>-0     [003] d.h.   230.000012: do_timer: [+]jiffies_64: 4294960296, caller:tick_do_update_jiffies64.part.0+0xa0/0x180 

사실 위 ftrace 로그는 104줄인데 초가 바뀌는 부분만 소개한 겁니다

2번 줄 로그를 보면 229.000074이라는 숫자가 보이죠? 228초에서 229초로 처음 바뀌는 첫 타임스탬프입니다. 이때 HZ단위의 jiffies는 4294960196입니다.

이번에는 4번 줄 로그를 봅시다. 230.000012 타임스탬프를 볼 수 있습니다. 229초에서 230초로 처음 바뀐 시각입니다. 오른쪽 로그를 보면 jiffies는 4294960296입니다. 정확히 100만큼 증가했음을 알 수 있습니다.

HZ가 100이면 1초 안에 jiffies가 100번 증감된다는 사실을 확인했습니다.

이번에 do_timer() 함수은 어떻게 호출하는지 알아봅시다.

do_timer() 함수에 필터를 걸고 ftrace 로그를 받아보면 콜스택이 다음과 같습니다.
<idle>-0     [000] d.h.   230.859933: irq_handler_entry: irq=17 name=arch_timer
<idle>-0     [001] d.h.   230.859933: irq_handler_entry: irq=17 name=arch_timer
<idle>-0     [000] d.h.   230.859943: do_timer <-tick_do_update_jiffies64.part.0
<idle>-0     [000] d.h.   230.859993: <stack trace>
 => tick_sched_timer
 => __hrtimer_run_queues
 => hrtimer_interrupt
 => arch_timer_handler_phys
 => handle_percpu_devid_irq
 => generic_handle_irq
 => __handle_domain_irq
 => bcm2836_arm_irqchip_handle_irq
 => __irq_svc
 => arch_cpu_idle
 => arch_cpu_idle
 => default_idle_call
 => do_idle
 => cpu_startup_entry
 => rest_init
 => start_kernel

17번 arch_timer란 인터럽트가 발생한 후 tick_sched_timer() -> tick_do_update_jiffies() 함수 순서로 호출됐음을 알 수 있습니다. tick_sched_timer() 함수는 1초당 HZ 개수만큼 jiffies를 증감하는 역할을 하는 틱 디바이스 함수입니다.  

이번에 jiffies가 1초에 얼만큼 증감하는지 알아봤습니다. 이론상으로 HZ가 100인데 실제 1초에 100번 증감하는 동작을 확인했습니다. 다음 절에서는 밀리초를 HZ(jiffies)단위로 변환하는 msecs_to_jiffies 함수에 대해 살펴보겠습니다.


BR,
Guillermo Austin Kim, 07/30/2018

핑백

덧글

댓글 입력 영역