diff options
author | Linus Torvalds <torvalds@linux-foundation.org> | 2009-12-11 23:49:09 -0500 |
---|---|---|
committer | Linus Torvalds <torvalds@linux-foundation.org> | 2009-12-11 23:49:09 -0500 |
commit | 3070f27d6ecb69364e7cffe16c8b15e1b8ef41dd (patch) | |
tree | 6a624eb764265b67b2765b978c749fbe08871886 | |
parent | 1e57c2186fc204ecd5e47f279d00eba3c3db245c (diff) | |
parent | e9c0748b687aa70179a9e6d8ffc24b2874fe350b (diff) |
Merge branch 'timers-fixes-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/linux-2.6-tip
* 'timers-fixes-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/linux-2.6-tip:
itimer: Fix the itimer trace print format
hrtimer: move timer stats helper functions to hrtimer.c
hrtimer: Tune hrtimer_interrupt hang logic
-rw-r--r-- | include/linux/hrtimer.h | 56 | ||||
-rw-r--r-- | include/trace/events/timer.h | 8 | ||||
-rw-r--r-- | kernel/hrtimer.c | 121 | ||||
-rw-r--r-- | kernel/time/timer_list.c | 5 |
4 files changed, 94 insertions, 96 deletions
diff --git a/include/linux/hrtimer.h b/include/linux/hrtimer.h index 9bace4b9f4fe..af634e95871d 100644 --- a/include/linux/hrtimer.h +++ b/include/linux/hrtimer.h | |||
@@ -162,10 +162,11 @@ struct hrtimer_clock_base { | |||
162 | * @expires_next: absolute time of the next event which was scheduled | 162 | * @expires_next: absolute time of the next event which was scheduled |
163 | * via clock_set_next_event() | 163 | * via clock_set_next_event() |
164 | * @hres_active: State of high resolution mode | 164 | * @hres_active: State of high resolution mode |
165 | * @check_clocks: Indictator, when set evaluate time source and clock | 165 | * @hang_detected: The last hrtimer interrupt detected a hang |
166 | * event devices whether high resolution mode can be | 166 | * @nr_events: Total number of hrtimer interrupt events |
167 | * activated. | 167 | * @nr_retries: Total number of hrtimer interrupt retries |
168 | * @nr_events: Total number of timer interrupt events | 168 | * @nr_hangs: Total number of hrtimer interrupt hangs |
169 | * @max_hang_time: Maximum time spent in hrtimer_interrupt | ||
169 | */ | 170 | */ |
170 | struct hrtimer_cpu_base { | 171 | struct hrtimer_cpu_base { |
171 | spinlock_t lock; | 172 | spinlock_t lock; |
@@ -173,7 +174,11 @@ struct hrtimer_cpu_base { | |||
173 | #ifdef CONFIG_HIGH_RES_TIMERS | 174 | #ifdef CONFIG_HIGH_RES_TIMERS |
174 | ktime_t expires_next; | 175 | ktime_t expires_next; |
175 | int hres_active; | 176 | int hres_active; |
177 | int hang_detected; | ||
176 | unsigned long nr_events; | 178 | unsigned long nr_events; |
179 | unsigned long nr_retries; | ||
180 | unsigned long nr_hangs; | ||
181 | ktime_t max_hang_time; | ||
177 | #endif | 182 | #endif |
178 | }; | 183 | }; |
179 | 184 | ||
@@ -435,47 +440,4 @@ extern u64 ktime_divns(const ktime_t kt, s64 div); | |||
435 | /* Show pending timers: */ | 440 | /* Show pending timers: */ |
436 | extern void sysrq_timer_list_show(void); | 441 | extern void sysrq_timer_list_show(void); |
437 | 442 | ||
438 | /* | ||
439 | * Timer-statistics info: | ||
440 | */ | ||
441 | #ifdef CONFIG_TIMER_STATS | ||
442 | |||
443 | extern void timer_stats_update_stats(void *timer, pid_t pid, void *startf, | ||
444 | void *timerf, char *comm, | ||
445 | unsigned int timer_flag); | ||
446 | |||
447 | static inline void timer_stats_account_hrtimer(struct hrtimer *timer) | ||
448 | { | ||
449 | if (likely(!timer_stats_active)) | ||
450 | return; | ||
451 | timer_stats_update_stats(timer, timer->start_pid, timer->start_site, | ||
452 | timer->function, timer->start_comm, 0); | ||
453 | } | ||
454 | |||
455 | extern void __timer_stats_hrtimer_set_start_info(struct hrtimer *timer, | ||
456 | void *addr); | ||
457 | |||
458 | static inline void timer_stats_hrtimer_set_start_info(struct hrtimer *timer) | ||
459 | { | ||
460 | __timer_stats_hrtimer_set_start_info(timer, __builtin_return_address(0)); | ||
461 | } | ||
462 | |||
463 | static inline void timer_stats_hrtimer_clear_start_info(struct hrtimer *timer) | ||
464 | { | ||
465 | timer->start_site = NULL; | ||
466 | } | ||
467 | #else | ||
468 | static inline void timer_stats_account_hrtimer(struct hrtimer *timer) | ||
469 | { | ||
470 | } | ||
471 | |||
472 | static inline void timer_stats_hrtimer_set_start_info(struct hrtimer *timer) | ||
473 | { | ||
474 | } | ||
475 | |||
476 | static inline void timer_stats_hrtimer_clear_start_info(struct hrtimer *timer) | ||
477 | { | ||
478 | } | ||
479 | #endif | ||
480 | |||
481 | #endif | 443 | #endif |
diff --git a/include/trace/events/timer.h b/include/trace/events/timer.h index e5ce87a0498d..9496b965d62a 100644 --- a/include/trace/events/timer.h +++ b/include/trace/events/timer.h | |||
@@ -301,8 +301,8 @@ TRACE_EVENT(itimer_state, | |||
301 | __entry->interval_usec = value->it_interval.tv_usec; | 301 | __entry->interval_usec = value->it_interval.tv_usec; |
302 | ), | 302 | ), |
303 | 303 | ||
304 | TP_printk("which=%d expires=%lu it_value=%lu.%lu it_interval=%lu.%lu", | 304 | TP_printk("which=%d expires=%llu it_value=%ld.%ld it_interval=%ld.%ld", |
305 | __entry->which, __entry->expires, | 305 | __entry->which, (unsigned long long)__entry->expires, |
306 | __entry->value_sec, __entry->value_usec, | 306 | __entry->value_sec, __entry->value_usec, |
307 | __entry->interval_sec, __entry->interval_usec) | 307 | __entry->interval_sec, __entry->interval_usec) |
308 | ); | 308 | ); |
@@ -331,8 +331,8 @@ TRACE_EVENT(itimer_expire, | |||
331 | __entry->pid = pid_nr(pid); | 331 | __entry->pid = pid_nr(pid); |
332 | ), | 332 | ), |
333 | 333 | ||
334 | TP_printk("which=%d pid=%d now=%lu", __entry->which, | 334 | TP_printk("which=%d pid=%d now=%llu", __entry->which, |
335 | (int) __entry->pid, __entry->now) | 335 | (int) __entry->pid, (unsigned long long)__entry->now) |
336 | ); | 336 | ); |
337 | 337 | ||
338 | #endif /* _TRACE_TIMER_H */ | 338 | #endif /* _TRACE_TIMER_H */ |
diff --git a/kernel/hrtimer.c b/kernel/hrtimer.c index ede527708123..d2f9239dc6ba 100644 --- a/kernel/hrtimer.c +++ b/kernel/hrtimer.c | |||
@@ -557,7 +557,7 @@ hrtimer_force_reprogram(struct hrtimer_cpu_base *cpu_base, int skip_equal) | |||
557 | static int hrtimer_reprogram(struct hrtimer *timer, | 557 | static int hrtimer_reprogram(struct hrtimer *timer, |
558 | struct hrtimer_clock_base *base) | 558 | struct hrtimer_clock_base *base) |
559 | { | 559 | { |
560 | ktime_t *expires_next = &__get_cpu_var(hrtimer_bases).expires_next; | 560 | struct hrtimer_cpu_base *cpu_base = &__get_cpu_var(hrtimer_bases); |
561 | ktime_t expires = ktime_sub(hrtimer_get_expires(timer), base->offset); | 561 | ktime_t expires = ktime_sub(hrtimer_get_expires(timer), base->offset); |
562 | int res; | 562 | int res; |
563 | 563 | ||
@@ -582,7 +582,16 @@ static int hrtimer_reprogram(struct hrtimer *timer, | |||
582 | if (expires.tv64 < 0) | 582 | if (expires.tv64 < 0) |
583 | return -ETIME; | 583 | return -ETIME; |
584 | 584 | ||
585 | if (expires.tv64 >= expires_next->tv64) | 585 | if (expires.tv64 >= cpu_base->expires_next.tv64) |
586 | return 0; | ||
587 | |||
588 | /* | ||
589 | * If a hang was detected in the last timer interrupt then we | ||
590 | * do not schedule a timer which is earlier than the expiry | ||
591 | * which we enforced in the hang detection. We want the system | ||
592 | * to make progress. | ||
593 | */ | ||
594 | if (cpu_base->hang_detected) | ||
586 | return 0; | 595 | return 0; |
587 | 596 | ||
588 | /* | 597 | /* |
@@ -590,7 +599,7 @@ static int hrtimer_reprogram(struct hrtimer *timer, | |||
590 | */ | 599 | */ |
591 | res = tick_program_event(expires, 0); | 600 | res = tick_program_event(expires, 0); |
592 | if (!IS_ERR_VALUE(res)) | 601 | if (!IS_ERR_VALUE(res)) |
593 | *expires_next = expires; | 602 | cpu_base->expires_next = expires; |
594 | return res; | 603 | return res; |
595 | } | 604 | } |
596 | 605 | ||
@@ -747,17 +756,33 @@ static inline void hrtimer_init_timer_hres(struct hrtimer *timer) { } | |||
747 | 756 | ||
748 | #endif /* CONFIG_HIGH_RES_TIMERS */ | 757 | #endif /* CONFIG_HIGH_RES_TIMERS */ |
749 | 758 | ||
750 | #ifdef CONFIG_TIMER_STATS | 759 | static inline void timer_stats_hrtimer_set_start_info(struct hrtimer *timer) |
751 | void __timer_stats_hrtimer_set_start_info(struct hrtimer *timer, void *addr) | ||
752 | { | 760 | { |
761 | #ifdef CONFIG_TIMER_STATS | ||
753 | if (timer->start_site) | 762 | if (timer->start_site) |
754 | return; | 763 | return; |
755 | 764 | timer->start_site = __builtin_return_address(0); | |
756 | timer->start_site = addr; | ||
757 | memcpy(timer->start_comm, current->comm, TASK_COMM_LEN); | 765 | memcpy(timer->start_comm, current->comm, TASK_COMM_LEN); |
758 | timer->start_pid = current->pid; | 766 | timer->start_pid = current->pid; |
767 | #endif | ||
759 | } | 768 | } |
769 | |||
770 | static inline void timer_stats_hrtimer_clear_start_info(struct hrtimer *timer) | ||
771 | { | ||
772 | #ifdef CONFIG_TIMER_STATS | ||
773 | timer->start_site = NULL; | ||
774 | #endif | ||
775 | } | ||
776 | |||
777 | static inline void timer_stats_account_hrtimer(struct hrtimer *timer) | ||
778 | { | ||
779 | #ifdef CONFIG_TIMER_STATS | ||
780 | if (likely(!timer_stats_active)) | ||
781 | return; | ||
782 | timer_stats_update_stats(timer, timer->start_pid, timer->start_site, | ||
783 | timer->function, timer->start_comm, 0); | ||
760 | #endif | 784 | #endif |
785 | } | ||
761 | 786 | ||
762 | /* | 787 | /* |
763 | * Counterpart to lock_hrtimer_base above: | 788 | * Counterpart to lock_hrtimer_base above: |
@@ -1217,30 +1242,6 @@ static void __run_hrtimer(struct hrtimer *timer, ktime_t *now) | |||
1217 | 1242 | ||
1218 | #ifdef CONFIG_HIGH_RES_TIMERS | 1243 | #ifdef CONFIG_HIGH_RES_TIMERS |
1219 | 1244 | ||
1220 | static int force_clock_reprogram; | ||
1221 | |||
1222 | /* | ||
1223 | * After 5 iteration's attempts, we consider that hrtimer_interrupt() | ||
1224 | * is hanging, which could happen with something that slows the interrupt | ||
1225 | * such as the tracing. Then we force the clock reprogramming for each future | ||
1226 | * hrtimer interrupts to avoid infinite loops and use the min_delta_ns | ||
1227 | * threshold that we will overwrite. | ||
1228 | * The next tick event will be scheduled to 3 times we currently spend on | ||
1229 | * hrtimer_interrupt(). This gives a good compromise, the cpus will spend | ||
1230 | * 1/4 of their time to process the hrtimer interrupts. This is enough to | ||
1231 | * let it running without serious starvation. | ||
1232 | */ | ||
1233 | |||
1234 | static inline void | ||
1235 | hrtimer_interrupt_hanging(struct clock_event_device *dev, | ||
1236 | ktime_t try_time) | ||
1237 | { | ||
1238 | force_clock_reprogram = 1; | ||
1239 | dev->min_delta_ns = (unsigned long)try_time.tv64 * 3; | ||
1240 | printk(KERN_WARNING "hrtimer: interrupt too slow, " | ||
1241 | "forcing clock min delta to %llu ns\n", | ||
1242 | (unsigned long long) dev->min_delta_ns); | ||
1243 | } | ||
1244 | /* | 1245 | /* |
1245 | * High resolution timer interrupt | 1246 | * High resolution timer interrupt |
1246 | * Called with interrupts disabled | 1247 | * Called with interrupts disabled |
@@ -1249,21 +1250,15 @@ void hrtimer_interrupt(struct clock_event_device *dev) | |||
1249 | { | 1250 | { |
1250 | struct hrtimer_cpu_base *cpu_base = &__get_cpu_var(hrtimer_bases); | 1251 | struct hrtimer_cpu_base *cpu_base = &__get_cpu_var(hrtimer_bases); |
1251 | struct hrtimer_clock_base *base; | 1252 | struct hrtimer_clock_base *base; |
1252 | ktime_t expires_next, now; | 1253 | ktime_t expires_next, now, entry_time, delta; |
1253 | int nr_retries = 0; | 1254 | int i, retries = 0; |
1254 | int i; | ||
1255 | 1255 | ||
1256 | BUG_ON(!cpu_base->hres_active); | 1256 | BUG_ON(!cpu_base->hres_active); |
1257 | cpu_base->nr_events++; | 1257 | cpu_base->nr_events++; |
1258 | dev->next_event.tv64 = KTIME_MAX; | 1258 | dev->next_event.tv64 = KTIME_MAX; |
1259 | 1259 | ||
1260 | retry: | 1260 | entry_time = now = ktime_get(); |
1261 | /* 5 retries is enough to notice a hang */ | 1261 | retry: |
1262 | if (!(++nr_retries % 5)) | ||
1263 | hrtimer_interrupt_hanging(dev, ktime_sub(ktime_get(), now)); | ||
1264 | |||
1265 | now = ktime_get(); | ||
1266 | |||
1267 | expires_next.tv64 = KTIME_MAX; | 1262 | expires_next.tv64 = KTIME_MAX; |
1268 | 1263 | ||
1269 | spin_lock(&cpu_base->lock); | 1264 | spin_lock(&cpu_base->lock); |
@@ -1325,10 +1320,48 @@ void hrtimer_interrupt(struct clock_event_device *dev) | |||
1325 | spin_unlock(&cpu_base->lock); | 1320 | spin_unlock(&cpu_base->lock); |
1326 | 1321 | ||
1327 | /* Reprogramming necessary ? */ | 1322 | /* Reprogramming necessary ? */ |
1328 | if (expires_next.tv64 != KTIME_MAX) { | 1323 | if (expires_next.tv64 == KTIME_MAX || |
1329 | if (tick_program_event(expires_next, force_clock_reprogram)) | 1324 | !tick_program_event(expires_next, 0)) { |
1330 | goto retry; | 1325 | cpu_base->hang_detected = 0; |
1326 | return; | ||
1331 | } | 1327 | } |
1328 | |||
1329 | /* | ||
1330 | * The next timer was already expired due to: | ||
1331 | * - tracing | ||
1332 | * - long lasting callbacks | ||
1333 | * - being scheduled away when running in a VM | ||
1334 | * | ||
1335 | * We need to prevent that we loop forever in the hrtimer | ||
1336 | * interrupt routine. We give it 3 attempts to avoid | ||
1337 | * overreacting on some spurious event. | ||
1338 | */ | ||
1339 | now = ktime_get(); | ||
1340 | cpu_base->nr_retries++; | ||
1341 | if (++retries < 3) | ||
1342 | goto retry; | ||
1343 | /* | ||
1344 | * Give the system a chance to do something else than looping | ||
1345 | * here. We stored the entry time, so we know exactly how long | ||
1346 | * we spent here. We schedule the next event this amount of | ||
1347 | * time away. | ||
1348 | */ | ||
1349 | cpu_base->nr_hangs++; | ||
1350 | cpu_base->hang_detected = 1; | ||
1351 | delta = ktime_sub(now, entry_time); | ||
1352 | if (delta.tv64 > cpu_base->max_hang_time.tv64) | ||
1353 | cpu_base->max_hang_time = delta; | ||
1354 | /* | ||
1355 | * Limit it to a sensible value as we enforce a longer | ||
1356 | * delay. Give the CPU at least 100ms to catch up. | ||
1357 | */ | ||
1358 | if (delta.tv64 > 100 * NSEC_PER_MSEC) | ||
1359 | expires_next = ktime_add_ns(now, 100 * NSEC_PER_MSEC); | ||
1360 | else | ||
1361 | expires_next = ktime_add(now, delta); | ||
1362 | tick_program_event(expires_next, 1); | ||
1363 | printk_once(KERN_WARNING "hrtimer: interrupt took %llu ns\n", | ||
1364 | ktime_to_ns(delta)); | ||
1332 | } | 1365 | } |
1333 | 1366 | ||
1334 | /* | 1367 | /* |
diff --git a/kernel/time/timer_list.c b/kernel/time/timer_list.c index 665c76edbf17..9d80db4747d4 100644 --- a/kernel/time/timer_list.c +++ b/kernel/time/timer_list.c | |||
@@ -150,6 +150,9 @@ static void print_cpu(struct seq_file *m, int cpu, u64 now) | |||
150 | P_ns(expires_next); | 150 | P_ns(expires_next); |
151 | P(hres_active); | 151 | P(hres_active); |
152 | P(nr_events); | 152 | P(nr_events); |
153 | P(nr_retries); | ||
154 | P(nr_hangs); | ||
155 | P_ns(max_hang_time); | ||
153 | #endif | 156 | #endif |
154 | #undef P | 157 | #undef P |
155 | #undef P_ns | 158 | #undef P_ns |
@@ -254,7 +257,7 @@ static int timer_list_show(struct seq_file *m, void *v) | |||
254 | u64 now = ktime_to_ns(ktime_get()); | 257 | u64 now = ktime_to_ns(ktime_get()); |
255 | int cpu; | 258 | int cpu; |
256 | 259 | ||
257 | SEQ_printf(m, "Timer List Version: v0.4\n"); | 260 | SEQ_printf(m, "Timer List Version: v0.5\n"); |
258 | SEQ_printf(m, "HRTIMER_MAX_CLOCK_BASES: %d\n", HRTIMER_MAX_CLOCK_BASES); | 261 | SEQ_printf(m, "HRTIMER_MAX_CLOCK_BASES: %d\n", HRTIMER_MAX_CLOCK_BASES); |
259 | SEQ_printf(m, "now at %Ld nsecs\n", (unsigned long long)now); | 262 | SEQ_printf(m, "now at %Ld nsecs\n", (unsigned long long)now); |
260 | 263 | ||