bm-plugin-core-ldap-import erreur sur timeout

couturie · February 17, 2014, 1:42pm

Bonjour,

Je n’arrive pas a importer des comptes ldap. Le test de connexion dans le menu de configuration du plugin fonctionne bien, mais toute tentative d’import retourne:

17 févr. 2014 14:36:34 - INFO - Import LDAP global pour le domaine : ipno.in2p3.fr
17 févr. 2014 14:36:34 - INFO - Import de l’annuaire LDAP en utilisant le scanner: MemberUidLdapScanner
17 févr. 2014 14:37:34 - ERROR - erreur serveur reçue: TimeOut occurred
17 févr. 2014 14:37:34 - ERROR - Tâche stoppée par une exception: org.apache.directory.shared.ldap.model.exception.LdapException: TimeOut occurred
17 févr. 2014 14:37:34 - PROGRESS - #progress 100

Auriez vous une idée? (BM Version 3.0 - 2.1.11531 sous debian 7.4)

Merci. Bien cordialement.

Toony · February 17, 2014, 3:07pm

Arrivez-vous à contacter votre annuaire LDAP avec la commande ldapsearch depuis le serveur BlueMind ?

couturie · February 17, 2014, 3:34pm

Oui après avoir installé apt-get install ldap-utils.

Faut il configurer le fichier /etc/ldap/ldap.conf? Je n’y ai pas touché; j’ai juste renseigné mon serveur ldap, sa racine et mes filtres dans la page web de configuration BM.

Toony · February 17, 2014, 3:51pm

Non, il n’y a pas besoin de configurer autre chose que ce qui est demandé dans la console d’administration.

Pouvez-vous nous envoyer le fichier de log de bm-core /var/log/bm/core.log ?

couturie · February 17, 2014, 4:15pm

Ce fichier de log est tres bavard (>1000 lignes en 5mn).
Ci dessous un extrait:

2014-02-17 16:06:00,024 n.b.c.j.i.JobHome INFO - Loaded 1 jobs from database.
2014-02-17 16:06:00,024 n.b.c.s.m.MemorySessionStoreFactory INFO - MQ: logout c55cbec0-cfe1-4cae-8255-c0f231bad082 sent.
2014-02-17 16:06:00,027 n.b.c.s.m.MemorySessionStoreFactory INFO - MQ: logout 1dc0ecc7-edaa-4803-a08a-d2fb4016870a sent.
2014-02-17 16:06:00,029 n.b.c.j.i.JobBindingImpl INFO - getJobFromId net.bluemind.job.mailindex.MailspoolIndexJob
2014-02-17 16:06:00,029 n.b.c.j.i.JobHome INFO - Loaded 0 jobs from database.
2014-02-17 16:06:00,030 n.b.c.s.m.MemorySessionStoreFactory INFO - MQ: logout fa9387d9-6e09-4a8f-a566-79f016984adc sent.
2014-02-17 16:06:00,033 n.b.c.s.m.MemorySessionStoreFactory INFO - MQ: logout a0cafae7-e98f-42b4-8ea5-4e79fd3b58a0 sent.
2014-02-17 16:06:00,034 n.b.c.j.i.JobBindingImpl INFO - getJobFromId net.bluemind.job.mailindex.ArchiveSpoolIndexJob
2014-02-17 16:06:00,034 n.b.c.j.i.JobHome INFO - Loaded 0 jobs from database.
2014-02-17 16:06:00,035 n.b.c.s.m.MemorySessionStoreFactory INFO - MQ: logout 714ca87c-ae20-4e37-b3b8-bd49255365c6 sent.
2014-02-17 16:06:00,038 n.b.c.s.m.MemorySessionStoreFactory INFO - MQ: logout c1c614e5-2776-4350-8026-d303cde800cb sent.
2014-02-17 16:06:00,039 n.b.c.j.i.JobBindingImpl INFO - getJobFromId Vacation
2014-02-17 16:06:00,040 n.b.c.j.i.JobHome INFO - Loaded 1 jobs from database.
2014-02-17 16:06:00,040 n.b.c.s.m.MemorySessionStoreFactory INFO - MQ: logout a77791fd-f468-4314-a4a3-54cc7fd28a2c sent.
2014-02-17 16:06:00,043 n.b.c.s.m.MemorySessionStoreFactory INFO - MQ: logout 2bbe35ec-5e30-4894-a585-9accb21e36ea sent.
2014-02-17 16:06:00,044 n.b.c.j.i.JobBindingImpl INFO - getJobFromId EventAlert
2014-02-17 16:06:00,045 n.b.c.j.i.JobHome INFO - Loaded 1 jobs from database.
2014-02-17 16:06:00,046 n.b.c.s.m.MemorySessionStoreFactory INFO - MQ: logout 694be552-7e16-4ed0-bd84-25ec9668b261 sent.
2014-02-17 16:06:00,049 n.b.c.s.m.MemorySessionStoreFactory INFO - MQ: logout 654a97dd-39ce-4530-84ea-4e840bd2e6c3 sent.
2014-02-17 16:06:00,050 n.b.c.j.i.JobBindingImpl INFO - getJobFromId net.bluemind.archive.core.ArchiveJob
2014-02-17 16:06:00,050 n.b.c.j.i.JobHome INFO - Loaded 0 jobs from database.
2014-02-17 16:06:00,051 n.b.c.s.m.MemorySessionStoreFactory INFO - MQ: logout 3aa965a3-9a95-4b92-b12c-4debf5a2b02c sent.
2014-02-17 16:06:00,054 n.b.c.s.m.MemorySessionStoreFactory INFO - MQ: logout 6d26ac73-c6fc-48a7-abb1-82716e01d156 sent.
2014-02-17 16:06:00,055 n.b.c.j.i.JobBindingImpl INFO - getJobFromId net.bluemind.dataprotect.core.DataProtectJob
2014-02-17 16:06:00,056 n.b.c.j.i.JobHome INFO - Loaded 0 jobs from database.
2014-02-17 16:06:00,056 n.b.c.s.m.MemorySessionStoreFactory INFO - MQ: logout 4ee93807-c729-414d-af9d-8ee3e12fcc19 sent.
2014-02-17 16:06:00,059 n.b.c.s.m.MemorySessionStoreFactory INFO - MQ: logout 55b70b39-d96b-45eb-8251-9fdf24c96957 sent.
2014-02-17 16:06:00,060 n.b.c.j.i.JobBindingImpl INFO - getJobFromId ImportLdapJob
2014-02-17 16:06:00,061 n.b.c.j.i.JobHome INFO - Loaded 2 jobs from database.
2014-02-17 16:06:00,062 n.b.c.s.m.MemorySessionStoreFactory INFO - MQ: logout 3956ddff-981c-4faa-ad7a-86ecb0a6f2a5 sent.
2014-02-17 16:06:00,065 n.b.c.s.m.MemorySessionStoreFactory INFO - MQ: logout 3626ec07-0529-4bed-b541-7f1f37538127 sent.
2014-02-17 16:06:00,066 n.b.c.j.i.JobBindingImpl INFO - getJobFromId net.bluemind.core.jobs.quota.QuotaGatheringJob
2014-02-17 16:06:00,067 n.b.c.j.i.JobHome INFO - Loaded 0 jobs from database.
2014-02-17 16:06:00,068 n.b.c.s.m.MemorySessionStoreFactory INFO - MQ: logout d024fbb7-5d3d-4ed6-9b8e-a9a9437ec361 sent.
2014-02-17 16:06:00,887 n.b.c.UserManagement INFO - Accepting token as password for admin0@global.virt in bm-hps-ping
2014-02-17 16:06:00,888 n.b.c.s.SyncServlet INFO - handler responded to login/validate in 1ms.
2014-02-17 16:06:00,894 n.b.c.j.i.JobBindingImpl INFO - getLiveLogs offset: 3
2014-02-17 16:06:00,894 n.b.c.j.i.JobBindingImpl INFO - entries.size: 4
2014-02-17 16:06:00,894 n.b.c.j.i.JobBindingImpl INFO - Adding entry Import LDAP directory using scanner: MemberUidLdapScanner
2014-02-17 16:06:00,895 n.b.c.s.SyncServlet INFO - handler responded to job/liveLogs in 2ms.
2014-02-17 16:06:03,943 n.b.c.j.i.JobBindingImpl INFO - getLiveLogs offset: 3
2014-02-17 16:06:03,943 n.b.c.j.i.JobBindingImpl INFO - entries.size: 4
2014-02-17 16:06:03,943 n.b.c.j.i.JobBindingImpl INFO - Adding entry Import LDAP directory using scanner: MemberUidLdapScanner
2014-02-17 16:06:03,944 n.b.c.s.SyncServlet INFO - handler responded to job/liveLogs in 3ms.
2014-02-17 16:06:06,469 n.b.s.l.i.s.LdapScanner ERROR - error occurred: TimeOut occurred
org.apache.directory.shared.ldap.model.exception.LdapException: TimeOut occurred
        at org.apache.directory.ldap.client.api.SearchCursorImpl.next(SearchCursorImpl.java:131) ~[na:na]
        at net.bluemind.system.ldap.importation.scanner.MemberInGroupDescLdapScanner.manageUsersFromCursor(MemberInGroupDescLdapScanner.java:217) ~[net.bluemind.system.ldap.importation.scanner_1.0.0.b11531.jar:na]
        at net.bluemind.system.ldap.importation.scanner.MemberInGroupDescLdapScanner.scanUsers(MemberInGroupDescLdapScanner.java:211) ~[net.bluemind.system.ldap.importation.scanner_1.0.0.b11531.jar:na]
        at net.bluemind.system.ldap.importation.scanner.MemberInGroupDescLdapScanner.scanLdap(MemberInGroupDescLdapScanner.java:135) ~[net.bluemind.system.ldap.importation.scanner_1.0.0.b11531.jar:na]
        at net.bluemind.system.ldap.importation.hooks.ImportLdapJob.tick(ImportLdapJob.java:124) [net.bluemind.system.ldap.importation_1.0.0.b11531.jar:na]
        at net.bluemind.core.jobs.impl.JobTicker.run(JobTicker.java:66) [net.bluemind.core_1.0.0.b11531.jar:na]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [na:1.7.0_51]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [na:1.7.0_51]
        at java.lang.Thread.run(Thread.java:744) [na:1.7.0_51]
2014-02-17 16:06:06,469 n.b.c.j.i.Scheduler ERROR - [ImportLdapJob-in2p3.fr-1392653106424] [en] => server fault received: TimeOut occurred
2014-02-17 16:06:06,469 n.b.c.j.i.Scheduler ERROR - [ImportLdapJob-in2p3.fr-1392653106424] [fr] => erreur serveur reçue: TimeOut occurred
2014-02-17 16:06:06,469 n.b.s.l.i.h.ImportLdapJob ERROR - LDAP import serverfault: org.apache.directory.shared.ldap.model.exception.LdapException: TimeOut occurred (UNKNOWN)
2014-02-17 16:06:06,469 n.b.c.s.m.MemorySessionStoreFactory INFO - MQ: logout 412eb73d-95e5-4c1b-9160-36449273b43e sent.
2014-02-17 16:06:06,472 n.b.c.j.i.JobTicker ERROR - org.apache.directory.shared.ldap.model.exception.LdapException: TimeOut occurred
net.bluemind.core.api.fault.ServerFault: org.apache.directory.shared.ldap.model.exception.LdapException: TimeOut occurred
        at net.bluemind.system.ldap.importation.scanner.MemberInGroupDescLdapScanner.scanLdap(MemberInGroupDescLdapScanner.java:155) ~[na:na]
        at net.bluemind.system.ldap.importation.hooks.ImportLdapJob.tick(ImportLdapJob.java:124) ~[na:na]
        at net.bluemind.core.jobs.impl.JobTicker.run(JobTicker.java:66) ~[na:na]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [na:1.7.0_51]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [na:1.7.0_51]
        at java.lang.Thread.run(Thread.java:744) [na:1.7.0_51]
Caused by: org.apache.directory.shared.ldap.model.exception.LdapException: TimeOut occurred
        at org.apache.directory.ldap.client.api.SearchCursorImpl.next(SearchCursorImpl.java:131) ~[na:na]
        at net.bluemind.system.ldap.importation.scanner.MemberInGroupDescLdapScanner.manageUsersFromCursor(MemberInGroupDescLdapScanner.java:217) ~[na:na]
        at net.bluemind.system.ldap.importation.scanner.MemberInGroupDescLdapScanner.scanUsers(MemberInGroupDescLdapScanner.java:211) ~[na:na]
        at net.bluemind.system.ldap.importation.scanner.MemberInGroupDescLdapScanner.scanLdap(MemberInGroupDescLdapScanner.java:135) ~[na:na]
        ... 5 common frames omitted
2014-02-17 16:06:06,473 n.b.c.j.i.Scheduler ERROR - [ImportLdapJob-in2p3.fr-1392653106424] [en] => Job halted by exception: org.apache.directory.shared.ldap.model.exception.LdapException: TimeOut occurred
2014-02-17 16:06:06,473 n.b.c.j.i.Scheduler ERROR - [ImportLdapJob-in2p3.fr-1392653106424] [fr] => Tâche stoppée par une exception: org.apache.directory.shared.ldap.model.exception.LdapException: TimeOut occurred
2014-02-17 16:06:06,473 n.b.c.j.i.Scheduler INFO - Finishing ImportLdapJob-in2p3.fr-1392653106424
2014-02-17 16:06:06,473 n.b.c.j.i.Scheduler ERROR - finish with FAILURE status called from here
java.lang.Throwable: sched.finish(FAILURE)
        at net.bluemind.core.jobs.impl.Scheduler.finish(Scheduler.java:142) ~[net.bluemind.core_1.0.0.b11531.jar:na]
        at net.bluemind.core.jobs.impl.JobTicker.finishIfNeeded(JobTicker.java:90) [net.bluemind.core_1.0.0.b11531.jar:na]
        at net.bluemind.core.jobs.impl.JobTicker.run(JobTicker.java:74) [net.bluemind.core_1.0.0.b11531.jar:na]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [na:1.7.0_51]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [na:1.7.0_51]
        at java.lang.Thread.run(Thread.java:744) [na:1.7.0_51]
2014-02-17 16:06:06,473 n.b.c.j.i.Scheduler INFO - [ImportLdapJob-in2p3.fr-1392653106424] progress is now 100%.
2014-02-17 16:06:06,474 n.b.c.j.i.ExecutionRecorder INFO - recording execution of ImportLdapJob-in2p3.fr-1392653106424
2014-02-17 16:06:06,475 n.b.c.j.i.JobHome INFO - recording execution for ImportLdapJob-in2p3.fr-1392653106424...
2014-02-17 16:06:06,476 n.b.c.j.i.JobHome INFO - run plan for ImportLdapJob@in2p3.fr updated with last_run set to id 968 (start: Mon Feb 17 16:05:06 GMT 2014)
2014-02-17 16:06:06,476 n.b.c.j.i.JobHome INFO - saving 9 entries...
2014-02-17 16:06:06,478 n.b.c.j.i.Scheduler INFO - [ImportLdapJob-in2p3.fr-1392653106424] finished and recorded: FAILURE, duration: 60049ms.
2014-02-17 16:06:06,481 n.b.c.j.i.Scheduler INFO - Finishing net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1392653160025
2014-02-17 16:06:06,481 n.b.c.j.i.Scheduler INFO - [net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1392653160025] progress is now 100%.
2014-02-17 16:06:06,481 n.b.c.j.i.ExecutionRecorder INFO - recording execution of net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1392653160025
2014-02-17 16:06:06,481 n.b.c.j.i.JobHome INFO - recording execution for net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1392653160025...
2014-02-17 16:06:06,482 n.b.c.j.i.JobHome INFO - run plan for net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob@global.virt updated with last_run set to id 969 (start: Mon Feb 17 16:06:00 GMT 2014)
2014-02-17 16:06:06,482 n.b.c.j.i.JobHome INFO - saving 7 entries...
2014-02-17 16:06:06,484 n.b.c.j.i.Scheduler INFO - [net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1392653160025] finished and recorded: SUCCESS, duration: 6456ms.
2014-02-17 16:06:06,484 n.b.c.j.i.Scheduler INFO - Finishing net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1392653160025
2014-02-17 16:06:06,484 n.b.j.m.MailspoolIndexJob INFO - Not planned.
2014-02-17 16:06:06,484 n.b.j.m.ArchiveSpoolIndexJob INFO - Not planned.
2014-02-17 16:06:06,487 n.b.c.s.m.MemorySessionStoreFactory INFO - MQ: logout 62a66452-0cdd-46df-bd25-92210738678a sent.
2014-02-17 16:06:06,488 n.b.c.j.i.Scheduler INFO - Finishing Vacation-global.virt-1392653160041
2014-02-17 16:06:06,488 n.b.c.j.i.Scheduler INFO - [Vacation-global.virt-1392653160041] progress is now 100%.
2014-02-17 16:06:06,491 n.b.c.s.m.MemorySessionStoreFactory INFO - MQ: logout d05f3e62-6804-4419-94d9-bd59bfb5bc5f sent.
2014-02-17 16:06:06,492 n.b.c.j.i.Scheduler INFO - Finishing EventAlert-global.virt-1392653160046
2014-02-17 16:06:06,492 n.b.c.j.i.Scheduler INFO - [EventAlert-global.virt-1392653160046] progress is now 100%.
2014-02-17 16:06:06,492 n.b.a.c.ArchiveJob INFO - not forced, last run was 8911secs ago.
2014-02-17 16:06:06,492 n.b.a.c.ArchiveJob INFO - less than one day ago, skipping execution.
2014-02-17 16:06:06,492 n.b.a.c.ArchiveJob INFO - not forced, last run was 8911secs ago.
2014-02-17 16:06:06,492 n.b.a.c.ArchiveJob INFO - less than one day ago, skipping execution.
2014-02-17 16:06:06,492 n.b.d.c.DataProtectJob INFO - not planned, last run was 9002secs ago.
2014-02-17 16:06:06,492 n.b.d.c.DataProtectJob INFO - less than one day ago, skipping execution.
2014-02-17 16:06:06,492 n.b.c.j.q.QuotaGatheringJob INFO - not forced, last run was 9002secs ago.
2014-02-17 16:06:06,492 n.b.c.j.q.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2014-02-17 16:06:06,492 n.b.c.j.q.QuotaGatheringJob INFO - not forced, last run was 9002secs ago.
2014-02-17 16:06:06,492 n.b.c.j.q.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2014-02-17 16:06:06,990 n.b.c.j.i.JobBindingImpl INFO - getLiveLogs offset: 3
2014-02-17 16:06:06,990 n.b.c.j.i.JobBindingImpl INFO - entries.size: 9
2014-02-17 16:06:06,990 n.b.c.j.i.JobBindingImpl INFO - Adding entry Import LDAP directory using scanner: MemberUidLdapScanner
2014-02-17 16:06:06,990 n.b.c.j.i.JobBindingImpl INFO - Adding entry server fault received: TimeOut occurred
2014-02-17 16:06:06,990 n.b.c.j.i.JobBindingImpl INFO - Adding entry erreur serveur reçue: TimeOut occurred
2014-02-17 16:06:06,990 n.b.c.j.i.JobBindingImpl INFO - Adding entry Job halted by exception: org.apache.directory.shared.ldap.model.exception.LdapException: TimeOut occurred
2014-02-17 16:06:06,990 n.b.c.j.i.JobBindingImpl INFO - Adding entry Tâche stoppée par une exception: org.apache.directory.shared.ldap.model.exception.LdapException: TimeOut occurred
2014-02-17 16:06:06,990 n.b.c.j.i.JobBindingImpl INFO - Adding entry #progress 100
2014-02-17 16:06:06,991 n.b.c.s.SyncServlet INFO - handler responded to job/liveLogs in 3ms.
2014-02-17 16:06:10,041 n.b.c.j.i.JobBindingImpl INFO - getLiveLogs offset: 9
2014-02-17 16:06:10,041 n.b.c.j.i.JobBindingImpl INFO - entries.size: 9
2014-02-17 16:06:10,042 n.b.c.s.SyncServlet INFO - handler responded to job/liveLogs in 2ms.
2014-02-17 16:06:12,479 n.b.c.j.i.ExecutionRecorder INFO - recording execution of Vacation-global.virt-1392653160041
2014-02-17 16:06:12,479 n.b.c.j.i.JobHome INFO - recording execution for Vacation-global.virt-1392653160041...
2014-02-17 16:06:12,480 n.b.c.j.i.JobHome INFO - run plan for Vacation@global.virt updated with last_run set to id 970 (start: Mon Feb 17 16:06:00 GMT 2014)
2014-02-17 16:06:12,481 n.b.c.j.i.JobHome INFO - saving 3 entries...
2014-02-17 16:06:12,482 n.b.c.j.i.Scheduler INFO - [Vacation-global.virt-1392653160041] finished and recorded: SUCCESS, duration: 6447ms.
2014-02-17 16:06:12,484 n.b.c.j.i.ExecutionRecorder INFO - recording execution of EventAlert-global.virt-1392653160046
2014-02-17 16:06:12,485 n.b.c.j.i.JobHome INFO - recording execution for EventAlert-global.virt-1392653160046...
2014-02-17 16:06:12,486 n.b.c.j.i.JobHome INFO - run plan for EventAlert@global.virt updated with last_run set to id 971 (start: Mon Feb 17 16:06:00 GMT 2014)
2014-02-17 16:06:12,486 n.b.c.j.i.JobHome INFO - saving 3 entries...
2014-02-17 16:06:12,487 n.b.c.j.i.Scheduler INFO - [EventAlert-global.virt-1392653160046] finished and recorded: SUCCESS, duration: 6446ms.
2014-02-17 16:06:13,092 n.b.c.j.i.JobBindingImpl INFO - getLiveLogs offset: 9
2014-02-17 16:06:13,092 n.b.c.s.SyncServlet WARN - sending ServerFault: Job finished

Toony · February 26, 2014, 6:41pm

Quel est le serveur LDAP que vous utilisez ? A-t-il un paramètre comme idletimeout positionné (ce dernier peut-être lié à l’utilisateur avec lequel vous vous connecté à l’annuaire) ?

Nous n’avons pas de limite sur la requête LDAP côté client à priori.