1 /* 2 * Copyright (c) 2009-2012, Salvatore Sanfilippo <antirez at gmail dot com> 3 * All rights reserved. 4 * 5 * Redistribution and use in source and binary forms, with or without 6 * modification, are permitted provided that the following conditions are met: 7 * 8 * * Redistributions of source code must retain the above copyright notice, 9 * this list of conditions and the following disclaimer. 10 * * Redistributions in binary form must reproduce the above copyright 11 * notice, this list of conditions and the following disclaimer in the 12 * documentation and/or other materials provided with the distribution. 13 * * Neither the name of Redis nor the names of its contributors may be used 14 * to endorse or promote products derived from this software without 15 * specific prior written permission. 16 * 17 * THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS "AS IS" 18 * AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE 19 * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE 20 * ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT OWNER OR CONTRIBUTORS BE 21 * LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR 22 * CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF 23 * SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS 24 * INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN 25 * CONTRACT, STRICT LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) 26 * ARISING IN ANY WAY OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE 27 * POSSIBILITY OF SUCH DAMAGE. 28 */ 29 30 #include "server.h" 31 #include "sha1.h" /* SHA1 is used for DEBUG DIGEST */ 32 #include "crc64.h" 33 34 #include <arpa/inet.h> 35 #include <signal.h> 36 37 #ifdef HAVE_BACKTRACE 38 #include <execinfo.h> 39 #include <ucontext.h> 40 #include <fcntl.h> 41 #include "bio.h" 42 #endif /* HAVE_BACKTRACE */ 43 44 #ifdef __CYGWIN__ 45 #ifndef SA_ONSTACK 46 #define SA_ONSTACK 0x08000000 47 #endif 48 #endif 49 50 /* ================================= Debugging ============================== */ 51 52 /* Compute the sha1 of string at 's' with 'len' bytes long. 53 * The SHA1 is then xored against the string pointed by digest. 54 * Since xor is commutative, this operation is used in order to 55 * "add" digests relative to unordered elements. 56 * 57 * So digest(a,b,c,d) will be the same of digest(b,a,c,d) */ 58 void xorDigest(unsigned char *digest, void *ptr, size_t len) { 59 SHA1_CTX ctx; 60 unsigned char hash[20], *s = ptr; 61 int j; 62 63 SHA1Init(&ctx); 64 SHA1Update(&ctx,s,len); 65 SHA1Final(hash,&ctx); 66 67 for (j = 0; j < 20; j++) 68 digest[j] ^= hash[j]; 69 } 70 71 void xorObjectDigest(unsigned char *digest, robj *o) { 72 o = getDecodedObject(o); 73 xorDigest(digest,o->ptr,sdslen(o->ptr)); 74 decrRefCount(o); 75 } 76 77 /* This function instead of just computing the SHA1 and xoring it 78 * against digest, also perform the digest of "digest" itself and 79 * replace the old value with the new one. 80 * 81 * So the final digest will be: 82 * 83 * digest = SHA1(digest xor SHA1(data)) 84 * 85 * This function is used every time we want to preserve the order so 86 * that digest(a,b,c,d) will be different than digest(b,c,d,a) 87 * 88 * Also note that mixdigest("foo") followed by mixdigest("bar") 89 * will lead to a different digest compared to "fo", "obar". 90 */ 91 void mixDigest(unsigned char *digest, void *ptr, size_t len) { 92 SHA1_CTX ctx; 93 char *s = ptr; 94 95 xorDigest(digest,s,len); 96 SHA1Init(&ctx); 97 SHA1Update(&ctx,digest,20); 98 SHA1Final(digest,&ctx); 99 } 100 101 void mixObjectDigest(unsigned char *digest, robj *o) { 102 o = getDecodedObject(o); 103 mixDigest(digest,o->ptr,sdslen(o->ptr)); 104 decrRefCount(o); 105 } 106 107 /* Compute the dataset digest. Since keys, sets elements, hashes elements 108 * are not ordered, we use a trick: every aggregate digest is the xor 109 * of the digests of their elements. This way the order will not change 110 * the result. For list instead we use a feedback entering the output digest 111 * as input in order to ensure that a different ordered list will result in 112 * a different digest. */ 113 void computeDatasetDigest(unsigned char *final) { 114 unsigned char digest[20]; 115 char buf[128]; 116 dictIterator *di = NULL; 117 dictEntry *de; 118 int j; 119 uint32_t aux; 120 121 memset(final,0,20); /* Start with a clean result */ 122 123 for (j = 0; j < server.dbnum; j++) { 124 redisDb *db = server.db+j; 125 126 if (dictSize(db->dict) == 0) continue; 127 di = dictGetIterator(db->dict); 128 129 /* hash the DB id, so the same dataset moved in a different 130 * DB will lead to a different digest */ 131 aux = htonl(j); 132 mixDigest(final,&aux,sizeof(aux)); 133 134 /* Iterate this DB writing every entry */ 135 while((de = dictNext(di)) != NULL) { 136 sds key; 137 robj *keyobj, *o; 138 long long expiretime; 139 140 memset(digest,0,20); /* This key-val digest */ 141 key = dictGetKey(de); 142 keyobj = createStringObject(key,sdslen(key)); 143 144 mixDigest(digest,key,sdslen(key)); 145 146 o = dictGetVal(de); 147 148 aux = htonl(o->type); 149 mixDigest(digest,&aux,sizeof(aux)); 150 expiretime = getExpire(db,keyobj); 151 152 /* Save the key and associated value */ 153 if (o->type == OBJ_STRING) { 154 mixObjectDigest(digest,o); 155 } else if (o->type == OBJ_LIST) { 156 listTypeIterator *li = listTypeInitIterator(o,0,LIST_TAIL); 157 listTypeEntry entry; 158 while(listTypeNext(li,&entry)) { 159 robj *eleobj = listTypeGet(&entry); 160 mixObjectDigest(digest,eleobj); 161 decrRefCount(eleobj); 162 } 163 listTypeReleaseIterator(li); 164 } else if (o->type == OBJ_SET) { 165 setTypeIterator *si = setTypeInitIterator(o); 166 robj *ele; 167 while((ele = setTypeNextObject(si)) != NULL) { 168 xorObjectDigest(digest,ele); 169 decrRefCount(ele); 170 } 171 setTypeReleaseIterator(si); 172 } else if (o->type == OBJ_ZSET) { 173 unsigned char eledigest[20]; 174 175 if (o->encoding == OBJ_ENCODING_ZIPLIST) { 176 unsigned char *zl = o->ptr; 177 unsigned char *eptr, *sptr; 178 unsigned char *vstr; 179 unsigned int vlen; 180 long long vll; 181 double score; 182 183 eptr = ziplistIndex(zl,0); 184 serverAssert(eptr != NULL); 185 sptr = ziplistNext(zl,eptr); 186 serverAssert(sptr != NULL); 187 188 while (eptr != NULL) { 189 serverAssert(ziplistGet(eptr,&vstr,&vlen,&vll)); 190 score = zzlGetScore(sptr); 191 192 memset(eledigest,0,20); 193 if (vstr != NULL) { 194 mixDigest(eledigest,vstr,vlen); 195 } else { 196 ll2string(buf,sizeof(buf),vll); 197 mixDigest(eledigest,buf,strlen(buf)); 198 } 199 200 snprintf(buf,sizeof(buf),"%.17g",score); 201 mixDigest(eledigest,buf,strlen(buf)); 202 xorDigest(digest,eledigest,20); 203 zzlNext(zl,&eptr,&sptr); 204 } 205 } else if (o->encoding == OBJ_ENCODING_SKIPLIST) { 206 zset *zs = o->ptr; 207 dictIterator *di = dictGetIterator(zs->dict); 208 dictEntry *de; 209 210 while((de = dictNext(di)) != NULL) { 211 robj *eleobj = dictGetKey(de); 212 double *score = dictGetVal(de); 213 214 snprintf(buf,sizeof(buf),"%.17g",*score); 215 memset(eledigest,0,20); 216 mixObjectDigest(eledigest,eleobj); 217 mixDigest(eledigest,buf,strlen(buf)); 218 xorDigest(digest,eledigest,20); 219 } 220 dictReleaseIterator(di); 221 } else { 222 serverPanic("Unknown sorted set encoding"); 223 } 224 } else if (o->type == OBJ_HASH) { 225 hashTypeIterator *hi; 226 robj *obj; 227 228 hi = hashTypeInitIterator(o); 229 while (hashTypeNext(hi) != C_ERR) { 230 unsigned char eledigest[20]; 231 232 memset(eledigest,0,20); 233 obj = hashTypeCurrentObject(hi,OBJ_HASH_KEY); 234 mixObjectDigest(eledigest,obj); 235 decrRefCount(obj); 236 obj = hashTypeCurrentObject(hi,OBJ_HASH_VALUE); 237 mixObjectDigest(eledigest,obj); 238 decrRefCount(obj); 239 xorDigest(digest,eledigest,20); 240 } 241 hashTypeReleaseIterator(hi); 242 } else { 243 serverPanic("Unknown object type"); 244 } 245 /* If the key has an expire, add it to the mix */ 246 if (expiretime != -1) xorDigest(digest,"!!expire!!",10); 247 /* We can finally xor the key-val digest to the final digest */ 248 xorDigest(final,digest,20); 249 decrRefCount(keyobj); 250 } 251 dictReleaseIterator(di); 252 } 253 } 254 255 #if defined(USE_JEMALLOC) 256 void inputCatSds(void *result, const char *str) { 257 /* result is actually a (sds *), so re-cast it here */ 258 sds *info = (sds *)result; 259 *info = sdscat(*info, str); 260 } 261 #endif 262 263 void debugCommand(client *c) { 264 if (!strcasecmp(c->argv[1]->ptr,"segfault")) { 265 *((char*)-1) = 'x'; 266 } else if (!strcasecmp(c->argv[1]->ptr,"restart") || 267 !strcasecmp(c->argv[1]->ptr,"crash-and-recover")) 268 { 269 long long delay = 0; 270 if (c->argc >= 3) { 271 if (getLongLongFromObjectOrReply(c, c->argv[2], &delay, NULL) 272 != C_OK) return; 273 if (delay < 0) delay = 0; 274 } 275 int flags = !strcasecmp(c->argv[1]->ptr,"restart") ? 276 (RESTART_SERVER_GRACEFULLY|RESTART_SERVER_CONFIG_REWRITE) : 277 RESTART_SERVER_NONE; 278 restartServer(flags,delay); 279 addReplyError(c,"failed to restart the server. Check server logs."); 280 } else if (!strcasecmp(c->argv[1]->ptr,"oom")) { 281 void *ptr = zmalloc(ULONG_MAX); /* Should trigger an out of memory. */ 282 zfree(ptr); 283 addReply(c,shared.ok); 284 } else if (!strcasecmp(c->argv[1]->ptr,"assert")) { 285 if (c->argc >= 3) c->argv[2] = tryObjectEncoding(c->argv[2]); 286 serverAssertWithInfo(c,c->argv[0],1 == 2); 287 } else if (!strcasecmp(c->argv[1]->ptr,"reload")) { 288 if (rdbSave(server.rdb_filename) != C_OK) { 289 addReply(c,shared.err); 290 return; 291 } 292 emptyDb(NULL); 293 if (rdbLoad(server.rdb_filename) != C_OK) { 294 addReplyError(c,"Error trying to load the RDB dump"); 295 return; 296 } 297 serverLog(LL_WARNING,"DB reloaded by DEBUG RELOAD"); 298 addReply(c,shared.ok); 299 } else if (!strcasecmp(c->argv[1]->ptr,"loadaof")) { 300 if (server.aof_state == AOF_ON) flushAppendOnlyFile(1); 301 emptyDb(NULL); 302 if (loadAppendOnlyFile(server.aof_filename) != C_OK) { 303 addReply(c,shared.err); 304 return; 305 } 306 server.dirty = 0; /* Prevent AOF / replication */ 307 serverLog(LL_WARNING,"Append Only File loaded by DEBUG LOADAOF"); 308 addReply(c,shared.ok); 309 } else if (!strcasecmp(c->argv[1]->ptr,"object") && c->argc == 3) { 310 dictEntry *de; 311 robj *val; 312 char *strenc; 313 314 if ((de = dictFind(c->db->dict,c->argv[2]->ptr)) == NULL) { 315 addReply(c,shared.nokeyerr); 316 return; 317 } 318 val = dictGetVal(de); 319 strenc = strEncoding(val->encoding); 320 321 char extra[128] = {0}; 322 if (val->encoding == OBJ_ENCODING_QUICKLIST) { 323 char *nextra = extra; 324 int remaining = sizeof(extra); 325 quicklist *ql = val->ptr; 326 /* Add number of quicklist nodes */ 327 int used = snprintf(nextra, remaining, " ql_nodes:%u", ql->len); 328 nextra += used; 329 remaining -= used; 330 /* Add average quicklist fill factor */ 331 double avg = (double)ql->count/ql->len; 332 used = snprintf(nextra, remaining, " ql_avg_node:%.2f", avg); 333 nextra += used; 334 remaining -= used; 335 /* Add quicklist fill level / max ziplist size */ 336 used = snprintf(nextra, remaining, " ql_ziplist_max:%d", ql->fill); 337 nextra += used; 338 remaining -= used; 339 /* Add isCompressed? */ 340 int compressed = ql->compress != 0; 341 used = snprintf(nextra, remaining, " ql_compressed:%d", compressed); 342 nextra += used; 343 remaining -= used; 344 /* Add total uncompressed size */ 345 unsigned long sz = 0; 346 for (quicklistNode *node = ql->head; node; node = node->next) { 347 sz += node->sz; 348 } 349 used = snprintf(nextra, remaining, " ql_uncompressed_size:%lu", sz); 350 nextra += used; 351 remaining -= used; 352 } 353 354 addReplyStatusFormat(c, 355 "Value at:%p refcount:%d " 356 "encoding:%s serializedlength:%zu " 357 "lru:%d lru_seconds_idle:%llu%s", 358 (void*)val, val->refcount, 359 strenc, rdbSavedObjectLen(val), 360 val->lru, estimateObjectIdleTime(val)/1000, extra); 361 } else if (!strcasecmp(c->argv[1]->ptr,"sdslen") && c->argc == 3) { 362 dictEntry *de; 363 robj *val; 364 sds key; 365 366 if ((de = dictFind(c->db->dict,c->argv[2]->ptr)) == NULL) { 367 addReply(c,shared.nokeyerr); 368 return; 369 } 370 val = dictGetVal(de); 371 key = dictGetKey(de); 372 373 if (val->type != OBJ_STRING || !sdsEncodedObject(val)) { 374 addReplyError(c,"Not an sds encoded string."); 375 } else { 376 addReplyStatusFormat(c, 377 "key_sds_len:%lld, key_sds_avail:%lld, " 378 "val_sds_len:%lld, val_sds_avail:%lld", 379 (long long) sdslen(key), 380 (long long) sdsavail(key), 381 (long long) sdslen(val->ptr), 382 (long long) sdsavail(val->ptr)); 383 } 384 } else if (!strcasecmp(c->argv[1]->ptr,"populate") && 385 (c->argc == 3 || c->argc == 4)) { 386 long keys, j; 387 robj *key, *val; 388 char buf[128]; 389 390 if (getLongFromObjectOrReply(c, c->argv[2], &keys, NULL) != C_OK) 391 return; 392 dictExpand(c->db->dict,keys); 393 for (j = 0; j < keys; j++) { 394 snprintf(buf,sizeof(buf),"%s:%lu", 395 (c->argc == 3) ? "key" : (char*)c->argv[3]->ptr, j); 396 key = createStringObject(buf,strlen(buf)); 397 if (lookupKeyWrite(c->db,key) != NULL) { 398 decrRefCount(key); 399 continue; 400 } 401 snprintf(buf,sizeof(buf),"value:%lu",j); 402 val = createStringObject(buf,strlen(buf)); 403 dbAdd(c->db,key,val); 404 signalModifiedKey(c->db,key); 405 decrRefCount(key); 406 } 407 addReply(c,shared.ok); 408 } else if (!strcasecmp(c->argv[1]->ptr,"digest") && c->argc == 2) { 409 unsigned char digest[20]; 410 sds d = sdsempty(); 411 int j; 412 413 computeDatasetDigest(digest); 414 for (j = 0; j < 20; j++) 415 d = sdscatprintf(d, "%02x",digest[j]); 416 addReplyStatus(c,d); 417 sdsfree(d); 418 } else if (!strcasecmp(c->argv[1]->ptr,"sleep") && c->argc == 3) { 419 double dtime = strtod(c->argv[2]->ptr,NULL); 420 long long utime = dtime*1000000; 421 struct timespec tv; 422 423 tv.tv_sec = utime / 1000000; 424 tv.tv_nsec = (utime % 1000000) * 1000; 425 nanosleep(&tv, NULL); 426 addReply(c,shared.ok); 427 } else if (!strcasecmp(c->argv[1]->ptr,"set-active-expire") && 428 c->argc == 3) 429 { 430 server.active_expire_enabled = atoi(c->argv[2]->ptr); 431 addReply(c,shared.ok); 432 } else if (!strcasecmp(c->argv[1]->ptr,"lua-always-replicate-commands") && 433 c->argc == 3) 434 { 435 server.lua_always_replicate_commands = atoi(c->argv[2]->ptr); 436 addReply(c,shared.ok); 437 } else if (!strcasecmp(c->argv[1]->ptr,"error") && c->argc == 3) { 438 sds errstr = sdsnewlen("-",1); 439 440 errstr = sdscatsds(errstr,c->argv[2]->ptr); 441 errstr = sdsmapchars(errstr,"\n\r"," ",2); /* no newlines in errors. */ 442 errstr = sdscatlen(errstr,"\r\n",2); 443 addReplySds(c,errstr); 444 } else if (!strcasecmp(c->argv[1]->ptr,"structsize") && c->argc == 2) { 445 sds sizes = sdsempty(); 446 sizes = sdscatprintf(sizes,"bits:%d ",(sizeof(void*) == 8)?64:32); 447 sizes = sdscatprintf(sizes,"robj:%d ",(int)sizeof(robj)); 448 sizes = sdscatprintf(sizes,"dictentry:%d ",(int)sizeof(dictEntry)); 449 sizes = sdscatprintf(sizes,"sdshdr5:%d ",(int)sizeof(struct sdshdr5)); 450 sizes = sdscatprintf(sizes,"sdshdr8:%d ",(int)sizeof(struct sdshdr8)); 451 sizes = sdscatprintf(sizes,"sdshdr16:%d ",(int)sizeof(struct sdshdr16)); 452 sizes = sdscatprintf(sizes,"sdshdr32:%d ",(int)sizeof(struct sdshdr32)); 453 sizes = sdscatprintf(sizes,"sdshdr64:%d ",(int)sizeof(struct sdshdr64)); 454 addReplyBulkSds(c,sizes); 455 } else if (!strcasecmp(c->argv[1]->ptr,"htstats") && c->argc == 3) { 456 long dbid; 457 sds stats = sdsempty(); 458 char buf[4096]; 459 460 if (getLongFromObjectOrReply(c, c->argv[2], &dbid, NULL) != C_OK) 461 return; 462 if (dbid < 0 || dbid >= server.dbnum) { 463 addReplyError(c,"Out of range database"); 464 return; 465 } 466 467 stats = sdscatprintf(stats,"[Dictionary HT]\n"); 468 dictGetStats(buf,sizeof(buf),server.db[dbid].dict); 469 stats = sdscat(stats,buf); 470 471 stats = sdscatprintf(stats,"[Expires HT]\n"); 472 dictGetStats(buf,sizeof(buf),server.db[dbid].expires); 473 stats = sdscat(stats,buf); 474 475 addReplyBulkSds(c,stats); 476 } else if (!strcasecmp(c->argv[1]->ptr,"jemalloc") && c->argc == 3) { 477 #if defined(USE_JEMALLOC) 478 if (!strcasecmp(c->argv[2]->ptr, "info")) { 479 sds info = sdsempty(); 480 je_malloc_stats_print(inputCatSds, &info, NULL); 481 addReplyBulkSds(c, info); 482 } else if (!strcasecmp(c->argv[2]->ptr, "purge")) { 483 char tmp[32]; 484 unsigned narenas = 0; 485 size_t sz = sizeof(unsigned); 486 if (!je_mallctl("arenas.narenas", &narenas, &sz, NULL, 0)) { 487 sprintf(tmp, "arena.%d.purge", narenas); 488 if (!je_mallctl(tmp, NULL, 0, NULL, 0)) { 489 addReply(c, shared.ok); 490 return; 491 } 492 } 493 addReplyError(c, "Error purging dirty pages"); 494 } else { 495 addReplyErrorFormat(c, "Valid jemalloc debug fields: info, purge"); 496 } 497 #else 498 addReplyErrorFormat(c, "jemalloc support not available"); 499 #endif 500 } else { 501 addReplyErrorFormat(c, "Unknown DEBUG subcommand or wrong number of arguments for '%s'", 502 (char*)c->argv[1]->ptr); 503 } 504 } 505 506 /* =========================== Crash handling ============================== */ 507 508 void _serverAssert(char *estr, char *file, int line) { 509 bugReportStart(); 510 serverLog(LL_WARNING,"=== ASSERTION FAILED ==="); 511 serverLog(LL_WARNING,"==> %s:%d '%s' is not true",file,line,estr); 512 #ifdef HAVE_BACKTRACE 513 server.assert_failed = estr; 514 server.assert_file = file; 515 server.assert_line = line; 516 serverLog(LL_WARNING,"(forcing SIGSEGV to print the bug report.)"); 517 #endif 518 *((char*)-1) = 'x'; 519 } 520 521 void _serverAssertPrintClientInfo(client *c) { 522 int j; 523 524 bugReportStart(); 525 serverLog(LL_WARNING,"=== ASSERTION FAILED CLIENT CONTEXT ==="); 526 serverLog(LL_WARNING,"client->flags = %d", c->flags); 527 serverLog(LL_WARNING,"client->fd = %d", c->fd); 528 serverLog(LL_WARNING,"client->argc = %d", c->argc); 529 for (j=0; j < c->argc; j++) { 530 char buf[128]; 531 char *arg; 532 533 if (c->argv[j]->type == OBJ_STRING && sdsEncodedObject(c->argv[j])) { 534 arg = (char*) c->argv[j]->ptr; 535 } else { 536 snprintf(buf,sizeof(buf),"Object type: %u, encoding: %u", 537 c->argv[j]->type, c->argv[j]->encoding); 538 arg = buf; 539 } 540 serverLog(LL_WARNING,"client->argv[%d] = \"%s\" (refcount: %d)", 541 j, arg, c->argv[j]->refcount); 542 } 543 } 544 545 void serverLogObjectDebugInfo(robj *o) { 546 serverLog(LL_WARNING,"Object type: %d", o->type); 547 serverLog(LL_WARNING,"Object encoding: %d", o->encoding); 548 serverLog(LL_WARNING,"Object refcount: %d", o->refcount); 549 if (o->type == OBJ_STRING && sdsEncodedObject(o)) { 550 serverLog(LL_WARNING,"Object raw string len: %zu", sdslen(o->ptr)); 551 if (sdslen(o->ptr) < 4096) { 552 sds repr = sdscatrepr(sdsempty(),o->ptr,sdslen(o->ptr)); 553 serverLog(LL_WARNING,"Object raw string content: %s", repr); 554 sdsfree(repr); 555 } 556 } else if (o->type == OBJ_LIST) { 557 serverLog(LL_WARNING,"List length: %d", (int) listTypeLength(o)); 558 } else if (o->type == OBJ_SET) { 559 serverLog(LL_WARNING,"Set size: %d", (int) setTypeSize(o)); 560 } else if (o->type == OBJ_HASH) { 561 serverLog(LL_WARNING,"Hash size: %d", (int) hashTypeLength(o)); 562 } else if (o->type == OBJ_ZSET) { 563 serverLog(LL_WARNING,"Sorted set size: %d", (int) zsetLength(o)); 564 if (o->encoding == OBJ_ENCODING_SKIPLIST) 565 serverLog(LL_WARNING,"Skiplist level: %d", (int) ((zset*)o->ptr)->zsl->level); 566 } 567 } 568 569 void _serverAssertPrintObject(robj *o) { 570 bugReportStart(); 571 serverLog(LL_WARNING,"=== ASSERTION FAILED OBJECT CONTEXT ==="); 572 serverLogObjectDebugInfo(o); 573 } 574 575 void _serverAssertWithInfo(client *c, robj *o, char *estr, char *file, int line) { 576 if (c) _serverAssertPrintClientInfo(c); 577 if (o) _serverAssertPrintObject(o); 578 _serverAssert(estr,file,line); 579 } 580 581 void _serverPanic(char *msg, char *file, int line) { 582 bugReportStart(); 583 serverLog(LL_WARNING,"------------------------------------------------"); 584 serverLog(LL_WARNING,"!!! Software Failure. Press left mouse button to continue"); 585 serverLog(LL_WARNING,"Guru Meditation: %s #%s:%d",msg,file,line); 586 #ifdef HAVE_BACKTRACE 587 serverLog(LL_WARNING,"(forcing SIGSEGV in order to print the stack trace)"); 588 #endif 589 serverLog(LL_WARNING,"------------------------------------------------"); 590 *((char*)-1) = 'x'; 591 } 592 593 void bugReportStart(void) { 594 if (server.bug_report_start == 0) { 595 serverLogRaw(LL_WARNING|LL_RAW, 596 "\n\n=== REDIS BUG REPORT START: Cut & paste starting from here ===\n"); 597 server.bug_report_start = 1; 598 } 599 } 600 601 #ifdef HAVE_BACKTRACE 602 static void *getMcontextEip(ucontext_t *uc) { 603 #if defined(__APPLE__) && !defined(MAC_OS_X_VERSION_10_6) 604 /* OSX < 10.6 */ 605 #if defined(__x86_64__) 606 return (void*) uc->uc_mcontext->__ss.__rip; 607 #elif defined(__i386__) 608 return (void*) uc->uc_mcontext->__ss.__eip; 609 #else 610 return (void*) uc->uc_mcontext->__ss.__srr0; 611 #endif 612 #elif defined(__APPLE__) && defined(MAC_OS_X_VERSION_10_6) 613 /* OSX >= 10.6 */ 614 #if defined(_STRUCT_X86_THREAD_STATE64) && !defined(__i386__) 615 return (void*) uc->uc_mcontext->__ss.__rip; 616 #else 617 return (void*) uc->uc_mcontext->__ss.__eip; 618 #endif 619 #elif defined(__linux__) 620 /* Linux */ 621 #if defined(__i386__) 622 return (void*) uc->uc_mcontext.gregs[14]; /* Linux 32 */ 623 #elif defined(__X86_64__) || defined(__x86_64__) 624 return (void*) uc->uc_mcontext.gregs[16]; /* Linux 64 */ 625 #elif defined(__ia64__) /* Linux IA64 */ 626 return (void*) uc->uc_mcontext.sc_ip; 627 #endif 628 #else 629 return NULL; 630 #endif 631 } 632 633 void logStackContent(void **sp) { 634 int i; 635 for (i = 15; i >= 0; i--) { 636 unsigned long addr = (unsigned long) sp+i; 637 unsigned long val = (unsigned long) sp[i]; 638 639 if (sizeof(long) == 4) 640 serverLog(LL_WARNING, "(%08lx) -> %08lx", addr, val); 641 else 642 serverLog(LL_WARNING, "(%016lx) -> %016lx", addr, val); 643 } 644 } 645 646 void logRegisters(ucontext_t *uc) { 647 serverLog(LL_WARNING|LL_RAW, "\n------ REGISTERS ------\n"); 648 649 /* OSX */ 650 #if defined(__APPLE__) && defined(MAC_OS_X_VERSION_10_6) 651 /* OSX AMD64 */ 652 #if defined(_STRUCT_X86_THREAD_STATE64) && !defined(__i386__) 653 serverLog(LL_WARNING, 654 "\n" 655 "RAX:%016lx RBX:%016lx\nRCX:%016lx RDX:%016lx\n" 656 "RDI:%016lx RSI:%016lx\nRBP:%016lx RSP:%016lx\n" 657 "R8 :%016lx R9 :%016lx\nR10:%016lx R11:%016lx\n" 658 "R12:%016lx R13:%016lx\nR14:%016lx R15:%016lx\n" 659 "RIP:%016lx EFL:%016lx\nCS :%016lx FS:%016lx GS:%016lx", 660 (unsigned long) uc->uc_mcontext->__ss.__rax, 661 (unsigned long) uc->uc_mcontext->__ss.__rbx, 662 (unsigned long) uc->uc_mcontext->__ss.__rcx, 663 (unsigned long) uc->uc_mcontext->__ss.__rdx, 664 (unsigned long) uc->uc_mcontext->__ss.__rdi, 665 (unsigned long) uc->uc_mcontext->__ss.__rsi, 666 (unsigned long) uc->uc_mcontext->__ss.__rbp, 667 (unsigned long) uc->uc_mcontext->__ss.__rsp, 668 (unsigned long) uc->uc_mcontext->__ss.__r8, 669 (unsigned long) uc->uc_mcontext->__ss.__r9, 670 (unsigned long) uc->uc_mcontext->__ss.__r10, 671 (unsigned long) uc->uc_mcontext->__ss.__r11, 672 (unsigned long) uc->uc_mcontext->__ss.__r12, 673 (unsigned long) uc->uc_mcontext->__ss.__r13, 674 (unsigned long) uc->uc_mcontext->__ss.__r14, 675 (unsigned long) uc->uc_mcontext->__ss.__r15, 676 (unsigned long) uc->uc_mcontext->__ss.__rip, 677 (unsigned long) uc->uc_mcontext->__ss.__rflags, 678 (unsigned long) uc->uc_mcontext->__ss.__cs, 679 (unsigned long) uc->uc_mcontext->__ss.__fs, 680 (unsigned long) uc->uc_mcontext->__ss.__gs 681 ); 682 logStackContent((void**)uc->uc_mcontext->__ss.__rsp); 683 #else 684 /* OSX x86 */ 685 serverLog(LL_WARNING, 686 "\n" 687 "EAX:%08lx EBX:%08lx ECX:%08lx EDX:%08lx\n" 688 "EDI:%08lx ESI:%08lx EBP:%08lx ESP:%08lx\n" 689 "SS:%08lx EFL:%08lx EIP:%08lx CS :%08lx\n" 690 "DS:%08lx ES:%08lx FS :%08lx GS :%08lx", 691 (unsigned long) uc->uc_mcontext->__ss.__eax, 692 (unsigned long) uc->uc_mcontext->__ss.__ebx, 693 (unsigned long) uc->uc_mcontext->__ss.__ecx, 694 (unsigned long) uc->uc_mcontext->__ss.__edx, 695 (unsigned long) uc->uc_mcontext->__ss.__edi, 696 (unsigned long) uc->uc_mcontext->__ss.__esi, 697 (unsigned long) uc->uc_mcontext->__ss.__ebp, 698 (unsigned long) uc->uc_mcontext->__ss.__esp, 699 (unsigned long) uc->uc_mcontext->__ss.__ss, 700 (unsigned long) uc->uc_mcontext->__ss.__eflags, 701 (unsigned long) uc->uc_mcontext->__ss.__eip, 702 (unsigned long) uc->uc_mcontext->__ss.__cs, 703 (unsigned long) uc->uc_mcontext->__ss.__ds, 704 (unsigned long) uc->uc_mcontext->__ss.__es, 705 (unsigned long) uc->uc_mcontext->__ss.__fs, 706 (unsigned long) uc->uc_mcontext->__ss.__gs 707 ); 708 logStackContent((void**)uc->uc_mcontext->__ss.__esp); 709 #endif 710 /* Linux */ 711 #elif defined(__linux__) 712 /* Linux x86 */ 713 #if defined(__i386__) 714 serverLog(LL_WARNING, 715 "\n" 716 "EAX:%08lx EBX:%08lx ECX:%08lx EDX:%08lx\n" 717 "EDI:%08lx ESI:%08lx EBP:%08lx ESP:%08lx\n" 718 "SS :%08lx EFL:%08lx EIP:%08lx CS:%08lx\n" 719 "DS :%08lx ES :%08lx FS :%08lx GS:%08lx", 720 (unsigned long) uc->uc_mcontext.gregs[11], 721 (unsigned long) uc->uc_mcontext.gregs[8], 722 (unsigned long) uc->uc_mcontext.gregs[10], 723 (unsigned long) uc->uc_mcontext.gregs[9], 724 (unsigned long) uc->uc_mcontext.gregs[4], 725 (unsigned long) uc->uc_mcontext.gregs[5], 726 (unsigned long) uc->uc_mcontext.gregs[6], 727 (unsigned long) uc->uc_mcontext.gregs[7], 728 (unsigned long) uc->uc_mcontext.gregs[18], 729 (unsigned long) uc->uc_mcontext.gregs[17], 730 (unsigned long) uc->uc_mcontext.gregs[14], 731 (unsigned long) uc->uc_mcontext.gregs[15], 732 (unsigned long) uc->uc_mcontext.gregs[3], 733 (unsigned long) uc->uc_mcontext.gregs[2], 734 (unsigned long) uc->uc_mcontext.gregs[1], 735 (unsigned long) uc->uc_mcontext.gregs[0] 736 ); 737 logStackContent((void**)uc->uc_mcontext.gregs[7]); 738 #elif defined(__X86_64__) || defined(__x86_64__) 739 /* Linux AMD64 */ 740 serverLog(LL_WARNING, 741 "\n" 742 "RAX:%016lx RBX:%016lx\nRCX:%016lx RDX:%016lx\n" 743 "RDI:%016lx RSI:%016lx\nRBP:%016lx RSP:%016lx\n" 744 "R8 :%016lx R9 :%016lx\nR10:%016lx R11:%016lx\n" 745 "R12:%016lx R13:%016lx\nR14:%016lx R15:%016lx\n" 746 "RIP:%016lx EFL:%016lx\nCSGSFS:%016lx", 747 (unsigned long) uc->uc_mcontext.gregs[13], 748 (unsigned long) uc->uc_mcontext.gregs[11], 749 (unsigned long) uc->uc_mcontext.gregs[14], 750 (unsigned long) uc->uc_mcontext.gregs[12], 751 (unsigned long) uc->uc_mcontext.gregs[8], 752 (unsigned long) uc->uc_mcontext.gregs[9], 753 (unsigned long) uc->uc_mcontext.gregs[10], 754 (unsigned long) uc->uc_mcontext.gregs[15], 755 (unsigned long) uc->uc_mcontext.gregs[0], 756 (unsigned long) uc->uc_mcontext.gregs[1], 757 (unsigned long) uc->uc_mcontext.gregs[2], 758 (unsigned long) uc->uc_mcontext.gregs[3], 759 (unsigned long) uc->uc_mcontext.gregs[4], 760 (unsigned long) uc->uc_mcontext.gregs[5], 761 (unsigned long) uc->uc_mcontext.gregs[6], 762 (unsigned long) uc->uc_mcontext.gregs[7], 763 (unsigned long) uc->uc_mcontext.gregs[16], 764 (unsigned long) uc->uc_mcontext.gregs[17], 765 (unsigned long) uc->uc_mcontext.gregs[18] 766 ); 767 logStackContent((void**)uc->uc_mcontext.gregs[15]); 768 #endif 769 #else 770 serverLog(LL_WARNING, 771 " Dumping of registers not supported for this OS/arch"); 772 #endif 773 } 774 775 /* Return a file descriptor to write directly to the Redis log with the 776 * write(2) syscall, that can be used in critical sections of the code 777 * where the rest of Redis can't be trusted (for example during the memory 778 * test) or when an API call requires a raw fd. 779 * 780 * Close it with closeDirectLogFiledes(). */ 781 int openDirectLogFiledes(void) { 782 int log_to_stdout = server.logfile[0] == '\0'; 783 int fd = log_to_stdout ? 784 STDOUT_FILENO : 785 open(server.logfile, O_APPEND|O_CREAT|O_WRONLY, 0644); 786 return fd; 787 } 788 789 /* Used to close what closeDirectLogFiledes() returns. */ 790 void closeDirectLogFiledes(int fd) { 791 int log_to_stdout = server.logfile[0] == '\0'; 792 if (!log_to_stdout) close(fd); 793 } 794 795 /* Logs the stack trace using the backtrace() call. This function is designed 796 * to be called from signal handlers safely. */ 797 void logStackTrace(ucontext_t *uc) { 798 void *trace[101]; 799 int trace_size = 0, fd = openDirectLogFiledes(); 800 801 if (fd == -1) return; /* If we can't log there is anything to do. */ 802 803 /* Generate the stack trace */ 804 trace_size = backtrace(trace+1, 100); 805 806 if (getMcontextEip(uc) != NULL) { 807 char *msg1 = "EIP:\n"; 808 char *msg2 = "\nBacktrace:\n"; 809 if (write(fd,msg1,strlen(msg1)) == -1) {/* Avoid warning. */}; 810 trace[0] = getMcontextEip(uc); 811 backtrace_symbols_fd(trace, 1, fd); 812 if (write(fd,msg2,strlen(msg2)) == -1) {/* Avoid warning. */}; 813 } 814 815 /* Write symbols to log file */ 816 backtrace_symbols_fd(trace+1, trace_size, fd); 817 818 /* Cleanup */ 819 closeDirectLogFiledes(fd); 820 } 821 822 /* Log information about the "current" client, that is, the client that is 823 * currently being served by Redis. May be NULL if Redis is not serving a 824 * client right now. */ 825 void logCurrentClient(void) { 826 if (server.current_client == NULL) return; 827 828 client *cc = server.current_client; 829 sds client; 830 int j; 831 832 serverLogRaw(LL_WARNING|LL_RAW, "\n------ CURRENT CLIENT INFO ------\n"); 833 client = catClientInfoString(sdsempty(),cc); 834 serverLog(LL_WARNING|LL_RAW,"%s\n", client); 835 sdsfree(client); 836 for (j = 0; j < cc->argc; j++) { 837 robj *decoded; 838 839 decoded = getDecodedObject(cc->argv[j]); 840 serverLog(LL_WARNING|LL_RAW,"argv[%d]: '%s'\n", j, 841 (char*)decoded->ptr); 842 decrRefCount(decoded); 843 } 844 /* Check if the first argument, usually a key, is found inside the 845 * selected DB, and if so print info about the associated object. */ 846 if (cc->argc >= 1) { 847 robj *val, *key; 848 dictEntry *de; 849 850 key = getDecodedObject(cc->argv[1]); 851 de = dictFind(cc->db->dict, key->ptr); 852 if (de) { 853 val = dictGetVal(de); 854 serverLog(LL_WARNING,"key '%s' found in DB containing the following object:", (char*)key->ptr); 855 serverLogObjectDebugInfo(val); 856 } 857 decrRefCount(key); 858 } 859 } 860 861 #if defined(HAVE_PROC_MAPS) 862 863 #define MEMTEST_MAX_REGIONS 128 864 865 /* A non destructive memory test executed during segfauls. */ 866 int memtest_test_linux_anonymous_maps(void) { 867 FILE *fp; 868 char line[1024]; 869 char logbuf[1024]; 870 size_t start_addr, end_addr, size; 871 size_t start_vect[MEMTEST_MAX_REGIONS]; 872 size_t size_vect[MEMTEST_MAX_REGIONS]; 873 int regions = 0, j; 874 875 int fd = openDirectLogFiledes(); 876 if (!fd) return 0; 877 878 fp = fopen("/proc/self/maps","r"); 879 if (!fp) return 0; 880 while(fgets(line,sizeof(line),fp) != NULL) { 881 char *start, *end, *p = line; 882 883 start = p; 884 p = strchr(p,'-'); 885 if (!p) continue; 886 *p++ = '\0'; 887 end = p; 888 p = strchr(p,' '); 889 if (!p) continue; 890 *p++ = '\0'; 891 if (strstr(p,"stack") || 892 strstr(p,"vdso") || 893 strstr(p,"vsyscall")) continue; 894 if (!strstr(p,"00:00")) continue; 895 if (!strstr(p,"rw")) continue; 896 897 start_addr = strtoul(start,NULL,16); 898 end_addr = strtoul(end,NULL,16); 899 size = end_addr-start_addr; 900 901 start_vect[regions] = start_addr; 902 size_vect[regions] = size; 903 snprintf(logbuf,sizeof(logbuf), 904 "*** Preparing to test memory region %lx (%lu bytes)\n", 905 (unsigned long) start_vect[regions], 906 (unsigned long) size_vect[regions]); 907 if (write(fd,logbuf,strlen(logbuf)) == -1) { /* Nothing to do. */ } 908 regions++; 909 } 910 911 int errors = 0; 912 for (j = 0; j < regions; j++) { 913 if (write(fd,".",1) == -1) { /* Nothing to do. */ } 914 errors += memtest_preserving_test((void*)start_vect[j],size_vect[j],1); 915 if (write(fd, errors ? "E" : "O",1) == -1) { /* Nothing to do. */ } 916 } 917 if (write(fd,"\n",1) == -1) { /* Nothing to do. */ } 918 919 /* NOTE: It is very important to close the file descriptor only now 920 * because closing it before may result into unmapping of some memory 921 * region that we are testing. */ 922 fclose(fp); 923 closeDirectLogFiledes(fd); 924 return errors; 925 } 926 #endif 927 928 void sigsegvHandler(int sig, siginfo_t *info, void *secret) { 929 ucontext_t *uc = (ucontext_t*) secret; 930 void *eip = getMcontextEip(uc); 931 sds infostring, clients; 932 struct sigaction act; 933 UNUSED(info); 934 935 bugReportStart(); 936 serverLog(LL_WARNING, 937 "Redis %s crashed by signal: %d", REDIS_VERSION, sig); 938 if (eip != NULL) { 939 serverLog(LL_WARNING, 940 "Crashed running the instuction at: %p", eip); 941 } 942 if (sig == SIGSEGV || sig == SIGBUS) { 943 serverLog(LL_WARNING, 944 "Accessing address: %p", (void*)info->si_addr); 945 } 946 serverLog(LL_WARNING, 947 "Failed assertion: %s (%s:%d)", server.assert_failed, 948 server.assert_file, server.assert_line); 949 950 /* Log the stack trace */ 951 serverLogRaw(LL_WARNING|LL_RAW, "\n------ STACK TRACE ------\n"); 952 logStackTrace(uc); 953 954 /* Log INFO and CLIENT LIST */ 955 serverLogRaw(LL_WARNING|LL_RAW, "\n------ INFO OUTPUT ------\n"); 956 infostring = genRedisInfoString("all"); 957 infostring = sdscatprintf(infostring, "hash_init_value: %u\n", 958 dictGetHashFunctionSeed()); 959 serverLogRaw(LL_WARNING|LL_RAW, infostring); 960 serverLogRaw(LL_WARNING|LL_RAW, "\n------ CLIENT LIST OUTPUT ------\n"); 961 clients = getAllClientsInfoString(); 962 serverLogRaw(LL_WARNING|LL_RAW, clients); 963 sdsfree(infostring); 964 sdsfree(clients); 965 966 /* Log the current client */ 967 logCurrentClient(); 968 969 /* Log dump of processor registers */ 970 logRegisters(uc); 971 972 #if defined(HAVE_PROC_MAPS) 973 /* Test memory */ 974 serverLogRaw(LL_WARNING|LL_RAW, "\n------ FAST MEMORY TEST ------\n"); 975 bioKillThreads(); 976 if (memtest_test_linux_anonymous_maps()) { 977 serverLogRaw(LL_WARNING|LL_RAW, 978 "!!! MEMORY ERROR DETECTED! Check your memory ASAP !!!"); 979 } else { 980 serverLogRaw(LL_WARNING|LL_RAW, 981 "Fast memory test PASSED, however your memory can still be broken. Please run a memory test for several hours if possible."); 982 } 983 #endif 984 985 serverLogRaw(LL_WARNING|LL_RAW, 986 "\n=== REDIS BUG REPORT END. Make sure to include from START to END. ===\n\n" 987 " Please report the crash by opening an issue on github:\n\n" 988 " http://github.com/antirez/redis/issues\n\n" 989 " Suspect RAM error? Use redis-server --test-memory to verify it.\n\n" 990 ); 991 /* free(messages); Don't call free() with possibly corrupted memory. */ 992 if (server.daemonize && server.supervised == 0) unlink(server.pidfile); 993 994 /* Make sure we exit with the right signal at the end. So for instance 995 * the core will be dumped if enabled. */ 996 sigemptyset (&act.sa_mask); 997 act.sa_flags = SA_NODEFER | SA_ONSTACK | SA_RESETHAND; 998 act.sa_handler = SIG_DFL; 999 sigaction (sig, &act, NULL); 1000 kill(getpid(),sig); 1001 } 1002 #endif /* HAVE_BACKTRACE */ 1003 1004 /* ==================== Logging functions for debugging ===================== */ 1005 1006 void serverLogHexDump(int level, char *descr, void *value, size_t len) { 1007 char buf[65], *b; 1008 unsigned char *v = value; 1009 char charset[] = "0123456789abcdef"; 1010 1011 serverLog(level,"%s (hexdump):", descr); 1012 b = buf; 1013 while(len) { 1014 b[0] = charset[(*v)>>4]; 1015 b[1] = charset[(*v)&0xf]; 1016 b[2] = '\0'; 1017 b += 2; 1018 len--; 1019 v++; 1020 if (b-buf == 64 || len == 0) { 1021 serverLogRaw(level|LL_RAW,buf); 1022 b = buf; 1023 } 1024 } 1025 serverLogRaw(level|LL_RAW,"\n"); 1026 } 1027 1028 /* =========================== Software Watchdog ============================ */ 1029 #include <sys/time.h> 1030 1031 void watchdogSignalHandler(int sig, siginfo_t *info, void *secret) { 1032 #ifdef HAVE_BACKTRACE 1033 ucontext_t *uc = (ucontext_t*) secret; 1034 #endif 1035 UNUSED(info); 1036 UNUSED(sig); 1037 1038 serverLogFromHandler(LL_WARNING,"\n--- WATCHDOG TIMER EXPIRED ---"); 1039 #ifdef HAVE_BACKTRACE 1040 logStackTrace(uc); 1041 #else 1042 serverLogFromHandler(LL_WARNING,"Sorry: no support for backtrace()."); 1043 #endif 1044 serverLogFromHandler(LL_WARNING,"--------\n"); 1045 } 1046 1047 /* Schedule a SIGALRM delivery after the specified period in milliseconds. 1048 * If a timer is already scheduled, this function will re-schedule it to the 1049 * specified time. If period is 0 the current timer is disabled. */ 1050 void watchdogScheduleSignal(int period) { 1051 struct itimerval it; 1052 1053 /* Will stop the timer if period is 0. */ 1054 it.it_value.tv_sec = period/1000; 1055 it.it_value.tv_usec = (period%1000)*1000; 1056 /* Don't automatically restart. */ 1057 it.it_interval.tv_sec = 0; 1058 it.it_interval.tv_usec = 0; 1059 setitimer(ITIMER_REAL, &it, NULL); 1060 } 1061 1062 /* Enable the software watchdog with the specified period in milliseconds. */ 1063 void enableWatchdog(int period) { 1064 int min_period; 1065 1066 if (server.watchdog_period == 0) { 1067 struct sigaction act; 1068 1069 /* Watchdog was actually disabled, so we have to setup the signal 1070 * handler. */ 1071 sigemptyset(&act.sa_mask); 1072 act.sa_flags = SA_ONSTACK | SA_SIGINFO; 1073 act.sa_sigaction = watchdogSignalHandler; 1074 sigaction(SIGALRM, &act, NULL); 1075 } 1076 /* If the configured period is smaller than twice the timer period, it is 1077 * too short for the software watchdog to work reliably. Fix it now 1078 * if needed. */ 1079 min_period = (1000/server.hz)*2; 1080 if (period < min_period) period = min_period; 1081 watchdogScheduleSignal(period); /* Adjust the current timer. */ 1082 server.watchdog_period = period; 1083 } 1084 1085 /* Disable the software watchdog. */ 1086 void disableWatchdog(void) { 1087 struct sigaction act; 1088 if (server.watchdog_period == 0) return; /* Already disabled. */ 1089 watchdogScheduleSignal(0); /* Stop the current timer. */ 1090 1091 /* Set the signal handler to SIG_IGN, this will also remove pending 1092 * signals from the queue. */ 1093 sigemptyset(&act.sa_mask); 1094 act.sa_flags = 0; 1095 act.sa_handler = SIG_IGN; 1096 sigaction(SIGALRM, &act, NULL); 1097 server.watchdog_period = 0; 1098 } 1099