libcfs/libcfs/watchdog.c

   1 /*
   2  * GPL HEADER START
   3  *
   4  * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
   5  *
   6  * This program is free software; you can redistribute it and/or modify
   7  * it under the terms of the GNU General Public License version 2 only,
   8  * as published by the Free Software Foundation.
   9  *
  10  * This program is distributed in the hope that it will be useful, but
  11  * WITHOUT ANY WARRANTY; without even the implied warranty of
  12  * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the GNU
  13  * General Public License version 2 for more details (a copy is included
  14  * in the LICENSE file that accompanied this code).
  15  *
  16  * You should have received a copy of the GNU General Public License
  17  * version 2 along with this program; If not, see
  18  * http://www.sun.com/software/products/lustre/docs/GPLv2.pdf
  19  *
  20  * Please contact Sun Microsystems, Inc., 4150 Network Circle, Santa Clara,
  21  * CA 95054 USA or visit www.sun.com if you need additional information or
  22  * have any questions.
  23  *
  24  * GPL HEADER END
  25  */
  26 /*
  27  * Copyright (c) 2008, 2010, Oracle and/or its affiliates. All rights reserved.
  28  * Use is subject to license terms.
  29  *
  30  * Copyright (c) 2012, Intel Corporation.
  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         spinlock_t  lcw_lock;     /* check or change lcw_list */
  48         int             lcw_refcount; /* must hold lcw_pending_timers_lock */
  49         cfs_timer_t     lcw_timer;    /* kernel timer */
  50         cfs_list_t      lcw_list;     /* chain on pending list */
  51         cfs_time_t      lcw_last_touched; /* last touched stamp */
  52         cfs_task_t     *lcw_task;     /* owner task */
  53         void          (*lcw_callback)(pid_t, void *);
  54         void           *lcw_data;
  55
  56         pid_t           lcw_pid;
  57
  58         enum {
  59                 LC_WATCHDOG_DISABLED,
  60                 LC_WATCHDOG_ENABLED,
  61                 LC_WATCHDOG_EXPIRED
  62         } lcw_state;
  63 };
  64
  65 #ifdef WITH_WATCHDOG
  66 /*
  67  * The dispatcher will complete lcw_start_completion when it starts,
  68  * and lcw_stop_completion when it exits.
  69  * Wake lcw_event_waitq to signal timer callback dispatches.
  70  */
  71 static struct completion lcw_start_completion;
  72 static struct completion  lcw_stop_completion;
  73 static cfs_waitq_t lcw_event_waitq;
  74
  75 /*
  76  * Set this and wake lcw_event_waitq to stop the dispatcher.
  77  */
  78 enum {
  79         LCW_FLAG_STOP = 0
  80 };
  81 static unsigned long lcw_flags = 0;
  82
  83 /*
  84  * Number of outstanding watchdogs.
  85  * When it hits 1, we start the dispatcher.
  86  * When it hits 0, we stop the dispatcher.
  87  */
  88 static __u32         lcw_refcount = 0;
  89 static DEFINE_MUTEX(lcw_refcount_mutex);
  90
  91 /*
  92  * List of timers that have fired that need their callbacks run by the
  93  * dispatcher.
  94  */
  95 /* BH lock! */
  96 static DEFINE_SPINLOCK(lcw_pending_timers_lock);
  97 static cfs_list_t lcw_pending_timers = CFS_LIST_HEAD_INIT(lcw_pending_timers);
  98
  99 /* Last time a watchdog expired */
 100 static cfs_time_t lcw_last_watchdog_time;
 101 static int lcw_recent_watchdog_count;
 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 #else
 110         rcu_read_lock();
 111 #endif
 112        if (lcw->lcw_task == NULL) {
 113                 LCONSOLE_WARN("Process " LPPID " was not found in the task "
 114                               "list; watchdog callback may be incomplete\n",
 115                               (int)lcw->lcw_pid);
 116         } else {
 117                 libcfs_debug_dumpstack(lcw->lcw_task);
 118         }
 119
 120 #if defined(HAVE_TASKLIST_LOCK)
 121         read_unlock(&tasklist_lock);
 122 #else
 123         rcu_read_unlock();
 124 #endif
 125         EXIT;
 126 }
 127
 128 static void lcw_cb(ulong_ptr_t data)
 129 {
 130         struct lc_watchdog *lcw = (struct lc_watchdog *)data;
 131         ENTRY;
 132
 133         if (lcw->lcw_state != LC_WATCHDOG_ENABLED) {
 134                 EXIT;
 135                 return;
 136         }
 137
 138         lcw->lcw_state = LC_WATCHDOG_EXPIRED;
 139
 140         spin_lock_bh(&lcw->lcw_lock);
 141         LASSERT(cfs_list_empty(&lcw->lcw_list));
 142
 143         spin_lock_bh(&lcw_pending_timers_lock);
 144         lcw->lcw_refcount++; /* +1 for pending list */
 145         cfs_list_add(&lcw->lcw_list, &lcw_pending_timers);
 146         cfs_waitq_signal(&lcw_event_waitq);
 147
 148         spin_unlock_bh(&lcw_pending_timers_lock);
 149         spin_unlock_bh(&lcw->lcw_lock);
 150         EXIT;
 151 }
 152
 153 static int is_watchdog_fired(void)
 154 {
 155         int rc;
 156
 157         if (test_bit(LCW_FLAG_STOP, &lcw_flags))
 158                 return 1;
 159
 160         spin_lock_bh(&lcw_pending_timers_lock);
 161         rc = !cfs_list_empty(&lcw_pending_timers);
 162         spin_unlock_bh(&lcw_pending_timers_lock);
 163         return rc;
 164 }
 165
 166 static void lcw_dump_stack(struct lc_watchdog *lcw)
 167 {
 168         cfs_time_t      current_time;
 169         cfs_duration_t  delta_time;
 170         struct timeval  timediff;
 171
 172         current_time = cfs_time_current();
 173         delta_time = cfs_time_sub(current_time, lcw->lcw_last_touched);
 174         cfs_duration_usec(delta_time, &timediff);
 175
 176         /*
 177          * Check to see if we should throttle the watchdog timer to avoid
 178          * too many dumps going to the console thus triggering an NMI.
 179          */
 180         delta_time = cfs_duration_sec(cfs_time_sub(current_time,
 181                                                    lcw_last_watchdog_time));
 182
 183         if (delta_time < libcfs_watchdog_ratelimit &&
 184             lcw_recent_watchdog_count > 3) {
 185                 LCONSOLE_WARN("Service thread pid %u was inactive for "
 186                               "%lu.%.02lus. Watchdog stack traces are limited "
 187                               "to 3 per %d seconds, skipping this one.\n",
 188                               (int)lcw->lcw_pid,
 189                               timediff.tv_sec,
 190                               timediff.tv_usec / 10000,
 191                               libcfs_watchdog_ratelimit);
 192         } else {
 193                 if (delta_time < libcfs_watchdog_ratelimit) {
 194                         lcw_recent_watchdog_count++;
 195                 } else {
 196                         memcpy(&lcw_last_watchdog_time, &current_time,
 197                                sizeof(current_time));
 198                         lcw_recent_watchdog_count = 0;
 199                 }
 200
 201                 LCONSOLE_WARN("Service thread pid %u was inactive for "
 202                               "%lu.%.02lus. The thread might be hung, or it "
 203                               "might only be slow and will resume later. "
 204                               "Dumping the stack trace for debugging purposes:"
 205                               "\n",
 206                               (int)lcw->lcw_pid,
 207                               timediff.tv_sec,
 208                               timediff.tv_usec / 10000);
 209                 lcw_dump(lcw);
 210         }
 211 }
 212
 213 static int lcw_dispatch_main(void *data)
 214 {
 215         int                 rc = 0;
 216         unsigned long       flags;
 217         struct lc_watchdog *lcw;
 218         CFS_LIST_HEAD      (zombies);
 219
 220         ENTRY;
 221
 222         cfs_daemonize("lc_watchdogd");
 223
 224         SIGNAL_MASK_LOCK(current, flags);
 225         sigfillset(&current->blocked);
 226         RECALC_SIGPENDING;
 227         SIGNAL_MASK_UNLOCK(current, flags);
 228
 229         complete(&lcw_start_completion);
 230
 231         while (1) {
 232                 int dumplog = 1;
 233
 234                 cfs_wait_event_interruptible(lcw_event_waitq,
 235                                              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 set, shutting down...\n");
 239
 240                         spin_lock_bh(&lcw_pending_timers_lock);
 241                         rc = !cfs_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 (!cfs_list_empty(&lcw_pending_timers)) {
 252                         int is_dumplog;
 253
 254                         lcw = cfs_list_entry(lcw_pending_timers.next,
 255                                              struct lc_watchdog, lcw_list);
 256                         /* +1 ref for callback to make sure lwc wouldn't be
 257                          * deleted after releasing lcw_pending_timers_lock */
 258                         lcw->lcw_refcount++;
 259                         spin_unlock_bh(&lcw_pending_timers_lock);
 260
 261                         /* lock ordering */
 262                         spin_lock_bh(&lcw->lcw_lock);
 263                         spin_lock_bh(&lcw_pending_timers_lock);
 264
 265                         if (cfs_list_empty(&lcw->lcw_list)) {
 266                                 /* already removed from pending list */
 267                                 lcw->lcw_refcount--; /* -1 ref for callback */
 268                                 if (lcw->lcw_refcount == 0)
 269                                         cfs_list_add(&lcw->lcw_list, &zombies);
 270                                 spin_unlock_bh(&lcw->lcw_lock);
 271                                 /* still hold lcw_pending_timers_lock */
 272                                 continue;
 273                         }
 274
 275                         cfs_list_del_init(&lcw->lcw_list);
 276                         lcw->lcw_refcount--; /* -1 ref for pending list */
 277
 278                         spin_unlock_bh(&lcw_pending_timers_lock);
 279                         spin_unlock_bh(&lcw->lcw_lock);
 280
 281                         CDEBUG(D_INFO, "found lcw for pid " LPPID "\n",
 282                                lcw->lcw_pid);
 283                         lcw_dump_stack(lcw);
 284
 285                         is_dumplog = lcw->lcw_callback == lc_watchdog_dumplog;
 286                         if (lcw->lcw_state != LC_WATCHDOG_DISABLED &&
 287                             (dumplog || !is_dumplog)) {
 288                                 lcw->lcw_callback(lcw->lcw_pid, lcw->lcw_data);
 289                                 if (dumplog && is_dumplog)
 290                                         dumplog = 0;
 291                         }
 292
 293                         spin_lock_bh(&lcw_pending_timers_lock);
 294                         lcw->lcw_refcount--; /* -1 ref for callback */
 295                         if (lcw->lcw_refcount == 0)
 296                                 cfs_list_add(&lcw->lcw_list, &zombies);
 297                 }
 298                 spin_unlock_bh(&lcw_pending_timers_lock);
 299
 300                 while (!cfs_list_empty(&zombies)) {
 301                         lcw = cfs_list_entry(lcw_pending_timers.next,
 302                                          struct lc_watchdog, lcw_list);
 303                         cfs_list_del(&lcw->lcw_list);
 304                         LIBCFS_FREE(lcw, sizeof(*lcw));
 305                 }
 306         }
 307
 308         complete(&lcw_stop_completion);
 309
 310         RETURN(rc);
 311 }
 312
 313 static void lcw_dispatch_start(void)
 314 {
 315         int rc;
 316
 317         ENTRY;
 318         LASSERT(lcw_refcount == 1);
 319
 320         init_completion(&lcw_stop_completion);
 321         init_completion(&lcw_start_completion);
 322         cfs_waitq_init(&lcw_event_waitq);
 323
 324         CDEBUG(D_INFO, "starting dispatch thread\n");
 325         rc = cfs_create_thread(lcw_dispatch_main, NULL, 0);
 326         if (rc < 0) {
 327                 CERROR("error spawning watchdog dispatch thread: %d\n", rc);
 328                 EXIT;
 329                 return;
 330         }
 331         wait_for_completion(&lcw_start_completion);
 332         CDEBUG(D_INFO, "watchdog dispatcher initialization complete.\n");
 333
 334         EXIT;
 335 }
 336
 337 static void lcw_dispatch_stop(void)
 338 {
 339         ENTRY;
 340         LASSERT(lcw_refcount == 0);
 341
 342         CDEBUG(D_INFO, "trying to stop watchdog dispatcher.\n");
 343
 344         set_bit(LCW_FLAG_STOP, &lcw_flags);
 345         cfs_waitq_signal(&lcw_event_waitq);
 346
 347         wait_for_completion(&lcw_stop_completion);
 348
 349         CDEBUG(D_INFO, "watchdog dispatcher has shut down.\n");
 350
 351         EXIT;
 352 }
 353
 354 struct lc_watchdog *lc_watchdog_add(int timeout,
 355                                     void (*callback)(pid_t, void *),
 356                                     void *data)
 357 {
 358         struct lc_watchdog *lcw = NULL;
 359         ENTRY;
 360
 361         LIBCFS_ALLOC(lcw, sizeof(*lcw));
 362         if (lcw == NULL) {
 363                 CDEBUG(D_INFO, "Could not allocate new lc_watchdog\n");
 364                 RETURN(ERR_PTR(-ENOMEM));
 365         }
 366
 367         spin_lock_init(&lcw->lcw_lock);
 368         lcw->lcw_refcount = 1; /* refcount for owner */
 369         lcw->lcw_task     = cfs_current();
 370         lcw->lcw_pid      = cfs_curproc_pid();
 371         lcw->lcw_callback = (callback != NULL) ? callback : lc_watchdog_dumplog;
 372         lcw->lcw_data     = data;
 373         lcw->lcw_state    = LC_WATCHDOG_DISABLED;
 374
 375         CFS_INIT_LIST_HEAD(&lcw->lcw_list);
 376         cfs_timer_init(&lcw->lcw_timer, lcw_cb, lcw);
 377
 378         mutex_lock(&lcw_refcount_mutex);
 379         if (++lcw_refcount == 1)
 380                 lcw_dispatch_start();
 381         mutex_unlock(&lcw_refcount_mutex);
 382
 383         /* Keep this working in case we enable them by default */
 384         if (lcw->lcw_state == LC_WATCHDOG_ENABLED) {
 385                 lcw->lcw_last_touched = cfs_time_current();
 386                 cfs_timer_arm(&lcw->lcw_timer, cfs_time_seconds(timeout) +
 387                               cfs_time_current());
 388         }
 389
 390         RETURN(lcw);
 391 }
 392 EXPORT_SYMBOL(lc_watchdog_add);
 393
 394 static void lcw_update_time(struct lc_watchdog *lcw, const char *message)
 395 {
 396         cfs_time_t newtime = cfs_time_current();;
 397
 398         if (lcw->lcw_state == LC_WATCHDOG_EXPIRED) {
 399                 struct timeval timediff;
 400                 cfs_time_t delta_time = cfs_time_sub(newtime,
 401                                                      lcw->lcw_last_touched);
 402                 cfs_duration_usec(delta_time, &timediff);
 403
 404                 LCONSOLE_WARN("Service thread pid %u %s after %lu.%.02lus. "
 405                               "This indicates the system was overloaded (too "
 406                               "many service threads, or there were not enough "
 407                               "hardware resources).\n",
 408                               lcw->lcw_pid,
 409                               message,
 410                               timediff.tv_sec,
 411                               timediff.tv_usec / 10000);
 412         }
 413         lcw->lcw_last_touched = newtime;
 414 }
 415
 416 static void lc_watchdog_del_pending(struct lc_watchdog *lcw)
 417 {
 418         spin_lock_bh(&lcw->lcw_lock);
 419         if (unlikely(!cfs_list_empty(&lcw->lcw_list))) {
 420                 spin_lock_bh(&lcw_pending_timers_lock);
 421                 cfs_list_del_init(&lcw->lcw_list);
 422                 lcw->lcw_refcount--; /* -1 ref for pending list */
 423                 spin_unlock_bh(&lcw_pending_timers_lock);
 424         }
 425
 426         spin_unlock_bh(&lcw->lcw_lock);
 427 }
 428
 429 void lc_watchdog_touch(struct lc_watchdog *lcw, int timeout)
 430 {
 431         ENTRY;
 432         LASSERT(lcw != NULL);
 433
 434         lc_watchdog_del_pending(lcw);
 435
 436         lcw_update_time(lcw, "resumed");
 437         lcw->lcw_state = LC_WATCHDOG_ENABLED;
 438
 439         cfs_timer_arm(&lcw->lcw_timer, cfs_time_current() +
 440                       cfs_time_seconds(timeout));
 441
 442         EXIT;
 443 }
 444 EXPORT_SYMBOL(lc_watchdog_touch);
 445
 446 void lc_watchdog_disable(struct lc_watchdog *lcw)
 447 {
 448         ENTRY;
 449         LASSERT(lcw != NULL);
 450
 451         lc_watchdog_del_pending(lcw);
 452
 453         lcw_update_time(lcw, "completed");
 454         lcw->lcw_state = LC_WATCHDOG_DISABLED;
 455
 456         EXIT;
 457 }
 458 EXPORT_SYMBOL(lc_watchdog_disable);
 459
 460 void lc_watchdog_delete(struct lc_watchdog *lcw)
 461 {
 462         int dead;
 463
 464         ENTRY;
 465         LASSERT(lcw != NULL);
 466
 467         cfs_timer_disarm(&lcw->lcw_timer);
 468
 469         lcw_update_time(lcw, "stopped");
 470
 471         spin_lock_bh(&lcw->lcw_lock);
 472         spin_lock_bh(&lcw_pending_timers_lock);
 473         if (unlikely(!cfs_list_empty(&lcw->lcw_list))) {
 474                 cfs_list_del_init(&lcw->lcw_list);
 475                 lcw->lcw_refcount--; /* -1 ref for pending list */
 476         }
 477
 478         lcw->lcw_refcount--; /* -1 ref for owner */
 479         dead = lcw->lcw_refcount == 0;
 480         spin_unlock_bh(&lcw_pending_timers_lock);
 481         spin_unlock_bh(&lcw->lcw_lock);
 482
 483         if (dead)
 484                 LIBCFS_FREE(lcw, sizeof(*lcw));
 485
 486         mutex_lock(&lcw_refcount_mutex);
 487         if (--lcw_refcount == 0)
 488                 lcw_dispatch_stop();
 489         mutex_unlock(&lcw_refcount_mutex);
 490
 491         EXIT;
 492 }
 493 EXPORT_SYMBOL(lc_watchdog_delete);
 494
 495 /*
 496  * Provided watchdog handlers
 497  */
 498
 499 void lc_watchdog_dumplog(pid_t pid, void *data)
 500 {
 501         libcfs_debug_dumplog_internal((void *)((long_ptr_t)pid));
 502 }
 503 EXPORT_SYMBOL(lc_watchdog_dumplog);
 504
 505 #else   /* !defined(WITH_WATCHDOG) */
 506
 507 struct lc_watchdog *lc_watchdog_add(int timeout,
 508                                     void (*callback)(pid_t pid, void *),
 509                                     void *data)
 510 {
 511         static struct lc_watchdog      watchdog;
 512         return &watchdog;
 513 }
 514 EXPORT_SYMBOL(lc_watchdog_add);
 515
 516 void lc_watchdog_touch(struct lc_watchdog *lcw, int timeout)
 517 {
 518 }
 519 EXPORT_SYMBOL(lc_watchdog_touch);
 520
 521 void lc_watchdog_disable(struct lc_watchdog *lcw)
 522 {
 523 }
 524 EXPORT_SYMBOL(lc_watchdog_disable);
 525
 526 void lc_watchdog_delete(struct lc_watchdog *lcw)
 527 {
 528 }
 529 EXPORT_SYMBOL(lc_watchdog_delete);
 530
 531 #endif