Débogage D'un programme C (serveur Redis)

Prémisse

Salut,

J'ai reçu plusieurs rapports d'un utilisateur Redis qui a connu des pannes de serveur, en utilisant une version stable de Redis (dernière version, 2.4.6). Le bug est étrange puisque l'utilisateur ne fait pas de choses ésotériques, travaille juste beaucoup avec le type d'ensemble trié, et seulement avec les commandes ZADD, ZREM et ZREVRANK. Cependant, il est étrange qu'un bug comme ça, provoquant des plantages après quelques milliards d'opérations exécutées, ne fut connu que par un seul utilisateur. Heureusement l'utilisateur dans question est extrêmement utile et a beaucoup collaboré dans le suivi de la question, donc j'ai été en mesure d'obtenir plusieurs fois les journaux avec la séquence exacte des opérations effectuées par Redis, que j'ai rejoué localement sans résultat, j'ai également essayé d'écrire des scripts pour imiter étroitement le genre de charge de travail, pour effectuer des examens de code

Même après tous ces efforts aucun moyen de reproduire le problème localement. Il est également intéressant de mentionner qu'à un moment donné l'Utilisateur a commencé à envoyer exactement le même trafic à une autre boîte exécutant la même version de Redis, mais compilée avec un autre gcc, et fonctionnant dans un matériel différent: jusqu'à présent, aucun problème dans cette deuxième instance. Encore je veux comprendre ce qui se passe.

Finalement, j'ai configuré une stratégie différente avec l'utilisateur et lui ai demandé d'exécuter Redis en utilisant gdb, afin d'obtenir un fichier de base. Enfin Redis s'est écrasé à nouveau et j'ai maintenant à la fois le fichier de base et l'exécutable. Malheureusement, j'ai oublié de demander à l'utilisateur de compiler Redis sans optimisations.

J'ai besoin de l'aide de la communauté stack overflow car avec GDB j'arrive à une conclusion mais je n'ai aucune idée de ce qui pourrait se passer ici: à un moment donné, une fonction calcule un pointeur, et quand elle appelle une autre fonction comme par magie, ce pointeur est différent, pointant vers un emplacement de mémoire

Session GDB

L'exécutable d'origine a été compilé avec GCC 4.4.5-8, c'est un GDB session qui montre mon enquête:

gdb ./redis-server core.16525
GNU gdb (GDB) 7.1-ubuntu
[snip]
Program terminated with signal 11, Segmentation fault.
#0  0x00007f3d9ecd216c in __pthread_rwlock_tryrdlock (rwlock=0x1)
    at pthread_rwlock_tryrdlock.c:46
46      pthread_rwlock_tryrdlock.c: No such file or directory.
        in pthread_rwlock_tryrdlock.c

En fait, la trace Strack montrée concerne un thread secondaire ne faisant rien (vous pouvez considérer Redis comme une application à un seul thread, les autres threads ne sont utilisés que pour effectuer des choses comme fsync() contre un descripteur de fichier sans bloquer), sélectionnons le bon.

(gdb) info threads
  3 Thread 16525  zslGetRank (zsl=0x7f3d8d71c360, score=19.498544884710096, 
    o=0x7f3d4cab5760) at t_zset.c:335
  2 Thread 16527  0x00007f3d9ecd216c in __pthread_rwlock_tryrdlock (
    rwlock=0x6b7f5) at pthread_rwlock_tryrdlock.c:46
* 1 Thread 16526  0x00007f3d9ecd216c in __pthread_rwlock_tryrdlock (rwlock=0x1)
    at pthread_rwlock_tryrdlock.c:46
(gdb) thread 3
[Switching to thread 3 (Thread 16525)]#0  zslGetRank (zsl=0x7f3d8d71c360, 
    score=19.498544884710096, o=0x7f3d4cab5760) at t_zset.c:335
335     t_zset.c: No such file or directory.
        in t_zset.c
(gdb) bt
#0  zslGetRank (zsl=0x7f3d8d71c360, score=19.498544884710096, o=0x7f3d4cab5760)
    at t_zset.c:335
#1  0x000000000042818b in zrankGenericCommand (c=0x7f3d9dcdc000, reverse=1)
    at t_zset.c:2046
#2  0x00000000004108d4 in call (c=0x7f3d9dcdc000) at redis.c:1024
#3  0x0000000000410c1c in processCommand (c=0x7f3d9dcdc000) at redis.c:1130
#4  0x0000000000419d3f in processInputBuffer (c=0x7f3d9dcdc000)
    at networking.c:865
#5  0x0000000000419e1c in readQueryFromClient (el=<value optimized out>, 
    fd=<value optimized out>, privdata=0x7f3d9dcdc000, 
    mask=<value optimized out>) at networking.c:908
#6  0x000000000040d4a3 in aeProcessEvents (eventLoop=0x7f3d9dc47000, 
    flags=<value optimized out>) at ae.c:342
#7  0x000000000040d6ee in aeMain (eventLoop=0x7f3d9dc47000) at ae.c:387
#8  0x0000000000412a4f in main (argc=2, argv=<value optimized out>)
    at redis.c:1719

Nous avons également généré un retour en arrière. Comme vous pouvez le voir call () dispatching la commande ZREVRANK, de sorte que le zrankGenericCommand() est appelé avec la structure du client et l'argument reverse = 1 (puisque C'est REV rank). Nous pouvons facilement enquêter pour vérifier quels sont les arguments de la commande ZREVRANK.

(gdb) up
#1  0x000000000042818b in zrankGenericCommand (c=0x7f3d9dcdc000, reverse=1)
    at t_zset.c:2046
2046    in t_zset.c
(gdb) print c->argc
$8 = 3
(gdb) print (redisClient*)c->argc
$9 = (redisClient *) 0x3
(gdb) print (char*)(redisClient*)c->argv[0]->ptr
$10 = 0x7f3d8267ce28 "zrevrank"
(gdb) print (char*)(redisClient*)c->argv[1]->ptr
$11 = 0x7f3d8267ce48 "pc_stat.hkperc"
(gdb) print (long)(redisClient*)c->argv[2]->ptr
$12 = 282472606

Donc, la commande réelle générant le crash était: zrevrank pc_stat.hkperc 282472606 Ceci est cohérent avec les journaux clients obtenus par l'utilisateur. Notez que j'ai converti le pointeur sur un entier long pour le dernier argument, puisque Redis encode des entiers de cette façon pour économiser de la mémoire si possible.

Maintenant c'est bien, il est maintenant temps pour enquêter sur le zrankGenericCommand () qui a appelé zslGetRan () qui a causé le crash réel. C'est le code source C de zrankGenericCommand autour comme 2046:

  2036      } else if (zobj->encoding == REDIS_ENCODING_SKIPLIST) {
  2037          zset *zs = zobj->ptr;
  2038          zskiplist *zsl = zs->zsl;
  2039          dictEntry *de;
  2040          double score;
  2041  
  2042          ele = c->argv[2] = tryObjectEncoding(c->argv[2]);
  2043          de = dictFind(zs->dict,ele);
  2044          if (de != NULL) {
  2045              score = *(double*)dictGetEntryVal(de);
  2046              rank = zslGetRank(zsl,score,ele);
  2047              redisAssert(rank); /* Existing elements always have a rank. */
  2048              if (reverse)
  2049                  addReplyLongLong(c,llen-rank);
  2050              else
  2051                  addReplyLongLong(c,rank-1);
  2052          } else {
  2053              addReply(c,shared.nullbulk);
  2054          }
  2055      }

Ok c'est comme ça que ça marche:

  • Nous recherchons une clé Redis, contenant un type de données set trié (recherche non incluse dans le code). L'objet Redis associé à la clé est stocké dans la variable locale zobj.
  • Le zobj ptr est un pointeur vers une structure de type zset représentant l'ensemble trié.
  • à son tour, la structure zset a deux pointeurs, l'un pointe vers une table de hachage et l'autre vers une liste de saut. Ceci est nécessaire car nous fournissons tous les deux des recherches element-to-score dans O (1) pour lesquelles nous avons besoin d'une table de hachage, mais nous prenons aussi les éléments commandés afin d'utiliser une liste de saut. À la ligne 2038, le pointeur vers la liste de saut (représentée par une structure zskiplist ) est affecté à la variable zsl.
  • plus tard, nous encodons le troisième argument (ligne 2042), c'est pourquoi nous avons converti la valeur en long pour l'imprimer à partir de la structure du client.
  • à la ligne 2043, nous recherchons l'élément à partir du dictionnaire, et l'opération réussit puisque nous savons que la fonction zslgetrank () côté si branche est appelée.
  • enfin à la ligne 2046, nous appelons zslGetRank() avec trois arguments: le pointeur vers la liste de saut, le score de l'élément et l'élément lui-même.

Très bien... maintenant, quelle est la pointeur que zslGetRank() devrait recevoir en théorie? Nous pouvons facilement étudier cela manuellement en recherchant la table de hachage Redis. J'ai haché manuellement la clé et elle correspond au seau 62 de la table de hachage, voyons si c'est vrai:

(gdb) print (char*)c->db->dict->ht->table[62]->key
$13 = 0x7f3d9dc0f6c8 "pc_stat.hkperc"

Exactement comme prévu. Vérifions l'objet associé:

(gdb) print *(robj*)c->db->dict->ht->table[62]->val
$16 = {type = 3, storage = 0, encoding = 7, lru = 557869, refcount = 1, 
  ptr = 0x7f3d9de574b0}

Type = 3, Encoding = 7, cela signifie: c'est un ensemble trié, codé comme une liste de saut. Bien à nouveau. L'adresse réglée triée (champ ptr) est 0x7f3d9de574b0, ainsi nous pouvons inspecter ceci comme Eh bien:

(gdb) print *(zset*)0x7f3d9de574b0
$17 = {dict = 0x7f3d9dcf6c20, zsl = 0x7f3d9de591c0}

Donc nous avons:

  • l'objet associé à la clé qui pointe vers un ensemble trié qui est stocké à l'adresse 0x7f3d9de574b0
  • à son tour, cet ensemble trié est implémenté avec une liste déroulante, à l'adresse 0x7f3d9de591c0 (champ zsl)

Vérifions maintenant si nos deux variables sont définies sur les bonnes valeurs:

2037            zset *zs = zobj->ptr;
2038            zskiplist *zsl = zs->zsl;

(gdb) info locals
zs = 0x7f3d9de574b0
zsl = 0x7f3d9de591c0
de = <value optimized out>
ele = <value optimized out>
zobj = <value optimized out>
llen = 165312
rank = <value optimized out>

Tout est parfait jusqu'à présent: la variable zs est définie sur 0x7f3d9de574b0 comme prévu, tout comme la variable zsl pointant vers la liste de ski, qui est définie sur 0x7f3d9de591c0.

Maintenant, ces variables ne sont pas touchées au cours de l'exécution du code:

Ce sont les seules lignes de code entre l'affectation des variables et l'appel à la zslGetRank fonction ():

2042            ele = c->argv[2] = tryObjectEncoding(c->argv[2]);
2043            de = dictFind(zs->dict,ele);
2044            if (de != NULL) {
2045                score = *(double*)dictGetEntryVal(de);
2046                rank = zslGetRank(zsl,score,ele);

Personne ne touche zsl, cependant si nous vérifions la trace de la pile, nous voyons que la fonction zslGetRank() est appelée non pas avec l'adresse 0x7f3d9de591c0 comme premier argument, mais avec un un autre:

#0  zslGetRank (zsl=0x7f3d8d71c360, score=19.498544884710096, o=0x7f3d4cab5760)
    at t_zset.c:335

Si vous lisez tout cela, vous êtes un héros, et la récompense est très faible, consistant en cette question: Avez-vous une idée, même en considérant que la défaillance matérielle est une option, sur la façon dont cet argument est modifié? Il semble très peu probable que la fonction d'encodage d'objet ou la recherche de table de hachage puissent corrompre la pile de l'appelant (mais apparemment l'argument est déjà dans les registres au moment de l'appel). Mon assembleur n'est pas génial, donc si vous en avez indice... il est très bien accueilli. Je vais vous laisser avec une sortie de registres d'informations et un démonter:

(gdb) info registers
rax            0x6      6
rbx            0x7f3d9dcdc000   139902617239552
rcx            0xf742d0b6       4148351158
rdx            0x7f3d95efada0   139902485245344
rsi            0x7f3d4cab5760   139901256030048
rdi            0x7f3d8d71c360   139902342775648
rbp            0x7f3d4cab5760   0x7f3d4cab5760
rsp            0x7fffe61a8040   0x7fffe61a8040
r8             0x7fffe61a7fd9   140737053884377
r9             0x1      1
r10            0x7f3d9dcd4ff0   139902617210864
r11            0x6      6
r12            0x1      1
r13            0x7f3d9de574b0   139902618793136
r14            0x7f3d9de591c0   139902618800576
r15            0x7f3d8267c9e0   139902157572576
rip            0x42818b 0x42818b <zrankGenericCommand+251>
eflags         0x10206  [ PF IF RF ]
cs             0x33     51
ss             0x2b     43
ds             0x0      0
es             0x0      0
fs             0x0      0
gs             0x0      0
(gdb) disassemble zrankGenericCommand
Dump of assembler code for function zrankGenericCommand:
   0x0000000000428090 <+0>:     mov    %rbx,-0x30(%rsp)
   0x0000000000428095 <+5>:     mov    %r12,-0x20(%rsp)
   0x000000000042809a <+10>:    mov    %esi,%r12d
   0x000000000042809d <+13>:    mov    %r14,-0x10(%rsp)
   0x00000000004280a2 <+18>:    mov    %rbp,-0x28(%rsp)
   0x00000000004280a7 <+23>:    mov    %rdi,%rbx
   0x00000000004280aa <+26>:    mov    %r13,-0x18(%rsp)
   0x00000000004280af <+31>:    mov    %r15,-0x8(%rsp)
   0x00000000004280b4 <+36>:    sub    $0x58,%rsp
   0x00000000004280b8 <+40>:    mov    0x28(%rdi),%rax
   0x00000000004280bc <+44>:    mov    0x23138d(%rip),%rdx        # 0x659450 <shared+80>
   0x00000000004280c3 <+51>:    mov    0x8(%rax),%rsi
   0x00000000004280c7 <+55>:    mov    0x10(%rax),%rbp
   0x00000000004280cb <+59>:    callq  0x41d370 <lookupKeyReadOrReply>
   0x00000000004280d0 <+64>:    test   %rax,%rax
   0x00000000004280d3 <+67>:    mov    %rax,%r14
   0x00000000004280d6 <+70>:    je     0x4280ec <zrankGenericCommand+92>
   0x00000000004280d8 <+72>:    mov    $0x3,%edx
   0x00000000004280dd <+77>:    mov    %rax,%rsi
   0x00000000004280e0 <+80>:    mov    %rbx,%rdi
   0x00000000004280e3 <+83>:    callq  0x41b270 <checkType>
   0x00000000004280e8 <+88>:    test   %eax,%eax
   0x00000000004280ea <+90>:    je     0x428110 <zrankGenericCommand+128>
   0x00000000004280ec <+92>:    mov    0x28(%rsp),%rbx
   0x00000000004280f1 <+97>:    mov    0x30(%rsp),%rbp
   0x00000000004280f6 <+102>:   mov    0x38(%rsp),%r12
   0x00000000004280fb <+107>:   mov    0x40(%rsp),%r13
   0x0000000000428100 <+112>:   mov    0x48(%rsp),%r14
   0x0000000000428105 <+117>:   mov    0x50(%rsp),%r15
   0x000000000042810a <+122>:   add    $0x58,%rsp
   0x000000000042810e <+126>:   retq   
   0x000000000042810f <+127>:   nop
   0x0000000000428110 <+128>:   mov    %r14,%rdi
   0x0000000000428113 <+131>:   callq  0x426250 <zsetLength>
   0x0000000000428118 <+136>:   testw  $0x3c0,0x0(%rbp)
   0x000000000042811e <+142>:   jne    0x4282b7 <zrankGenericCommand+551>
   0x0000000000428124 <+148>:   mov    %eax,%eax
   0x0000000000428126 <+150>:   mov    %rax,0x8(%rsp)
   0x000000000042812b <+155>:   movzwl (%r14),%eax
   0x000000000042812f <+159>:   and    $0x3c0,%ax
   0x0000000000428133 <+163>:   cmp    $0x140,%ax
   0x0000000000428137 <+167>:   je     0x4281c8 <zrankGenericCommand+312>
   0x000000000042813d <+173>:   cmp    $0x1c0,%ax
   0x0000000000428141 <+177>:   jne    0x428299 <zrankGenericCommand+521>
   0x0000000000428147 <+183>:   mov    0x28(%rbx),%r15
   0x000000000042814b <+187>:   mov    0x8(%r14),%r13
   0x000000000042814f <+191>:   mov    0x10(%r15),%rdi
   0x0000000000428153 <+195>:   mov    0x8(%r13),%r14
   0x0000000000428157 <+199>:   callq  0x41bcc0 <tryObjectEncoding>
   0x000000000042815c <+204>:   mov    0x0(%r13),%rdi
   0x0000000000428160 <+208>:   mov    %rax,0x10(%r15)
   0x0000000000428164 <+212>:   mov    %rax,%rsi
   0x0000000000428167 <+215>:   mov    %rax,%rbp
   0x000000000042816a <+218>:   callq  0x40ede0 <dictFind>
   0x000000000042816f <+223>:   test   %rax,%rax
   0x0000000000428172 <+226>:   je     0x428270 <zrankGenericCommand+480>
   0x0000000000428178 <+232>:   mov    0x8(%rax),%rax
   0x000000000042817c <+236>:   mov    %rbp,%rsi
   0x000000000042817f <+239>:   mov    %r14,%rdi
   0x0000000000428182 <+242>:   movsd  (%rax),%xmm0
   0x0000000000428186 <+246>:   callq  0x427fd0 <zslGetRank>
=> 0x000000000042818b <+251>:   test   %rax,%rax
   0x000000000042818e <+254>:   je     0x4282d5 <zrankGenericCommand+581>
   0x0000000000428194 <+260>:   test   %r12d,%r12d
   0x0000000000428197 <+263>:   je     0x4281b0 <zrankGenericCommand+288>
   0x0000000000428199 <+265>:   mov    0x8(%rsp),%rsi
   0x000000000042819e <+270>:   mov    %rbx,%rdi
   0x00000000004281a1 <+273>:   sub    %rax,%rsi
   0x00000000004281a4 <+276>:   callq  0x41a430 <addReplyLongLong>
   0x00000000004281a9 <+281>:   jmpq   0x4280ec <zrankGenericCommand+92>
   0x00000000004281ae <+286>:   xchg   %ax,%ax
   0x00000000004281b0 <+288>:   lea    -0x1(%rax),%rsi
   0x00000000004281b4 <+292>:   mov    %rbx,%rdi
   0x00000000004281b7 <+295>:   callq  0x41a430 <addReplyLongLong>
   0x00000000004281bc <+300>:   nopl   0x0(%rax)
   0x00000000004281c0 <+304>:   jmpq   0x4280ec <zrankGenericCommand+92>
   0x00000000004281c5 <+309>:   nopl   (%rax)
   0x00000000004281c8 <+312>:   mov    0x8(%r14),%r14
   0x00000000004281cc <+316>:   xor    %esi,%esi
   0x00000000004281ce <+318>:   mov    %r14,%rdi
   0x00000000004281d1 <+321>:   callq  0x417600 <ziplistIndex>
   0x00000000004281d6 <+326>:   test   %rax,%rax
   0x00000000004281d9 <+329>:   mov    %rax,0x18(%rsp)
   0x00000000004281de <+334>:   je     0x428311 <zrankGenericCommand+641>
   0x00000000004281e4 <+340>:   mov    %rax,%rsi
   0x00000000004281e7 <+343>:   mov    %r14,%rdi
   0x00000000004281ea <+346>:   callq  0x4175c0 <ziplistNext>
   0x00000000004281ef <+351>:   test   %rax,%rax
   0x00000000004281f2 <+354>:   mov    %rax,0x10(%rsp)
   0x00000000004281f7 <+359>:   je     0x4282f3 <zrankGenericCommand+611>
   0x00000000004281fd <+365>:   mov    0x18(%rsp),%rdi
   0x0000000000428202 <+370>:   mov    $0x1,%r13d
   0x0000000000428208 <+376>:   lea    0x10(%rsp),%r15
   0x000000000042820d <+381>:   test   %rdi,%rdi
   0x0000000000428210 <+384>:   jne    0x428236 <zrankGenericCommand+422>
   0x0000000000428212 <+386>:   jmp    0x428270 <zrankGenericCommand+480>
   0x0000000000428214 <+388>:   nopl   0x0(%rax)
   0x0000000000428218 <+392>:   lea    0x18(%rsp),%rsi
   0x000000000042821d <+397>:   mov    %r14,%rdi
   0x0000000000428220 <+400>:   mov    %r15,%rdx
   0x0000000000428223 <+403>:   callq  0x425610 <zzlNext>
   0x0000000000428228 <+408>:   mov    0x18(%rsp),%rdi
   0x000000000042822d <+413>:   test   %rdi,%rdi
   0x0000000000428230 <+416>:   je     0x428270 <zrankGenericCommand+480>
   0x0000000000428232 <+418>:   add    $0x1,%r13
   0x0000000000428236 <+422>:   mov    0x8(%rbp),%rsi
   0x000000000042823a <+426>:   movslq -0x8(%rsi),%rdx
   0x000000000042823e <+430>:   callq  0x417a40 <ziplistCompare>
   0x0000000000428243 <+435>:   test   %eax,%eax
   0x0000000000428245 <+437>:   je     0x428218 <zrankGenericCommand+392>
   0x0000000000428247 <+439>:   cmpq   $0x0,0x18(%rsp)
   0x000000000042824d <+445>:   je     0x428270 <zrankGenericCommand+480>
   0x000000000042824f <+447>:   test   %r12d,%r12d
   0x0000000000428252 <+450>:   je     0x428288 <zrankGenericCommand+504>
   0x0000000000428254 <+452>:   mov    0x8(%rsp),%rsi
   0x0000000000428259 <+457>:   mov    %rbx,%rdi
   0x000000000042825c <+460>:   sub    %r13,%rsi
   0x000000000042825f <+463>:   callq  0x41a430 <addReplyLongLong>
   0x0000000000428264 <+468>:   jmpq   0x4280ec <zrankGenericCommand+92>
   0x0000000000428269 <+473>:   nopl   0x0(%rax)
   0x0000000000428270 <+480>:   mov    0x2311d9(%rip),%rsi        # 0x659450 <shared+80>
   0x0000000000428277 <+487>:   mov    %rbx,%rdi
   0x000000000042827a <+490>:   callq  0x419f60 <addReply>
   0x000000000042827f <+495>:   jmpq   0x4280ec <zrankGenericCommand+92>
   0x0000000000428284 <+500>:   nopl   0x0(%rax)
   0x0000000000428288 <+504>:   lea    -0x1(%r13),%rsi
   0x000000000042828c <+508>:   mov    %rbx,%rdi
   0x000000000042828f <+511>:   callq  0x41a430 <addReplyLongLong>
   0x0000000000428294 <+516>:   jmpq   0x4280ec <zrankGenericCommand+92>
   0x0000000000428299 <+521>:   mov    $0x44939f,%edi
   0x000000000042829e <+526>:   mov    $0x808,%edx
   0x00000000004282a3 <+531>:   mov    $0x44a674,%esi
   0x00000000004282a8 <+536>:   callq  0x432010 <_redisPanic>
   0x00000000004282ad <+541>:   mov    $0x1,%edi
   0x00000000004282b2 <+546>:   callq  0x40c3a0 <_exit@plt>
   0x00000000004282b7 <+551>:   mov    $0x44a7d0,%edi
   0x00000000004282bc <+556>:   mov    $0x7da,%edx
   0x00000000004282c1 <+561>:   mov    $0x44a674,%esi
   0x00000000004282c6 <+566>:   callq  0x432090 <_redisAssert>
   0x00000000004282cb <+571>:   mov    $0x1,%edi
   0x00000000004282d0 <+576>:   callq  0x40c3a0 <_exit@plt>
   0x00000000004282d5 <+581>:   mov    $0x448982,%edi
   0x00000000004282da <+586>:   mov    $0x7ff,%edx
   0x00000000004282df <+591>:   mov    $0x44a674,%esi
   0x00000000004282e4 <+596>:   callq  0x432090 <_redisAssert>
   0x00000000004282e9 <+601>:   mov    $0x1,%edi
   0x00000000004282ee <+606>:   callq  0x40c3a0 <_exit@plt>
   0x00000000004282f3 <+611>:   mov    $0x44a6e5,%edi
   0x00000000004282f8 <+616>:   mov    $0x7e2,%edx
   0x00000000004282fd <+621>:   mov    $0x44a674,%esi
   0x0000000000428302 <+626>:   callq  0x432090 <_redisAssert>
   0x0000000000428307 <+631>:   mov    $0x1,%edi
   0x000000000042830c <+636>:   callq  0x40c3a0 <_exit@plt>
   0x0000000000428311 <+641>:   mov    $0x44a6bd,%edi
   0x0000000000428316 <+646>:   mov    $0x7e0,%edx
   0x000000000042831b <+651>:   mov    $0x44a674,%esi
   0x0000000000428320 <+656>:   callq  0x432090 <_redisAssert>
   0x0000000000428325 <+661>:   mov    $0x1,%edi
   0x000000000042832a <+666>:   callq  0x40c3a0 <_exit@plt>
   End of assembler dump.

Comme demandé, c'est la fonction tryObjectEncoding:

/* Try to encode a string object in order to save space */
robj *tryObjectEncoding(robj *o) {
    long value;
    sds s = o->ptr;

    if (o->encoding != REDIS_ENCODING_RAW)
        return o; /* Already encoded */

    /* It's not safe to encode shared objects: shared objects can be shared
     * everywhere in the "object space" of Redis. Encoded objects can only
     * appear as "values" (and not, for instance, as keys) */
     if (o->refcount > 1) return o;

    /* Currently we try to encode only strings */
    redisAssert(o->type == REDIS_STRING);

    /* Check if we can represent this string as a long integer */
    if (!string2l(s,sdslen(s),&value)) return o;

    /* Ok, this object can be encoded...
     *
     * Can I use a shared object? Only if the object is inside a given
     * range and if this is the main thread, since when VM is enabled we
     * have the constraint that I/O thread should only handle non-shared
     * objects, in order to avoid race conditions (we don't have per-object
     * locking).
     *
     * Note that we also avoid using shared integers when maxmemory is used
     * because very object needs to have a private LRU field for the LRU
     * algorithm to work well. */
    if (server.maxmemory == 0 && value >= 0 && value < REDIS_SHARED_INTEGERS &&
        pthread_equal(pthread_self(),server.mainthread)) {
        decrRefCount(o);
        incrRefCount(shared.integers[value]);
        return shared.integers[value];
    } else {
        o->encoding = REDIS_ENCODING_INT;
        sdsfree(o->ptr);
        o->ptr = (void*) value;
        return o;
    }
}
24
demandé sur antirez 2012-01-18 18:33:56

5 réponses

Je pense que je peux répondre à ma propre question maintenant...

Fondamentalement, c'est ce qui se passe. zslGetRank () est appelé par zrankGenericCommand() avec le premier argument dans le registre %rdi. Cependant, plus tard, cette fonction utilisera le registre % rdi pour définir un objet (et en effet le registre %RDI est défini sur un objet valide):

(gdb) print *(robj*)0x7f3d8d71c360
$1 = {type = 0, storage = 0, encoding = 1, lru = 517611, refcount = 2, 
ptr = 0x1524db19}

Le pointeur d'instruction pointait en fait vers zslGetRank + 64 au moment du crash, j'ai fait quelque chose de mal avec gdb et modifié le Registre avant de poster le question originale.

Aussi comment vérifier que zslGetRank () obtient la bonne adresse comme premier argument? Parce que %r14 est enregistré sur la pile par zslGetRank() afin que nous puissions inspecter la pile pour vérifier s'il y a un bon emplacement. Nous vidons donc près du pointeur de pile:

0x7fffe61a8000: 0x40337fa0a3376aff      0x00007f3d9dcdc000
0x7fffe61a8010: 0x00007f3d9dcdc000      0x00007f3d4cab5760
0x7fffe61a8020: 0x0000000000000001      0x00007f3d9de574b0
---> 0x7fffe61a8030: 0x00007f3d9de591c0      0x000000000042818b
0x7fffe61a8040: 0x0000000000000000      0x00000000000285c0
0x7fffe61a8050: 0x0000000000000000      0x00007f3d9dcdc000
0x7fffe61a8060: 0x0000000000000000      0x00007f3d9dcdc000
0x7fffe61a8070: 0x0000000000000000      0x0004b6b413e12d9a
0x7fffe61a8080: 0x00000000000003d8      0x0000000000000001

Comme vous pouvez le voir, la bonne adresse est ici dans la pile.

Bref, la fonction est appelée avec la bonne adresse, c'est juste que gdb ne peut pas vider la bonne trace de pile parce que le registre %rdi est modifié et utilisé pour une autre chose à l'intérieur de la fonction.

Donc, cela peut être une chose de corruption de mémoire, peut-être. Ce que je vais faire maintenant est de marcher l'ensemble trié à la main simulant le travail de zslGetRank() afin que je puisse isoler le nœud qui est cassé, et vérifier, espérons-le, de quelle manière il est corrompu.

Merci pour votre aide.

Edit: ici vous pouvez trouver une version désassemblée annotée manuellement de la fonction zslGetRank () - > https://gist.github.com/1641112 (j'ai utilisé à la fois pour apprendre un peu plus d'assembleur et pour rendre mon inspection plus simple).

10
répondu antirez 2012-01-19 17:18:23

Dans cette situation, la première chose que je vais faire, est d'utiliser valgrind. L'inconvénient est que valgrind est environ x10 Plus lent que l'exécution native, et il peut changer le comportement car il semble sérialiser les threads. Mais il me sauver tant de fois !

De toute façon concernant ce crash, il se produit dans le thread 3, le pthread_rwlock_tryrdlock () reçoit un mauvais pointeur (rwlock est 0x1). C'est peut-être une corruption de mémoire causée par d'autres threads. Si c'est possible, essayez de mettre une "montre" sur ce pi

J'espère que ça aide.

1
répondu rafal98 2012-01-18 16:08:58

C'est un longshot à une supposition intuitive, mais la seule chose que je pourrais voir causer cette erreur est l'affectation aux pointeurs à la ligne 2042:

2042   ele = c->argv[2] = tryObjectEncoding(c->argv[2]);

J'espère que cela aide

0
répondu Lloyd Moore 2012-01-18 14:50:59

Pouvez-vous ajouter le désassemblage pour zslGetRank ?

Si vous regardez l'autre, r14 a la bonne valeur et rdi a la mauvaise valeur mais juste avant l'appel il y a un "mov r14, rdi" donc vraisemblablement zslGetRank a été appelé avec les valeurs correctes.

0
répondu Raffaele 2012-01-18 15:54:28

Mise à jour: la RAM dans cette boîte était cassée, nous avons trouvé beaucoup de problèmes dans la RAM de l'utilisateur après celui-ci, et maintenant Redis implémente même une option --test-memory... Grâce.

0
répondu antirez 2012-04-04 22:25:35