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 /*
  31  * This file is part of Lustre, http://www.lustre.org/
  32  * Lustre is a trademark of Sun Microsystems, Inc.
  33  *
  34  * libcfs/libcfs/watchdog.c
  35  *
  36  * Author: Jacob Berkman <jacob@clusterfs.com>
  37  */
  38
  39 #define DEBUG_SUBSYSTEM S_LNET
  40
  41 #include <libcfs/libcfs.h>
  42 #include "tracefile.h"
  43
  44 struct lc_watchdog {
  45         cfs_spinlock_t  lcw_lock;     /* check or change lcw_list */
  46         int             lcw_refcount; /* must hold lcw_pending_timers_lock */
  47         cfs_timer_t     lcw_timer;    /* kernel timer */
  48         cfs_list_t      lcw_list;     /* chain on pending list */
  49         cfs_time_t      lcw_last_touched; /* last touched stamp */
  50         cfs_task_t     *lcw_task;     /* owner task */
  51         void          (*lcw_callback)(pid_t, void *);
  52         void           *lcw_data;
  53
  54         pid_t           lcw_pid;
  55
  56         enum {
  57                 LC_WATCHDOG_DISABLED,
  58                 LC_WATCHDOG_ENABLED,
  59                 LC_WATCHDOG_EXPIRED
  60         } lcw_state;
  61 };
  62
  63 #ifdef WITH_WATCHDOG
  64 /*
  65  * The dispatcher will complete lcw_start_completion when it starts,
  66  * and lcw_stop_completion when it exits.
  67  * Wake lcw_event_waitq to signal timer callback dispatches.
  68  */
  69 static cfs_completion_t lcw_start_completion;
  70 static cfs_completion_t  lcw_stop_completion;
  71 static cfs_waitq_t lcw_event_waitq;
  72
  73 /*
  74  * Set this and wake lcw_event_waitq to stop the dispatcher.
  75  */
  76 enum {
  77         LCW_FLAG_STOP = 0
  78 };
  79 static unsigned long lcw_flags = 0;
  80
  81 /*
  82  * Number of outstanding watchdogs.
  83  * When it hits 1, we start the dispatcher.
  84  * When it hits 0, we stop the dispatcher.
  85  */
  86 static __u32         lcw_refcount = 0;
  87 static CFS_DEFINE_MUTEX(lcw_refcount_mutex);
  88
  89 /*
  90  * List of timers that have fired that need their callbacks run by the
  91  * dispatcher.
  92  */
  93 /* BH lock! */
  94 static cfs_spinlock_t lcw_pending_timers_lock = CFS_SPIN_LOCK_UNLOCKED;
  95 static cfs_list_t 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
 102 static void
 103 lcw_dump(struct lc_watchdog *lcw)
 104 {
 105         ENTRY;
 106 #if defined(HAVE_TASKLIST_LOCK)
 107         cfs_read_lock(&tasklist_lock);
 108 #else
 109         rcu_read_lock();
 110 #endif
 111        if (lcw->lcw_task == NULL) {
 112                 LCONSOLE_WARN("Process " LPPID " was not found in the task "
 113                               "list; watchdog callback may be incomplete\n",
 114                               (int)lcw->lcw_pid);
 115         } else {
 116                 libcfs_debug_dumpstack(lcw->lcw_task);
 117         }
 118
 119 #if defined(HAVE_TASKLIST_LOCK)
 120         cfs_read_unlock(&tasklist_lock);
 121 #else
 122         rcu_read_unlock();
 123 #endif
 124         EXIT;
 125 }
 126
 127 static void lcw_cb(ulong_ptr_t data)
 128 {
 129         struct lc_watchdog *lcw = (struct lc_watchdog *)data;
 130         ENTRY;
 131
 132         if (lcw->lcw_state != LC_WATCHDOG_ENABLED) {
 133                 EXIT;
 134                 return;
 135         }
 136
 137         lcw->lcw_state = LC_WATCHDOG_EXPIRED;
 138
 139         cfs_spin_lock_bh(&lcw->lcw_lock);
 140         LASSERT(cfs_list_empty(&lcw->lcw_list));
 141
 142         cfs_spin_lock_bh(&lcw_pending_timers_lock);
 143         lcw->lcw_refcount++; /* +1 for pending list */
 144         cfs_list_add(&lcw->lcw_list, &lcw_pending_timers);
 145         cfs_waitq_signal(&lcw_event_waitq);
 146
 147         cfs_spin_unlock_bh(&lcw_pending_timers_lock);
 148         cfs_spin_unlock_bh(&lcw->lcw_lock);
 149         EXIT;
 150 }
 151
 152 static int is_watchdog_fired(void)
 153 {
 154         int rc;
 155
 156         if (cfs_test_bit(LCW_FLAG_STOP, &lcw_flags))
 157                 return 1;
 158
 159         cfs_spin_lock_bh(&lcw_pending_timers_lock);
 160         rc = !cfs_list_empty(&lcw_pending_timers);
 161         cfs_spin_unlock_bh(&lcw_pending_timers_lock);
 162         return rc;
 163 }
 164
 165 static void lcw_dump_stack(struct lc_watchdog *lcw)
 166 {
 167         cfs_time_t      current_time;
 168         cfs_duration_t  delta_time;
 169         struct timeval  timediff;
 170
 171         current_time = cfs_time_current();
 172         delta_time = cfs_time_sub(current_time, lcw->lcw_last_touched);
 173         cfs_duration_usec(delta_time, &timediff);
 174
 175         /*
 176          * Check to see if we should throttle the watchdog timer to avoid
 177          * too many dumps going to the console thus triggering an NMI.
 178          */
 179         delta_time = cfs_duration_sec(cfs_time_sub(current_time,
 180                                                    lcw_last_watchdog_time));
 181
 182         if (delta_time < libcfs_watchdog_ratelimit &&
 183             lcw_recent_watchdog_count > 3) {
 184                 LCONSOLE_WARN("Service thread pid %u was inactive for "
 185                               "%lu.%.02lus. Watchdog stack traces are limited "
 186                               "to 3 per %d seconds, skipping this one.\n",
 187                               (int)lcw->lcw_pid,
 188                               timediff.tv_sec,
 189                               timediff.tv_usec / 10000,
 190                               libcfs_watchdog_ratelimit);
 191         } else {
 192                 if (delta_time < libcfs_watchdog_ratelimit) {
 193                         lcw_recent_watchdog_count++;
 194                 } else {
 195                         memcpy(&lcw_last_watchdog_time, &current_time,
 196                                sizeof(current_time));
 197                         lcw_recent_watchdog_count = 0;
 198                 }
 199
 200                 LCONSOLE_WARN("Service thread pid %u was inactive for "
 201                               "%lu.%.02lus. The thread might be hung, or it "
 202                               "might only be slow and will resume later. "
 203                               "Dumping the stack trace for debugging purposes:"
 204                               "\n",
 205                               (int)lcw->lcw_pid,
 206                               timediff.tv_sec,
 207                               timediff.tv_usec / 10000);
 208                 lcw_dump(lcw);
 209         }
 210 }
 211
 212 static int lcw_dispatch_main(void *data)
 213 {
 214         int                 rc = 0;
 215         unsigned long       flags;
 216         struct lc_watchdog *lcw;
 217         CFS_LIST_HEAD      (zombies);
 218
 219         ENTRY;
 220
 221         cfs_daemonize("lc_watchdogd");
 222
 223         SIGNAL_MASK_LOCK(current, flags);
 224         sigfillset(&current->blocked);
 225         RECALC_SIGPENDING;
 226         SIGNAL_MASK_UNLOCK(current, flags);
 227
 228         cfs_complete(&lcw_start_completion);
 229
 230         while (1) {
 231                 int dumplog = 1;
 232
 233                 cfs_wait_event_interruptible(lcw_event_waitq,
 234                                              is_watchdog_fired(), rc);
 235                 CDEBUG(D_INFO, "Watchdog got woken up...\n");
 236                 if (cfs_test_bit(LCW_FLAG_STOP, &lcw_flags)) {
 237                         CDEBUG(D_INFO, "LCW_FLAG_STOP was set, shutting down...\n");
 238
 239                         cfs_spin_lock_bh(&lcw_pending_timers_lock);
 240                         rc = !cfs_list_empty(&lcw_pending_timers);
 241                         cfs_spin_unlock_bh(&lcw_pending_timers_lock);
 242                         if (rc) {
 243                                 CERROR("pending timers list was not empty at "
 244                                        "time of watchdog dispatch shutdown\n");
 245                         }
 246                         break;
 247                 }
 248
 249                 cfs_spin_lock_bh(&lcw_pending_timers_lock);
 250                 while (!cfs_list_empty(&lcw_pending_timers)) {
 251                         int is_dumplog;
 252
 253                         lcw = cfs_list_entry(lcw_pending_timers.next,
 254                                              struct lc_watchdog, lcw_list);
 255                         /* +1 ref for callback to make sure lwc wouldn't be
 256                          * deleted after releasing lcw_pending_timers_lock */
 257                         lcw->lcw_refcount++;
 258                         cfs_spin_unlock_bh(&lcw_pending_timers_lock);
 259
 260                         /* lock ordering */
 261                         cfs_spin_lock_bh(&lcw->lcw_lock);
 262                         cfs_spin_lock_bh(&lcw_pending_timers_lock);
 263
 264                         if (cfs_list_empty(&lcw->lcw_list)) {
 265                                 /* already removed from pending list */
 266                                 lcw->lcw_refcount--; /* -1 ref for callback */
 267                                 if (lcw->lcw_refcount == 0)
 268                                         cfs_list_add(&lcw->lcw_list, &zombies);
 269                                 cfs_spin_unlock_bh(&lcw->lcw_lock);
 270                                 /* still hold lcw_pending_timers_lock */
 271                                 continue;
 272                         }
 273
 274                         cfs_list_del_init(&lcw->lcw_list);
 275                         lcw->lcw_refcount--; /* -1 ref for pending list */
 276
 277                         cfs_spin_unlock_bh(&lcw_pending_timers_lock);
 278                         cfs_spin_unlock_bh(&lcw->lcw_lock);
 279
 280                         CDEBUG(D_INFO, "found lcw for pid " LPPID "\n",
 281                                lcw->lcw_pid);
 282                         lcw_dump_stack(lcw);
 283
 284                         is_dumplog = lcw->lcw_callback == lc_watchdog_dumplog;
 285                         if (lcw->lcw_state != LC_WATCHDOG_DISABLED &&
 286                             (dumplog || !is_dumplog)) {
 287                                 lcw->lcw_callback(lcw->lcw_pid, lcw->lcw_data);
 288                                 if (dumplog && is_dumplog)
 289                                         dumplog = 0;
 290                         }
 291
 292                         cfs_spin_lock_bh(&lcw_pending_timers_lock);
 293                         lcw->lcw_refcount--; /* -1 ref for callback */
 294                         if (lcw->lcw_refcount == 0)
 295                                 cfs_list_add(&lcw->lcw_list, &zombies);
 296                 }
 297                 cfs_spin_unlock_bh(&lcw_pending_timers_lock);
 298
 299                 while (!cfs_list_empty(&zombies)) {
 300                         lcw = cfs_list_entry(lcw_pending_timers.next,
 301                                          struct lc_watchdog, lcw_list);
 302                         cfs_list_del(&lcw->lcw_list);
 303                         LIBCFS_FREE(lcw, sizeof(*lcw));
 304                 }
 305         }
 306
 307         cfs_complete(&lcw_stop_completion);
 308
 309         RETURN(rc);
 310 }
 311
 312 static void lcw_dispatch_start(void)
 313 {
 314         int rc;
 315
 316         ENTRY;
 317         LASSERT(lcw_refcount == 1);
 318
 319         cfs_init_completion(&lcw_stop_completion);
 320         cfs_init_completion(&lcw_start_completion);
 321         cfs_waitq_init(&lcw_event_waitq);
 322
 323         CDEBUG(D_INFO, "starting dispatch thread\n");
 324         rc = cfs_create_thread(lcw_dispatch_main, NULL, 0);
 325         if (rc < 0) {
 326                 CERROR("error spawning watchdog dispatch thread: %d\n", rc);
 327                 EXIT;
 328                 return;
 329         }
 330         cfs_wait_for_completion(&lcw_start_completion);
 331         CDEBUG(D_INFO, "watchdog dispatcher initialization complete.\n");
 332
 333         EXIT;
 334 }
 335
 336 static void lcw_dispatch_stop(void)
 337 {
 338         ENTRY;
 339         LASSERT(lcw_refcount == 0);
 340
 341         CDEBUG(D_INFO, "trying to stop watchdog dispatcher.\n");
 342
 343         cfs_set_bit(LCW_FLAG_STOP, &lcw_flags);
 344         cfs_waitq_signal(&lcw_event_waitq);
 345
 346         cfs_wait_for_completion(&lcw_stop_completion);
 347
 348         CDEBUG(D_INFO, "watchdog dispatcher has shut down.\n");
 349
 350         EXIT;
 351 }
 352
 353 struct lc_watchdog *lc_watchdog_add(int timeout,
 354                                     void (*callback)(pid_t, void *),
 355                                     void *data)
 356 {
 357         struct lc_watchdog *lcw = NULL;
 358         ENTRY;
 359
 360         LIBCFS_ALLOC(lcw, sizeof(*lcw));
 361         if (lcw == NULL) {
 362                 CDEBUG(D_INFO, "Could not allocate new lc_watchdog\n");
 363                 RETURN(ERR_PTR(-ENOMEM));
 364         }
 365
 366         cfs_spin_lock_init(&lcw->lcw_lock);
 367         lcw->lcw_refcount = 1; /* refcount for owner */
 368         lcw->lcw_task     = cfs_current();
 369         lcw->lcw_pid      = cfs_curproc_pid();
 370         lcw->lcw_callback = (callback != NULL) ? callback : lc_watchdog_dumplog;
 371         lcw->lcw_data     = data;
 372         lcw->lcw_state    = LC_WATCHDOG_DISABLED;
 373
 374         CFS_INIT_LIST_HEAD(&lcw->lcw_list);
 375         cfs_timer_init(&lcw->lcw_timer, lcw_cb, lcw);
 376
 377         cfs_mutex_lock(&lcw_refcount_mutex);
 378         if (++lcw_refcount == 1)
 379                 lcw_dispatch_start();
 380         cfs_mutex_unlock(&lcw_refcount_mutex);
 381
 382         /* Keep this working in case we enable them by default */
 383         if (lcw->lcw_state == LC_WATCHDOG_ENABLED) {
 384                 lcw->lcw_last_touched = cfs_time_current();
 385                 cfs_timer_arm(&lcw->lcw_timer, cfs_time_seconds(timeout) +
 386                               cfs_time_current());
 387         }
 388
 389         RETURN(lcw);
 390 }
 391 EXPORT_SYMBOL(lc_watchdog_add);
 392
 393 static void lcw_update_time(struct lc_watchdog *lcw, const char *message)
 394 {
 395         cfs_time_t newtime = cfs_time_current();;
 396
 397         if (lcw->lcw_state == LC_WATCHDOG_EXPIRED) {
 398                 struct timeval timediff;
 399                 cfs_time_t delta_time = cfs_time_sub(newtime,
 400                                                      lcw->lcw_last_touched);
 401                 cfs_duration_usec(delta_time, &timediff);
 402
 403                 LCONSOLE_WARN("Service thread pid %u %s after %lu.%.02lus. "
 404                               "This indicates the system was overloaded (too "
 405                               "many service threads, or there were not enough "
 406                               "hardware resources).\n",
 407                               lcw->lcw_pid,
 408                               message,
 409                               timediff.tv_sec,
 410                               timediff.tv_usec / 10000);
 411         }
 412         lcw->lcw_last_touched = newtime;
 413 }
 414
 415 static void lc_watchdog_del_pending(struct lc_watchdog *lcw)
 416 {
 417         cfs_spin_lock_bh(&lcw->lcw_lock);
 418         if (unlikely(!cfs_list_empty(&lcw->lcw_list))) {
 419                 cfs_spin_lock_bh(&lcw_pending_timers_lock);
 420                 cfs_list_del_init(&lcw->lcw_list);
 421                 lcw->lcw_refcount--; /* -1 ref for pending list */
 422                 cfs_spin_unlock_bh(&lcw_pending_timers_lock);
 423         }
 424
 425         cfs_spin_unlock_bh(&lcw->lcw_lock);
 426 }
 427
 428 void lc_watchdog_touch(struct lc_watchdog *lcw, int timeout)
 429 {
 430         ENTRY;
 431         LASSERT(lcw != NULL);
 432
 433         lc_watchdog_del_pending(lcw);
 434
 435         lcw_update_time(lcw, "resumed");
 436         lcw->lcw_state = LC_WATCHDOG_ENABLED;
 437
 438         cfs_timer_arm(&lcw->lcw_timer, cfs_time_current() +
 439                       cfs_time_seconds(timeout));
 440
 441         EXIT;
 442 }
 443 EXPORT_SYMBOL(lc_watchdog_touch);
 444
 445 void lc_watchdog_disable(struct lc_watchdog *lcw)
 446 {
 447         ENTRY;
 448         LASSERT(lcw != NULL);
 449
 450         lc_watchdog_del_pending(lcw);
 451
 452         lcw_update_time(lcw, "completed");
 453         lcw->lcw_state = LC_WATCHDOG_DISABLED;
 454
 455         EXIT;
 456 }
 457 EXPORT_SYMBOL(lc_watchdog_disable);
 458
 459 void lc_watchdog_delete(struct lc_watchdog *lcw)
 460 {
 461         int dead;
 462
 463         ENTRY;
 464         LASSERT(lcw != NULL);
 465
 466         cfs_timer_disarm(&lcw->lcw_timer);
 467
 468         lcw_update_time(lcw, "stopped");
 469
 470         cfs_spin_lock_bh(&lcw->lcw_lock);
 471         cfs_spin_lock_bh(&lcw_pending_timers_lock);
 472         if (unlikely(!cfs_list_empty(&lcw->lcw_list))) {
 473                 cfs_list_del_init(&lcw->lcw_list);
 474                 lcw->lcw_refcount--; /* -1 ref for pending list */
 475         }
 476
 477         lcw->lcw_refcount--; /* -1 ref for owner */
 478         dead = lcw->lcw_refcount == 0;
 479         cfs_spin_unlock_bh(&lcw_pending_timers_lock);
 480         cfs_spin_unlock_bh(&lcw->lcw_lock);
 481
 482         if (dead)
 483                 LIBCFS_FREE(lcw, sizeof(*lcw));
 484
 485         cfs_mutex_lock(&lcw_refcount_mutex);
 486         if (--lcw_refcount == 0)
 487                 lcw_dispatch_stop();
 488         cfs_mutex_unlock(&lcw_refcount_mutex);
 489
 490         EXIT;
 491 }
 492 EXPORT_SYMBOL(lc_watchdog_delete);
 493
 494 /*
 495  * Provided watchdog handlers
 496  */
 497
 498 void lc_watchdog_dumplog(pid_t pid, void *data)
 499 {
 500         libcfs_debug_dumplog_internal((void *)((long_ptr_t)pid));
 501 }
 502 EXPORT_SYMBOL(lc_watchdog_dumplog);
 503
 504 #else   /* !defined(WITH_WATCHDOG) */
 505
 506 struct lc_watchdog *lc_watchdog_add(int timeout,
 507                                     void (*callback)(pid_t pid, void *),
 508                                     void *data)
 509 {
 510         static struct lc_watchdog      watchdog;
 511         return &watchdog;
 512 }
 513 EXPORT_SYMBOL(lc_watchdog_add);
 514
 515 void lc_watchdog_touch(struct lc_watchdog *lcw, int timeout)
 516 {
 517 }
 518 EXPORT_SYMBOL(lc_watchdog_touch);
 519
 520 void lc_watchdog_disable(struct lc_watchdog *lcw)
 521 {
 522 }
 523 EXPORT_SYMBOL(lc_watchdog_disable);
 524
 525 void lc_watchdog_delete(struct lc_watchdog *lcw)
 526 {
 527 }
 528 EXPORT_SYMBOL(lc_watchdog_delete);
 529
 530 #endif