Whamcloud - gitweb
b=20722 Fix watchdog timer messages to be more clear.
[fs/lustre-release.git] / libcfs / libcfs / watchdog.c
1 /* -*- mode: c; c-basic-offset: 8; indent-tabs-mode: nil; -*-
2  * vim:expandtab:shiftwidth=8:tabstop=8:
3  *
4  * GPL HEADER START
5  *
6  * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
7  *
8  * This program is free software; you can redistribute it and/or modify
9  * it under the terms of the GNU General Public License version 2 only,
10  * as published by the Free Software Foundation.
11  *
12  * This program is distributed in the hope that it will be useful, but
13  * WITHOUT ANY WARRANTY; without even the implied warranty of
14  * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the GNU
15  * General Public License version 2 for more details (a copy is included
16  * in the LICENSE file that accompanied this code).
17  *
18  * You should have received a copy of the GNU General Public License
19  * version 2 along with this program; If not, see
20  * http://www.sun.com/software/products/lustre/docs/GPLv2.pdf
21  *
22  * Please contact Sun Microsystems, Inc., 4150 Network Circle, Santa Clara,
23  * CA 95054 USA or visit www.sun.com if you need additional information or
24  * have any questions.
25  *
26  * GPL HEADER END
27  */
28 /*
29  * Copyright  2008 Sun Microsystems, Inc. All rights reserved
30  * Use is subject to license terms.
31  */
32 /*
33  * This file is part of Lustre, http://www.lustre.org/
34  * Lustre is a trademark of Sun Microsystems, Inc.
35  *
36  * libcfs/libcfs/watchdog.c
37  *
38  * Author: Jacob Berkman <jacob@clusterfs.com>
39  */
40
41 #define DEBUG_SUBSYSTEM S_LNET
42
43 #include <libcfs/libcfs.h>
44 #include "tracefile.h"
45
46 struct lc_watchdog {
47         cfs_timer_t       lcw_timer; /* kernel timer */
48         struct list_head  lcw_list;
49         cfs_time_t        lcw_last_touched;
50         cfs_task_t       *lcw_task;
51
52         void            (*lcw_callback)(pid_t, void *);
53         void             *lcw_data;
54
55         pid_t             lcw_pid;
56
57         enum {
58                 LC_WATCHDOG_DISABLED,
59                 LC_WATCHDOG_ENABLED,
60                 LC_WATCHDOG_EXPIRED
61         } lcw_state;
62 };
63
64 #ifdef WITH_WATCHDOG
65 /*
66  * The dispatcher will complete lcw_start_completion when it starts,
67  * and lcw_stop_completion when it exits.
68  * Wake lcw_event_waitq to signal timer callback dispatches.
69  */
70 static struct completion lcw_start_completion;
71 static struct completion lcw_stop_completion;
72 static cfs_waitq_t lcw_event_waitq;
73
74 /*
75  * Set this and wake lcw_event_waitq to stop the dispatcher.
76  */
77 enum {
78         LCW_FLAG_STOP = 0
79 };
80 static unsigned long lcw_flags = 0;
81
82 /*
83  * Number of outstanding watchdogs.
84  * When it hits 1, we start the dispatcher.
85  * When it hits 0, we stop the distpatcher.
86  */
87 static __u32         lcw_refcount = 0;
88 static DECLARE_MUTEX(lcw_refcount_sem);
89
90 /*
91  * List of timers that have fired that need their callbacks run by the
92  * dispatcher.
93  */
94 static spinlock_t lcw_pending_timers_lock = SPIN_LOCK_UNLOCKED; /* BH lock! */
95 static struct list_head lcw_pending_timers = \
96         CFS_LIST_HEAD_INIT(lcw_pending_timers);
97
98 /* Last time a watchdog expired */
99 static cfs_time_t lcw_last_watchdog_time;
100 static int lcw_recent_watchdog_count;
101 static spinlock_t lcw_last_watchdog_lock = SPIN_LOCK_UNLOCKED;
102
103 static void
104 lcw_dump(struct lc_watchdog *lcw)
105 {
106         ENTRY;
107 #if defined(HAVE_TASKLIST_LOCK)
108         read_lock(&tasklist_lock);
109 #elif defined(HAVE_TASK_RCU)
110         rcu_read_lock();
111 #else
112         CERROR("unable to dump stack because of missing export\n"); 
113         RETURN_EXIT;
114 #endif
115        if (lcw->lcw_task == NULL) { 
116                 LCONSOLE_WARN("Process " LPPID " was not found in the task "
117                               "list; watchdog callback may be incomplete\n",
118                               (int)lcw->lcw_pid);
119         } else {
120                 libcfs_debug_dumpstack(lcw->lcw_task);
121         }
122
123 #if defined(HAVE_TASKLIST_LOCK)
124         read_unlock(&tasklist_lock);
125 #elif defined(HAVE_TASK_RCU)
126         rcu_read_unlock();
127 #endif
128         EXIT;
129 }
130
131 static void lcw_cb(ulong_ptr_t data)
132 {
133         struct lc_watchdog *lcw = (struct lc_watchdog *)data;
134         cfs_time_t current_time;
135         cfs_duration_t delta_time;
136         struct timeval timediff;
137
138         ENTRY;
139
140         if (lcw->lcw_state != LC_WATCHDOG_ENABLED) {
141                 EXIT;
142                 return;
143         }
144
145         lcw->lcw_state = LC_WATCHDOG_EXPIRED;
146         current_time = cfs_time_current();
147
148         delta_time = cfs_time_sub(current_time, lcw->lcw_last_touched);
149         cfs_duration_usec(delta_time, &timediff);
150
151         /* Check to see if we should throttle the watchdog timer to avoid
152          * too many dumps going to the console thus triggering an NMI.
153          * Normally we would not hold the spin lock over the CWARN but in
154          * this case we hold it to ensure non ratelimited lcw_dumps are not
155          * interleaved on the console making them hard to read. */
156         spin_lock_bh(&lcw_last_watchdog_lock);
157         delta_time = cfs_duration_sec(cfs_time_sub(current_time,
158                                                    lcw_last_watchdog_time));
159
160         if (delta_time < libcfs_watchdog_ratelimit &&
161             lcw_recent_watchdog_count > 3) {
162                 LCONSOLE_WARN("Service thread pid %u was inactive for "
163                               "%lu.%.02lus. Watchdog stack traces are limited "
164                               "to 3 per %d seconds, skipping this one.\n",
165                               (int)lcw->lcw_pid,
166                               timediff.tv_sec,
167                               timediff.tv_usec / 10000,
168                               libcfs_watchdog_ratelimit);
169         } else {
170                 if (delta_time < libcfs_watchdog_ratelimit) {
171                         lcw_recent_watchdog_count++;
172                 } else {
173                         memcpy(&lcw_last_watchdog_time, &current_time,
174                                sizeof(current_time));
175                         lcw_recent_watchdog_count = 0;
176                 }
177
178                 /* This warning should appear on the console, but may not get
179                  * into the logs since we're running in a softirq handler */
180                 LCONSOLE_WARN("Service thread pid %u was inactive for "
181                               "%lu.%.02lus. The thread might be hung, or it "
182                               "might only be slow and will resume later. "
183                               "Dumping the stack trace for debugging purposes:"
184                               "\n",
185                               (int)lcw->lcw_pid,
186                               timediff.tv_sec,
187                               timediff.tv_usec / 10000);
188                 lcw_dump(lcw);
189         }
190
191         spin_unlock_bh(&lcw_last_watchdog_lock);
192         spin_lock_bh(&lcw_pending_timers_lock);
193
194         if (list_empty(&lcw->lcw_list)) {
195                 list_add(&lcw->lcw_list, &lcw_pending_timers);
196                 cfs_waitq_signal(&lcw_event_waitq);
197         }
198
199         spin_unlock_bh(&lcw_pending_timers_lock);
200
201         EXIT;
202 }
203
204 static int is_watchdog_fired(void)
205 {
206         int rc;
207
208         if (test_bit(LCW_FLAG_STOP, &lcw_flags))
209                 return 1;
210
211         spin_lock_bh(&lcw_pending_timers_lock);
212         rc = !list_empty(&lcw_pending_timers);
213         spin_unlock_bh(&lcw_pending_timers_lock);
214         return rc;
215 }
216
217 static int lcw_dispatch_main(void *data)
218 {
219         int                 rc = 0;
220         unsigned long       flags;
221         struct lc_watchdog *lcw;
222
223         ENTRY;
224
225         cfs_daemonize("lc_watchdogd");
226
227         SIGNAL_MASK_LOCK(current, flags);
228         sigfillset(&current->blocked);
229         RECALC_SIGPENDING;
230         SIGNAL_MASK_UNLOCK(current, flags);
231
232         complete(&lcw_start_completion);
233
234         while (1) {
235                 cfs_wait_event_interruptible(lcw_event_waitq, is_watchdog_fired(), rc);
236                 CDEBUG(D_INFO, "Watchdog got woken up...\n");
237                 if (test_bit(LCW_FLAG_STOP, &lcw_flags)) {
238                         CDEBUG(D_INFO, "LCW_FLAG_STOP was set, shutting down...\n");
239
240                         spin_lock_bh(&lcw_pending_timers_lock);
241                         rc = !list_empty(&lcw_pending_timers);
242                         spin_unlock_bh(&lcw_pending_timers_lock);
243                         if (rc) {
244                                 CERROR("pending timers list was not empty at "
245                                        "time of watchdog dispatch shutdown\n");
246                         }
247                         break;
248                 }
249
250                 spin_lock_bh(&lcw_pending_timers_lock);
251                 while (!list_empty(&lcw_pending_timers)) {
252
253                         lcw = list_entry(lcw_pending_timers.next,
254                                          struct lc_watchdog,
255                                          lcw_list);
256                         list_del_init(&lcw->lcw_list);
257                         spin_unlock_bh(&lcw_pending_timers_lock);
258
259                         CDEBUG(D_INFO, "found lcw for pid " LPPID "\n", lcw->lcw_pid);
260
261                         if (lcw->lcw_state != LC_WATCHDOG_DISABLED)
262                                 lcw->lcw_callback(lcw->lcw_pid, lcw->lcw_data);
263
264                         spin_lock_bh(&lcw_pending_timers_lock);
265                 }
266                 spin_unlock_bh(&lcw_pending_timers_lock);
267         }
268
269         complete(&lcw_stop_completion);
270
271         RETURN(rc);
272 }
273
274 static void lcw_dispatch_start(void)
275 {
276         int rc;
277
278         ENTRY;
279         LASSERT(lcw_refcount == 1);
280
281         init_completion(&lcw_stop_completion);
282         init_completion(&lcw_start_completion);
283         cfs_waitq_init(&lcw_event_waitq);
284
285         CDEBUG(D_INFO, "starting dispatch thread\n");
286         rc = kernel_thread(lcw_dispatch_main, NULL, 0);
287         if (rc < 0) {
288                 CERROR("error spawning watchdog dispatch thread: %d\n", rc);
289                 EXIT;
290                 return;
291         }
292         wait_for_completion(&lcw_start_completion);
293         CDEBUG(D_INFO, "watchdog dispatcher initialization complete.\n");
294
295         EXIT;
296 }
297
298 static void lcw_dispatch_stop(void)
299 {
300         ENTRY;
301         LASSERT(lcw_refcount == 0);
302
303         CDEBUG(D_INFO, "trying to stop watchdog dispatcher.\n");
304
305         set_bit(LCW_FLAG_STOP, &lcw_flags);
306         cfs_waitq_signal(&lcw_event_waitq);
307
308         wait_for_completion(&lcw_stop_completion);
309
310         CDEBUG(D_INFO, "watchdog dispatcher has shut down.\n");
311
312         EXIT;
313 }
314
315 struct lc_watchdog *lc_watchdog_add(int timeout,
316                                     void (*callback)(pid_t, void *),
317                                     void *data)
318 {
319         struct lc_watchdog *lcw = NULL;
320         ENTRY;
321
322         LIBCFS_ALLOC(lcw, sizeof(*lcw));
323         if (lcw == NULL) {
324                 CDEBUG(D_INFO, "Could not allocate new lc_watchdog\n");
325                 RETURN(ERR_PTR(-ENOMEM));
326         }
327
328         lcw->lcw_task     = cfs_current();
329         lcw->lcw_pid      = cfs_curproc_pid();
330         lcw->lcw_callback = (callback != NULL) ? callback : lc_watchdog_dumplog;
331         lcw->lcw_data     = data;
332         lcw->lcw_state    = LC_WATCHDOG_DISABLED;
333
334         CFS_INIT_LIST_HEAD(&lcw->lcw_list);
335         cfs_timer_init(&lcw->lcw_timer, lcw_cb, lcw);
336
337         down(&lcw_refcount_sem);
338         if (++lcw_refcount == 1)
339                 lcw_dispatch_start();
340         up(&lcw_refcount_sem);
341
342         /* Keep this working in case we enable them by default */
343         if (lcw->lcw_state == LC_WATCHDOG_ENABLED) {
344                 lcw->lcw_last_touched = cfs_time_current();
345                 cfs_timer_arm(&lcw->lcw_timer, cfs_time_seconds(timeout) +
346                               cfs_time_current());
347         }
348
349         RETURN(lcw);
350 }
351 EXPORT_SYMBOL(lc_watchdog_add);
352
353 static void lcw_update_time(struct lc_watchdog *lcw, const char *message)
354 {
355         cfs_time_t newtime = cfs_time_current();;
356
357         if (lcw->lcw_state == LC_WATCHDOG_EXPIRED) {
358                 struct timeval timediff;
359                 cfs_time_t delta_time = cfs_time_sub(newtime,
360                                                      lcw->lcw_last_touched);
361                 cfs_duration_usec(delta_time, &timediff);
362
363                 LCONSOLE_WARN("Service thread pid %u %s after %lu.%.02lus. "
364                               "This indicates the system was overloaded (too "
365                               "many service threads, or there were not enough "
366                               "hardware resources).\n",
367                               lcw->lcw_pid,
368                               message,
369                               timediff.tv_sec,
370                               timediff.tv_usec / 10000);
371         }
372         lcw->lcw_last_touched = newtime;
373 }
374
375 void lc_watchdog_touch(struct lc_watchdog *lcw, int timeout)
376 {
377         ENTRY;
378         LASSERT(lcw != NULL);
379
380         spin_lock_bh(&lcw_pending_timers_lock);
381         list_del_init(&lcw->lcw_list);
382         spin_unlock_bh(&lcw_pending_timers_lock);
383
384         lcw_update_time(lcw, "resumed");
385         lcw->lcw_state = LC_WATCHDOG_ENABLED;
386
387         cfs_timer_arm(&lcw->lcw_timer, cfs_time_current() +
388                       cfs_time_seconds(timeout));
389
390         EXIT;
391 }
392 EXPORT_SYMBOL(lc_watchdog_touch);
393
394 void lc_watchdog_disable(struct lc_watchdog *lcw)
395 {
396         ENTRY;
397         LASSERT(lcw != NULL);
398
399         spin_lock_bh(&lcw_pending_timers_lock);
400         if (!list_empty(&lcw->lcw_list))
401                 list_del_init(&lcw->lcw_list);
402         spin_unlock_bh(&lcw_pending_timers_lock);
403
404         lcw_update_time(lcw, "completed");
405         lcw->lcw_state = LC_WATCHDOG_DISABLED;
406
407         EXIT;
408 }
409 EXPORT_SYMBOL(lc_watchdog_disable);
410
411 void lc_watchdog_delete(struct lc_watchdog *lcw)
412 {
413         ENTRY;
414         LASSERT(lcw != NULL);
415
416         cfs_timer_disarm(&lcw->lcw_timer);
417
418         lcw_update_time(lcw, "stopped");
419
420         spin_lock_bh(&lcw_pending_timers_lock);
421         if (!list_empty(&lcw->lcw_list))
422                 list_del_init(&lcw->lcw_list);
423         spin_unlock_bh(&lcw_pending_timers_lock);
424
425         down(&lcw_refcount_sem);
426         if (--lcw_refcount == 0)
427                 lcw_dispatch_stop();
428         up(&lcw_refcount_sem);
429
430         LIBCFS_FREE(lcw, sizeof(*lcw));
431
432         EXIT;
433 }
434 EXPORT_SYMBOL(lc_watchdog_delete);
435
436 /*
437  * Provided watchdog handlers
438  */
439
440 void lc_watchdog_dumplog(pid_t pid, void *data)
441 {
442         libcfs_debug_dumplog_internal((void *)((long_ptr_t)pid));
443 }
444 EXPORT_SYMBOL(lc_watchdog_dumplog);
445
446 #else   /* !defined(WITH_WATCHDOG) */
447
448 struct lc_watchdog *lc_watchdog_add(int timeout,
449                                     void (*callback)(pid_t pid, void *),
450                                     void *data)
451 {
452         static struct lc_watchdog      watchdog;
453         return &watchdog;
454 }
455 EXPORT_SYMBOL(lc_watchdog_add);
456
457 void lc_watchdog_touch(struct lc_watchdog *lcw, int timeout)
458 {
459 }
460 EXPORT_SYMBOL(lc_watchdog_touch);
461
462 void lc_watchdog_disable(struct lc_watchdog *lcw)
463 {
464 }
465 EXPORT_SYMBOL(lc_watchdog_disable);
466
467 void lc_watchdog_delete(struct lc_watchdog *lcw)
468 {
469 }
470 EXPORT_SYMBOL(lc_watchdog_delete);
471
472 #endif