]> git.saurik.com Git - redis.git/blobdiff - src/debug.c
A reimplementation of blocking operation internals.
[redis.git] / src / debug.c
index 59e15844ca7cf7fbecfd3e03132a75a4aeca5079..566b2b959cd2d6c7a0fdae950c4b3221ea4d8b1a 100644 (file)
@@ -7,6 +7,7 @@
 #ifdef HAVE_BACKTRACE
 #include <execinfo.h>
 #include <ucontext.h>
+#include <fcntl.h>
 #endif /* HAVE_BACKTRACE */
 
 /* ================================= Debugging ============================== */
@@ -105,7 +106,6 @@ void computeDatasetDigest(unsigned char *final) {
 
             mixDigest(digest,key,sdslen(key));
 
-            /* Make sure the key is loaded if VM is active */
             o = dictGetVal(de);
 
             aux = htonl(o->type);
@@ -218,6 +218,10 @@ void computeDatasetDigest(unsigned char *final) {
 void debugCommand(redisClient *c) {
     if (!strcasecmp(c->argv[1]->ptr,"segfault")) {
         *((char*)-1) = 'x';
+    } else if (!strcasecmp(c->argv[1]->ptr,"oom")) {
+        void *ptr = zmalloc(ULONG_MAX); /* Should trigger an out of memory. */
+        zfree(ptr);
+        addReply(c,shared.ok);
     } else if (!strcasecmp(c->argv[1]->ptr,"assert")) {
         if (c->argc >= 3) c->argv[2] = tryObjectEncoding(c->argv[2]);
         redisAssertWithInfo(c,c->argv[0],1 == 2);
@@ -314,8 +318,8 @@ void _redisAssert(char *estr, char *file, int line) {
     server.assert_file = file;
     server.assert_line = line;
     redisLog(REDIS_WARNING,"(forcing SIGSEGV to print the bug report.)");
-    *((char*)-1) = 'x';
 #endif
+    *((char*)-1) = 'x';
 }
 
 void _redisAssertPrintClientInfo(redisClient *c) {
@@ -384,68 +388,75 @@ void _redisPanic(char *msg, char *file, int line) {
     redisLog(REDIS_WARNING,"Guru Meditation: %s #%s:%d",msg,file,line);
 #ifdef HAVE_BACKTRACE
     redisLog(REDIS_WARNING,"(forcing SIGSEGV in order to print the stack trace)");
+#endif
     redisLog(REDIS_WARNING,"------------------------------------------------");
     *((char*)-1) = 'x';
-#endif
+}
+
+void bugReportStart(void) {
+    if (server.bug_report_start == 0) {
+        redisLog(REDIS_WARNING,
+            "\n\n=== REDIS BUG REPORT START: Cut & paste starting from here ===");
+        server.bug_report_start = 1;
+    }
 }
 
 #ifdef HAVE_BACKTRACE
 static void *getMcontextEip(ucontext_t *uc) {
-#if defined(__FreeBSD__)
-    return (void*) uc->uc_mcontext.mc_eip;
-#elif defined(__dietlibc__)
-    return (void*) uc->uc_mcontext.eip;
-#elif defined(__APPLE__) && !defined(MAC_OS_X_VERSION_10_6)
-  #if __x86_64__
+#if defined(__APPLE__) && !defined(MAC_OS_X_VERSION_10_6)
+    /* OSX < 10.6 */
+    #if defined(__x86_64__)
     return (void*) uc->uc_mcontext->__ss.__rip;
-  #elif __i386__
+    #elif defined(__i386__)
     return (void*) uc->uc_mcontext->__ss.__eip;
-  #else
+    #else
     return (void*) uc->uc_mcontext->__ss.__srr0;
-  #endif
+    #endif
 #elif defined(__APPLE__) && defined(MAC_OS_X_VERSION_10_6)
-  #if defined(_STRUCT_X86_THREAD_STATE64) && !defined(__i386__)
+    /* OSX >= 10.6 */
+    #if defined(_STRUCT_X86_THREAD_STATE64) && !defined(__i386__)
     return (void*) uc->uc_mcontext->__ss.__rip;
-  #else
+    #else
     return (void*) uc->uc_mcontext->__ss.__eip;
-  #endif
-#elif defined(__i386__)
+    #endif
+#elif defined(__linux__)
+    /* Linux */
+    #if defined(__i386__)
     return (void*) uc->uc_mcontext.gregs[14]; /* Linux 32 */
-#elif defined(__X86_64__) || defined(__x86_64__)
+    #elif defined(__X86_64__) || defined(__x86_64__)
     return (void*) uc->uc_mcontext.gregs[16]; /* Linux 64 */
-#elif defined(__ia64__) /* Linux IA64 */
+    #elif defined(__ia64__) /* Linux IA64 */
     return (void*) uc->uc_mcontext.sc_ip;
+    #endif
 #else
     return NULL;
 #endif
 }
 
-void bugReportStart(void) {
-    if (server.bug_report_start == 0) {
-        redisLog(REDIS_WARNING,
-            "\n\n=== REDIS BUG REPORT START: Cut & paste starting from here ===");
-        server.bug_report_start = 1;
-    }
-}
-
 void logStackContent(void **sp) {
     int i;
     for (i = 15; i >= 0; i--) {
-        redisLog(REDIS_WARNING, "(%p) -> %p", sp+i, sp[i]);
+        if (sizeof(long) == 4)
+            redisLog(REDIS_WARNING, "(%08lx) -> %08lx", sp+i, sp[i]);
+        else
+            redisLog(REDIS_WARNING, "(%016lx) -> %016lx", sp+i, sp[i]);
     }
 }
 
 void logRegisters(ucontext_t *uc) {
     redisLog(REDIS_WARNING, "--- REGISTERS");
+
+/* OSX */
 #if defined(__APPLE__) && defined(MAC_OS_X_VERSION_10_6)
-  #if defined(_STRUCT_X86_THREAD_STATE64) && !defined(__i386__)
+  /* OSX AMD64 */
+    #if defined(_STRUCT_X86_THREAD_STATE64) && !defined(__i386__)
     redisLog(REDIS_WARNING,
     "\n"
-    "RAX:%p RBX:%p RCX:%p RDX:%p\n"
-    "RDI:%p RSI:%p RBP:%p RSP:%p\n"
-    "R8:%p  R9:%p  R10:%p R11:%p\n"
-    "R12:%p R13:%p R14:%p R15:%p\n"
-    "RIP:%p EFL:%p CS:%p  FS:%p GS:%p",
+    "RAX:%016lx RBX:%016lx\nRCX:%016lx RDX:%016lx\n"
+    "RDI:%016lx RSI:%016lx\nRBP:%016lx RSP:%016lx\n"
+    "R8 :%016lx R9 :%016lx\nR10:%016lx R11:%016lx\n"
+    "R12:%016lx R13:%016lx\nR14:%016lx R15:%016lx\n"
+    "RIP:%016lx EFL:%016lx\nCS :%016lx FS:%016lx  GS:%016lx",
         uc->uc_mcontext->__ss.__rax,
         uc->uc_mcontext->__ss.__rbx,
         uc->uc_mcontext->__ss.__rcx,
@@ -469,13 +480,14 @@ void logRegisters(ucontext_t *uc) {
         uc->uc_mcontext->__ss.__gs
     );
     logStackContent((void**)uc->uc_mcontext->__ss.__rsp);
-  #else
+    #else
+    /* OSX x86 */
     redisLog(REDIS_WARNING,
     "\n"
-    "EAX:%p EBX:%p ECX:%p EDX:%p\n"
-    "EDI:%p ESI:%p EBP:%p ESP:%p\n"
-    "SS:%p  EFL:%p EIP:%p CS:%p\n"
-    "DS:%p  ES:%p  FS:%p  GS:%p",
+    "EAX:%08lx EBX:%08lx ECX:%08lx EDX:%08lx\n"
+    "EDI:%08lx ESI:%08lx EBP:%08lx ESP:%08lx\n"
+    "SS:%08lx  EFL:%08lx EIP:%08lx CS :%08lx\n"
+    "DS:%08lx  ES:%08lx  FS :%08lx GS :%08lx",
         uc->uc_mcontext->__ss.__eax,
         uc->uc_mcontext->__ss.__ebx,
         uc->uc_mcontext->__ss.__ecx,
@@ -494,21 +506,137 @@ void logRegisters(ucontext_t *uc) {
         uc->uc_mcontext->__ss.__gs
     );
     logStackContent((void**)uc->uc_mcontext->__ss.__esp);
-  #endif
-#elif defined(__i386__)
-    return (void*) uc->uc_mcontext.gregs[14]; /* Linux 32 */
-#elif defined(__X86_64__) || defined(__x86_64__)
-    return (void*) uc->uc_mcontext.gregs[16]; /* Linux 64 */
+    #endif
+/* Linux */
+#elif defined(__linux__)
+    /* Linux x86 */
+    #if defined(__i386__)
+    redisLog(REDIS_WARNING,
+    "\n"
+    "EAX:%08lx EBX:%08lx ECX:%08lx EDX:%08lx\n"
+    "EDI:%08lx ESI:%08lx EBP:%08lx ESP:%08lx\n"
+    "SS :%08lx EFL:%08lx EIP:%08lx CS:%08lx\n"
+    "DS :%08lx ES :%08lx FS :%08lx GS:%08lx",
+        uc->uc_mcontext.gregs[11],
+        uc->uc_mcontext.gregs[8],
+        uc->uc_mcontext.gregs[10],
+        uc->uc_mcontext.gregs[9],
+        uc->uc_mcontext.gregs[4],
+        uc->uc_mcontext.gregs[5],
+        uc->uc_mcontext.gregs[6],
+        uc->uc_mcontext.gregs[7],
+        uc->uc_mcontext.gregs[18],
+        uc->uc_mcontext.gregs[17],
+        uc->uc_mcontext.gregs[14],
+        uc->uc_mcontext.gregs[15],
+        uc->uc_mcontext.gregs[3],
+        uc->uc_mcontext.gregs[2],
+        uc->uc_mcontext.gregs[1],
+        uc->uc_mcontext.gregs[0]
+    );
+    logStackContent((void**)uc->uc_mcontext.gregs[7]);
+    #elif defined(__X86_64__) || defined(__x86_64__)
+    /* Linux AMD64 */
+    redisLog(REDIS_WARNING,
+    "\n"
+    "RAX:%016lx RBX:%016lx\nRCX:%016lx RDX:%016lx\n"
+    "RDI:%016lx RSI:%016lx\nRBP:%016lx RSP:%016lx\n"
+    "R8 :%016lx R9 :%016lx\nR10:%016lx R11:%016lx\n"
+    "R12:%016lx R13:%016lx\nR14:%016lx R15:%016lx\n"
+    "RIP:%016lx EFL:%016lx\nCSGSFS:%016lx",
+        uc->uc_mcontext.gregs[13],
+        uc->uc_mcontext.gregs[11],
+        uc->uc_mcontext.gregs[14],
+        uc->uc_mcontext.gregs[12],
+        uc->uc_mcontext.gregs[8],
+        uc->uc_mcontext.gregs[9],
+        uc->uc_mcontext.gregs[10],
+        uc->uc_mcontext.gregs[15],
+        uc->uc_mcontext.gregs[0],
+        uc->uc_mcontext.gregs[1],
+        uc->uc_mcontext.gregs[2],
+        uc->uc_mcontext.gregs[3],
+        uc->uc_mcontext.gregs[4],
+        uc->uc_mcontext.gregs[5],
+        uc->uc_mcontext.gregs[6],
+        uc->uc_mcontext.gregs[7],
+        uc->uc_mcontext.gregs[16],
+        uc->uc_mcontext.gregs[17],
+        uc->uc_mcontext.gregs[18]
+    );
+    logStackContent((void**)uc->uc_mcontext.gregs[15]);
+    #endif
 #else
     redisLog(REDIS_WARNING,
         "  Dumping of registers not supported for this OS/arch");
 #endif
 }
 
-void sigsegvHandler(int sig, siginfo_t *info, void *secret) {
+/* Logs the stack trace using the backtrace() call. This function is designed
+ * to be called from signal handlers safely. */
+void logStackTrace(ucontext_t *uc) {
     void *trace[100];
-    char **messages = NULL;
-    int i, trace_size = 0;
+    int trace_size = 0, fd;
+
+    /* Open the log file in append mode. */
+    fd = server.logfile ?
+        open(server.logfile, O_APPEND|O_CREAT|O_WRONLY, 0644) :
+        STDOUT_FILENO;
+    if (fd == -1) return;
+
+    /* Generate the stack trace */
+    trace_size = backtrace(trace, 100);
+
+    /* overwrite sigaction with caller's address */
+    if (getMcontextEip(uc) != NULL)
+        trace[1] = getMcontextEip(uc);
+
+    /* Write symbols to log file */
+    backtrace_symbols_fd(trace, trace_size, fd);
+
+    /* Cleanup */
+    if (server.logfile) close(fd);
+}
+
+/* Log information about the "current" client, that is, the client that is
+ * currently being served by Redis. May be NULL if Redis is not serving a
+ * client right now. */
+void logCurrentClient(void) {
+    if (server.current_client == NULL) return;
+
+    redisClient *cc = server.current_client;
+    sds client;
+    int j;
+
+    redisLog(REDIS_WARNING, "--- CURRENT CLIENT INFO");
+    client = getClientInfoString(cc);
+    redisLog(REDIS_WARNING,"client: %s", client);
+    sdsfree(client);
+    for (j = 0; j < cc->argc; j++) {
+        robj *decoded;
+
+        decoded = getDecodedObject(cc->argv[j]);
+        redisLog(REDIS_WARNING,"argv[%d]: '%s'", j, (char*)decoded->ptr);
+        decrRefCount(decoded);
+    }
+    /* Check if the first argument, usually a key, is found inside the
+     * selected DB, and if so print info about the associated object. */
+    if (cc->argc >= 1) {
+        robj *val, *key;
+        dictEntry *de;
+
+        key = getDecodedObject(cc->argv[1]);
+        de = dictFind(cc->db->dict, key->ptr);
+        if (de) {
+            val = dictGetVal(de);
+            redisLog(REDIS_WARNING,"key '%s' found in DB containing the following object:", key->ptr);
+            redisLogObjectDebugInfo(val);
+        }
+        decrRefCount(key);
+    }
+}
+
+void sigsegvHandler(int sig, siginfo_t *info, void *secret) {
     ucontext_t *uc = (ucontext_t*) secret;
     sds infostring, clients;
     struct sigaction act;
@@ -521,68 +649,33 @@ void sigsegvHandler(int sig, siginfo_t *info, void *secret) {
         "    Failed assertion: %s (%s:%d)", server.assert_failed,
                         server.assert_file, server.assert_line);
 
-    /* Generate the stack trace */
-    trace_size = backtrace(trace, 100);
-
-    /* overwrite sigaction with caller's address */
-    if (getMcontextEip(uc) != NULL) {
-        trace[1] = getMcontextEip(uc);
-    }
-    messages = backtrace_symbols(trace, trace_size);
+    /* Log the stack trace */
     redisLog(REDIS_WARNING, "--- STACK TRACE");
-    for (i=1; i<trace_size; ++i)
-        redisLog(REDIS_WARNING,"%s", messages[i]);
+    logStackTrace(uc);
 
     /* Log INFO and CLIENT LIST */
     redisLog(REDIS_WARNING, "--- INFO OUTPUT");
     infostring = genRedisInfoString("all");
+    infostring = sdscatprintf(infostring, "hash_init_value: %u\n",
+        dictGetHashFunctionSeed());
     redisLogRaw(REDIS_WARNING, infostring);
     redisLog(REDIS_WARNING, "--- CLIENT LIST OUTPUT");
     clients = getAllClientsInfoString();
     redisLogRaw(REDIS_WARNING, clients);
-    /* Don't sdsfree() strings to avoid a crash. Memory may be corrupted. */
-
-    /* Log CURRENT CLIENT info */
-    if (server.current_client) {
-        redisClient *cc = server.current_client;
-        sds client;
-        int j;
+    sdsfree(infostring);
+    sdsfree(clients);
 
-        redisLog(REDIS_WARNING, "--- CURRENT CLIENT INFO");
-        client = getClientInfoString(cc);
-        redisLog(REDIS_WARNING,"client: %s", client);
-        /* Missing sdsfree(client) to avoid crash if memory is corrupted. */
-        for (j = 0; j < cc->argc; j++) {
-            robj *decoded;
-
-            decoded = getDecodedObject(cc->argv[j]);
-            redisLog(REDIS_WARNING,"argv[%d]: '%s'", j, (char*)decoded->ptr);
-            decrRefCount(decoded);
-        }
-        /* Check if the first argument, usually a key, is found inside the
-         * selected DB, and if so print info about the associated object. */
-        if (cc->argc >= 1) {
-            robj *val, *key;
-            dictEntry *de;
-
-            key = getDecodedObject(cc->argv[1]);
-            de = dictFind(cc->db->dict, key->ptr);
-            if (de) {
-                val = dictGetVal(de);
-                redisLog(REDIS_WARNING,"key '%s' found in DB containing the following object:", key->ptr);
-                redisLogObjectDebugInfo(val);
-            }
-            decrRefCount(key);
-        }
-    }
+    /* Log the current client */
+    logCurrentClient();
 
     /* Log dump of processor registers */
     logRegisters(uc);
 
     redisLog(REDIS_WARNING,
 "\n=== REDIS BUG REPORT END. Make sure to include from START to END. ===\n\n"
-"    Please report the crash opening an issue on github:\n\n"
-"        http://github.com/antirez/redis/issues\n\n"
+"       Please report the crash opening an issue on github:\n\n"
+"           http://github.com/antirez/redis/issues\n\n"
+"  Suspect RAM error? Use redis-server --test-memory to veryfy it.\n\n"
 );
     /* free(messages); Don't call free() with possibly corrupted memory. */
     if (server.daemonize) unlink(server.pidfile);
@@ -590,11 +683,105 @@ void sigsegvHandler(int sig, siginfo_t *info, void *secret) {
     /* Make sure we exit with the right signal at the end. So for instance
      * the core will be dumped if enabled. */
     sigemptyset (&act.sa_mask);
-    /* When the SA_SIGINFO flag is set in sa_flags then sa_sigaction
-     * is used. Otherwise, sa_handler is used */
     act.sa_flags = SA_NODEFER | SA_ONSTACK | SA_RESETHAND;
     act.sa_handler = SIG_DFL;
     sigaction (sig, &act, NULL);
     kill(getpid(),sig);
 }
 #endif /* HAVE_BACKTRACE */
+
+/* ==================== Logging functions for debugging ===================== */
+
+void redisLogHexDump(int level, char *descr, void *value, size_t len) {
+    char buf[65], *b;
+    unsigned char *v = value;
+    char charset[] = "0123456789abcdef";
+
+    redisLog(level,"%s (hexdump):", descr);
+    b = buf;
+    while(len) {
+        b[0] = charset[(*v)>>4];
+        b[1] = charset[(*v)&0xf];
+        b[2] = '\0';
+        b += 2;
+        len--;
+        v++;
+        if (b-buf == 64 || len == 0) {
+            redisLogRaw(level|REDIS_LOG_RAW,buf);
+            b = buf;
+        }
+    }
+    redisLogRaw(level|REDIS_LOG_RAW,"\n");
+}
+
+/* =========================== Software Watchdog ============================ */
+#include <sys/time.h>
+
+void watchdogSignalHandler(int sig, siginfo_t *info, void *secret) {
+#ifdef HAVE_BACKTRACE
+    ucontext_t *uc = (ucontext_t*) secret;
+#endif
+    REDIS_NOTUSED(info);
+    REDIS_NOTUSED(sig);
+
+    redisLogFromHandler(REDIS_WARNING,"\n--- WATCHDOG TIMER EXPIRED ---");
+#ifdef HAVE_BACKTRACE
+    logStackTrace(uc);
+#else
+    redisLogFromHandler(REDIS_WARNING,"Sorry: no support for backtrace().");
+#endif
+    redisLogFromHandler(REDIS_WARNING,"--------\n");
+}
+
+/* Schedule a SIGALRM delivery after the specified period in milliseconds.
+ * If a timer is already scheduled, this function will re-schedule it to the
+ * specified time. If period is 0 the current timer is disabled. */
+void watchdogScheduleSignal(int period) {
+    struct itimerval it;
+
+    /* Will stop the timer if period is 0. */
+    it.it_value.tv_sec = period/1000;
+    it.it_value.tv_usec = (period%1000)*1000;
+    /* Don't automatically restart. */
+    it.it_interval.tv_sec = 0;
+    it.it_interval.tv_usec = 0;
+    setitimer(ITIMER_REAL, &it, NULL);
+}
+
+/* Enable the software watchdong with the specified period in milliseconds. */
+void enableWatchdog(int period) {
+    int min_period;
+
+    if (server.watchdog_period == 0) {
+        struct sigaction act;
+
+        /* Watchdog was actually disabled, so we have to setup the signal
+         * handler. */
+        sigemptyset(&act.sa_mask);
+        act.sa_flags = SA_NODEFER | SA_ONSTACK | SA_SIGINFO;
+        act.sa_sigaction = watchdogSignalHandler;
+        sigaction(SIGALRM, &act, NULL);
+    }
+    /* If the configured period is smaller than twice the timer period, it is
+     * too short for the software watchdog to work reliably. Fix it now
+     * if needed. */
+    min_period = (1000/REDIS_HZ)*2;
+    if (period < min_period) period = min_period;
+    watchdogScheduleSignal(period); /* Adjust the current timer. */
+    server.watchdog_period = period;
+}
+
+/* Disable the software watchdog. */
+void disableWatchdog(void) {
+    struct sigaction act;
+    if (server.watchdog_period == 0) return; /* Already disabled. */
+    watchdogScheduleSignal(0); /* Stop the current timer. */
+
+    /* Set the signal handler to SIG_IGN, this will also remove pending
+     * signals from the queue. */
+    sigemptyset(&act.sa_mask);
+    act.sa_flags = 0;
+    act.sa_handler = SIG_IGN;
+    sigaction(SIGALRM, &act, NULL);
+    server.watchdog_period = 0;
+}