Pourquoi le curseur de disponibilité de MongoDB est-il connecté aussi lent?

Question

J'utilise un curseur disponible pour lire une collection de traces (http://docs.mongodb.org/manual/tutorial/create-tailable-cursor). Cela semble fonctionner très bien, mais j'obtenir les requêtes lentes suivantes enregistrées:

Tue Jan 15 17:54:37 [conn28] getmore trace.traces query: { time: { $gte: new Date(1358254406370) } } cursorid:7095190436798608732 reslen:20 2268ms 
Tue Jan 15 17:54:38 [conn28] getmore trace.traces query: { time: { $gte: new Date(1358254406370) } } cursorid:7095190436798608732 nreturned:1 reslen:513 315ms 
Tue Jan 15 17:54:39 [conn28] getmore trace.traces query: { time: { $gte: new Date(1358254406370) } } cursorid:7095190436798608732 nreturned:2 reslen:1800 962ms 
Tue Jan 15 17:54:41 [conn28] getmore trace.traces query: { time: { $gte: new Date(1358254406370) } } cursorid:7095190436798608732 reslen:20 2268ms 
Tue Jan 15 17:54:43 [conn28] getmore trace.traces query: { time: { $gte: new Date(1358254406370) } } cursorid:7095190436798608732 reslen:20 2283ms 

La ligne continue à être connecté toutes les quelques secondes, même lorsqu'ils ne sont pas écrit à la collecte du tout. J'utilise Mongo 2.0.8 (et le Java Driver 2.10.1). Je l'ai également essayé sur Mongo 2.2.2, mais ici il n'est pas connecté (même avec --profile 2), cependant, je le vois toujours dans la collection system.profile.

Est-ce que quelqu'un sait pourquoi cette requête est (signalée comme) lente?

Voici le profil info:

> db.system.profile.find().limit(1).sort({ millis : -1 }).pretty() 
{ 
    "ts" : ISODate("2013-01-15T17:33:48.354Z"), 
    "op" : "getmore", 
    "ns" : "trace.traces", 
    "query" : { 
      "time" : { 
        "$gte" : ISODate("2013-01-15T12:56:57.589Z") 
      } 
    }, 
    "cursorid" : NumberLong("8205177764687670896"), 
    "ntoreturn" : 0, 
    "keyUpdates" : 0, 
    "numYield" : 0, 
    "lockStats" : { 
      "timeLockedMicros" : { 
        "r" : NumberLong(30492), 
        "w" : NumberLong(0) 
      }, 
      "timeAcquiringMicros" : { 
        "r" : NumberLong(22499), 
        "w" : NumberLong(3) 
      } 
    }, 
    "nreturned" : 0, 
    "responseLength" : 20, 
    "millis" : 2356, 
    "client" : "127.0.0.1", 
    "user" : "" 
} 

Voici les statistiques de la collection:

> db.traces.stats() 
{ 
    "ns" : "trace.traces", 
    "count" : 41897, 
    "size" : 51760464, 
    "avgObjSize" : 1235.4217247058261, 
    "storageSize" : 52432896, 
    "numExtents" : 1, 
    "nindexes" : 1, 
    "lastExtentSize" : 52432896, 
    "paddingFactor" : 1, 
    "systemFlags" : 1, 
    "userFlags" : 0, 
    "totalIndexSize" : 1422624, 
    "indexSizes" : { 
      "_id_" : 1422624 
    }, 
    "capped" : true, 
    "max" : 2147483647, 
    "ok" : 1 
} 

Answer 1

Je pense que vos blocs de curseur attendent de nouveaux documents quand il n'y a pas de documents disponibles. Voir que les requêtes lentes ont tous reslen:20. Cela ressemble à un comportement normal pour moi.