Ubuntu-fr

goug

[Résolu] Recoll, comportement, consommation ressources et iowait

Bonjour, j'utilise l'excellent moteur de recherche recoll depuis quelques mois, je souhaitais savoir si le comportement de recoll est le même chez vous, à savoir la consommation des ressources au démarrage de la session utilisateur.

Recoll est lancé avec "indexation au fil de l'eau" et la première indexation principale a déjà bien eu lieu.

Sur ma machine, à chaque démarrage de session, recoll (en fait recollindex) monopolise les accès disque pendant une bonne trentaine de minutes.
Si je lance glances par exemple, ça donne (classer par I/O rate) :

(impression d'écran)

recollindex lit entre 2Mo/s et 7Mo/s et l'iowait du cpu est entre 45 et 55% ce qui ralentit considérablement les accès disques pour les autres applications (bien que recollindex soit lancé en "nice" et "ionice" avec des priorités minimales)

Si je lance en même temps l'interface graphique recoll, j'ai dans dans la barre d'info en bas de la fenêtre :
indexation en cours : mise à jour <chemin des fichiers>
(<- impression d'écran)

(Question : est-ce normal qu'à ce moment recoll ré-indexe alors qu'il est lancé au démarrage "au fil de l'eau")

puis dans une seconde phase :
indexation en cours : moniteur <chemin des fichiers>
(<- impression d'écran)

Une fois cette phase passée (30 à 40 mn env) tout redevient normal et recollindex redevient transparent.

J'ai déjà vidé la base ~/.recoll/xapiandb/ et relancer la première et longue indexation des docs (3h env), le comportement est le même.

version recoll : Recoll 1.19.14p1 + Xapian 1.2.15
recoll indexe environ 180 000 documents
hdd : 2To hybride seagate, cpu : Intel(R) Core(TM)2 Duo CPU E8400  @ 3.00GHz

Voili, désolé d'être un peu long, merci de me dire si vous avez ce comportement de votre côté, bonne journée !

Dernière modification par goug (Le 16/10/2014, à 21:19)

---

Fai virar leis babolins e leis ideias ! : )

medoc

Re : [Résolu] Recoll, comportement, consommation ressources et iowait

Au moment de son lancement, l'indexeur "fil de l'eau" execute une passe d'indexation incrementale normale, parce qu'il ne peut pas savoir ce qui s'est passe dans les documents pendant qu'il etait arrete (bien sur). Mais normalement, cette passe est un simple parcours du systeme de fichiers, et ne devrait pas prendre enormement de temps et de ressources. Il est possible d'eviter cette phase en utilisant l'option -n en plus de celles qui sont passees normalement (-m sans doute). Ceci permettrait un essai manuel, apres avoir arrete l'indexeur lance automatiquement.

Autrement, la seule facon de savoir ce qu'il fait vraiment est d'activer le journal. Au niveau 4, on devrait avoir une bonne idee de ce qui se passe pendant cette phase (ca peut se parametrer dans les options d'index depuis l'interface graphique).

Le genre de chose qui peut arriver est qu'il decompresse des gros fichiers avant de s'apercevoir qu'il ne peut pas les indexer ou autres du meme genre.

goug

Re : [Résolu] Recoll, comportement, consommation ressources et iowait

Merci beaucoup pour votre réponse.
J'ai activé l'option -n et les logs au niveau 4

Cette fois quand je démarre l'interface graphique de recoll, je n'ai plus dans la barre des taches de la fenêtre :
indexation en cours : mise à jour <chemin des fichiers>
mais directement :
indexation en cours : moniteur <chemin des fichiers> ou tous les fichiers sont parcourus
Cette phase dure environ 15 minutes (donc moitié moins de temps) avec une forte sollicitation du disque et un iowait assez important :
et

Le fichier de log daemrcltrace produit fait 19Mo, les fichiers y sont par bloc de 20, voici un cours extrait :

[ ...]
:4:../rcldb/rcldb.cpp:1777:Db::needUpdate:no: [Q/home/guog/Documents/photos_perso/2013/2013-04-25 photo grand seminaire eps/DSC_0246.JPG|]
:4:../rcldb/rcldb.cpp:1777:Db::needUpdate:no: [Q/home/guog/Documents/photos_perso/2013/2013-11-10_30/DSC_1304.JPG|]
:4:../rcldb/rcldb.cpp:1777:Db::needUpdate:no: [Q/home/guog/Documents/photos_perso/2013/2013-11-10_30/dsc_1177.jpg|]
:3:../rcldb/rcldb.cpp:1682:Db::waitUpdIdle: total xapian work 0 mS
:4:../index/fsindexer.cpp:376:Indexfiles: purging orphans
:3:../rcldb/rcldb.cpp:1682:Db::waitUpdIdle: total xapian work 0 mS
:4:../index/fsindexer.cpp:388:FsIndexer::indexFiles: done
:4:../rcldb/rcldb.cpp:857:Db::i_close(0): m_isopen 1 m_iswritable 1
:3:../rcldb/rcldb.cpp:1682:Db::waitUpdIdle: total xapian work 0 mS
:4:../rcldb/rcldb.cpp:871:Rcl::Db:close: xapian will close. May take some time
:4:../utils/workqueue.h:189:setTerminateAndWait:DbUpd
:4:../utils/workqueue.h:309:WorkQueue:ok:DbUpd: not ok m_ok 0 m_workers_exited 0 m_worker_threads size 1
:4:../utils/workqueue.h:309:WorkQueue:ok:DbUpd: not ok m_ok 0 m_workers_exited 0 m_worker_threads size 1
:4:../utils/workqueue.h:288:workerExit:DbUpd
:3:../utils/workqueue.h:212:DbUpd: tasks 0 nowakes 0 wsleeps 1 csleeps 0
:4:../utils/workqueue.h:231:setTerminateAndWait:DbUpd done
:4:../rcldb/rcldb.cpp:875:Rcl::Db:close() xapian close done.
:4:../internfile/mimehandler.cpp:128:clearMimeHandlerCache()
:4:../rcldb/rcldb.cpp:756:Db::open: m_isopen 0 m_iswritable 0 mode 1
:4:../rcldb/rcldb.cpp:214:RclDb:: threads: haveWriteQ 1, wqlen 2 wqts 1
:4:../rcldb/rcldb.cpp:795:Db::open: lastdocid: 190701
:4:../index/fsindexer.cpp:312:FsIndexer::indexFiles
:4:../rcldb/rcldb.cpp:1777:Db::needUpdate:no: [Q/home/guog/Documents/photos_perso/2013/2013-11-10_30/2013-11-13 16.21.50.jpg|]
:4:../rcldb/rcldb.cpp:1777:Db::needUpdate:no: [Q/home/guog/Documents/photos_perso/2013/2013-11-10_30/2013-11-29 21.31.51.jpg|]
:4:../rcldb/rcldb.cpp:1777:Db::needUpdate:no: [Q/home/guog/Documents/photos_perso/2013/2013-11-10_30/DSC_1283.JPG|]
:4:../rcldb/rcldb.cpp:1777:Db::needUpdate:no: [Q/home/guog/Documents/photos_perso/2013/2013-11-10_30/DSC_1292.JPG|]
:4:../rcldb/rcldb.cpp:1777:Db::needUpdate:no: [Q/home/guog/Documents/photos_perso/2013/2013-11-10_30/DSC_1308.JPG|]
:4:../rcldb/rcldb.cpp:1777:Db::needUpdate:no: [Q/home/guog/Documents/photos_perso/2013/2013-11-10_30/DSC_1306.JPG|]
:4:../rcldb/rcldb.cpp:1777:Db::needUpdate:no: [Q/home/guog/Documents/photos_perso/2013/2013-11-10_30/DSC_1348.JPG|]
:4:../rcldb/rcldb.cpp:1777:Db::needUpdate:no: [Q/home/guog/Documents/photos_perso/2013/2013-11-10_30/DSC_1368.JPG|]
:4:../rcldb/rcldb.cpp:1777:Db::needUpdate:no: [Q/home/guog/Documents/photos_perso/2013/2013-11-10_30/dsc_0898.jpg|]
:4:../rcldb/rcldb.cpp:1777:Db::needUpdate:no: [Q/home/guog/Documents/photos_perso/2013/2013-11-10_30/dsc_0913.jpg|]
:4:../rcldb/rcldb.cpp:1777:Db::needUpdate:no: [Q/home/guog/Documents/photos_perso/2013/2013-11-10_30/dsc_0936.jpg|]
:4:../rcldb/rcldb.cpp:1777:Db::needUpdate:no: [Q/home/guog/Documents/photos_perso/2013/2013-11-10_30/dsc_0952.jpg|]
:4:../rcldb/rcldb.cpp:1777:Db::needUpdate:no: [Q/home/guog/Documents/photos_perso/2013/2013-11-10_30/dsc_0991.jpg|]
:4:../rcldb/rcldb.cpp:1777:Db::needUpdate:no: [Q/home/guog/Documents/photos_perso/2013/2013-11-10_30/dsc_1016.jpg|]
:4:../rcldb/rcldb.cpp:1777:Db::needUpdate:no: [Q/home/guog/Documents/photos_perso/2013/2013-11-10_30/dsc_1021.jpg|]
:4:../rcldb/rcldb.cpp:1777:Db::needUpdate:no: [Q/home/guog/Documents/photos_perso/2013/2013-11-10_30/dsc_1071.jpg|]
:4:../rcldb/rcldb.cpp:1777:Db::needUpdate:no: [Q/home/guog/Documents/photos_perso/2013/2013-11-10_30/dsc_1143 corrigé.jpg|]
:4:../rcldb/rcldb.cpp:1777:Db::needUpdate:no: [Q/home/guog/Documents/photos_perso/2013/2013-11-10_30/dsc_1103.jpg|]
:4:../rcldb/rcldb.cpp:1777:Db::needUpdate:no: [Q/home/guog/Documents/photos_perso/2013/2013-11-10_30/dsc_1163.jpg|]
:4:../rcldb/rcldb.cpp:1777:Db::needUpdate:no: [Q/home/guog/Documents/photos_perso/2013/2013-11-10_30/dsc_1217.jpg|]
:4:../rcldb/rcldb.cpp:1777:Db::needUpdate:no: [Q/home/guog/Documents/photos_perso/2013/2013-11-10_30/dsc_1254.jpg|]
:3:../rcldb/rcldb.cpp:1682:Db::waitUpdIdle: total xapian work 0 mS
:4:../index/fsindexer.cpp:376:Indexfiles: purging orphans
:3:../rcldb/rcldb.cpp:1682:Db::waitUpdIdle: total xapian work 0 mS
:4:../index/fsindexer.cpp:388:FsIndexer::indexFiles: done
:4:../rcldb/rcldb.cpp:857:Db::i_close(0): m_isopen 1 m_iswritable 1
:3:../rcldb/rcldb.cpp:1682:Db::waitUpdIdle: total xapian work 0 mS
:4:../rcldb/rcldb.cpp:871:Rcl::Db:close: xapian will close. May take some time
:4:../utils/workqueue.h:189:setTerminateAndWait:DbUpd
:4:../utils/workqueue.h:309:WorkQueue:ok:DbUpd: not ok m_ok 0 m_workers_exited 0 m_worker_threads size 1
:4:../utils/workqueue.h:309:WorkQueue:ok:DbUpd: not ok m_ok 0 m_workers_exited 0 m_worker_threads size 1
:4:../utils/workqueue.h:288:workerExit:DbUpd
:3:../utils/workqueue.h:212:DbUpd: tasks 0 nowakes 0 wsleeps 1 csleeps 0
:4:../utils/workqueue.h:231:setTerminateAndWait:DbUpd done
:4:../rcldb/rcldb.cpp:875:Rcl::Db:close() xapian close done.
:4:../internfile/mimehandler.cpp:128:clearMimeHandlerCache()
:4:../rcldb/rcldb.cpp:756:Db::open: m_isopen 0 m_iswritable 0 mode 1
:4:../rcldb/rcldb.cpp:214:RclDb:: threads: haveWriteQ 1, wqlen 2 wqts 1
:4:../rcldb/rcldb.cpp:795:Db::open: lastdocid: 190701
:4:../index/fsindexer.cpp:312:FsIndexer::indexFiles
:4:../rcldb/rcldb.cpp:1777:Db::needUpdate:no: [Q/home/guog/Documents/photos_perso/2013/2013-11-10_30/2013-11-07 12.02.27.jpg|]
:4:../rcldb/rcldb.cpp:1777:Db::needUpdate:no: [Q/home/guog/Documents/photos_perso/2013/2013-11-10_30/2013-11-14 19.03.08.jpg|]
:4:../rcldb/rcldb.cpp:1777:Db::needUpdate:no: [Q/home/guog/Documents/photos_perso/2013/2013-11-10_30/DSC_1280.JPG|]
:4:../rcldb/rcldb.cpp:1777:Db::needUpdate:no: [Q/home/guog/Documents/photos_perso/2013/2013-11-10_30/DSC_1289.JPG|]
:4:../rcldb/rcldb.cpp:1777:Db::needUpdate:no: [Q/home/guog/Documents/photos_perso/2013/2013-11-10_30/DSC_1297.JPG|]
[ ... ]

Note : Peut être est-ce le nombre important de fichiers (180 000 fichiers indexés, dont bcp de photo) ? Sur mon portable où j'ai peu de documents, recoll est làcomplètement transparent.

---

Fai virar leis babolins e leis ideias ! : )

medoc

Re : [Résolu] Recoll, comportement, consommation ressources et iowait

J'ai experimente chez moi sur un relativement gros jeu de fichiers: 250.000 fichiers, dont environ 173.049 indexes, produisant 283.000 documents Xapian, stockes sur des disques rotatifs deja anciens, sur une machine core i5 750 avec 12 Go de memoire, donc une machine relativement puissante mais rien d'extraordinaire. L'index produit fait 4.2 Go, le volume de donnees total a l'air de l'ordre de 150 GO, mais c'est sans signification, il y a de tres gros fichiers non indexes probablement.

L'indexation initiale prend 75 mn. Une passe d'indexation incrementale ulterieure (pas ou tres peu de fichiers modifies) prend 43 S, sans effet notable sur le fonctionnement de la machine. La phase initiale de lancement d'un recollindex -n -mw 0 prend environ 1mn, de meme sans impact majeur.

Il y a donc quelque chose de different sur votre systeme...

Je pense qu'il faudrait s'interesser aux fichiers effectivement reindexes. Pour cela monter le niveau de verbosite a 5, et regarder les lignes commencant comme celle qui suit (la partie importante est "processone: processing":

:5:../index/fsindexer.cpp:689:processone: processing: [819 KB ] /y/home/...

Il serait anormal qu'il y en ait beaucoup sur un index suppose a jour, dans ce cas il faudrait regarder pourquoi ces fichiers sont reindexes (erreurs?) et faire quelque chose en fonction des resultats.

L'autre hypothese serait un probleme disque ou systeme de fichiers. Il serait peut-etre interessant d'avoir le temps d'un "find -ls" sur la meme arborescence. L'importance du pourcentage iowait avec un debit de donnees modeste aurait tendance a indiquer que le disque passe beaucoup de temps en "seek".

goug

Re : [Résolu] Recoll, comportement, consommation ressources et iowait

J'ai oublié de mentionner que mon répertoire /home/user est chiffré sous ecryptfs, ceci a peut-être son importance, bien que je ne vois pas le processus associé consommer bcp de ressources cpu qd il y a les sollicitations en début de session.

Je suis reparti de zero, j'ai supprimer mon ~/.recoll, refais une indexation générale (120mn), puis redémarrer la session.
Cette fois les 2 phases indiquées dans la barre des taches de recoll (l'indexation incrémentale sans doute) : indexation en cours : mise à jour <fichiers indexés défilant>, pause d'environ 1mn, puis indexation en cours : moniteur <fichiers indexés défilant> durent environ 10mn chacune, soit 20mn de forte sollicitation du disque après le démarrage de session.
Nb de docs indexés : un peu plus de 170 000 (j'ai supprimé qq dossiers)

Le fichier de log, verbosité 5, fait 70Mo, 650 000 lignes.
Seules 288 occurrences de "processone: processing", (et beaucoup concernent des fichiers audio/vidéos mp4 (?))

Extrait d'un bloc à propos d'un de ces fichiers :

:5:../index/fsindexer.cpp:521:FsIndexerInternfileWorker: task fn /home/guog/Documents/ziq perso/percussions/28012011007.mp4
:4:../rcldb/rcldb.cpp:1772:Db::needUpdate:yes: olsig [133799951410277129+] new [133799951410277129] [Q/home/guog/Documents/ziq perso/percussions/28012011007.mp4|]
:5:../index/fsindexer.cpp:661:processone: processing: [13 MB ] /home/guog/Documents/ziq perso/percussions/28012011007.mp4
:5:../internfile/internfile.cpp:117:FileInterner::FileInterner(fn=/home/guog/Documents/ziq perso/percussions/28012011007.mp4)
:4:../internfile/internfile.cpp:161:FileInterner::init fn [/home/guog/Documents/ziq perso/percussions/28012011007.mp4] mime [(null)] preview 0
:4:../internfile/mimehandler.cpp:249:getMimeHandler: mtype [audio/mp4] filtertypes 1
:4:../internfile/mimehandler.cpp:64:getMimeHandlerFromCache: 148e941113667c071ca8f2e5a79f6a20 cache size 4
:4:../internfile/mimehandler.cpp:77:getMimeHandlerFromCache: 148e941113667c071ca8f2e5a79f6a20 found size 3
:4:../internfile/internfile.cpp:250:FileInterner:: init ok audio/mp4 [/home/guog/Documents/ziq perso/percussions/28012011007.mp4]
:4:../internfile/internfile.cpp:741:FileInterner::internfile. ipath []
:4:../internfile/mh_execm.cpp:152:MimeHandlerExecMultiple::next_document(): [/home/guog/Documents/ziq perso/percussions/28012011007.mp4]
:4:../internfile/mh_execm.cpp:214:MHExecMultiple: got EOFNOW
:4:../internfile/mh_execm.cpp:220:MHExecMultiple: got SUBDOCERROR
:4:../internfile/mh_execm.cpp:90:MHExecMultiple: Got empty line
:2:../internfile/internfile.cpp:736:FileInterner::internfile: next_document error [/home/guog/Documents/ziq perso/percussions/28012011007.mp4] audio/mp4
:4:../internfile/mimehandler.cpp:98:returnMimeHandler: returning filter for audio/mp4 cache size 3
:4:../internfile/internfile.cpp:856:FileInterner::internfile: conversion ended with no doc
:5:../index/fsindexer.cpp:497:FsIndexerDbUpdWorker: task ql 1
:4:../rcldb/rcldb.cpp:1256:Db::add: udi [/home/guog/Documents/ziq perso/percussions/28012011007.mp4|] parent []
:5:../rcldb/rcldb.cpp:1353:Db::add: field [filename] pfx [XSFN] inc 1: [28012011007.mp4]
:5:../rcldb/rcldb.cpp:1569:Rcl::Db::add: new doc record:
url=file:///home/guog/Documents/ziq perso/percussions/28012011007.mp4
mtype=audio/mp4
fmtime=01296244350
origcharset=
fbytes=13379995
pcbytes=13379995
dbytes=0
sig=133799951410277129+
filename=28012011007.mp4

:4:../rcldb/rcldb.cpp:168:DbUpdWorker: got add/update task, ql 1
:3:../rcldb/rcldb.cpp:604:Db::add: docid 77924 updated [/home/guog/Documents/ziq perso/percussions/28012011007.mp4|]

J'ai lancé un find ~/Documents -ls (98% des fichiers indexés y sont) il a fallu presque 7mn pour finir la commande, avec un iowait entre 50 et 55%

Peut-être le disque n'est pas très véloce en lecture ? c'est un SSHD ST2000DX001-1CM1 hybride de Seagate.

Sinon je vais désactiver le lancement au fil de l'eau et lancer l'indexation manuel de temps en temps ... pas de soucis. Merci d'avoir pris le temps de me répondre.

---

Fai virar leis babolins e leis ideias ! : )

medoc

Re : [Résolu] Recoll, comportement, consommation ressources et iowait

Sur mon systeme, sur l'arborescence decrite ci-dessus, le find -ls prend 22 S apres un boot, 2 S pour l'essai suivant, sur des disques 600 GO qui ont au moins 5 ans !

Je pense qu'il y a quelque chose de tout a fait anormal sur votre systeme de disque, mais c'est relativement coherent (sur cette ample statistique ), la passe incrementale prend un petit multiple du temps du find.

Il ne faut pas trop focaliser sur l'iowait d'une maniere generale, ca peut simplement vouloir dire que le systeme n'a rien d'autre a faire.

Pour les audio/mp4 c'est une mauvaise identification, il faut supprimer la ligne .mp4 = audio/mp4 de /usr/share/recoll/mimemap (ca sera dans une prochaine version). Etant pris pour des fichiers audio, le filtre d'extraction des tags genere une erreur, et ils sont reessayes a chaque fois (ca ne cosomme pas enormement de temps normalement)

goug

Re : [Résolu] Recoll, comportement, consommation ressources et iowait

Oui, il y a sans doute des soucis au niveau du disque, et le fait que le dossier soit chiffré comme je le l'indiquais précédemment ne doit pas aider. Merci en tout cas pour ce diagnostic, je relancerai l'indexation manuellement de temps en temps.

---

Fai virar leis babolins e leis ideias ! : )