CernVM-FS  2.10.0
 All Classes Namespaces Files Functions Variables Typedefs Enumerations Enumerator Friends Macros Pages
monitor.cc
Go to the documentation of this file.
1 
11 #include "cvmfs_config.h"
12 #include "monitor.h"
13 
14 #include <errno.h>
15 #include <execinfo.h>
16 #include <poll.h>
17 #include <pthread.h>
18 #include <signal.h>
19 #include <sys/resource.h>
20 #include <sys/types.h>
21 #ifdef __APPLE__
22  #include <sys/ucontext.h>
23 #else
24  #include <ucontext.h>
25 #endif
26 #include <sys/uio.h>
27 #include <sys/wait.h>
28 #include <time.h>
29 #include <unistd.h>
30 
31 #include <cassert>
32 #include <cstdio>
33 #include <cstdlib>
34 #include <cstring>
35 #include <map>
36 #include <string>
37 #include <vector>
38 
39 #if defined(CVMFS_FUSE_MODULE)
40 #include "cvmfs.h"
41 #endif
42 #include "logging.h"
43 #include "platform.h"
44 #include "smalloc.h"
45 #include "util/exception.h"
46 #include "util/posix.h"
47 #include "util/string.h"
48 
49 // Used for address offset calculation
50 #if defined(CVMFS_FUSE_MODULE)
51 extern loader::CvmfsExports *g_cvmfs_exports;
52 #endif
53 
54 using namespace std; // NOLINT
55 
57 
58 
59 Watchdog *Watchdog::Create(const string &crash_dump_path) {
60  assert(instance_ == NULL);
61  instance_ = new Watchdog(crash_dump_path);
62  return instance_;
63 }
64 
65 
70 string Watchdog::GenerateStackTrace(pid_t pid) {
71  int retval;
72  string result = "";
73 
74  // re-gain root permissions to allow for ptrace of died cvmfs2 process
75  const bool retrievable = true;
76  if (!SwitchCredentials(0, getgid(), retrievable)) {
77  result += "failed to re-gain root permissions... still give it a try\n";
78  }
79 
80  // run gdb and attach to the dying process
81  int fd_stdin;
82  int fd_stdout;
83  int fd_stderr;
84  vector<string> argv;
85  argv.push_back("-p");
86  argv.push_back(StringifyInt(pid));
87  pid_t gdb_pid = 0;
88  const bool double_fork = false;
89  retval = ExecuteBinary(&fd_stdin,
90  &fd_stdout,
91  &fd_stderr,
92 #ifdef __APPLE__
93  "lldb",
94 #else
95  "gdb",
96 #endif
97  argv,
98  double_fork,
99  &gdb_pid);
100  assert(retval);
101 
102 
103  // Skip the gdb startup output
104  ReadUntilGdbPrompt(fd_stdout);
105 
106  // Send stacktrace command to gdb
107 #ifdef __APPLE__
108  const string gdb_cmd = "bt all\n" "quit\n";
109 #else
110  const string gdb_cmd = "thread apply all bt\n" "quit\n";
111 #endif
112  // The execve can have failed, which can't be detected in ExecuteBinary.
113  // Instead, writing to the pipe will fail.
114  ssize_t nbytes = write(fd_stdin, gdb_cmd.data(), gdb_cmd.length());
115  if ((nbytes < 0) || (static_cast<unsigned>(nbytes) != gdb_cmd.length())) {
116  result += "failed to start gdb/lldb (" + StringifyInt(nbytes) + " bytes "
117  "written, errno " + StringifyInt(errno) + ")\n";
118  return result;
119  }
120 
121  // Read the stack trace from the stdout of our gdb process
122 #ifdef __APPLE__
123  // lldb has one more prompt
124  result += ReadUntilGdbPrompt(fd_stdout);
125 #endif
126  result += ReadUntilGdbPrompt(fd_stdout) + "\n\n";
127 
128  // Check for output on stderr
129  string result_err;
130  Block2Nonblock(fd_stderr);
131  char cbuf;
132  while (read(fd_stderr, &cbuf, 1) == 1)
133  result_err.push_back(cbuf);
134  if (!result_err.empty())
135  result += "\nError output:\n" + result_err + "\n";
136 
137  // Close the connection to the terminated gdb process
138  close(fd_stderr);
139  close(fd_stdout);
140  close(fd_stdin);
141 
142  // Make sure gdb has terminated (wait for it for a short while)
143  unsigned int timeout = 15;
144  int statloc;
145  while (timeout > 0 && waitpid(gdb_pid, &statloc, WNOHANG) != gdb_pid) {
146  --timeout;
147  SafeSleepMs(1000);
148  }
149 
150  // when the timeout expired, gdb probably hangs... we need to kill it
151  if (timeout == 0) {
152  result += "gdb did not exit as expected. sending SIGKILL... ";
153  result += (kill(gdb_pid, SIGKILL) != 0) ? "failed\n" : "okay\n";
154  }
155 
156  return result;
157 }
158 
159 
161  if (instance_ != NULL) {
162  if (!instance_->spawned_)
163  return getpid();
164  else
165  return instance_->watchdog_pid_;
166  }
167  return getpid();
168 }
169 
174 void Watchdog::LogEmergency(string msg) {
175  char ctime_buffer[32];
176 
177  if (!crash_dump_path_.empty()) {
178  FILE *fp = fopen(crash_dump_path_.c_str(), "a");
179  if (fp) {
180  time_t now = time(NULL);
181  msg += "\nTimestamp: " + string(ctime_r(&now, ctime_buffer));
182  if (fwrite(&msg[0], 1, msg.length(), fp) != msg.length()) {
183  msg +=
184  " (failed to report into crash dump file " + crash_dump_path_ + ")";
185  } else {
186  msg += "\n Crash logged also on file: " + crash_dump_path_ + "\n";
187  }
188  fclose(fp);
189  } else {
190  msg += " (failed to open crash dump file " + crash_dump_path_ + ")";
191  }
192  }
193  LogCvmfs(kLogMonitor, kLogSyslogErr, "%s", msg.c_str());
194 }
195 
203 string Watchdog::ReadUntilGdbPrompt(int fd_pipe) {
204 #ifdef __APPLE__
205  static const string gdb_prompt = "(lldb)";
206 #else
207  static const string gdb_prompt = "\n(gdb) ";
208 #endif
209 
210  string result;
211  char mini_buffer;
212  int chars_io;
213  unsigned int ring_buffer_pos = 0;
214 
215  // read from stdout of gdb until gdb prompt occures --> (gdb)
216  while (1) {
217  chars_io = read(fd_pipe, &mini_buffer, 1);
218 
219  // in case something goes wrong...
220  if (chars_io <= 0) break;
221 
222  result += mini_buffer;
223 
224  // find the gdb_promt in the stdout data
225  if (mini_buffer == gdb_prompt[ring_buffer_pos]) {
226  ++ring_buffer_pos;
227  if (ring_buffer_pos == gdb_prompt.size()) {
228  break;
229  }
230  } else {
231  ring_buffer_pos = 0;
232  }
233  }
234 
235  return result;
236 }
237 
238 
239 void Watchdog::RegisterOnCrash(void (*CleanupOnCrash)(void)) {
240  on_crash_ = CleanupOnCrash;
241 }
242 
243 
248  // Re-activate ┬ÁSyslog, if necessary
250 
251  CrashData crash_data;
252  if (!pipe_watchdog_->Read(&crash_data)) {
253  return "failed to read crash data (" + StringifyInt(errno) + ")";
254  }
255 
256  string debug = "--\n";
257  debug += "Signal: " + StringifyInt(crash_data.signal);
258  debug += ", errno: " + StringifyInt(crash_data.sys_errno);
259  debug += ", version: " + string(VERSION);
260  debug += ", PID: " + StringifyInt(crash_data.pid) + "\n";
261  debug += "Executable path: " + exe_path_ + "\n";
262 
263  debug += GenerateStackTrace(crash_data.pid);
264 
265  // Give the dying process the finishing stroke
266  if (kill(crash_data.pid, SIGKILL) != 0) {
267  debug += "Failed to kill cvmfs client! (";
268  switch (errno) {
269  case EINVAL:
270  debug += "invalid signal";
271  break;
272  case EPERM:
273  debug += "permission denied";
274  break;
275  case ESRCH:
276  debug += "no such process";
277  break;
278  default:
279  debug += "unknown error " + StringifyInt(errno);
280  }
281  debug += ")\n\n";
282  }
283 
284  return debug;
285 }
286 
287 
288 void Watchdog::SendTrace(int sig, siginfo_t *siginfo, void *context) {
289  int send_errno = errno;
290  if (platform_spinlock_trylock(&Me()->lock_handler_) != 0) {
291  // Concurrent call, wait for the first one to exit the process
292  while (true) {}
293  }
294 
295  // Set the original signal handler for the raised signal in
296  // SIGQUIT (watchdog process will raise SIGQUIT)
297  (void) sigaction(SIGQUIT, &(Me()->old_signal_handlers_[sig]), NULL);
298 
299  // Inform the watchdog that CernVM-FS crashed
300  if (!Me()->pipe_watchdog_->Write(ControlFlow::kProduceStacktrace)) {
301  _exit(1);
302  }
303 
304  // Send crash information to the watchdog
305  CrashData crash_data;
306  crash_data.signal = sig;
307  crash_data.sys_errno = send_errno;
308  crash_data.pid = getpid();
309  if (!Me()->pipe_watchdog_->Write(crash_data)) {
310  _exit(1);
311  }
312 
313  // Do not die before the stack trace was generated
314  // kill -SIGQUIT <pid> will finish this
315  int counter = 0;
316  while (true) {
317  SafeSleepMs(100);
318  // quit anyway after 30 seconds
319  if (++counter == 300) {
320  LogCvmfs(kLogCvmfs, kLogSyslogErr, "stack trace generation failed");
321  // Last attempt to log something useful
322 #if defined(CVMFS_FUSE_MODULE)
323  LogCvmfs(kLogCvmfs, kLogSyslogErr, "Signal %d, errno %d",
324  sig, send_errno);
325  void *addr[kMaxBacktrace];
326  // Note: this doesn't work due to the signal stack on OS X (it works on
327  // Linux). Since anyway lldb is supposed to produce the backtrace, we
328  // consider it more important to protect cvmfs against stack overflows.
329  int num_addr = backtrace(addr, kMaxBacktrace);
330  char **symbols = backtrace_symbols(addr, num_addr);
331  string backtrace = "Backtrace (" + StringifyInt(num_addr) +
332  " symbols):\n";
333  for (int i = 0; i < num_addr; ++i)
334  backtrace += string(symbols[i]) + "\n";
335  LogCvmfs(kLogCvmfs, kLogSyslogErr, "%s", backtrace.c_str());
336  LogCvmfs(kLogCvmfs, kLogSyslogErr, "address of g_cvmfs_exports: %p",
337  &g_cvmfs_exports);
338 #endif
339 
340  _exit(1);
341  }
342  }
343 
344  _exit(1);
345 }
346 
347 
356  const SigactionMap &signal_handlers)
357 {
358  SigactionMap old_signal_handlers;
359  SigactionMap::const_iterator i = signal_handlers.begin();
360  SigactionMap::const_iterator iend = signal_handlers.end();
361  for (; i != iend; ++i) {
362  struct sigaction old_signal_handler;
363  if (sigaction(i->first, &i->second, &old_signal_handler) != 0) {
364  PANIC(NULL);
365  }
366  old_signal_handlers[i->first] = old_signal_handler;
367  }
368 
369  return old_signal_handlers;
370 }
371 
372 
377  Pipe pipe_pid;
378  pipe_watchdog_ = new Pipe();
379  pipe_listener_ = new Pipe();
380 
381  pid_t pid;
382  int statloc;
383  int max_fd = sysconf(_SC_OPEN_MAX);
384  assert(max_fd >= 0);
385  switch (pid = fork()) {
386  case -1: PANIC(NULL);
387  case 0:
388  // Double fork to avoid zombie
389  switch (fork()) {
390  case -1: exit(1);
391  case 0: {
392  close(pipe_watchdog_->write_end);
393  Daemonize();
394  // send the watchdog PID to cvmfs
395  pid_t watchdog_pid = getpid();
396  pipe_pid.Write(watchdog_pid);
397  close(pipe_pid.write_end);
398  // Close all unused file descriptors
399  // close also usyslog, only get it back if necessary
400  // string usyslog_save = GetLogMicroSyslog();
401  string debuglog_save = GetLogDebugFile();
402  // SetLogMicroSyslog("");
403  SetLogDebugFile("");
404  for (int fd = 0; fd < max_fd; fd++) {
405  if (fd == pipe_watchdog_->read_end)
406  continue;
407  if (fd == pipe_listener_->write_end)
408  continue;
409  close(fd);
410  }
411  // SetLogMicroSyslog(usyslog_save); // no-op if usyslog not used
412  SetLogDebugFile(debuglog_save); // no-op if debug log not used
413  Supervise();
414  exit(0);
415  }
416  default:
417  exit(0);
418  }
419  default:
420  close(pipe_watchdog_->read_end);
421  close(pipe_listener_->write_end);
422  if (waitpid(pid, &statloc, 0) != pid) PANIC(NULL);
423  if (!WIFEXITED(statloc) || WEXITSTATUS(statloc)) PANIC(NULL);
424  }
425 
426  // retrieve the watchdog PID from the pipe
427  close(pipe_pid.write_end);
428  pipe_pid.Read(&watchdog_pid_);
429  close(pipe_pid.read_end);
430 
431  // lower restrictions for ptrace
432  if (!platform_allow_ptrace(watchdog_pid_)) {
434  "failed to allow ptrace() for watchdog (PID: %d). "
435  "Post crash stacktrace might not work",
436  watchdog_pid_);
437  }
438 
439  // Extra stack for signal handlers
440  int stack_size = kSignalHandlerStacksize; // 2 MB
441  sighandler_stack_.ss_sp = smalloc(stack_size);
442  sighandler_stack_.ss_size = stack_size;
443  sighandler_stack_.ss_flags = 0;
444  if (sigaltstack(&sighandler_stack_, NULL) != 0)
445  PANIC(NULL);
446 
447  // define our crash signal handler
448  struct sigaction sa;
449  memset(&sa, 0, sizeof(sa));
450  sa.sa_sigaction = SendTrace;
451  sa.sa_flags = SA_SIGINFO | SA_ONSTACK;
452  sigfillset(&sa.sa_mask);
453 
454  SigactionMap signal_handlers;
455  signal_handlers[SIGQUIT] = sa;
456  signal_handlers[SIGILL] = sa;
457  signal_handlers[SIGABRT] = sa;
458  signal_handlers[SIGFPE] = sa;
459  signal_handlers[SIGSEGV] = sa;
460  signal_handlers[SIGBUS] = sa;
461  signal_handlers[SIGPIPE] = sa;
462  signal_handlers[SIGXFSZ] = sa;
463  old_signal_handlers_ = SetSignalHandlers(signal_handlers);
464 
465  pipe_terminate_ = new Pipe();
466  int retval =
467  pthread_create(&thread_listener_, NULL, MainWatchdogListener, this);
468  assert(retval == 0);
469 
470  spawned_ = true;
471 }
472 
473 
475  Watchdog *watchdog = static_cast<Watchdog *>(data);
476  LogCvmfs(kLogMonitor, kLogDebug, "starting watchdog listener");
477 
478  struct pollfd watch_fds[2];
479  watch_fds[0].fd = watchdog->pipe_listener_->read_end;
480  watch_fds[0].events = POLLIN | POLLPRI;
481  watch_fds[0].revents = 0;
482  watch_fds[1].fd = watchdog->pipe_terminate_->read_end;
483  watch_fds[1].events = POLLIN | POLLPRI;
484  watch_fds[1].revents = 0;
485  while (true) {
486  int retval = poll(watch_fds, 2, -1);
487  if (retval < 0) {
488  continue;
489  }
490 
491  // Terminate I/O thread
492  if (watch_fds[1].revents)
493  break;
494 
495  if (watch_fds[0].revents) {
496  if ((watch_fds[0].revents & POLLERR) ||
497  (watch_fds[0].revents & POLLHUP) ||
498  (watch_fds[0].revents & POLLNVAL))
499  {
501  "watchdog disappeared, disabling stack trace reporting");
502  watchdog->SetSignalHandlers(watchdog->old_signal_handlers_);
503  PANIC(kLogDebug | kLogSyslogErr, "watchdog disappeared, aborting");
504  }
505  PANIC(NULL);
506  }
507  }
508  close(watchdog->pipe_listener_->read_end);
509 
510  LogCvmfs(kLogMonitor, kLogDebug, "stopping watchdog listener");
511  return NULL;
512 }
513 
514 
516  signal(SIGPIPE, SIG_IGN);
517  ControlFlow::Flags control_flow;
518 
519  if (!pipe_watchdog_->Read(&control_flow)) {
520  // Re-activate ┬ÁSyslog, if necessary
522  LogEmergency("unexpected termination (" + StringifyInt(control_flow) + ")");
523  if (on_crash_) on_crash_();
524  } else {
525  switch (control_flow) {
526  case ControlFlow::kProduceStacktrace:
527  LogEmergency(ReportStacktrace());
528  if (on_crash_) on_crash_();
529  break;
530 
531  case ControlFlow::kQuit:
532  break;
533 
534  default:
535  // Re-activate ┬ÁSyslog, if necessary
537  LogEmergency("unexpected error");
538  break;
539  }
540  }
541 
542  close(pipe_watchdog_->read_end);
543  close(pipe_listener_->write_end);
544 }
545 
546 
547 Watchdog::Watchdog(const string &crash_dump_path)
548  : spawned_(false)
549  , crash_dump_path_(crash_dump_path)
550  , exe_path_(string(platform_getexepath()))
551  , watchdog_pid_(0)
552  , pipe_watchdog_(NULL)
553  , pipe_listener_(NULL)
554  , pipe_terminate_(NULL)
555  , on_crash_(NULL)
556 {
557  int retval = platform_spinlock_init(&lock_handler_, 0);
558  assert(retval == 0);
559  memset(&sighandler_stack_, 0, sizeof(sighandler_stack_));
560 }
561 
562 
564  if (spawned_) {
565  // Reset signal handlers
566  signal(SIGQUIT, SIG_DFL);
567  signal(SIGILL, SIG_DFL);
568  signal(SIGABRT, SIG_DFL);
569  signal(SIGFPE, SIG_DFL);
570  signal(SIGSEGV, SIG_DFL);
571  signal(SIGBUS, SIG_DFL);
572  signal(SIGPIPE, SIG_DFL);
573  signal(SIGXFSZ, SIG_DFL);
574  free(sighandler_stack_.ss_sp);
575  sighandler_stack_.ss_size = 0;
576 
578  pthread_join(thread_listener_, NULL);
580 
582  close(pipe_watchdog_->write_end);
583  }
584 
585  delete pipe_watchdog_;
586  delete pipe_listener_;
587  delete pipe_terminate_;
588 
590  LogCvmfs(kLogMonitor, kLogDebug, "monitor stopped");
591  instance_ = NULL;
592 }
593 
594 
595 
596 namespace monitor {
597 
598 const unsigned kMinOpenFiles = 8192;
599 
600 unsigned GetMaxOpenFiles() {
601  static unsigned max_open_files;
602  static bool already_done = false;
603 
604  /* check number of open files (lazy evaluation) */
605  if (!already_done) {
606  unsigned soft_limit = 0;
607  unsigned hard_limit = 0;
608  GetLimitNoFile(&soft_limit, &hard_limit);
609 
610  if (soft_limit < kMinOpenFiles) {
612  "Warning: current limits for number of open files are "
613  "(%lu/%lu)\n"
614  "CernVM-FS is likely to run out of file descriptors, "
615  "set ulimit -n to at least %lu",
616  soft_limit, hard_limit, kMinOpenFiles);
617  }
618  max_open_files = soft_limit;
619  already_done = true;
620  }
621 
622  return max_open_files;
623 }
624 
625 } // namespace monitor
#define LogCvmfs(source, mask,...)
Definition: logging.h:20
Watchdog(const std::string &crash_dump_path)
Definition: monitor.cc:547
void Supervise()
Definition: monitor.cc:515
std::map< int, struct sigaction > SigactionMap
Definition: monitor.h:36
std::string GenerateStackTrace(pid_t pid)
Definition: monitor.cc:70
std::string ReportStacktrace()
Definition: monitor.cc:247
SigactionMap old_signal_handlers_
Definition: monitor.h:89
static void SendTrace(int sig, siginfo_t *siginfo, void *context)
Definition: monitor.cc:288
static Watchdog * Create(const std::string &crash_dump_path)
Definition: monitor.cc:59
#define PANIC(...)
Definition: exception.h:26
int read_end
Definition: posix.h:224
int platform_spinlock_init(platform_spinlock *lock, int pshared)
void Daemonize()
Definition: posix.cc:1642
bool Read(T *data)
Definition: posix.h:208
static void * MainWatchdogListener(void *data)
void Spawn()
Definition: monitor.cc:376
void LogEmergency(std::string msg)
Definition: monitor.cc:174
assert((mem||(size==0))&&"Out Of Memory")
void SetLogMicroSyslog(const std::string &filename)
Definition: logging.cc:267
std::string platform_getexepath()
static Watchdog * instance_
Definition: monitor.h:63
bool Write(const T &data)
Definition: posix.h:201
void Close()
Definition: posix.h:195
#define SetLogDebugFile(filename)
bool platform_allow_ptrace(const pid_t pid)
stack_t sighandler_stack_
Definition: monitor.h:88
static pid_t GetPid()
Definition: monitor.cc:160
pthread_t thread_listener_
Definition: monitor.h:85
Pipe * pipe_watchdog_
Definition: monitor.h:80
void GetLimitNoFile(unsigned *soft_limit, unsigned *hard_limit)
Definition: posix.cc:1495
#define GetLogDebugFile()
int platform_spinlock_trylock(platform_spinlock *lock)
int write_end
Definition: posix.h:225
std::string ReadUntilGdbPrompt(int fd_pipe)
Definition: monitor.cc:203
static void * MainWatchdogListener(void *data)
Definition: monitor.cc:474
unsigned GetMaxOpenFiles()
Definition: monitor.cc:600
Pipe * pipe_terminate_
Send the terminate signal to the listener.
Definition: monitor.h:84
SigactionMap SetSignalHandlers(const SigactionMap &signal_handlers)
Definition: monitor.cc:355
string StringifyInt(const int64_t value)
Definition: string.cc:78
std::string GetLogMicroSyslog()
Definition: logging.cc:303
bool spawned_
Definition: monitor.h:76
bool ExecuteBinary(int *fd_stdin, int *fd_stdout, int *fd_stderr, const std::string &binary_path, const std::vector< std::string > &argv, const bool double_fork, pid_t *child_pid)
Definition: posix.cc:1673
~Watchdog()
Definition: monitor.cc:563
void RegisterOnCrash(void(*CleanupOnCrash)(void))
Definition: monitor.cc:239
Definition: posix.h:184
bool SwitchCredentials(const uid_t uid, const gid_t gid, const bool temporarily)
Definition: posix.cc:786
Pipe * pipe_listener_
The supervisee makes sure its watchdog does not die.
Definition: monitor.h:82
void SafeSleepMs(const unsigned ms)
Definition: posix.cc:1918
void Block2Nonblock(int filedes)
Definition: posix.cc:680
int platform_spinlock_destroy(platform_spinlock *lock)
const unsigned kMinOpenFiles
Definition: monitor.cc:598
platform_spinlock lock_handler_
Definition: monitor.h:87