Pus accès a Bluemind 3

isys-online · February 29, 2016, 1:38pm

Bonjour,

J’ai installé BM3 il y a quelques semaines, cela fonctionnais parfaitement.

En revanche ce matin, je ne pouvais plus me connecter avec mes identifiants utilisateurs et admin.

J’ai redémarré le serveur et depuis page blanche et plus rien ne réponds. Mon serveur ping bien et les services BM démarres et redemarres bien.

Quelqu’un aurait une idée ?

Merci

franck

Poustiquet · February 29, 2016, 10:26pm

Bonjour

que donne la commande :

bmctl restart

En cas d’erreur, ils s’afficheront principalement dans le fichier de log /var/log/bm./core.log

isys-online · March 2, 2016, 9:41am

tout les services redémarres sans erreur

Toony · March 2, 2016, 9:58am

Tout fonctionne correctement maintenant ?
Avez-vous essayez un nouveau re-démarrage du serveur ?

isys-online · March 2, 2016, 10:15am

oui aussi,

j’ai pas d’erreur non plus au demarrage

isys-online · March 2, 2016, 11:12am

on peut pas joindr ele fichier log sur le forum ?

isys-online · March 2, 2016, 11:14am

j’ai eventuellement ca dans le log :

java.lang.NullPointerException: null
	at net.bluemind.core.utils.TokenHelper.createToken(TokenHelper.java:85) ~[net.bluemind.core_1.0.0.b13439.jar:na]
	at net.bluemind.core.utils.TokenHelper.createToken(TokenHelper.java:53) ~[net.bluemind.core_1.0.0.b13439.jar:na]
	at net.bluemind.core.jobs.impl.JobRunner.getRelevantDomains(JobRunner.java:150) ~[net.bluemind.core_1.0.0.b13439.jar:na]
	at net.bluemind.core.jobs.impl.JobRunner.run(JobRunner.java:68) ~[net.bluemind.core_1.0.0.b13439.jar:na]
	at net.bluemind.core.jobs.JobRegistry$1.run(JobRegistry.java:101) [net.bluemind.core_1.0.0.b13439.jar:na]
	at java.util.TimerThread.mainLoop(Timer.java:555) [na:1.7.0_60]
	at java.util.TimerThread.run(Timer.java:505) [na:1.7.0_60]
2016-03-02 10:42:03,327 [Timer-2] net.bluemind.pool.xa.impl.ConnectionProxy ERROR - Could not recycle connection to the database. Retrying in 2 seconds...
2016-03-02 10:42:05,339 [Timer-2] net.bluemind.pool.xa.impl.ConnectionProxy ERROR - Could not recycle connection to the database. Retrying in 2 seconds...
2016-03-02 10:42:07,266 [Timer-3] net.bluemind.pool.xa.impl.ConnectionPool ERROR - pingMutex: could not grab lock.
2016-03-02 10:42:07,268 [Timer-3] net.bluemind.pool.Pool ERROR - Error getting SQL connection to database

Toony · March 2, 2016, 11:29am

Les heures de ces logs correspondent au démarrage qui a échoué ?

Ils semblent indiquer que le core n’a pas réussi a joindre postgres lors de ce démarrage. Peut-être postgres a été plus long à démarrer qu’habituellement - suite a un crash, il fait un check de sa base, ce qui peut entraîner un temps plus long avant qu’il ne se mette en écoute sur le réseau.

isys-online · March 2, 2016, 11:33am

ca pourrais correspondre au redemarrage mais il y a beaucoup de lignes que je ne sais décoder

il ne me remet plus ces lignes en fin de fichier de LOG et je n’ai toujours pas d’accès web;

2016-03-02 10:57:00,140 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 10:57:00,140 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 299secs ago.
2016-03-02 10:57:00,141 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 10:57:00,141 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 299secs ago.
2016-03-02 10:57:00,141 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 10:57:00,141 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 299secs ago.
2016-03-02 10:57:00,141 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 10:57:00,141 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 299secs ago.
2016-03-02 10:57:00,141 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 10:57:00,141 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 299secs ago.
2016-03-02 10:57:00,141 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 10:57:00,148 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.dataprotect.core.DataProtectJob
2016-03-02 10:57:00,150 [pool-5-thread-4] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing EventAlert-global.virt-1456916220120
2016-03-02 10:57:00,150 [pool-5-thread-4] net.bluemind.core.jobs.impl.Scheduler INFO - [EventAlert-global.virt-1456916220120] progress is now 100%.
2016-03-02 10:57:00,150 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 10:57:00,151 [pool-5-thread-1] net.bluemind.dataprotect.core.DataProtectJob INFO - not planned, last run was 337secs ago.
2016-03-02 10:57:00,151 [pool-5-thread-1] net.bluemind.dataprotect.core.DataProtectJob INFO - less than one day ago, skipping execution.
2016-03-02 10:57:00,162 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.core.jobs.quota.QuotaGatheringJob
2016-03-02 10:57:00,164 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 10:57:00,164 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 337secs ago.
2016-03-02 10:57:00,164 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 337secs ago.
2016-03-02 10:57:00,164 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 10:57:00,164 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 10:57:00,165 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 337secs ago.
2016-03-02 10:57:00,165 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 10:57:00,165 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 337secs ago.
2016-03-02 10:57:00,165 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 10:57:00,165 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 337secs ago.
2016-03-02 10:57:00,165 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 10:57:00,165 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 337secs ago.
2016-03-02 10:57:00,165 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 10:57:00,165 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 337secs ago.
2016-03-02 10:57:00,165 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 10:57:00,165 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 337secs ago.
2016-03-02 10:57:00,165 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 10:57:00,165 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 337secs ago.
2016-03-02 10:57:00,165 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 10:57:00,165 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 337secs ago.
2016-03-02 10:57:00,165 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 10:57:00,166 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 337secs ago.
2016-03-02 10:57:00,166 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 10:57:06,087 [pool-4-thread-1] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for EventBoundariesJob
2016-03-02 10:57:06,087 [pool-4-thread-1] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of Vacation-global.virt-1456916220108
2016-03-02 10:57:06,089 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for Vacation-global.virt-1456916220108...
2016-03-02 10:57:06,095 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - run plan for Vacation@global.virt updated with last_run set to id 3403203 (start: Wed Mar 02 10:57:00 GMT 2016)
2016-03-02 10:57:06,095 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - saving 3 entries...
2016-03-02 10:57:06,098 [pool-4-thread-2] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for Vacation
2016-03-02 10:57:06,098 [pool-4-thread-2] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of EventAlert-global.virt-1456916220120
2016-03-02 10:57:06,101 [pool-4-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - [Vacation-global.virt-1456916220108] finished and recorded: SUCCESS, duration: 10ms.
2016-03-02 10:57:06,102 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for EventAlert-global.virt-1456916220120...
2016-03-02 10:57:06,108 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - run plan for EventAlert@global.virt updated with last_run set to id 3403204 (start: Wed Mar 02 10:57:00 GMT 2016)
2016-03-02 10:57:06,108 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - saving 3 entries...
2016-03-02 10:57:06,115 [pool-4-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - [EventAlert-global.virt-1456916220120] finished and recorded: SUCCESS, duration: 30ms.
2016-03-02 10:57:12,104 [pool-4-thread-1] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for EventAlert
2016-03-02 10:58:00,019 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob
2016-03-02 10:58:00,024 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 10:58:00,039 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.mailindex.MailspoolIndexJob
2016-03-02 10:58:00,040 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 10:58:00,041 [pool-5-thread-4] net.bluemind.job.mailindex.MailspoolIndexJob INFO - Not planned.
2016-03-02 10:58:00,048 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId EventBoundariesJob
2016-03-02 10:58:00,050 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 10:58:00,064 [pool-5-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing EventBoundariesJob-global.virt-1456916280051
2016-03-02 10:58:00,064 [pool-5-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - [EventBoundariesJob-global.virt-1456916280051] progress is now 100%.
2016-03-02 10:58:00,065 [pool-4-thread-1] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of EventBoundariesJob-global.virt-1456916280051
2016-03-02 10:58:00,066 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for EventBoundariesJob-global.virt-1456916280051...
2016-03-02 10:58:00,067 [pool-4-thread-2] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for EventBoundariesJob
2016-03-02 10:58:00,068 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.contactindex.ContactIndexJob
2016-03-02 10:58:00,069 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 0 jobs from database.
2016-03-02 10:58:00,070 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - run plan for EventBoundariesJob@global.virt updated with last_run set to id 3403205 (start: Wed Mar 02 10:58:00 GMT 2016)
2016-03-02 10:58:00,070 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - saving 1 entries...
2016-03-02 10:58:00,070 [pool-5-thread-1] net.bluemind.job.contactindex.ContactIndexJob INFO - Not planned.
2016-03-02 10:58:00,076 [pool-5-thread-3] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916280031
2016-03-02 10:58:00,076 [pool-5-thread-3] net.bluemind.core.jobs.impl.Scheduler INFO - [net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916280031] progress is now 100%.
2016-03-02 10:58:00,076 [pool-4-thread-2] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916280031
2016-03-02 10:58:00,077 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.mailindex.MailspoolResyncIndexJob
2016-03-02 10:58:00,077 [pool-4-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - [EventBoundariesJob-global.virt-1456916280051] finished and recorded: SUCCESS, duration: 13ms.
2016-03-02 10:58:00,077 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916280031...
2016-03-02 10:58:00,079 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 0 jobs from database.
2016-03-02 10:58:00,079 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - run plan for net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob@global.virt updated with last_run set to id 3403206 (start: Wed Mar 02 10:58:00 GMT 2016)
2016-03-02 10:58:00,080 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - saving 9 entries...
2016-03-02 10:58:00,080 [pool-5-thread-4] net.bluemind.job.mailindex.MailspoolResyncIndexJob INFO - Not planned.
2016-03-02 10:58:00,083 [pool-4-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - [net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916280031] finished and recorded: SUCCESS, duration: 45ms.
2016-03-02 10:58:00,087 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.calendarindex.CalendarIndexJob
2016-03-02 10:58:00,088 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 0 jobs from database.
2016-03-02 10:58:00,089 [pool-5-thread-2] net.bluemind.job.calendarindex.CalendarIndexJob INFO - Not planned.
2016-03-02 10:58:00,095 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.mailindex.ArchiveSpoolIndexJob
2016-03-02 10:58:00,097 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 10:58:00,098 [pool-5-thread-1] net.bluemind.job.mailindex.ArchiveSpoolIndexJob INFO - Not planned.
2016-03-02 10:58:00,103 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId Vacation
2016-03-02 10:58:00,104 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 10:58:00,112 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId EventAlert
2016-03-02 10:58:00,113 [pool-5-thread-3] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing Vacation-global.virt-1456916280105
2016-03-02 10:58:00,113 [pool-5-thread-3] net.bluemind.core.jobs.impl.Scheduler INFO - [Vacation-global.virt-1456916280105] progress is now 100%.
2016-03-02 10:58:00,113 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 10:58:00,127 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.archive.core.ArchiveJob
2016-03-02 10:58:00,130 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 11 jobs from database.
2016-03-02 10:58:00,132 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 359secs ago.
2016-03-02 10:58:00,132 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 10:58:00,132 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 359secs ago.
2016-03-02 10:58:00,132 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 10:58:00,132 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 359secs ago.
2016-03-02 10:58:00,132 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 10:58:00,132 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 359secs ago.
2016-03-02 10:58:00,132 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 10:58:00,132 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 359secs ago.
2016-03-02 10:58:00,132 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 10:58:00,132 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 359secs ago.
2016-03-02 10:58:00,132 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 10:58:00,132 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 359secs ago.
2016-03-02 10:58:00,132 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 10:58:00,132 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 359secs ago.
2016-03-02 10:58:00,132 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 10:58:00,132 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 359secs ago.
2016-03-02 10:58:00,132 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 10:58:00,133 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 359secs ago.
2016-03-02 10:58:00,133 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 10:58:00,133 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 359secs ago.
2016-03-02 10:58:00,133 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 10:58:00,140 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.dataprotect.core.DataProtectJob
2016-03-02 10:58:00,142 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 10:58:00,142 [pool-5-thread-4] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing EventAlert-global.virt-1456916280114
2016-03-02 10:58:00,142 [pool-5-thread-4] net.bluemind.core.jobs.impl.Scheduler INFO - [EventAlert-global.virt-1456916280114] progress is now 100%.
2016-03-02 10:58:00,143 [pool-5-thread-2] net.bluemind.dataprotect.core.DataProtectJob INFO - not planned, last run was 397secs ago.
2016-03-02 10:58:00,143 [pool-5-thread-2] net.bluemind.dataprotect.core.DataProtectJob INFO - less than one day ago, skipping execution.
2016-03-02 10:58:00,153 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.core.jobs.quota.QuotaGatheringJob
2016-03-02 10:58:00,155 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 10:58:00,156 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 397secs ago.
2016-03-02 10:58:00,156 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 10:58:00,156 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 397secs ago.
2016-03-02 10:58:00,156 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 10:58:00,157 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 397secs ago.
2016-03-02 10:58:00,157 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 10:58:00,157 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 397secs ago.
2016-03-02 10:58:00,157 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 10:58:00,157 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 397secs ago.
2016-03-02 10:58:00,157 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 10:58:00,157 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 397secs ago.
2016-03-02 10:58:00,157 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 10:58:00,157 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 397secs ago.
2016-03-02 10:58:00,157 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 10:58:00,157 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 397secs ago.
2016-03-02 10:58:00,157 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 10:58:00,157 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 397secs ago.
2016-03-02 10:58:00,157 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 10:58:00,157 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 397secs ago.
2016-03-02 10:58:00,157 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 10:58:00,157 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 397secs ago.
2016-03-02 10:58:00,157 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 10:58:06,079 [pool-4-thread-1] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob
2016-03-02 10:58:06,080 [pool-4-thread-1] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of Vacation-global.virt-1456916280105
2016-03-02 10:58:06,081 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for Vacation-global.virt-1456916280105...
2016-03-02 10:58:06,085 [pool-4-thread-2] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for Vacation
2016-03-02 10:58:06,085 [pool-4-thread-2] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of EventAlert-global.virt-1456916280114
2016-03-02 10:58:06,085 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - run plan for Vacation@global.virt updated with last_run set to id 3403207 (start: Wed Mar 02 10:58:00 GMT 2016)
2016-03-02 10:58:06,085 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - saving 3 entries...
2016-03-02 10:58:06,087 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for EventAlert-global.virt-1456916280114...
2016-03-02 10:58:06,090 [pool-4-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - [Vacation-global.virt-1456916280105] finished and recorded: SUCCESS, duration: 8ms.
2016-03-02 10:58:06,092 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - run plan for EventAlert@global.virt updated with last_run set to id 3403208 (start: Wed Mar 02 10:58:00 GMT 2016)
2016-03-02 10:58:06,092 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - saving 3 entries...
2016-03-02 10:58:06,097 [pool-4-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - [EventAlert-global.virt-1456916280114] finished and recorded: SUCCESS, duration: 28ms.
2016-03-02 10:58:12,094 [pool-4-thread-1] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for EventAlert
2016-03-02 10:59:00,020 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob
2016-03-02 10:59:00,022 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 10:59:00,038 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.mailindex.MailspoolIndexJob
2016-03-02 10:59:00,040 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 10:59:00,040 [pool-5-thread-3] net.bluemind.job.mailindex.MailspoolIndexJob INFO - Not planned.
2016-03-02 10:59:00,046 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId EventBoundariesJob
2016-03-02 10:59:00,047 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 10:59:00,061 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.contactindex.ContactIndexJob
2016-03-02 10:59:00,062 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 0 jobs from database.
2016-03-02 10:59:00,063 [pool-5-thread-2] net.bluemind.job.contactindex.ContactIndexJob INFO - Not planned.
2016-03-02 10:59:00,067 [pool-5-thread-4] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing EventBoundariesJob-global.virt-1456916340048
2016-03-02 10:59:00,067 [pool-5-thread-4] net.bluemind.core.jobs.impl.Scheduler INFO - [EventBoundariesJob-global.virt-1456916340048] progress is now 100%.
2016-03-02 10:59:00,067 [pool-4-thread-1] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of EventBoundariesJob-global.virt-1456916340048
2016-03-02 10:59:00,067 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for EventBoundariesJob-global.virt-1456916340048...
2016-03-02 10:59:00,068 [pool-4-thread-2] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for EventBoundariesJob
2016-03-02 10:59:00,069 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - run plan for EventBoundariesJob@global.virt updated with last_run set to id 3403209 (start: Wed Mar 02 10:59:00 GMT 2016)
2016-03-02 10:59:00,070 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - saving 1 entries...
2016-03-02 10:59:00,070 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.mailindex.MailspoolResyncIndexJob
2016-03-02 10:59:00,071 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 0 jobs from database.
2016-03-02 10:59:00,072 [pool-5-thread-3] net.bluemind.job.mailindex.MailspoolResyncIndexJob INFO - Not planned.
2016-03-02 10:59:00,072 [pool-4-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - [EventBoundariesJob-global.virt-1456916340048] finished and recorded: SUCCESS, duration: 19ms.
2016-03-02 10:59:00,077 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.calendarindex.CalendarIndexJob
2016-03-02 10:59:00,079 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 0 jobs from database.
2016-03-02 10:59:00,080 [pool-5-thread-2] net.bluemind.job.calendarindex.CalendarIndexJob INFO - Not planned.
2016-03-02 10:59:00,082 [pool-5-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916340022
2016-03-02 10:59:00,083 [pool-5-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - [net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916340022] progress is now 100%.
2016-03-02 10:59:00,083 [pool-4-thread-2] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916340022
2016-03-02 10:59:00,083 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916340022...
2016-03-02 10:59:00,084 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.mailindex.ArchiveSpoolIndexJob
2016-03-02 10:59:00,085 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - run plan for net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob@global.virt updated with last_run set to id 3403210 (start: Wed Mar 02 10:59:00 GMT 2016)
2016-03-02 10:59:00,086 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - saving 9 entries...
2016-03-02 10:59:00,086 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 10:59:00,086 [pool-5-thread-4] net.bluemind.job.mailindex.ArchiveSpoolIndexJob INFO - Not planned.
2016-03-02 10:59:00,089 [pool-4-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - [net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916340022] finished and recorded: SUCCESS, duration: 61ms.
2016-03-02 10:59:00,091 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId Vacation
2016-03-02 10:59:00,093 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 10:59:00,099 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId EventAlert
2016-03-02 10:59:00,100 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 10:59:00,104 [pool-5-thread-3] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing Vacation-global.virt-1456916340093
2016-03-02 10:59:00,104 [pool-5-thread-3] net.bluemind.core.jobs.impl.Scheduler INFO - [Vacation-global.virt-1456916340093] progress is now 100%.
2016-03-02 10:59:00,112 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.archive.core.ArchiveJob
2016-03-02 10:59:00,114 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 11 jobs from database.
2016-03-02 10:59:00,115 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 419secs ago.
2016-03-02 10:59:00,115 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 10:59:00,115 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 419secs ago.
2016-03-02 10:59:00,115 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 419secs ago.
2016-03-02 10:59:00,115 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 10:59:00,115 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 10:59:00,115 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 419secs ago.
2016-03-02 10:59:00,115 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 10:59:00,115 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 419secs ago.
2016-03-02 10:59:00,115 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 10:59:00,115 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 419secs ago.
2016-03-02 10:59:00,115 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 10:59:00,116 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 419secs ago.
2016-03-02 10:59:00,116 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 10:59:00,116 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 419secs ago.
2016-03-02 10:59:00,116 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 10:59:00,116 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 419secs ago.
2016-03-02 10:59:00,116 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 10:59:00,116 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 419secs ago.
2016-03-02 10:59:00,116 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 10:59:00,116 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 419secs ago.
2016-03-02 10:59:00,116 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 10:59:00,120 [pool-5-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing EventAlert-global.virt-1456916340101
2016-03-02 10:59:00,120 [pool-5-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - [EventAlert-global.virt-1456916340101] progress is now 100%.
2016-03-02 10:59:00,122 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.dataprotect.core.DataProtectJob
2016-03-02 10:59:00,123 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 10:59:00,124 [pool-5-thread-1] net.bluemind.dataprotect.core.DataProtectJob INFO - not planned, last run was 457secs ago.
2016-03-02 10:59:00,124 [pool-5-thread-1] net.bluemind.dataprotect.core.DataProtectJob INFO - less than one day ago, skipping execution.
2016-03-02 10:59:00,133 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.core.jobs.quota.QuotaGatheringJob
2016-03-02 10:59:00,136 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 10:59:00,137 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 457secs ago.
2016-03-02 10:59:00,137 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 10:59:00,137 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 457secs ago.
2016-03-02 10:59:00,137 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 457secs ago.
2016-03-02 10:59:00,137 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 10:59:00,137 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 457secs ago.
2016-03-02 10:59:00,137 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 10:59:00,137 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 10:59:00,137 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 457secs ago.
2016-03-02 10:59:00,137 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 10:59:00,137 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 457secs ago.
2016-03-02 10:59:00,137 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 457secs ago.
2016-03-02 10:59:00,137 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 10:59:00,137 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 10:59:00,137 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 457secs ago.
2016-03-02 10:59:00,137 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 10:59:00,137 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 457secs ago.
2016-03-02 10:59:00,137 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 457secs ago.
2016-03-02 10:59:00,137 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 10:59:00,137 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 10:59:00,137 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 457secs ago.
2016-03-02 10:59:00,137 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 10:59:06,074 [pool-4-thread-1] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob
2016-03-02 10:59:06,074 [pool-4-thread-1] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of Vacation-global.virt-1456916340093
2016-03-02 10:59:06,076 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for Vacation-global.virt-1456916340093...
2016-03-02 10:59:06,080 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - run plan for Vacation@global.virt updated with last_run set to id 3403211 (start: Wed Mar 02 10:59:00 GMT 2016)
2016-03-02 10:59:06,080 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - saving 3 entries...
2016-03-02 10:59:06,085 [pool-4-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - [Vacation-global.virt-1456916340093] finished and recorded: SUCCESS, duration: 11ms.
2016-03-02 10:59:06,091 [pool-4-thread-2] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for Vacation
2016-03-02 10:59:06,091 [pool-4-thread-2] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of EventAlert-global.virt-1456916340101
2016-03-02 10:59:06,093 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for EventAlert-global.virt-1456916340101...
2016-03-02 10:59:06,097 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - run plan for EventAlert@global.virt updated with last_run set to id 3403212 (start: Wed Mar 02 10:59:00 GMT 2016)
2016-03-02 10:59:06,097 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - saving 3 entries...
2016-03-02 10:59:06,101 [pool-4-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - [EventAlert-global.virt-1456916340101] finished and recorded: SUCCESS, duration: 19ms.
2016-03-02 10:59:12,087 [pool-4-thread-1] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for EventAlert
2016-03-02 10:59:35,747 [vert.x-worker-thread-0] net.bluemind.core.UserManagement INFO - UserManagement.validate: access refused to login: 'island' domain: 'global.virt', auth type: BM DB, origin: ysnp
2016-03-02 10:59:35,750 [vert.x-eventloop-thread-3] net.bluemind.core.server.vertx.XmlBufferHandler INFO - login/validate in 13ms.
2016-03-02 11:00:00,019 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob
2016-03-02 11:00:00,022 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:00:00,030 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.mailindex.MailspoolIndexJob
2016-03-02 11:00:00,031 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:00:00,032 [pool-5-thread-3] net.bluemind.job.mailindex.MailspoolIndexJob INFO - Not planned.
2016-03-02 11:00:00,041 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId EventBoundariesJob
2016-03-02 11:00:00,043 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:00:00,050 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.contactindex.ContactIndexJob
2016-03-02 11:00:00,052 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 0 jobs from database.
2016-03-02 11:00:00,053 [pool-5-thread-1] net.bluemind.job.contactindex.ContactIndexJob INFO - Not planned.
2016-03-02 11:00:00,059 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.mailindex.MailspoolResyncIndexJob
2016-03-02 11:00:00,061 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 0 jobs from database.
2016-03-02 11:00:00,061 [pool-5-thread-3] net.bluemind.job.mailindex.MailspoolResyncIndexJob INFO - Not planned.
2016-03-02 11:00:00,068 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.calendarindex.CalendarIndexJob
2016-03-02 11:00:00,069 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 0 jobs from database.
2016-03-02 11:00:00,070 [pool-5-thread-1] net.bluemind.job.calendarindex.CalendarIndexJob INFO - Not planned.
2016-03-02 11:00:00,071 [pool-5-thread-4] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing EventBoundariesJob-global.virt-1456916400043
2016-03-02 11:00:00,071 [pool-5-thread-4] net.bluemind.core.jobs.impl.Scheduler INFO - [EventBoundariesJob-global.virt-1456916400043] progress is now 100%.
2016-03-02 11:00:00,071 [pool-4-thread-1] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of EventBoundariesJob-global.virt-1456916400043
2016-03-02 11:00:00,072 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for EventBoundariesJob-global.virt-1456916400043...
2016-03-02 11:00:00,072 [pool-4-thread-2] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for EventBoundariesJob
2016-03-02 11:00:00,074 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - run plan for EventBoundariesJob@global.virt updated with last_run set to id 3403213 (start: Wed Mar 02 11:00:00 GMT 2016)
2016-03-02 11:00:00,074 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - saving 1 entries...
2016-03-02 11:00:00,077 [pool-4-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - [EventBoundariesJob-global.virt-1456916400043] finished and recorded: SUCCESS, duration: 28ms.
2016-03-02 11:00:00,084 [pool-5-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916400023
2016-03-02 11:00:00,084 [pool-5-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - [net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916400023] progress is now 100%.
2016-03-02 11:00:00,084 [pool-4-thread-2] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916400023
2016-03-02 11:00:00,085 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916400023...
2016-03-02 11:00:00,087 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - run plan for net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob@global.virt updated with last_run set to id 3403214 (start: Wed Mar 02 11:00:00 GMT 2016)
2016-03-02 11:00:00,087 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - saving 9 entries...
2016-03-02 11:00:00,088 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.mailindex.ArchiveSpoolIndexJob
2016-03-02 11:00:00,089 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:00:00,090 [pool-5-thread-3] net.bluemind.job.mailindex.ArchiveSpoolIndexJob INFO - Not planned.
2016-03-02 11:00:00,090 [pool-4-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - [net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916400023] finished and recorded: SUCCESS, duration: 61ms.
2016-03-02 11:00:00,096 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId Vacation
2016-03-02 11:00:00,097 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:00:00,104 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId EventAlert
2016-03-02 11:00:00,105 [pool-5-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing Vacation-global.virt-1456916400098
2016-03-02 11:00:00,106 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:00:00,106 [pool-5-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - [Vacation-global.virt-1456916400098] progress is now 100%.
2016-03-02 11:00:00,116 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.archive.core.ArchiveJob
2016-03-02 11:00:00,119 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 11 jobs from database.
2016-03-02 11:00:00,119 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 479secs ago.
2016-03-02 11:00:00,119 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:00:00,119 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 479secs ago.
2016-03-02 11:00:00,119 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:00:00,120 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 479secs ago.
2016-03-02 11:00:00,120 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:00:00,120 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 479secs ago.
2016-03-02 11:00:00,120 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:00:00,120 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 479secs ago.
2016-03-02 11:00:00,120 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:00:00,120 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 479secs ago.
2016-03-02 11:00:00,120 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:00:00,120 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 479secs ago.
2016-03-02 11:00:00,120 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:00:00,120 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 479secs ago.
2016-03-02 11:00:00,120 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:00:00,120 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 479secs ago.
2016-03-02 11:00:00,120 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:00:00,120 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 479secs ago.
2016-03-02 11:00:00,121 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:00:00,121 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 479secs ago.
2016-03-02 11:00:00,121 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:00:00,123 [pool-5-thread-4] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing EventAlert-global.virt-1456916400106
2016-03-02 11:00:00,124 [pool-5-thread-4] net.bluemind.core.jobs.impl.Scheduler INFO - [EventAlert-global.virt-1456916400106] progress is now 100%.
2016-03-02 11:00:00,128 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.dataprotect.core.DataProtectJob
2016-03-02 11:00:00,129 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:00:00,130 [pool-5-thread-3] net.bluemind.dataprotect.core.DataProtectJob INFO - not planned, last run was 517secs ago.
2016-03-02 11:00:00,130 [pool-5-thread-3] net.bluemind.dataprotect.core.DataProtectJob INFO - less than one day ago, skipping execution.
2016-03-02 11:00:00,138 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.core.jobs.quota.QuotaGatheringJob
2016-03-02 11:00:00,140 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:00:00,141 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 517secs ago.
2016-03-02 11:00:00,141 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:00:00,141 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 517secs ago.
2016-03-02 11:00:00,141 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:00:00,141 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 517secs ago.
2016-03-02 11:00:00,141 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 517secs ago.
2016-03-02 11:00:00,141 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:00:00,141 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:00:00,141 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 517secs ago.
2016-03-02 11:00:00,141 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:00:00,141 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 517secs ago.
2016-03-02 11:00:00,141 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 517secs ago.
2016-03-02 11:00:00,141 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:00:00,141 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:00:00,141 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 517secs ago.
2016-03-02 11:00:00,141 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:00:00,141 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 517secs ago.
2016-03-02 11:00:00,141 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:00:00,141 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 517secs ago.
2016-03-02 11:00:00,141 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:00:00,142 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 517secs ago.
2016-03-02 11:00:00,142 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:00:06,079 [pool-4-thread-1] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob
2016-03-02 11:00:06,079 [pool-4-thread-1] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of Vacation-global.virt-1456916400098
2016-03-02 11:00:06,080 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for Vacation-global.virt-1456916400098...
2016-03-02 11:00:06,084 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - run plan for Vacation@global.virt updated with last_run set to id 3403215 (start: Wed Mar 02 11:00:00 GMT 2016)
2016-03-02 11:00:06,084 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - saving 3 entries...
2016-03-02 11:00:06,088 [pool-4-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - [Vacation-global.virt-1456916400098] finished and recorded: SUCCESS, duration: 8ms.
2016-03-02 11:00:06,092 [pool-4-thread-2] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for Vacation
2016-03-02 11:00:06,092 [pool-4-thread-2] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of EventAlert-global.virt-1456916400106
2016-03-02 11:00:06,092 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for EventAlert-global.virt-1456916400106...
2016-03-02 11:00:06,095 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - run plan for EventAlert@global.virt updated with last_run set to id 3403216 (start: Wed Mar 02 11:00:00 GMT 2016)
2016-03-02 11:00:06,095 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - saving 3 entries...
2016-03-02 11:00:06,098 [pool-4-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - [EventAlert-global.virt-1456916400106] finished and recorded: SUCCESS, duration: 17ms.
2016-03-02 11:00:12,090 [pool-4-thread-1] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for EventAlert
2016-03-02 11:01:00,018 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob
2016-03-02 11:01:00,020 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:01:00,028 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.mailindex.MailspoolIndexJob
2016-03-02 11:01:00,029 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:01:00,030 [pool-5-thread-4] net.bluemind.job.mailindex.MailspoolIndexJob INFO - Not planned.
2016-03-02 11:01:00,037 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId EventBoundariesJob
2016-03-02 11:01:00,040 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:01:00,046 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.contactindex.ContactIndexJob
2016-03-02 11:01:00,047 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 0 jobs from database.
2016-03-02 11:01:00,048 [pool-5-thread-1] net.bluemind.job.contactindex.ContactIndexJob INFO - Not planned.
2016-03-02 11:01:00,054 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.mailindex.MailspoolResyncIndexJob
2016-03-02 11:01:00,056 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 0 jobs from database.
2016-03-02 11:01:00,058 [pool-5-thread-3] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing EventBoundariesJob-global.virt-1456916460040
2016-03-02 11:01:00,058 [pool-5-thread-3] net.bluemind.core.jobs.impl.Scheduler INFO - [EventBoundariesJob-global.virt-1456916460040] progress is now 100%.
2016-03-02 11:01:00,058 [pool-4-thread-1] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of EventBoundariesJob-global.virt-1456916460040
2016-03-02 11:01:00,059 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for EventBoundariesJob-global.virt-1456916460040...
2016-03-02 11:01:00,059 [pool-4-thread-2] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for EventBoundariesJob
2016-03-02 11:01:00,060 [pool-5-thread-4] net.bluemind.job.mailindex.MailspoolResyncIndexJob INFO - Not planned.
2016-03-02 11:01:00,061 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - run plan for EventBoundariesJob@global.virt updated with last_run set to id 3403217 (start: Wed Mar 02 11:01:00 GMT 2016)
2016-03-02 11:01:00,062 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - saving 1 entries...
2016-03-02 11:01:00,065 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.calendarindex.CalendarIndexJob
2016-03-02 11:01:00,086 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 0 jobs from database.
2016-03-02 11:01:00,087 [pool-5-thread-1] net.bluemind.job.calendarindex.CalendarIndexJob INFO - Not planned.
2016-03-02 11:01:00,092 [pool-4-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - [EventBoundariesJob-global.virt-1456916460040] finished and recorded: SUCCESS, duration: 18ms.
2016-03-02 11:01:00,096 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.mailindex.ArchiveSpoolIndexJob
2016-03-02 11:01:00,098 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:01:00,099 [pool-5-thread-3] net.bluemind.job.mailindex.ArchiveSpoolIndexJob INFO - Not planned.
2016-03-02 11:01:00,104 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId Vacation
2016-03-02 11:01:00,105 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:01:00,113 [pool-5-thread-4] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing Vacation-global.virt-1456916460106
2016-03-02 11:01:00,113 [pool-5-thread-4] net.bluemind.core.jobs.impl.Scheduler INFO - [Vacation-global.virt-1456916460106] progress is now 100%.
2016-03-02 11:01:00,113 [pool-4-thread-2] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of Vacation-global.virt-1456916460106
2016-03-02 11:01:00,113 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for Vacation-global.virt-1456916460106...
2016-03-02 11:01:00,112 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId EventAlert
2016-03-02 11:01:00,115 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:01:00,116 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - run plan for Vacation@global.virt updated with last_run set to id 3403218 (start: Wed Mar 02 11:01:00 GMT 2016)
2016-03-02 11:01:00,116 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - saving 3 entries...
2016-03-02 11:01:00,123 [pool-4-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - [Vacation-global.virt-1456916460106] finished and recorded: SUCCESS, duration: 7ms.
2016-03-02 11:01:00,128 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.archive.core.ArchiveJob
2016-03-02 11:01:00,131 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 11 jobs from database.
2016-03-02 11:01:00,132 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 539secs ago.
2016-03-02 11:01:00,132 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:01:00,132 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 539secs ago.
2016-03-02 11:01:00,132 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 539secs ago.
2016-03-02 11:01:00,132 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:01:00,132 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:01:00,132 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 539secs ago.
2016-03-02 11:01:00,132 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 539secs ago.
2016-03-02 11:01:00,132 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:01:00,132 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:01:00,133 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 539secs ago.
2016-03-02 11:01:00,133 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 539secs ago.
2016-03-02 11:01:00,133 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:01:00,133 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:01:00,133 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 539secs ago.
2016-03-02 11:01:00,133 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:01:00,133 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 539secs ago.
2016-03-02 11:01:00,133 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:01:00,133 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 539secs ago.
2016-03-02 11:01:00,133 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 539secs ago.
2016-03-02 11:01:00,133 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:01:00,133 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:01:00,138 [pool-5-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing EventAlert-global.virt-1456916460117
2016-03-02 11:01:00,138 [pool-5-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - [EventAlert-global.virt-1456916460117] progress is now 100%.
2016-03-02 11:01:00,142 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.dataprotect.core.DataProtectJob
2016-03-02 11:01:00,143 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:01:00,144 [pool-5-thread-4] net.bluemind.dataprotect.core.DataProtectJob INFO - not planned, last run was 577secs ago.
2016-03-02 11:01:00,144 [pool-5-thread-4] net.bluemind.dataprotect.core.DataProtectJob INFO - less than one day ago, skipping execution.
2016-03-02 11:01:00,146 [pool-5-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916460021
2016-03-02 11:01:00,147 [pool-5-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - [net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916460021] progress is now 100%.
2016-03-02 11:01:00,152 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.core.jobs.quota.QuotaGatheringJob
2016-03-02 11:01:00,154 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:01:00,155 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 577secs ago.
2016-03-02 11:01:00,155 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:01:00,155 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 577secs ago.
2016-03-02 11:01:00,155 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:01:00,155 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 577secs ago.
2016-03-02 11:01:00,155 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:01:00,155 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 577secs ago.
2016-03-02 11:01:00,155 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:01:00,155 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 577secs ago.
2016-03-02 11:01:00,155 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:01:00,155 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 577secs ago.
2016-03-02 11:01:00,155 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:01:00,155 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 577secs ago.
2016-03-02 11:01:00,155 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:01:00,155 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 577secs ago.
2016-03-02 11:01:00,155 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:01:00,155 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 577secs ago.
2016-03-02 11:01:00,155 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:01:00,155 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 577secs ago.
2016-03-02 11:01:00,156 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:01:00,156 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 577secs ago.
2016-03-02 11:01:00,156 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:01:06,094 [pool-4-thread-1] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for Vacation
2016-03-02 11:01:06,094 [pool-4-thread-1] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of EventAlert-global.virt-1456916460117
2016-03-02 11:01:06,095 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for EventAlert-global.virt-1456916460117...
2016-03-02 11:01:06,097 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - run plan for EventAlert@global.virt updated with last_run set to id 3403219 (start: Wed Mar 02 11:01:00 GMT 2016)
2016-03-02 11:01:06,097 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - saving 3 entries...
2016-03-02 11:01:06,101 [pool-4-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - [EventAlert-global.virt-1456916460117] finished and recorded: SUCCESS, duration: 21ms.
2016-03-02 11:01:06,125 [pool-4-thread-2] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for EventAlert
2016-03-02 11:01:06,125 [pool-4-thread-2] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916460021
2016-03-02 11:01:06,126 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916460021...
2016-03-02 11:01:06,129 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - run plan for net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob@global.virt updated with last_run set to id 3403220 (start: Wed Mar 02 11:01:00 GMT 2016)
2016-03-02 11:01:06,129 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - saving 9 entries...
2016-03-02 11:01:06,134 [pool-4-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - [net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916460021] finished and recorded: SUCCESS, duration: 126ms.
2016-03-02 11:01:12,103 [pool-4-thread-1] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob
2016-03-02 11:01:58,657 [vert.x-worker-thread-16] net.bluemind.core.UserManagement INFO - Accepting token as password for admin0@global.virt in bm-xmpp
2016-03-02 11:01:58,659 [vert.x-eventloop-thread-1] net.bluemind.core.server.vertx.XmlBufferHandler INFO - login/validate in 4ms.
2016-03-02 11:02:00,021 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob
2016-03-02 11:02:00,024 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:02:00,040 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.mailindex.MailspoolIndexJob
2016-03-02 11:02:00,041 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:02:00,042 [pool-5-thread-1] net.bluemind.job.mailindex.MailspoolIndexJob INFO - Not planned.
2016-03-02 11:02:00,050 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId EventBoundariesJob
2016-03-02 11:02:00,052 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:02:00,059 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.contactindex.ContactIndexJob
2016-03-02 11:02:00,060 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 0 jobs from database.
2016-03-02 11:02:00,061 [pool-5-thread-2] net.bluemind.job.contactindex.ContactIndexJob INFO - Not planned.
2016-03-02 11:02:00,064 [pool-5-thread-3] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916520025
2016-03-02 11:02:00,064 [pool-5-thread-3] net.bluemind.core.jobs.impl.Scheduler INFO - [net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916520025] progress is now 100%.
2016-03-02 11:02:00,064 [pool-4-thread-1] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916520025
2016-03-02 11:02:00,064 [pool-5-thread-4] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing EventBoundariesJob-global.virt-1456916520052
2016-03-02 11:02:00,064 [pool-5-thread-4] net.bluemind.core.jobs.impl.Scheduler INFO - [EventBoundariesJob-global.virt-1456916520052] progress is now 100%.
2016-03-02 11:02:00,065 [pool-4-thread-2] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob
2016-03-02 11:02:00,065 [pool-4-thread-2] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of EventBoundariesJob-global.virt-1456916520052
2016-03-02 11:02:00,065 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916520025...
2016-03-02 11:02:00,065 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for EventBoundariesJob-global.virt-1456916520052...
2016-03-02 11:02:00,067 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - run plan for EventBoundariesJob@global.virt updated with last_run set to id 3403221 (start: Wed Mar 02 11:02:00 GMT 2016)
2016-03-02 11:02:00,067 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - saving 1 entries...
2016-03-02 11:02:00,068 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - run plan for net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob@global.virt updated with last_run set to id 3403222 (start: Wed Mar 02 11:02:00 GMT 2016)
2016-03-02 11:02:00,068 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - saving 5 entries...
2016-03-02 11:02:00,069 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.mailindex.MailspoolResyncIndexJob
2016-03-02 11:02:00,069 [pool-4-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - [EventBoundariesJob-global.virt-1456916520052] finished and recorded: SUCCESS, duration: 12ms.
2016-03-02 11:02:00,070 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 0 jobs from database.
2016-03-02 11:02:00,072 [pool-5-thread-1] net.bluemind.job.mailindex.MailspoolResyncIndexJob INFO - Not planned.
2016-03-02 11:02:00,073 [pool-4-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - [net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916520025] finished and recorded: SUCCESS, duration: 39ms.
2016-03-02 11:02:00,080 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.calendarindex.CalendarIndexJob
2016-03-02 11:02:00,080 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 0 jobs from database.
2016-03-02 11:02:00,081 [pool-5-thread-2] net.bluemind.job.calendarindex.CalendarIndexJob INFO - Not planned.
2016-03-02 11:02:00,086 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.mailindex.ArchiveSpoolIndexJob
2016-03-02 11:02:00,087 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:02:00,088 [pool-5-thread-3] net.bluemind.job.mailindex.ArchiveSpoolIndexJob INFO - Not planned.
2016-03-02 11:02:00,093 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId Vacation
2016-03-02 11:02:00,095 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:02:00,101 [pool-5-thread-4] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing Vacation-global.virt-1456916520096
2016-03-02 11:02:00,101 [pool-5-thread-4] net.bluemind.core.jobs.impl.Scheduler INFO - [Vacation-global.virt-1456916520096] progress is now 100%.
2016-03-02 11:02:00,104 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId EventAlert
2016-03-02 11:02:00,105 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:02:00,115 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.archive.core.ArchiveJob
2016-03-02 11:02:00,118 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 11 jobs from database.
2016-03-02 11:02:00,118 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 599secs ago.
2016-03-02 11:02:00,118 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 599secs ago.
2016-03-02 11:02:00,118 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:02:00,119 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 599secs ago.
2016-03-02 11:02:00,119 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:02:00,119 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:02:00,119 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 599secs ago.
2016-03-02 11:02:00,119 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:02:00,119 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 599secs ago.
2016-03-02 11:02:00,119 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:02:00,119 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 599secs ago.
2016-03-02 11:02:00,119 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:02:00,119 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 599secs ago.
2016-03-02 11:02:00,119 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 599secs ago.
2016-03-02 11:02:00,119 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:02:00,119 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:02:00,119 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 599secs ago.
2016-03-02 11:02:00,119 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:02:00,119 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 599secs ago.
2016-03-02 11:02:00,119 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:02:00,119 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 599secs ago.
2016-03-02 11:02:00,119 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:02:00,125 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.dataprotect.core.DataProtectJob
2016-03-02 11:02:00,126 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:02:00,127 [pool-5-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing EventAlert-global.virt-1456916520105
2016-03-02 11:02:00,127 [pool-5-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - [EventAlert-global.virt-1456916520105] progress is now 100%.
2016-03-02 11:02:00,127 [pool-5-thread-4] net.bluemind.dataprotect.core.DataProtectJob INFO - not planned, last run was 637secs ago.
2016-03-02 11:02:00,127 [pool-5-thread-4] net.bluemind.dataprotect.core.DataProtectJob INFO - less than one day ago, skipping execution.
2016-03-02 11:02:00,142 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.core.jobs.quota.QuotaGatheringJob
2016-03-02 11:02:00,144 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:02:00,145 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 637secs ago.
2016-03-02 11:02:00,145 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:02:00,145 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 637secs ago.
2016-03-02 11:02:00,145 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:02:00,145 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 637secs ago.
2016-03-02 11:02:00,145 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 637secs ago.
2016-03-02 11:02:00,145 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:02:00,145 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:02:00,145 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 637secs ago.
2016-03-02 11:02:00,145 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 637secs ago.
2016-03-02 11:02:00,145 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:02:00,145 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:02:00,146 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 637secs ago.
2016-03-02 11:02:00,146 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:02:00,146 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 637secs ago.
2016-03-02 11:02:00,146 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:02:00,146 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 637secs ago.
2016-03-02 11:02:00,146 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:02:00,146 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 637secs ago.
2016-03-02 11:02:00,146 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:02:00,146 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 637secs ago.
2016-03-02 11:02:00,146 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:02:06,071 [pool-4-thread-2] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for EventBoundariesJob
2016-03-02 11:02:06,072 [pool-4-thread-2] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of Vacation-global.virt-1456916520096
2016-03-02 11:02:06,073 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for Vacation-global.virt-1456916520096...
2016-03-02 11:02:06,074 [pool-4-thread-1] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for Vacation
2016-03-02 11:02:06,074 [pool-4-thread-1] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of EventAlert-global.virt-1456916520105
2016-03-02 11:02:06,076 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for EventAlert-global.virt-1456916520105...
2016-03-02 11:02:06,077 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - run plan for Vacation@global.virt updated with last_run set to id 3403223 (start: Wed Mar 02 11:02:00 GMT 2016)
2016-03-02 11:02:06,077 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - saving 3 entries...
2016-03-02 11:02:06,080 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - run plan for EventAlert@global.virt updated with last_run set to id 3403224 (start: Wed Mar 02 11:02:00 GMT 2016)
2016-03-02 11:02:06,080 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - saving 3 entries...
2016-03-02 11:02:06,081 [pool-4-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - [Vacation-global.virt-1456916520096] finished and recorded: SUCCESS, duration: 5ms.
2016-03-02 11:02:06,084 [pool-4-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - [EventAlert-global.virt-1456916520105] finished and recorded: SUCCESS, duration: 22ms.
2016-03-02 11:02:12,083 [pool-4-thread-2] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for EventAlert
2016-03-02 11:02:30,833 [vert.x-worker-thread-5] net.bluemind.core.UserManagement INFO - UserManagement.validate: access refused to login: 'robert' domain: 'global.virt', auth type: BM DB, origin: ysnp
2016-03-02 11:02:30,837 [vert.x-eventloop-thread-2] net.bluemind.core.server.vertx.XmlBufferHandler INFO - login/validate in 12ms.
2016-03-02 11:03:00,020 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob
2016-03-02 11:03:00,023 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:03:00,040 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.mailindex.MailspoolIndexJob
2016-03-02 11:03:00,041 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:03:00,042 [pool-5-thread-3] net.bluemind.job.mailindex.MailspoolIndexJob INFO - Not planned.
2016-03-02 11:03:00,049 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId EventBoundariesJob
2016-03-02 11:03:00,050 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:03:00,059 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.contactindex.ContactIndexJob
2016-03-02 11:03:00,060 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 0 jobs from database.
2016-03-02 11:03:00,061 [pool-5-thread-1] net.bluemind.job.contactindex.ContactIndexJob INFO - Not planned.
2016-03-02 11:03:00,063 [pool-5-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing EventBoundariesJob-global.virt-1456916580051
2016-03-02 11:03:00,063 [pool-5-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - [EventBoundariesJob-global.virt-1456916580051] progress is now 100%.
2016-03-02 11:03:00,064 [pool-4-thread-2] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of EventBoundariesJob-global.virt-1456916580051
2016-03-02 11:03:00,064 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for EventBoundariesJob-global.virt-1456916580051...
2016-03-02 11:03:00,064 [pool-4-thread-1] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for EventBoundariesJob
2016-03-02 11:03:00,066 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - run plan for EventBoundariesJob@global.virt updated with last_run set to id 3403225 (start: Wed Mar 02 11:03:00 GMT 2016)
2016-03-02 11:03:00,066 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - saving 1 entries...
2016-03-02 11:03:00,069 [pool-4-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - [EventBoundariesJob-global.virt-1456916580051] finished and recorded: SUCCESS, duration: 12ms.
2016-03-02 11:03:00,070 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.mailindex.MailspoolResyncIndexJob
2016-03-02 11:03:00,071 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 0 jobs from database.
2016-03-02 11:03:00,072 [pool-5-thread-3] net.bluemind.job.mailindex.MailspoolResyncIndexJob INFO - Not planned.
2016-03-02 11:03:00,079 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.calendarindex.CalendarIndexJob
2016-03-02 11:03:00,080 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 0 jobs from database.
2016-03-02 11:03:00,081 [pool-5-thread-1] net.bluemind.job.calendarindex.CalendarIndexJob INFO - Not planned.
2016-03-02 11:03:00,087 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.mailindex.ArchiveSpoolIndexJob
2016-03-02 11:03:00,089 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:03:00,089 [pool-5-thread-2] net.bluemind.job.mailindex.ArchiveSpoolIndexJob INFO - Not planned.
2016-03-02 11:03:00,097 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId Vacation
2016-03-02 11:03:00,098 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:03:00,105 [pool-5-thread-3] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing Vacation-global.virt-1456916580099
2016-03-02 11:03:00,105 [pool-5-thread-3] net.bluemind.core.jobs.impl.Scheduler INFO - [Vacation-global.virt-1456916580099] progress is now 100%.
2016-03-02 11:03:00,105 [pool-4-thread-1] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of Vacation-global.virt-1456916580099
2016-03-02 11:03:00,106 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for Vacation-global.virt-1456916580099...
2016-03-02 11:03:00,106 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId EventAlert
2016-03-02 11:03:00,108 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:03:00,108 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - run plan for Vacation@global.virt updated with last_run set to id 3403226 (start: Wed Mar 02 11:03:00 GMT 2016)
2016-03-02 11:03:00,109 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - saving 3 entries...
2016-03-02 11:03:00,113 [pool-4-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - [Vacation-global.virt-1456916580099] finished and recorded: SUCCESS, duration: 6ms.
2016-03-02 11:03:00,122 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.archive.core.ArchiveJob
2016-03-02 11:03:00,125 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 11 jobs from database.
2016-03-02 11:03:00,125 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 659secs ago.
2016-03-02 11:03:00,125 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:03:00,125 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 659secs ago.
2016-03-02 11:03:00,125 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:03:00,126 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 659secs ago.
2016-03-02 11:03:00,126 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:03:00,126 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 659secs ago.
2016-03-02 11:03:00,126 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:03:00,126 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 659secs ago.
2016-03-02 11:03:00,126 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:03:00,126 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 659secs ago.
2016-03-02 11:03:00,126 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:03:00,126 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 659secs ago.
2016-03-02 11:03:00,126 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:03:00,126 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 659secs ago.
2016-03-02 11:03:00,126 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:03:00,126 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 659secs ago.
2016-03-02 11:03:00,126 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:03:00,126 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 659secs ago.
2016-03-02 11:03:00,126 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:03:00,126 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 659secs ago.
2016-03-02 11:03:00,126 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:03:00,128 [pool-5-thread-4] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916580024
2016-03-02 11:03:00,128 [pool-5-thread-4] net.bluemind.core.jobs.impl.Scheduler INFO - [net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916580024] progress is now 100%.
2016-03-02 11:03:00,130 [pool-5-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing EventAlert-global.virt-1456916580109
2016-03-02 11:03:00,130 [pool-5-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - [EventAlert-global.virt-1456916580109] progress is now 100%.
2016-03-02 11:03:00,134 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.dataprotect.core.DataProtectJob
2016-03-02 11:03:00,135 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:03:00,135 [pool-5-thread-2] net.bluemind.dataprotect.core.DataProtectJob INFO - not planned, last run was 697secs ago.
2016-03-02 11:03:00,135 [pool-5-thread-2] net.bluemind.dataprotect.core.DataProtectJob INFO - less than one day ago, skipping execution.
2016-03-02 11:03:00,144 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.core.jobs.quota.QuotaGatheringJob
2016-03-02 11:03:00,145 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:03:00,147 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 697secs ago.
2016-03-02 11:03:00,147 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 697secs ago.
2016-03-02 11:03:00,147 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:03:00,147 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 697secs ago.
2016-03-02 11:03:00,147 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:03:00,147 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 697secs ago.
2016-03-02 11:03:00,147 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:03:00,147 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 697secs ago.
2016-03-02 11:03:00,147 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:03:00,147 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:03:00,148 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 697secs ago.
2016-03-02 11:03:00,148 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:03:00,149 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 697secs ago.
2016-03-02 11:03:00,149 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:03:00,149 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 697secs ago.
2016-03-02 11:03:00,149 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:03:00,149 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 697secs ago.
2016-03-02 11:03:00,149 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:03:00,149 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 697secs ago.
2016-03-02 11:03:00,149 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:03:00,149 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 697secs ago.
2016-03-02 11:03:00,149 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:03:06,071 [pool-4-thread-2] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for Vacation
2016-03-02 11:03:06,072 [pool-4-thread-2] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916580024
2016-03-02 11:03:06,073 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916580024...
2016-03-02 11:03:06,077 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - run plan for net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob@global.virt updated with last_run set to id 3403227 (start: Wed Mar 02 11:03:00 GMT 2016)
2016-03-02 11:03:06,077 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - saving 9 entries...
2016-03-02 11:03:06,091 [pool-4-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - [net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916580024] finished and recorded: SUCCESS, duration: 104ms.
2016-03-02 11:03:06,115 [pool-4-thread-1] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob
2016-03-02 11:03:06,115 [pool-4-thread-1] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of EventAlert-global.virt-1456916580109
2016-03-02 11:03:06,116 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for EventAlert-global.virt-1456916580109...
2016-03-02 11:03:06,120 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - run plan for EventAlert@global.virt updated with last_run set to id 3403228 (start: Wed Mar 02 11:03:00 GMT 2016)
2016-03-02 11:03:06,120 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - saving 3 entries...
2016-03-02 11:03:06,127 [pool-4-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - [EventAlert-global.virt-1456916580109] finished and recorded: SUCCESS, duration: 21ms.
2016-03-02 11:03:12,093 [pool-4-thread-2] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for EventAlert
2016-03-02 11:04:00,019 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob
2016-03-02 11:04:00,022 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:04:00,030 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.mailindex.MailspoolIndexJob
2016-03-02 11:04:00,032 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:04:00,033 [pool-5-thread-3] net.bluemind.job.mailindex.MailspoolIndexJob INFO - Not planned.
2016-03-02 11:04:00,042 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId EventBoundariesJob
2016-03-02 11:04:00,044 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:04:00,053 [pool-5-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916640023
2016-03-02 11:04:00,053 [pool-5-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - [net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916640023] progress is now 100%.
2016-03-02 11:04:00,053 [pool-4-thread-2] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916640023
2016-03-02 11:04:00,053 [pool-4-thread-1] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob
2016-03-02 11:04:00,054 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916640023...
2016-03-02 11:04:00,055 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - run plan for net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob@global.virt updated with last_run set to id 3403229 (start: Wed Mar 02 11:04:00 GMT 2016)
2016-03-02 11:04:00,055 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - saving 5 entries...
2016-03-02 11:04:00,057 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.contactindex.ContactIndexJob
2016-03-02 11:04:00,058 [pool-5-thread-4] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing EventBoundariesJob-global.virt-1456916640045
2016-03-02 11:04:00,058 [pool-5-thread-4] net.bluemind.core.jobs.impl.Scheduler INFO - [EventBoundariesJob-global.virt-1456916640045] progress is now 100%.
2016-03-02 11:04:00,059 [pool-4-thread-1] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of EventBoundariesJob-global.virt-1456916640045
2016-03-02 11:04:00,059 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 0 jobs from database.
2016-03-02 11:04:00,059 [pool-4-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - [net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916640023] finished and recorded: SUCCESS, duration: 30ms.
2016-03-02 11:04:00,059 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for EventBoundariesJob-global.virt-1456916640045...
2016-03-02 11:04:00,060 [pool-5-thread-1] net.bluemind.job.contactindex.ContactIndexJob INFO - Not planned.
2016-03-02 11:04:00,062 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - run plan for EventBoundariesJob@global.virt updated with last_run set to id 3403230 (start: Wed Mar 02 11:04:00 GMT 2016)
2016-03-02 11:04:00,062 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - saving 1 entries...
2016-03-02 11:04:00,067 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.mailindex.MailspoolResyncIndexJob
2016-03-02 11:04:00,068 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 0 jobs from database.
2016-03-02 11:04:00,068 [pool-4-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - [EventBoundariesJob-global.virt-1456916640045] finished and recorded: SUCCESS, duration: 13ms.
2016-03-02 11:04:00,069 [pool-5-thread-3] net.bluemind.job.mailindex.MailspoolResyncIndexJob INFO - Not planned.
2016-03-02 11:04:00,075 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.calendarindex.CalendarIndexJob
2016-03-02 11:04:00,075 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 0 jobs from database.
2016-03-02 11:04:00,076 [pool-5-thread-2] net.bluemind.job.calendarindex.CalendarIndexJob INFO - Not planned.
2016-03-02 11:04:00,082 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.mailindex.ArchiveSpoolIndexJob
2016-03-02 11:04:00,083 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:04:00,084 [pool-5-thread-4] net.bluemind.job.mailindex.ArchiveSpoolIndexJob INFO - Not planned.
2016-03-02 11:04:00,089 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId Vacation
2016-03-02 11:04:00,091 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:04:00,097 [pool-5-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing Vacation-global.virt-1456916640091
2016-03-02 11:04:00,097 [pool-5-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - [Vacation-global.virt-1456916640091] progress is now 100%.
2016-03-02 11:04:00,098 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId EventAlert
2016-03-02 11:04:00,099 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:04:00,111 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.archive.core.ArchiveJob
2016-03-02 11:04:00,116 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 11 jobs from database.
2016-03-02 11:04:00,116 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 719secs ago.
2016-03-02 11:04:00,116 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:04:00,116 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 719secs ago.
2016-03-02 11:04:00,116 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:04:00,116 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 719secs ago.
2016-03-02 11:04:00,116 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 719secs ago.
2016-03-02 11:04:00,116 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:04:00,117 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:04:00,117 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 719secs ago.
2016-03-02 11:04:00,117 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 719secs ago.
2016-03-02 11:04:00,117 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:04:00,117 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:04:00,117 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 719secs ago.
2016-03-02 11:04:00,117 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:04:00,117 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 719secs ago.
2016-03-02 11:04:00,117 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:04:00,117 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 719secs ago.
2016-03-02 11:04:00,117 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:04:00,117 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 719secs ago.
2016-03-02 11:04:00,117 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:04:00,117 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 719secs ago.
2016-03-02 11:04:00,117 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:04:00,121 [pool-5-thread-3] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing EventAlert-global.virt-1456916640100
2016-03-02 11:04:00,121 [pool-5-thread-3] net.bluemind.core.jobs.impl.Scheduler INFO - [EventAlert-global.virt-1456916640100] progress is now 100%.
2016-03-02 11:04:00,123 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.dataprotect.core.DataProtectJob
2016-03-02 11:04:00,125 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:04:00,125 [pool-5-thread-4] net.bluemind.dataprotect.core.DataProtectJob INFO - not planned, last run was 757secs ago.
2016-03-02 11:04:00,125 [pool-5-thread-4] net.bluemind.dataprotect.core.DataProtectJob INFO - less than one day ago, skipping execution.
2016-03-02 11:04:00,134 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.core.jobs.quota.QuotaGatheringJob
2016-03-02 11:04:00,135 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:04:00,136 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 757secs ago.
2016-03-02 11:04:00,136 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 757secs ago.
2016-03-02 11:04:00,136 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:04:00,136 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:04:00,136 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 757secs ago.
2016-03-02 11:04:00,136 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:04:00,136 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 757secs ago.
2016-03-02 11:04:00,136 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 757secs ago.
2016-03-02 11:04:00,136 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:04:00,136 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:04:00,136 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 757secs ago.
2016-03-02 11:04:00,136 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:04:00,136 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 757secs ago.
2016-03-02 11:04:00,136 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 757secs ago.
2016-03-02 11:04:00,136 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:04:00,136 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:04:00,136 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 757secs ago.
2016-03-02 11:04:00,136 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 757secs ago.
2016-03-02 11:04:00,136 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:04:00,136 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 757secs ago.
2016-03-02 11:04:00,136 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:04:00,136 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:04:06,062 [pool-4-thread-2] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for EventBoundariesJob
2016-03-02 11:04:06,063 [pool-4-thread-2] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of Vacation-global.virt-1456916640091
2016-03-02 11:04:06,064 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for Vacation-global.virt-1456916640091...
2016-03-02 11:04:06,068 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - run plan for Vacation@global.virt updated with last_run set to id 3403231 (start: Wed Mar 02 11:04:00 GMT 2016)
2016-03-02 11:04:06,068 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - saving 3 entries...
2016-03-02 11:04:06,070 [pool-4-thread-1] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for Vacation
2016-03-02 11:04:06,070 [pool-4-thread-1] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of EventAlert-global.virt-1456916640100
2016-03-02 11:04:06,072 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for EventAlert-global.virt-1456916640100...
2016-03-02 11:04:06,073 [pool-4-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - [Vacation-global.virt-1456916640091] finished and recorded: SUCCESS, duration: 6ms.
2016-03-02 11:04:06,076 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - run plan for EventAlert@global.virt updated with last_run set to id 3403232 (start: Wed Mar 02 11:04:00 GMT 2016)
2016-03-02 11:04:06,077 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - saving 3 entries...
2016-03-02 11:04:06,081 [pool-4-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - [EventAlert-global.virt-1456916640100] finished and recorded: SUCCESS, duration: 21ms.
2016-03-02 11:04:12,076 [pool-4-thread-2] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for EventAlert
2016-03-02 11:05:00,020 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob
2016-03-02 11:05:00,023 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:05:00,038 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.mailindex.MailspoolIndexJob
2016-03-02 11:05:00,039 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:05:00,041 [pool-5-thread-1] net.bluemind.job.mailindex.MailspoolIndexJob INFO - Not planned.
2016-03-02 11:05:00,047 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId EventBoundariesJob
2016-03-02 11:05:00,048 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:05:00,055 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.contactindex.ContactIndexJob
2016-03-02 11:05:00,056 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 0 jobs from database.
2016-03-02 11:05:00,056 [pool-5-thread-4] net.bluemind.job.contactindex.ContactIndexJob INFO - Not planned.
2016-03-02 11:05:00,061 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.mailindex.MailspoolResyncIndexJob
2016-03-02 11:05:00,062 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 0 jobs from database.
2016-03-02 11:05:00,063 [pool-5-thread-3] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing EventBoundariesJob-global.virt-1456916700048
2016-03-02 11:05:00,063 [pool-5-thread-3] net.bluemind.core.jobs.impl.Scheduler INFO - [EventBoundariesJob-global.virt-1456916700048] progress is now 100%.
2016-03-02 11:05:00,063 [pool-4-thread-2] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of EventBoundariesJob-global.virt-1456916700048
2016-03-02 11:05:00,063 [pool-5-thread-1] net.bluemind.job.mailindex.MailspoolResyncIndexJob INFO - Not planned.
2016-03-02 11:05:00,064 [pool-4-thread-1] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for EventBoundariesJob
2016-03-02 11:05:00,064 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for EventBoundariesJob-global.virt-1456916700048...
2016-03-02 11:05:00,066 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - run plan for EventBoundariesJob@global.virt updated with last_run set to id 3403233 (start: Wed Mar 02 11:05:00 GMT 2016)
2016-03-02 11:05:00,066 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - saving 1 entries...
2016-03-02 11:05:00,069 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.calendarindex.CalendarIndexJob
2016-03-02 11:05:00,069 [pool-4-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - [EventBoundariesJob-global.virt-1456916700048] finished and recorded: SUCCESS, duration: 15ms.
2016-03-02 11:05:00,070 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 0 jobs from database.
2016-03-02 11:05:00,071 [pool-5-thread-4] net.bluemind.job.calendarindex.CalendarIndexJob INFO - Not planned.
2016-03-02 11:05:00,076 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.mailindex.ArchiveSpoolIndexJob
2016-03-02 11:05:00,077 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:05:00,078 [pool-5-thread-3] net.bluemind.job.mailindex.ArchiveSpoolIndexJob INFO - Not planned.
2016-03-02 11:05:00,084 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId Vacation
2016-03-02 11:05:00,086 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:05:00,091 [pool-5-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing Vacation-global.virt-1456916700086
2016-03-02 11:05:00,091 [pool-5-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - [Vacation-global.virt-1456916700086] progress is now 100%.
2016-03-02 11:05:00,092 [pool-4-thread-1] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of Vacation-global.virt-1456916700086
2016-03-02 11:05:00,093 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for Vacation-global.virt-1456916700086...
2016-03-02 11:05:00,094 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - run plan for Vacation@global.virt updated with last_run set to id 3403234 (start: Wed Mar 02 11:05:00 GMT 2016)
2016-03-02 11:05:00,094 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - saving 3 entries...
2016-03-02 11:05:00,094 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId EventAlert
2016-03-02 11:05:00,095 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:05:00,097 [pool-4-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - [Vacation-global.virt-1456916700086] finished and recorded: SUCCESS, duration: 5ms.
2016-03-02 11:05:00,102 [pool-5-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916700025
2016-03-02 11:05:00,102 [pool-5-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - [net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916700025] progress is now 100%.
2016-03-02 11:05:00,106 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.archive.core.ArchiveJob
2016-03-02 11:05:00,109 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 11 jobs from database.
2016-03-02 11:05:00,109 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 779secs ago.
2016-03-02 11:05:00,109 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:05:00,109 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 779secs ago.
2016-03-02 11:05:00,109 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:05:00,110 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 779secs ago.
2016-03-02 11:05:00,110 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:05:00,110 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 779secs ago.
2016-03-02 11:05:00,110 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:05:00,110 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 779secs ago.
2016-03-02 11:05:00,110 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:05:00,110 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 779secs ago.
2016-03-02 11:05:00,110 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:05:00,110 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 779secs ago.
2016-03-02 11:05:00,110 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:05:00,110 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 779secs ago.
2016-03-02 11:05:00,110 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:05:00,110 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 779secs ago.
2016-03-02 11:05:00,110 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:05:00,110 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 779secs ago.
2016-03-02 11:05:00,110 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:05:00,110 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 779secs ago.
2016-03-02 11:05:00,110 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:05:00,115 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.dataprotect.core.DataProtectJob
2016-03-02 11:05:00,117 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:05:00,118 [pool-5-thread-3] net.bluemind.dataprotect.core.DataProtectJob INFO - not planned, last run was 817secs ago.
2016-03-02 11:05:00,118 [pool-5-thread-3] net.bluemind.dataprotect.core.DataProtectJob INFO - less than one day ago, skipping execution.
2016-03-02 11:05:00,121 [pool-5-thread-4] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing EventAlert-global.virt-1456916700098
2016-03-02 11:05:00,121 [pool-5-thread-4] net.bluemind.core.jobs.impl.Scheduler INFO - [EventAlert-global.virt-1456916700098] progress is now 100%.
2016-03-02 11:05:00,126 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.core.jobs.quota.QuotaGatheringJob
2016-03-02 11:05:00,127 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:05:00,128 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 817secs ago.
2016-03-02 11:05:00,128 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:05:00,128 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 817secs ago.
2016-03-02 11:05:00,128 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:05:00,128 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 817secs ago.
2016-03-02 11:05:00,128 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 817secs ago.
2016-03-02 11:05:00,128 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:05:00,128 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:05:00,128 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 817secs ago.
2016-03-02 11:05:00,128 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 817secs ago.
2016-03-02 11:05:00,128 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:05:00,128 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:05:00,128 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 817secs ago.
2016-03-02 11:05:00,128 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:05:00,128 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 817secs ago.
2016-03-02 11:05:00,128 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:05:00,128 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 817secs ago.
2016-03-02 11:05:00,128 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:05:00,128 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 817secs ago.
2016-03-02 11:05:00,128 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:05:00,128 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 817secs ago.
2016-03-02 11:05:00,128 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:05:06,071 [pool-4-thread-2] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for Vacation
2016-03-02 11:05:06,071 [pool-4-thread-2] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916700025
2016-03-02 11:05:06,073 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916700025...
2016-03-02 11:05:06,076 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - run plan for net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob@global.virt updated with last_run set to id 3403235 (start: Wed Mar 02 11:05:00 GMT 2016)
2016-03-02 11:05:06,076 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - saving 9 entries...
2016-03-02 11:05:06,081 [pool-4-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - [net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916700025] finished and recorded: SUCCESS, duration: 77ms.
2016-03-02 11:05:06,099 [pool-4-thread-1] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob
2016-03-02 11:05:06,099 [pool-4-thread-1] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of EventAlert-global.virt-1456916700098
2016-03-02 11:05:06,100 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for EventAlert-global.virt-1456916700098...
2016-03-02 11:05:06,104 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - run plan for EventAlert@global.virt updated with last_run set to id 3403236 (start: Wed Mar 02 11:05:00 GMT 2016)
2016-03-02 11:05:06,104 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - saving 3 entries...
2016-03-02 11:05:06,108 [pool-4-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - [EventAlert-global.virt-1456916700098] finished and recorded: SUCCESS, duration: 23ms.
2016-03-02 11:05:12,083 [pool-4-thread-2] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for EventAlert
2016-03-02 11:05:34,455 [vert.x-worker-thread-6] net.bluemind.core.UserManagement INFO - UserManagement.validate: access refused to login: 'library' domain: 'global.virt', auth type: BM DB, origin: ysnp
2016-03-02 11:05:34,459 [vert.x-eventloop-thread-5] net.bluemind.core.server.vertx.XmlBufferHandler INFO - login/validate in 10ms.
2016-03-02 11:06:00,017 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob
2016-03-02 11:06:00,019 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:06:00,029 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.mailindex.MailspoolIndexJob
2016-03-02 11:06:00,031 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:06:00,031 [pool-5-thread-2] net.bluemind.job.mailindex.MailspoolIndexJob INFO - Not planned.
2016-03-02 11:06:00,043 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId EventBoundariesJob
2016-03-02 11:06:00,044 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:06:00,051 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.contactindex.ContactIndexJob
2016-03-02 11:06:00,052 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 0 jobs from database.
2016-03-02 11:06:00,053 [pool-5-thread-4] net.bluemind.job.contactindex.ContactIndexJob INFO - Not planned.
2016-03-02 11:06:00,061 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.mailindex.MailspoolResyncIndexJob
2016-03-02 11:06:00,062 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 0 jobs from database.
2016-03-02 11:06:00,063 [pool-5-thread-2] net.bluemind.job.mailindex.MailspoolResyncIndexJob INFO - Not planned.
2016-03-02 11:06:00,065 [pool-5-thread-3] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing EventBoundariesJob-global.virt-1456916760045
2016-03-02 11:06:00,065 [pool-5-thread-3] net.bluemind.core.jobs.impl.Scheduler INFO - [EventBoundariesJob-global.virt-1456916760045] progress is now 100%.
2016-03-02 11:06:00,065 [pool-4-thread-2] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of EventBoundariesJob-global.virt-1456916760045
2016-03-02 11:06:00,066 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for EventBoundariesJob-global.virt-1456916760045...
2016-03-02 11:06:00,066 [pool-4-thread-1] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for EventBoundariesJob
2016-03-02 11:06:00,069 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - run plan for EventBoundariesJob@global.virt updated with last_run set to id 3403237 (start: Wed Mar 02 11:06:00 GMT 2016)
2016-03-02 11:06:00,069 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - saving 1 entries...
2016-03-02 11:06:00,071 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.calendarindex.CalendarIndexJob
2016-03-02 11:06:00,072 [pool-4-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - [EventBoundariesJob-global.virt-1456916760045] finished and recorded: SUCCESS, duration: 20ms.
2016-03-02 11:06:00,072 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 0 jobs from database.
2016-03-02 11:06:00,073 [pool-5-thread-4] net.bluemind.job.calendarindex.CalendarIndexJob INFO - Not planned.
2016-03-02 11:06:00,080 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.mailindex.ArchiveSpoolIndexJob
2016-03-02 11:06:00,082 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:06:00,082 [pool-5-thread-2] net.bluemind.job.mailindex.ArchiveSpoolIndexJob INFO - Not planned.
2016-03-02 11:06:00,089 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId Vacation
2016-03-02 11:06:00,090 [pool-5-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916760020
2016-03-02 11:06:00,090 [pool-5-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - [net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916760020] progress is now 100%.
2016-03-02 11:06:00,090 [pool-4-thread-1] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916760020
2016-03-02 11:06:00,091 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:06:00,091 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916760020...
2016-03-02 11:06:00,093 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - run plan for net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob@global.virt updated with last_run set to id 3403238 (start: Wed Mar 02 11:06:00 GMT 2016)
2016-03-02 11:06:00,093 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - saving 9 entries...
2016-03-02 11:06:00,098 [pool-4-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - [net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916760020] finished and recorded: SUCCESS, duration: 70ms.
2016-03-02 11:06:00,098 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId EventAlert
2016-03-02 11:06:00,100 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:06:00,100 [pool-5-thread-3] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing Vacation-global.virt-1456916760091
2016-03-02 11:06:00,100 [pool-5-thread-3] net.bluemind.core.jobs.impl.Scheduler INFO - [Vacation-global.virt-1456916760091] progress is now 100%.
2016-03-02 11:06:00,111 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.archive.core.ArchiveJob
2016-03-02 11:06:00,116 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 11 jobs from database.
2016-03-02 11:06:00,116 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 839secs ago.
2016-03-02 11:06:00,116 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:06:00,117 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 839secs ago.
2016-03-02 11:06:00,117 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:06:00,117 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 839secs ago.
2016-03-02 11:06:00,117 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:06:00,117 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 839secs ago.
2016-03-02 11:06:00,117 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:06:00,117 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 839secs ago.
2016-03-02 11:06:00,117 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:06:00,117 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 839secs ago.
2016-03-02 11:06:00,117 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:06:00,117 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 839secs ago.
2016-03-02 11:06:00,117 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:06:00,117 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 839secs ago.
2016-03-02 11:06:00,117 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:06:00,117 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 839secs ago.
2016-03-02 11:06:00,117 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 839secs ago.
2016-03-02 11:06:00,117 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:06:00,117 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 839secs ago.
2016-03-02 11:06:00,117 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:06:00,117 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:06:00,122 [pool-5-thread-4] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing EventAlert-global.virt-1456916760101
2016-03-02 11:06:00,122 [pool-5-thread-4] net.bluemind.core.jobs.impl.Scheduler INFO - [EventAlert-global.virt-1456916760101] progress is now 100%.
2016-03-02 11:06:00,124 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.dataprotect.core.DataProtectJob
2016-03-02 11:06:00,125 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:06:00,126 [pool-5-thread-3] net.bluemind.dataprotect.core.DataProtectJob INFO - not planned, last run was 877secs ago.
2016-03-02 11:06:00,126 [pool-5-thread-3] net.bluemind.dataprotect.core.DataProtectJob INFO - less than one day ago, skipping execution.
2016-03-02 11:06:00,134 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.core.jobs.quota.QuotaGatheringJob
2016-03-02 11:06:00,136 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:06:00,137 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 877secs ago.
2016-03-02 11:06:00,137 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:06:00,137 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 877secs ago.
2016-03-02 11:06:00,137 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 877secs ago.
2016-03-02 11:06:00,137 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:06:00,137 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:06:00,137 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 877secs ago.
2016-03-02 11:06:00,137 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:06:00,137 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 877secs ago.
2016-03-02 11:06:00,137 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 877secs ago.
2016-03-02 11:06:00,137 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:06:00,137 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:06:00,137 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 877secs ago.
2016-03-02 11:06:00,137 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:06:00,137 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 877secs ago.
2016-03-02 11:06:00,137 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:06:00,137 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 877secs ago.
2016-03-02 11:06:00,137 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:06:00,137 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 877secs ago.
2016-03-02 11:06:00,137 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:06:00,137 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 877secs ago.
2016-03-02 11:06:00,137 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:06:06,073 [pool-4-thread-2] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob
2016-03-02 11:06:06,074 [pool-4-thread-2] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of Vacation-global.virt-1456916760091
2016-03-02 11:06:06,075 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for Vacation-global.virt-1456916760091...
2016-03-02 11:06:06,079 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - run plan for Vacation@global.virt updated with last_run set to id 3403239 (start: Wed Mar 02 11:06:00 GMT 2016)
2016-03-02 11:06:06,079 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - saving 3 entries...
2016-03-02 11:06:06,082 [pool-4-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - [Vacation-global.virt-1456916760091] finished and recorded: SUCCESS, duration: 9ms.
2016-03-02 11:06:06,100 [pool-4-thread-1] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for Vacation
2016-03-02 11:06:06,100 [pool-4-thread-1] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of EventAlert-global.virt-1456916760101
2016-03-02 11:06:06,101 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for EventAlert-global.virt-1456916760101...
2016-03-02 11:06:06,105 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - run plan for EventAlert@global.virt updated with last_run set to id 3403240 (start: Wed Mar 02 11:06:00 GMT 2016)
2016-03-02 11:06:06,105 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - saving 3 entries...
2016-03-02 11:06:06,108 [pool-4-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - [EventAlert-global.virt-1456916760101] finished and recorded: SUCCESS, duration: 21ms.
2016-03-02 11:06:12,084 [pool-4-thread-2] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for EventAlert
2016-03-02 11:07:00,017 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob
2016-03-02 11:07:00,018 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:07:00,029 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.mailindex.MailspoolIndexJob
2016-03-02 11:07:00,030 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:07:00,031 [pool-5-thread-2] net.bluemind.job.mailindex.MailspoolIndexJob INFO - Not planned.
2016-03-02 11:07:00,063 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId EventBoundariesJob
2016-03-02 11:07:00,065 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:07:00,072 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.contactindex.ContactIndexJob
2016-03-02 11:07:00,073 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 0 jobs from database.
2016-03-02 11:07:00,076 [pool-5-thread-4] net.bluemind.job.contactindex.ContactIndexJob INFO - Not planned.
2016-03-02 11:07:00,080 [pool-5-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing EventBoundariesJob-global.virt-1456916820066
2016-03-02 11:07:00,081 [pool-5-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - [EventBoundariesJob-global.virt-1456916820066] progress is now 100%.
2016-03-02 11:07:00,081 [pool-4-thread-2] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of EventBoundariesJob-global.virt-1456916820066
2016-03-02 11:07:00,081 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for EventBoundariesJob-global.virt-1456916820066...
2016-03-02 11:07:00,084 [pool-4-thread-1] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for EventBoundariesJob
2016-03-02 11:07:00,085 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - run plan for EventBoundariesJob@global.virt updated with last_run set to id 3403241 (start: Wed Mar 02 11:07:00 GMT 2016)
2016-03-02 11:07:00,086 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - saving 1 entries...
2016-03-02 11:07:00,086 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.mailindex.MailspoolResyncIndexJob
2016-03-02 11:07:00,087 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 0 jobs from database.
2016-03-02 11:07:00,088 [pool-5-thread-2] net.bluemind.job.mailindex.MailspoolResyncIndexJob INFO - Not planned.
2016-03-02 11:07:00,089 [pool-4-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - [EventBoundariesJob-global.virt-1456916820066] finished and recorded: SUCCESS, duration: 14ms.
2016-03-02 11:07:00,094 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.calendarindex.CalendarIndexJob
2016-03-02 11:07:00,096 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 0 jobs from database.
2016-03-02 11:07:00,096 [pool-5-thread-4] net.bluemind.job.calendarindex.CalendarIndexJob INFO - Not planned.
2016-03-02 11:07:00,102 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.mailindex.ArchiveSpoolIndexJob
2016-03-02 11:07:00,104 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:07:00,105 [pool-5-thread-1] net.bluemind.job.mailindex.ArchiveSpoolIndexJob INFO - Not planned.
2016-03-02 11:07:00,111 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId Vacation
2016-03-02 11:07:00,113 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:07:00,120 [pool-5-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing Vacation-global.virt-1456916820114
2016-03-02 11:07:00,120 [pool-5-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - [Vacation-global.virt-1456916820114] progress is now 100%.
2016-03-02 11:07:00,120 [pool-4-thread-1] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of Vacation-global.virt-1456916820114
2016-03-02 11:07:00,120 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId EventAlert
2016-03-02 11:07:00,121 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for Vacation-global.virt-1456916820114...
2016-03-02 11:07:00,121 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:07:00,124 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - run plan for Vacation@global.virt updated with last_run set to id 3403242 (start: Wed Mar 02 11:07:00 GMT 2016)
2016-03-02 11:07:00,124 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - saving 3 entries...
2016-03-02 11:07:00,128 [pool-4-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - [Vacation-global.virt-1456916820114] finished and recorded: SUCCESS, duration: 6ms.
2016-03-02 11:07:00,131 [pool-5-thread-3] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916820019
2016-03-02 11:07:00,131 [pool-5-thread-3] net.bluemind.core.jobs.impl.Scheduler INFO - [net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916820019] progress is now 100%.
2016-03-02 11:07:00,140 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.archive.core.ArchiveJob
2016-03-02 11:07:00,142 [pool-5-thread-4] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing EventAlert-global.virt-1456916820122
2016-03-02 11:07:00,142 [pool-5-thread-4] net.bluemind.core.jobs.impl.Scheduler INFO - [EventAlert-global.virt-1456916820122] progress is now 100%.
2016-03-02 11:07:00,143 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 11 jobs from database.
2016-03-02 11:07:00,144 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 899secs ago.
2016-03-02 11:07:00,144 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:07:00,144 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 899secs ago.
2016-03-02 11:07:00,144 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:07:00,145 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 899secs ago.
2016-03-02 11:07:00,145 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:07:00,145 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 899secs ago.
2016-03-02 11:07:00,145 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:07:00,145 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 899secs ago.
2016-03-02 11:07:00,145 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:07:00,145 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 899secs ago.
2016-03-02 11:07:00,145 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:07:00,146 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 899secs ago.
2016-03-02 11:07:00,146 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:07:00,146 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 899secs ago.
2016-03-02 11:07:00,146 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:07:00,146 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 899secs ago.
2016-03-02 11:07:00,146 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:07:00,146 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 899secs ago.
2016-03-02 11:07:00,146 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:07:00,146 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 899secs ago.
2016-03-02 11:07:00,146 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:07:00,152 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.dataprotect.core.DataProtectJob
2016-03-02 11:07:00,153 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:07:00,154 [pool-5-thread-4] net.bluemind.dataprotect.core.DataProtectJob INFO - not planned, last run was 937secs ago.
2016-03-02 11:07:00,154 [pool-5-thread-4] net.bluemind.dataprotect.core.DataProtectJob INFO - less than one day ago, skipping execution.
2016-03-02 11:07:00,163 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.core.jobs.quota.QuotaGatheringJob
2016-03-02 11:07:00,164 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:07:00,165 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 937secs ago.
2016-03-02 11:07:00,165 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 937secs ago.
2016-03-02 11:07:00,165 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 937secs ago.
2016-03-02 11:07:00,165 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:07:00,165 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 937secs ago.
2016-03-02 11:07:00,165 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:07:00,165 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 937secs ago.
2016-03-02 11:07:00,165 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:07:00,165 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 937secs ago.
2016-03-02 11:07:00,165 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:07:00,166 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 937secs ago.
2016-03-02 11:07:00,165 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:07:00,166 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:07:00,165 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:07:00,166 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 937secs ago.
2016-03-02 11:07:00,166 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:07:00,166 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 937secs ago.
2016-03-02 11:07:00,166 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 937secs ago.
2016-03-02 11:07:00,166 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 937secs ago.
2016-03-02 11:07:00,166 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:07:00,166 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:07:00,166 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:07:06,091 [pool-4-thread-2] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for Vacation
2016-03-02 11:07:06,091 [pool-4-thread-2] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916820019
2016-03-02 11:07:06,092 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916820019...
2016-03-02 11:07:06,097 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - run plan for net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob@global.virt updated with last_run set to id 3403243 (start: Wed Mar 02 11:07:00 GMT 2016)
2016-03-02 11:07:06,097 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - saving 9 entries...
2016-03-02 11:07:06,102 [pool-4-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - [net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916820019] finished and recorded: SUCCESS, duration: 112ms.
2016-03-02 11:07:06,130 [pool-4-thread-1] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob
2016-03-02 11:07:06,130 [pool-4-thread-1] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of EventAlert-global.virt-1456916820122
2016-03-02 11:07:06,131 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for EventAlert-global.virt-1456916820122...
2016-03-02 11:07:06,136 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - run plan for EventAlert@global.virt updated with last_run set to id 3403244 (start: Wed Mar 02 11:07:00 GMT 2016)
2016-03-02 11:07:06,136 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - saving 3 entries...
2016-03-02 11:07:06,140 [pool-4-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - [EventAlert-global.virt-1456916820122] finished and recorded: SUCCESS, duration: 20ms.
2016-03-02 11:07:12,104 [pool-4-thread-2] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for EventAlert
2016-03-02 11:08:00,018 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob
2016-03-02 11:08:00,021 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:08:00,033 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.mailindex.MailspoolIndexJob
2016-03-02 11:08:00,034 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:08:00,038 [pool-5-thread-3] net.bluemind.job.mailindex.MailspoolIndexJob INFO - Not planned.
2016-03-02 11:08:00,046 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId EventBoundariesJob
2016-03-02 11:08:00,047 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:08:00,053 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.contactindex.ContactIndexJob
2016-03-02 11:08:00,054 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 0 jobs from database.
2016-03-02 11:08:00,055 [pool-5-thread-1] net.bluemind.job.contactindex.ContactIndexJob INFO - Not planned.
2016-03-02 11:08:00,060 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.mailindex.MailspoolResyncIndexJob
2016-03-02 11:08:00,061 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 0 jobs from database.
2016-03-02 11:08:00,062 [pool-5-thread-3] net.bluemind.job.mailindex.MailspoolResyncIndexJob INFO - Not planned.
2016-03-02 11:08:00,076 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.calendarindex.CalendarIndexJob
2016-03-02 11:08:00,077 [pool-5-thread-4] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing EventBoundariesJob-global.virt-1456916880048
2016-03-02 11:08:00,077 [pool-5-thread-4] net.bluemind.core.jobs.impl.Scheduler INFO - [EventBoundariesJob-global.virt-1456916880048] progress is now 100%.
2016-03-02 11:08:00,077 [pool-4-thread-2] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of EventBoundariesJob-global.virt-1456916880048
2016-03-02 11:08:00,078 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for EventBoundariesJob-global.virt-1456916880048...
2016-03-02 11:08:00,078 [pool-4-thread-1] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for EventBoundariesJob
2016-03-02 11:08:00,079 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - run plan for EventBoundariesJob@global.virt updated with last_run set to id 3403245 (start: Wed Mar 02 11:08:00 GMT 2016)
2016-03-02 11:08:00,079 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - saving 1 entries...
2016-03-02 11:08:00,080 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 0 jobs from database.
2016-03-02 11:08:00,080 [pool-5-thread-1] net.bluemind.job.calendarindex.CalendarIndexJob INFO - Not planned.
2016-03-02 11:08:00,085 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.mailindex.ArchiveSpoolIndexJob
2016-03-02 11:08:00,087 [pool-5-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916880023
2016-03-02 11:08:00,087 [pool-5-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - [net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916880023] progress is now 100%.
2016-03-02 11:08:00,087 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:08:00,087 [pool-4-thread-1] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916880023
2016-03-02 11:08:00,088 [pool-5-thread-3] net.bluemind.job.mailindex.ArchiveSpoolIndexJob INFO - Not planned.
2016-03-02 11:08:00,088 [pool-4-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - [EventBoundariesJob-global.virt-1456916880048] finished and recorded: SUCCESS, duration: 29ms.
2016-03-02 11:08:00,089 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916880023...
2016-03-02 11:08:00,093 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - run plan for net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob@global.virt updated with last_run set to id 3403246 (start: Wed Mar 02 11:08:00 GMT 2016)
2016-03-02 11:08:00,093 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - saving 9 entries...
2016-03-02 11:08:00,094 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId Vacation
2016-03-02 11:08:00,096 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:08:00,098 [pool-4-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - [net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916880023] finished and recorded: SUCCESS, duration: 64ms.
2016-03-02 11:08:00,101 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId EventAlert
2016-03-02 11:08:00,103 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:08:00,104 [pool-5-thread-4] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing Vacation-global.virt-1456916880096
2016-03-02 11:08:00,104 [pool-5-thread-4] net.bluemind.core.jobs.impl.Scheduler INFO - [Vacation-global.virt-1456916880096] progress is now 100%.
2016-03-02 11:08:00,115 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.archive.core.ArchiveJob
2016-03-02 11:08:00,117 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 11 jobs from database.
2016-03-02 11:08:00,118 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 959secs ago.
2016-03-02 11:08:00,118 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:08:00,118 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 959secs ago.
2016-03-02 11:08:00,118 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:08:00,118 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 959secs ago.
2016-03-02 11:08:00,118 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 959secs ago.
2016-03-02 11:08:00,118 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:08:00,118 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:08:00,118 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 959secs ago.
2016-03-02 11:08:00,118 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 959secs ago.
2016-03-02 11:08:00,118 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:08:00,118 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:08:00,119 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 959secs ago.
2016-03-02 11:08:00,119 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:08:00,119 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 959secs ago.
2016-03-02 11:08:00,119 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:08:00,119 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 959secs ago.
2016-03-02 11:08:00,119 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:08:00,119 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 959secs ago.
2016-03-02 11:08:00,119 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:08:00,119 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 959secs ago.
2016-03-02 11:08:00,119 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:08:00,124 [pool-5-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing EventAlert-global.virt-1456916880104
2016-03-02 11:08:00,124 [pool-5-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - [EventAlert-global.virt-1456916880104] progress is now 100%.
2016-03-02 11:08:00,125 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.dataprotect.core.DataProtectJob
2016-03-02 11:08:00,126 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:08:00,127 [pool-5-thread-2] net.bluemind.dataprotect.core.DataProtectJob INFO - not planned, last run was 997secs ago.
2016-03-02 11:08:00,127 [pool-5-thread-2] net.bluemind.dataprotect.core.DataProtectJob INFO - less than one day ago, skipping execution.
2016-03-02 11:08:00,136 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.core.jobs.quota.QuotaGatheringJob
2016-03-02 11:08:00,138 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:08:00,139 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 997secs ago.
2016-03-02 11:08:00,139 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:08:00,139 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 997secs ago.
2016-03-02 11:08:00,139 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:08:00,139 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 997secs ago.
2016-03-02 11:08:00,139 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 997secs ago.
2016-03-02 11:08:00,139 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:08:00,139 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:08:00,139 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 997secs ago.
2016-03-02 11:08:00,139 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 997secs ago.
2016-03-02 11:08:00,139 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:08:00,139 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 997secs ago.
2016-03-02 11:08:00,139 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:08:00,139 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:08:00,139 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 997secs ago.
2016-03-02 11:08:00,139 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 997secs ago.
2016-03-02 11:08:00,139 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 997secs ago.
2016-03-02 11:08:00,139 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:08:00,139 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:08:00,139 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:08:00,139 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 997secs ago.
2016-03-02 11:08:00,139 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:08:06,090 [pool-4-thread-2] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob
2016-03-02 11:08:06,090 [pool-4-thread-2] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of Vacation-global.virt-1456916880096
2016-03-02 11:08:06,091 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for Vacation-global.virt-1456916880096...
2016-03-02 11:08:06,095 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - run plan for Vacation@global.virt updated with last_run set to id 3403247 (start: Wed Mar 02 11:08:00 GMT 2016)
2016-03-02 11:08:06,096 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - saving 3 entries...
2016-03-02 11:08:06,100 [pool-4-thread-1] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for Vacation
2016-03-02 11:08:06,101 [pool-4-thread-1] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of EventAlert-global.virt-1456916880104
2016-03-02 11:08:06,102 [pool-4-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - [Vacation-global.virt-1456916880096] finished and recorded: SUCCESS, duration: 8ms.
2016-03-02 11:08:06,102 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for EventAlert-global.virt-1456916880104...
2016-03-02 11:08:06,106 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - run plan for EventAlert@global.virt updated with last_run set to id 3403248 (start: Wed Mar 02 11:08:00 GMT 2016)
2016-03-02 11:08:06,106 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - saving 3 entries...
2016-03-02 11:08:06,111 [pool-4-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - [EventAlert-global.virt-1456916880104] finished and recorded: SUCCESS, duration: 20ms.
2016-03-02 11:08:12,104 [pool-4-thread-2] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for EventAlert
2016-03-02 11:08:22,809 [vert.x-worker-thread-8] net.bluemind.core.UserManagement INFO - UserManagement.validate: access refused to login: 'reed' domain: 'global.virt', auth type: BM DB, origin: ysnp
2016-03-02 11:08:22,814 [vert.x-eventloop-thread-6] net.bluemind.core.server.vertx.XmlBufferHandler INFO - login/validate in 14ms.
2016-03-02 11:09:00,020 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob
2016-03-02 11:09:00,023 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:09:00,031 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.mailindex.MailspoolIndexJob
2016-03-02 11:09:00,037 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:09:00,037 [pool-5-thread-1] net.bluemind.job.mailindex.MailspoolIndexJob INFO - Not planned.
2016-03-02 11:09:00,043 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId EventBoundariesJob
2016-03-02 11:09:00,045 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:09:00,051 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.contactindex.ContactIndexJob
2016-03-02 11:09:00,053 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 0 jobs from database.
2016-03-02 11:09:00,053 [pool-5-thread-4] net.bluemind.job.contactindex.ContactIndexJob INFO - Not planned.
2016-03-02 11:09:00,056 [pool-5-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing EventBoundariesJob-global.virt-1456916940046
2016-03-02 11:09:00,056 [pool-5-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - [EventBoundariesJob-global.virt-1456916940046] progress is now 100%.
2016-03-02 11:09:00,056 [pool-4-thread-2] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of EventBoundariesJob-global.virt-1456916940046
2016-03-02 11:09:00,057 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for EventBoundariesJob-global.virt-1456916940046...
2016-03-02 11:09:00,057 [pool-4-thread-1] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for EventBoundariesJob
2016-03-02 11:09:00,058 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.mailindex.MailspoolResyncIndexJob
2016-03-02 11:09:00,058 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - run plan for EventBoundariesJob@global.virt updated with last_run set to id 3403249 (start: Wed Mar 02 11:09:00 GMT 2016)
2016-03-02 11:09:00,059 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - saving 1 entries...
2016-03-02 11:09:00,059 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 0 jobs from database.
2016-03-02 11:09:00,060 [pool-5-thread-1] net.bluemind.job.mailindex.MailspoolResyncIndexJob INFO - Not planned.
2016-03-02 11:09:00,061 [pool-4-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - [EventBoundariesJob-global.virt-1456916940046] finished and recorded: SUCCESS, duration: 10ms.
2016-03-02 11:09:00,064 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.calendarindex.CalendarIndexJob
2016-03-02 11:09:00,065 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 0 jobs from database.
2016-03-02 11:09:00,066 [pool-5-thread-4] net.bluemind.job.calendarindex.CalendarIndexJob INFO - Not planned.
2016-03-02 11:09:00,070 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.mailindex.ArchiveSpoolIndexJob
2016-03-02 11:09:00,072 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:09:00,072 [pool-5-thread-2] net.bluemind.job.mailindex.ArchiveSpoolIndexJob INFO - Not planned.
2016-03-02 11:09:00,078 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId Vacation
2016-03-02 11:09:00,079 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:09:00,085 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId EventAlert
2016-03-02 11:09:00,086 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:09:00,088 [pool-5-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing Vacation-global.virt-1456916940079
2016-03-02 11:09:00,088 [pool-5-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - [Vacation-global.virt-1456916940079] progress is now 100%.
2016-03-02 11:09:00,088 [pool-4-thread-1] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of Vacation-global.virt-1456916940079
2016-03-02 11:09:00,089 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for Vacation-global.virt-1456916940079...
2016-03-02 11:09:00,090 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - run plan for Vacation@global.virt updated with last_run set to id 3403250 (start: Wed Mar 02 11:09:00 GMT 2016)
2016-03-02 11:09:00,090 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - saving 3 entries...
2016-03-02 11:09:00,094 [pool-4-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - [Vacation-global.virt-1456916940079] finished and recorded: SUCCESS, duration: 9ms.
2016-03-02 11:09:00,100 [pool-5-thread-3] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916940024
2016-03-02 11:09:00,100 [pool-5-thread-3] net.bluemind.core.jobs.impl.Scheduler INFO - [net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916940024] progress is now 100%.
2016-03-02 11:09:00,103 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.archive.core.ArchiveJob
2016-03-02 11:09:00,104 [pool-5-thread-4] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing EventAlert-global.virt-1456916940087
2016-03-02 11:09:00,104 [pool-5-thread-4] net.bluemind.core.jobs.impl.Scheduler INFO - [EventAlert-global.virt-1456916940087] progress is now 100%.
2016-03-02 11:09:00,106 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 11 jobs from database.
2016-03-02 11:09:00,107 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 1019secs ago.
2016-03-02 11:09:00,107 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 1019secs ago.
2016-03-02 11:09:00,107 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:09:00,107 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:09:00,107 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 1019secs ago.
2016-03-02 11:09:00,107 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 1019secs ago.
2016-03-02 11:09:00,107 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:09:00,107 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:09:00,107 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 1019secs ago.
2016-03-02 11:09:00,107 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 1019secs ago.
2016-03-02 11:09:00,107 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:09:00,107 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:09:00,107 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 1019secs ago.
2016-03-02 11:09:00,107 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 1019secs ago.
2016-03-02 11:09:00,107 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:09:00,107 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:09:00,107 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 1019secs ago.
2016-03-02 11:09:00,107 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 1019secs ago.
2016-03-02 11:09:00,107 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:09:00,107 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:09:00,107 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 1019secs ago.
2016-03-02 11:09:00,107 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:09:00,112 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.dataprotect.core.DataProtectJob
2016-03-02 11:09:00,113 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:09:00,114 [pool-5-thread-1] net.bluemind.dataprotect.core.DataProtectJob INFO - not planned, last run was 1057secs ago.
2016-03-02 11:09:00,114 [pool-5-thread-1] net.bluemind.dataprotect.core.DataProtectJob INFO - less than one day ago, skipping execution.
2016-03-02 11:09:00,121 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.core.jobs.quota.QuotaGatheringJob
2016-03-02 11:09:00,123 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:09:00,124 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 1057secs ago.
2016-03-02 11:09:00,124 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 1057secs ago.
2016-03-02 11:09:00,124 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:09:00,124 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:09:00,124 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 1057secs ago.
2016-03-02 11:09:00,124 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 1057secs ago.
2016-03-02 11:09:00,124 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 1057secs ago.
2016-03-02 11:09:00,124 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:09:00,124 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:09:00,124 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 1057secs ago.
2016-03-02 11:09:00,124 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 1057secs ago.
2016-03-02 11:09:00,124 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:09:00,124 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:09:00,124 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 1057secs ago.
2016-03-02 11:09:00,124 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:09:00,124 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:09:00,124 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 1057secs ago.
2016-03-02 11:09:00,124 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 1057secs ago.
2016-03-02 11:09:00,124 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:09:00,124 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 1057secs ago.
2016-03-02 11:09:00,124 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:09:00,124 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:09:06,063 [pool-4-thread-2] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for Vacation
2016-03-02 11:09:06,063 [pool-4-thread-2] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916940024
2016-03-02 11:09:06,065 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916940024...
2016-03-02 11:09:06,069 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - run plan for net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob@global.virt updated with last_run set to id 3403251 (start: Wed Mar 02 11:09:00 GMT 2016)
2016-03-02 11:09:06,069 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - saving 9 entries...
2016-03-02 11:09:06,075 [pool-4-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - [net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456916940024] finished and recorded: SUCCESS, duration: 76ms.
2016-03-02 11:09:06,096 [pool-4-thread-1] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob
2016-03-02 11:09:06,096 [pool-4-thread-1] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of EventAlert-global.virt-1456916940087
2016-03-02 11:09:06,098 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for EventAlert-global.virt-1456916940087...
2016-03-02 11:09:06,102 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - run plan for EventAlert@global.virt updated with last_run set to id 3403252 (start: Wed Mar 02 11:09:00 GMT 2016)
2016-03-02 11:09:06,102 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - saving 3 entries...
2016-03-02 11:09:06,109 [pool-4-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - [EventAlert-global.virt-1456916940087] finished and recorded: SUCCESS, duration: 17ms.
2016-03-02 11:09:12,078 [pool-4-thread-2] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for EventAlert
2016-03-02 11:10:00,019 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob
2016-03-02 11:10:00,022 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:10:00,030 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.mailindex.MailspoolIndexJob
2016-03-02 11:10:00,032 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:10:00,032 [pool-5-thread-3] net.bluemind.job.mailindex.MailspoolIndexJob INFO - Not planned.
2016-03-02 11:10:00,046 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId EventBoundariesJob
2016-03-02 11:10:00,047 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:10:00,053 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.contactindex.ContactIndexJob
2016-03-02 11:10:00,056 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 0 jobs from database.
2016-03-02 11:10:00,057 [pool-5-thread-4] net.bluemind.job.contactindex.ContactIndexJob INFO - Not planned.
2016-03-02 11:10:00,061 [pool-5-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing EventBoundariesJob-global.virt-1456917000048
2016-03-02 11:10:00,061 [pool-5-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - [EventBoundariesJob-global.virt-1456917000048] progress is now 100%.
2016-03-02 11:10:00,061 [pool-4-thread-2] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of EventBoundariesJob-global.virt-1456917000048
2016-03-02 11:10:00,062 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for EventBoundariesJob-global.virt-1456917000048...
2016-03-02 11:10:00,062 [pool-4-thread-1] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for EventBoundariesJob
2016-03-02 11:10:00,063 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - run plan for EventBoundariesJob@global.virt updated with last_run set to id 3403253 (start: Wed Mar 02 11:10:00 GMT 2016)
2016-03-02 11:10:00,064 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - saving 1 entries...
2016-03-02 11:10:00,064 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.mailindex.MailspoolResyncIndexJob
2016-03-02 11:10:00,065 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 0 jobs from database.
2016-03-02 11:10:00,066 [pool-5-thread-3] net.bluemind.job.mailindex.MailspoolResyncIndexJob INFO - Not planned.
2016-03-02 11:10:00,067 [pool-4-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - [EventBoundariesJob-global.virt-1456917000048] finished and recorded: SUCCESS, duration: 13ms.
2016-03-02 11:10:00,069 [pool-5-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456917000023
2016-03-02 11:10:00,069 [pool-5-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - [net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456917000023] progress is now 100%.
2016-03-02 11:10:00,069 [pool-4-thread-1] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456917000023
2016-03-02 11:10:00,070 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456917000023...
2016-03-02 11:10:00,072 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - run plan for net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob@global.virt updated with last_run set to id 3403254 (start: Wed Mar 02 11:10:00 GMT 2016)
2016-03-02 11:10:00,072 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - saving 7 entries...
2016-03-02 11:10:00,074 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.calendarindex.CalendarIndexJob
2016-03-02 11:10:00,075 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 0 jobs from database.
2016-03-02 11:10:00,075 [pool-5-thread-4] net.bluemind.job.calendarindex.CalendarIndexJob INFO - Not planned.
2016-03-02 11:10:00,076 [pool-4-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - [net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456917000023] finished and recorded: SUCCESS, duration: 46ms.
2016-03-02 11:10:00,081 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.mailindex.ArchiveSpoolIndexJob
2016-03-02 11:10:00,082 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:10:00,082 [pool-5-thread-1] net.bluemind.job.mailindex.ArchiveSpoolIndexJob INFO - Not planned.
2016-03-02 11:10:00,087 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId Vacation
2016-03-02 11:10:00,088 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:10:00,094 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId EventAlert
2016-03-02 11:10:00,095 [pool-5-thread-3] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing Vacation-global.virt-1456917000089
2016-03-02 11:10:00,095 [pool-5-thread-3] net.bluemind.core.jobs.impl.Scheduler INFO - [Vacation-global.virt-1456917000089] progress is now 100%.
2016-03-02 11:10:00,096 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:10:00,105 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.archive.core.ArchiveJob
2016-03-02 11:10:00,108 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 11 jobs from database.
2016-03-02 11:10:00,109 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 1079secs ago.
2016-03-02 11:10:00,109 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:10:00,109 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 1079secs ago.
2016-03-02 11:10:00,109 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 1079secs ago.
2016-03-02 11:10:00,109 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:10:00,109 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:10:00,109 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 1079secs ago.
2016-03-02 11:10:00,109 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:10:00,109 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 1079secs ago.
2016-03-02 11:10:00,109 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:10:00,109 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 1079secs ago.
2016-03-02 11:10:00,109 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 1079secs ago.
2016-03-02 11:10:00,109 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:10:00,109 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:10:00,109 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 1079secs ago.
2016-03-02 11:10:00,109 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:10:00,109 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 1079secs ago.
2016-03-02 11:10:00,109 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 1079secs ago.
2016-03-02 11:10:00,109 [pool-5-thread-4] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:10:00,109 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 1079secs ago.
2016-03-02 11:10:00,109 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:10:00,109 [pool-5-thread-1] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:10:00,113 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.dataprotect.core.DataProtectJob
2016-03-02 11:10:00,115 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:10:00,115 [pool-5-thread-4] net.bluemind.dataprotect.core.DataProtectJob INFO - not planned, last run was 1117secs ago.
2016-03-02 11:10:00,115 [pool-5-thread-4] net.bluemind.dataprotect.core.DataProtectJob INFO - less than one day ago, skipping execution.
2016-03-02 11:10:00,120 [pool-5-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing EventAlert-global.virt-1456917000097
2016-03-02 11:10:00,120 [pool-5-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - [EventAlert-global.virt-1456917000097] progress is now 100%.
2016-03-02 11:10:00,123 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.core.jobs.quota.QuotaGatheringJob
2016-03-02 11:10:00,124 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:10:00,125 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 1117secs ago.
2016-03-02 11:10:00,125 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:10:00,125 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 1117secs ago.
2016-03-02 11:10:00,125 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 1117secs ago.
2016-03-02 11:10:00,125 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:10:00,125 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 1117secs ago.
2016-03-02 11:10:00,125 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:10:00,125 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 1117secs ago.
2016-03-02 11:10:00,125 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:10:00,125 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 1117secs ago.
2016-03-02 11:10:00,125 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:10:00,125 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 1117secs ago.
2016-03-02 11:10:00,125 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:10:00,125 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 1117secs ago.
2016-03-02 11:10:00,125 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:10:00,125 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 1117secs ago.
2016-03-02 11:10:00,125 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:10:00,125 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 1117secs ago.
2016-03-02 11:10:00,126 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:10:00,126 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 1117secs ago.
2016-03-02 11:10:00,126 [pool-5-thread-3] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:10:00,125 [pool-5-thread-1] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:10:06,070 [pool-4-thread-2] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob
2016-03-02 11:10:06,070 [pool-4-thread-2] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of Vacation-global.virt-1456917000089
2016-03-02 11:10:06,071 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for Vacation-global.virt-1456917000089...
2016-03-02 11:10:06,074 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - run plan for Vacation@global.virt updated with last_run set to id 3403255 (start: Wed Mar 02 11:10:00 GMT 2016)
2016-03-02 11:10:06,074 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - saving 3 entries...
2016-03-02 11:10:06,078 [pool-4-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - [Vacation-global.virt-1456917000089] finished and recorded: SUCCESS, duration: 6ms.
2016-03-02 11:10:06,078 [pool-4-thread-1] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for Vacation
2016-03-02 11:10:06,078 [pool-4-thread-1] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of EventAlert-global.virt-1456917000097
2016-03-02 11:10:06,079 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for EventAlert-global.virt-1456917000097...
2016-03-02 11:10:06,082 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - run plan for EventAlert@global.virt updated with last_run set to id 3403256 (start: Wed Mar 02 11:10:00 GMT 2016)
2016-03-02 11:10:06,082 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - saving 3 entries...
2016-03-02 11:10:06,087 [pool-4-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - [EventAlert-global.virt-1456917000097] finished and recorded: SUCCESS, duration: 23ms.
2016-03-02 11:10:12,080 [pool-4-thread-2] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for EventAlert
2016-03-02 11:11:00,016 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob
2016-03-02 11:11:00,017 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:11:00,026 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.mailindex.MailspoolIndexJob
2016-03-02 11:11:00,028 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:11:00,028 [pool-5-thread-4] net.bluemind.job.mailindex.MailspoolIndexJob INFO - Not planned.
2016-03-02 11:11:00,033 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId EventBoundariesJob
2016-03-02 11:11:00,042 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:11:00,050 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.contactindex.ContactIndexJob
2016-03-02 11:11:00,051 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 0 jobs from database.
2016-03-02 11:11:00,052 [pool-5-thread-1] net.bluemind.job.contactindex.ContactIndexJob INFO - Not planned.
2016-03-02 11:11:00,054 [pool-5-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing EventBoundariesJob-global.virt-1456917060043
2016-03-02 11:11:00,054 [pool-5-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - [EventBoundariesJob-global.virt-1456917060043] progress is now 100%.
2016-03-02 11:11:00,054 [pool-4-thread-2] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of EventBoundariesJob-global.virt-1456917060043
2016-03-02 11:11:00,055 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for EventBoundariesJob-global.virt-1456917060043...
2016-03-02 11:11:00,055 [pool-4-thread-1] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for EventBoundariesJob
2016-03-02 11:11:00,056 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - run plan for EventBoundariesJob@global.virt updated with last_run set to id 3403257 (start: Wed Mar 02 11:11:00 GMT 2016)
2016-03-02 11:11:00,056 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - saving 1 entries...
2016-03-02 11:11:00,059 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.mailindex.MailspoolResyncIndexJob
2016-03-02 11:11:00,059 [pool-4-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - [EventBoundariesJob-global.virt-1456917060043] finished and recorded: SUCCESS, duration: 11ms.
2016-03-02 11:11:00,060 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 0 jobs from database.
2016-03-02 11:11:00,061 [pool-5-thread-4] net.bluemind.job.mailindex.MailspoolResyncIndexJob INFO - Not planned.
2016-03-02 11:11:00,067 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.calendarindex.CalendarIndexJob
2016-03-02 11:11:00,068 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 0 jobs from database.
2016-03-02 11:11:00,069 [pool-5-thread-1] net.bluemind.job.calendarindex.CalendarIndexJob INFO - Not planned.
2016-03-02 11:11:00,074 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.job.mailindex.ArchiveSpoolIndexJob
2016-03-02 11:11:00,076 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:11:00,076 [pool-5-thread-2] net.bluemind.job.mailindex.ArchiveSpoolIndexJob INFO - Not planned.
2016-03-02 11:11:00,078 [pool-5-thread-3] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456917060018
2016-03-02 11:11:00,078 [pool-5-thread-3] net.bluemind.core.jobs.impl.Scheduler INFO - [net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456917060018] progress is now 100%.
2016-03-02 11:11:00,079 [pool-4-thread-1] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456917060018
2016-03-02 11:11:00,079 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456917060018...
2016-03-02 11:11:00,081 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - run plan for net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob@global.virt updated with last_run set to id 3403258 (start: Wed Mar 02 11:11:00 GMT 2016)
2016-03-02 11:11:00,081 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - saving 9 entries...
2016-03-02 11:11:00,083 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId Vacation
2016-03-02 11:11:00,084 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:11:00,085 [pool-4-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - [net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob-global.virt-1456917060018] finished and recorded: SUCCESS, duration: 60ms.
2016-03-02 11:11:00,090 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId EventAlert
2016-03-02 11:11:00,092 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:11:00,092 [pool-5-thread-4] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing Vacation-global.virt-1456917060085
2016-03-02 11:11:00,092 [pool-5-thread-4] net.bluemind.core.jobs.impl.Scheduler INFO - [Vacation-global.virt-1456917060085] progress is now 100%.
2016-03-02 11:11:00,100 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.archive.core.ArchiveJob
2016-03-02 11:11:00,102 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 11 jobs from database.
2016-03-02 11:11:00,103 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 1139secs ago.
2016-03-02 11:11:00,103 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:11:00,103 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 1139secs ago.
2016-03-02 11:11:00,103 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 1139secs ago.
2016-03-02 11:11:00,103 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:11:00,103 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:11:00,103 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 1139secs ago.
2016-03-02 11:11:00,103 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 1139secs ago.
2016-03-02 11:11:00,103 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:11:00,103 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:11:00,103 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 1139secs ago.
2016-03-02 11:11:00,103 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:11:00,103 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 1139secs ago.
2016-03-02 11:11:00,103 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:11:00,103 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 1139secs ago.
2016-03-02 11:11:00,103 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:11:00,103 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 1139secs ago.
2016-03-02 11:11:00,103 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:11:00,103 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 1139secs ago.
2016-03-02 11:11:00,104 [pool-5-thread-3] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:11:00,104 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - not forced, last run was 1139secs ago.
2016-03-02 11:11:00,104 [pool-5-thread-2] net.bluemind.archive.core.ArchiveJob INFO - less than one day ago, skipping execution.
2016-03-02 11:11:00,108 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.dataprotect.core.DataProtectJob
2016-03-02 11:11:00,110 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:11:00,110 [pool-5-thread-3] net.bluemind.dataprotect.core.DataProtectJob INFO - not planned, last run was 1177secs ago.
2016-03-02 11:11:00,110 [pool-5-thread-3] net.bluemind.dataprotect.core.DataProtectJob INFO - less than one day ago, skipping execution.
2016-03-02 11:11:00,112 [pool-5-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - Finishing EventAlert-global.virt-1456917060092
2016-03-02 11:11:00,112 [pool-5-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - [EventAlert-global.virt-1456917060092] progress is now 100%.
2016-03-02 11:11:00,118 [Timer-3] net.bluemind.core.jobs.impl.JobBindingImpl INFO - getJobFromId net.bluemind.core.jobs.quota.QuotaGatheringJob
2016-03-02 11:11:00,120 [Timer-3] net.bluemind.core.jobs.impl.JobHome INFO - Loaded 1 jobs from database.
2016-03-02 11:11:00,120 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 1177secs ago.
2016-03-02 11:11:00,121 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:11:00,121 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 1177secs ago.
2016-03-02 11:11:00,121 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:11:00,121 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 1177secs ago.
2016-03-02 11:11:00,121 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:11:00,121 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 1177secs ago.
2016-03-02 11:11:00,121 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:11:00,121 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 1177secs ago.
2016-03-02 11:11:00,121 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:11:00,121 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 1177secs ago.
2016-03-02 11:11:00,121 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:11:00,121 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 1177secs ago.
2016-03-02 11:11:00,121 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:11:00,121 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 1177secs ago.
2016-03-02 11:11:00,121 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:11:00,121 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 1177secs ago.
2016-03-02 11:11:00,121 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:11:00,121 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 1177secs ago.
2016-03-02 11:11:00,121 [pool-5-thread-4] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:11:00,121 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - not forced, last run was 1177secs ago.
2016-03-02 11:11:00,121 [pool-5-thread-2] net.bluemind.core.jobs.quota.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2016-03-02 11:11:06,061 [pool-4-thread-2] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob
2016-03-02 11:11:06,061 [pool-4-thread-2] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of Vacation-global.virt-1456917060085
2016-03-02 11:11:06,062 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for Vacation-global.virt-1456917060085...
2016-03-02 11:11:06,065 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - run plan for Vacation@global.virt updated with last_run set to id 3403259 (start: Wed Mar 02 11:11:00 GMT 2016)
2016-03-02 11:11:06,065 [pool-4-thread-2] net.bluemind.core.jobs.impl.JobHome INFO - saving 3 entries...
2016-03-02 11:11:06,067 [pool-4-thread-2] net.bluemind.core.jobs.impl.Scheduler INFO - [Vacation-global.virt-1456917060085] finished and recorded: SUCCESS, duration: 7ms.
2016-03-02 11:11:06,086 [pool-4-thread-1] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for Vacation
2016-03-02 11:11:06,086 [pool-4-thread-1] net.bluemind.core.jobs.impl.ExecutionRecorder INFO - recording execution of EventAlert-global.virt-1456917060092
2016-03-02 11:11:06,087 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - recording execution for EventAlert-global.virt-1456917060092...
2016-03-02 11:11:06,090 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - run plan for EventAlert@global.virt updated with last_run set to id 3403260 (start: Wed Mar 02 11:11:00 GMT 2016)
2016-03-02 11:11:06,090 [pool-4-thread-1] net.bluemind.core.jobs.impl.JobHome INFO - saving 3 entries...
2016-03-02 11:11:06,093 [pool-4-thread-1] net.bluemind.core.jobs.impl.Scheduler INFO - [EventAlert-global.virt-1456917060092] finished and recorded: SUCCESS, duration: 20ms.
2016-03-02 11:11:12,069 [pool-4-thread-2] net.bluemind.core.jobs.impl.SendReport INFO - No report sent for EventAlert
2016-03-02 11:11:17,370 [vert.x-worker-thread-7] net.bluemind.core.UserManagement INFO - UserManagement.validate: access refused to login: 'fiona' domain: 'global.virt', auth type: BM DB, origin: ysnp
2016-03-02 11:11:17,372 [vert.x-eventloop-thread-7] net.bluemind.core.server.vertx.XmlBufferHandler INFO - login/validate in 8ms.

isys-online · March 2, 2016, 11:44am

Starting Nmap 6.00 ( [http://nmap.org](http://nmap.org) ) at 2016-03-02 12:43 CET
Nmap scan report for localhost (127.0.0.1)
Host is up (0.0000060s latency).
Other addresses for localhost (not scanned): 127.0.0.1
Not shown: 977 closed ports
PORT     STATE SERVICE
22/tcp   open  ssh
24/tcp   open  priv-mail
25/tcp   open  smtp
81/tcp   open  hosts2-ns
111/tcp  open  rpcbind
144/tcp  open  news
587/tcp  open  submission
1110/tcp open  nfsd-status
2000/tcp open  cisco-sccp
5222/tcp open  xmpp-client
5269/tcp open  xmpp-server
5280/tcp open  xmpp-bosh
5432/tcp open  postgresql
8022/tcp open  oa-system
8080/tcp open  http-proxy
8082/tcp open  blackice-alerts
8084/tcp open  unknown
8085/tcp open  unknown
8086/tcp open  d-s-n
8087/tcp open  simplifymedia
9000/tcp open  cslistener
9091/tcp open  xmltec-xmlmail
9200/tcp open  wap-wsp

Poustiquet · March 2, 2016, 12:05pm

Un redémarrage plus long de la Database …
Postgres est très souple sur ce point et très tolérant même quand on n’en prend pas soin (arrêt électrique brutal par exemple) …

Quel est la configuration du serveur ? RAM/Proc , etc …
Erreur I/O des disques ? Erreur du contrôleur Raid (physique ou logiciel) ? Quel est le Load de la machine ? etc …
Y a t’il des erreurs dans le syslog ?

isys-online · March 2, 2016, 12:08pm

Syslog :

root@mx1:~# tail -f /var/log/syslog
Mar  2 13:07:52 mx1 postfix/smtp[12309]: 9366F20B81: to=<root@telecoma.fr>, relay=149.202.166.161[149.202.166.161]:25, delay=408002, delays=408002/0.13/0.05/0.02, dsn=4.7.1, status=deferred (host 149.202.166.161[149.202.166.161] said: 454 4.7.1 <root@telecoma.fr>: Relay access denied (in reply to RCPT TO command))
Mar  2 13:07:52 mx1 postfix/smtp[12310]: 5998920370: to=<root@telecoma.fr>, relay=149.202.166.161[149.202.166.161]:25, delay=206400, delays=206399/0.15/0.04/0.04, dsn=4.7.1, status=deferred (host 149.202.166.161[149.202.166.161] said: 454 4.7.1 <root@telecoma.fr>: Relay access denied (in reply to RCPT TO command))
Mar  2 13:07:52 mx1 postfix/smtp[12317]: 2654620BE0: to=<root@telecoma.fr>, relay=149.202.166.161[149.202.166.161]:25, delay=315496, delays=315496/0.15/0.04/0.03, dsn=4.7.1, status=deferred (host 149.202.166.161[149.202.166.161] said: 454 4.7.1 <root@telecoma.fr>: Relay access denied (in reply to RCPT TO command))
Mar  2 13:07:52 mx1 postfix/smtp[12308]: 97DE7202EF: to=<root@telecoma.fr>, relay=149.202.166.161[149.202.166.161]:25, delay=365899, delays=365899/0.15/0.04/0.04, dsn=4.7.1, status=deferred (host 149.202.166.161[149.202.166.161] said: 454 4.7.1 <root@telecoma.fr>: Relay access denied (in reply to RCPT TO command))
Mar  2 13:07:52 mx1 postfix/smtp[12311]: BF6C02026A: to=<root@telecoma.fr>, relay=149.202.166.161[149.202.166.161]:25, delay=416303, delays=416303/0.15/0.04/0.03, dsn=4.7.1, status=deferred (host 149.202.166.161[149.202.166.161] said: 454 4.7.1 <root@telecoma.fr>: Relay access denied (in reply to RCPT TO command))
Mar  2 13:07:53 mx1 postfix/smtp[12319]: E96391FE65: to=<root@telecoma.fr>, relay=149.202.166.161[149.202.166.161]:25, delay=214688, delays=214688/0.16/0.06/0.03, dsn=4.7.1, status=deferred (host 149.202.166.161[149.202.166.161] said: 454 4.7.1 <root@telecoma.fr>: Relay access denied (in reply to RCPT TO command))
Mar  2 13:07:53 mx1 postfix/smtp[12312]: E800D203A3: to=<info@visionweb.ch>, relay=149.202.166.161[149.202.166.161]:25, delay=88602, delays=88602/0.16/0.07/0.02, dsn=4.7.1, status=deferred (host 149.202.166.161[149.202.166.161] said: 454 4.7.1 <info@visionweb.ch>: Relay access denied (in reply to RCPT TO command))
Mar  2 13:07:53 mx1 postfix/smtp[12320]: C49E620E95: to=<root@telecoma.fr>, relay=149.202.166.161[149.202.166.161]:25, delay=307200, delays=307200/0.17/0.07/0.02, dsn=4.7.1, status=deferred (host 149.202.166.161[149.202.166.161] said: 454 4.7.1 <root@telecoma.fr>: Relay access denied (in reply to RCPT TO command))
Mar  2 13:07:53 mx1 postfix/smtp[12321]: C57EF20395: to=<koebischnyder@visionweb.ch>, relay=149.202.166.161[149.202.166.161]:25, delay=88710, delays=88710/0.18/0.07/0.02, dsn=4.7.1, status=deferred (host 149.202.166.161[149.202.166.161] said: 454 4.7.1 <koebischnyder@visionweb.ch>: Relay access denied (in reply to RCPT TO command))
Mar  2 13:07:53 mx1 postfix/smtp[12322]: C29B220C8E: to=<root@telecoma.fr>, relay=149.202.166.161[149.202.166.161]:25, delay=4800, delays=4800/0.19/0.07/0.01, dsn=4.7.1, status=deferred (host 149.202.166.161[149.202.166.161] said: 454 4.7.1 <root@telecoma.fr>: Relay access denied (in reply to RCPT TO command))

isys-online · March 2, 2016, 12:10pm

load :

root@mx1:~# cat /proc/cpuinfo
processor       : 0
vendor_id       : AuthenticAMD
cpu family      : 21
model           : 0
model name      : AMD Opteron(tm) Processor 4284
stepping        : 2
microcode       : 0x600063d
cpu MHz         : 3000.000
cache size      : 2048 KB
physical id     : 0
siblings        : 4
core id         : 0
cpu cores       : 4
apicid          : 0
initial apicid  : 0
fpu             : yes
fpu_exception   : yes
cpuid level     : 13
wp              : yes
flags           : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ht syscall nx mmxext fxsr_opt rdtscp lm constant_tsc rep_good nopl tsc_reliable nonstop_tsc aperfmperf pni pclmulqdq ssse3 cx16 sse4_1 sse4_2 popcnt aes xsave avx hypervisor lahf_lm extapic abm sse4a misalignsse 3dnowprefetch osvw xop fma4 arat vmmcall
bogomips        : 6000.00
TLB size        : 1536 4K pages
clflush size    : 64
cache_alignment : 64
address sizes   : 40 bits physical, 48 bits virtual
power management:

processor       : 1
vendor_id       : AuthenticAMD
cpu family      : 21
model           : 0
model name      : AMD Opteron(tm) Processor 4284
stepping        : 2
microcode       : 0x600063d
cpu MHz         : 3000.000
cache size      : 2048 KB
physical id     : 0
siblings        : 4
core id         : 1
cpu cores       : 4
apicid          : 1
initial apicid  : 1
fpu             : yes
fpu_exception   : yes
cpuid level     : 13
wp              : yes
flags           : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ht syscall nx mmxext fxsr_opt rdtscp lm constant_tsc rep_good nopl tsc_reliable nonstop_tsc aperfmperf pni pclmulqdq ssse3 cx16 sse4_1 sse4_2 popcnt aes xsave avx hypervisor lahf_lm extapic abm sse4a misalignsse 3dnowprefetch osvw xop fma4 arat vmmcall
bogomips        : 6000.00
TLB size        : 1536 4K pages
clflush size    : 64
cache_alignment : 64
address sizes   : 40 bits physical, 48 bits virtual
power management:

processor       : 2
vendor_id       : AuthenticAMD
cpu family      : 21
model           : 0
model name      : AMD Opteron(tm) Processor 4284
stepping        : 2
microcode       : 0x600063d
cpu MHz         : 3000.000
cache size      : 2048 KB
physical id     : 0
siblings        : 4
core id         : 2
cpu cores       : 4
apicid          : 2
initial apicid  : 2
fpu             : yes
fpu_exception   : yes
cpuid level     : 13
wp              : yes
flags           : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ht syscall nx mmxext fxsr_opt rdtscp lm constant_tsc rep_good nopl tsc_reliable nonstop_tsc aperfmperf pni pclmulqdq ssse3 cx16 sse4_1 sse4_2 popcnt aes xsave avx hypervisor lahf_lm extapic abm sse4a misalignsse 3dnowprefetch osvw xop fma4 arat vmmcall
bogomips        : 6000.00
TLB size        : 1536 4K pages
clflush size    : 64
cache_alignment : 64
address sizes   : 40 bits physical, 48 bits virtual
power management:

processor       : 3
vendor_id       : AuthenticAMD
cpu family      : 21
model           : 0
model name      : AMD Opteron(tm) Processor 4284
stepping        : 2
microcode       : 0x600063d
cpu MHz         : 3000.000
cache size      : 2048 KB
physical id     : 0
siblings        : 4
core id         : 3
cpu cores       : 4
apicid          : 3
initial apicid  : 3
fpu             : yes
fpu_exception   : yes
cpuid level     : 13
wp              : yes
flags           : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ht syscall nx mmxext fxsr_opt rdtscp lm constant_tsc rep_good nopl tsc_reliable nonstop_tsc aperfmperf pni pclmulqdq ssse3 cx16 sse4_1 sse4_2 popcnt aes xsave avx hypervisor lahf_lm extapic abm sse4a misalignsse 3dnowprefetch osvw xop fma4 arat vmmcall
bogomips        : 6000.00
TLB size        : 1536 4K pages
clflush size    : 64
cache_alignment : 64
address sizes   : 40 bits physical, 48 bits virtual
power management:

Poustiquet · March 2, 2016, 12:12pm

Là , coté tentative de connexion,
le serveur ayant de port ouvert et un service derrrière,
des millions de PC ou serveur infectés pas des malware, cherchent à rentrer en bruteforce pour exploiter le serveur pour des SPAM (et des choses pires aussi)

La sécurisation et régles d’hygiènes ne sont pas à exclure …

===

Mais coté syslog, sur le plan matériel et logiciel, y a t’il des erreurs ?

Poustiquet · March 2, 2016, 12:13pm

la commande , au choix,

top

htop

atop

pour afficher le load du serveur

atop permet de voir du premier coup d’oeil (afficher en rouge) les surcharges des disques ou/et raid et volumes de stockage

isys-online · March 2, 2016, 12:18pm

PID RUID EUID THR SYSCPU USRCPU VGROW RGROW RDDSK WRDSK ST EXC S CPUNR CPU CMD 1/3
5753 root root 167 0.05s 0.18s 0K 1368K 0K 4K – - S 3 2% java
13188 root root 1 0.08s 0.01s 8820K 660K 0K 0K – - R 1 1% atop
5878 root root 78 0.02s 0.06s 0K 0K 0K 4K – - S 0 1% java
6589 root root 81 0.04s 0.04s 0K 0K 0K 0K – - S 1 1% java
6574 root root 100 0.02s 0.05s 0K 0K 0K 8K – - S 3 1% java
6520 root root 522 0.04s 0.02s 0K 0K 0K 4K – - S 3 1% java
6250 root root 86 0.05s 0.01s 0K 0K 0K 8K – - S 1 1% java
6258 root root 72 0.03s 0.02s 0K 0K 0K 0K – - S 2 1% java
6351 root root 58 0.02s 0.02s 0K 0K 0K 0K – - S 3 0% java
5643 root root 90 0.01s 0.03s 0K 0K 0K 0K – - S 2 0% java
6267 root root 62 0.01s 0.03s 0K 0K 0K 0K – - S 1 0% java
6201 root root 70 0.03s 0.01s 0K 0K 0K 8K – - S 2 0% java
5844 root root 73 0.03s 0.01s 0K 0K 0K 0K – - S 0 0% java
2820 root root 57 0.00s 0.02s 0K 0K 0K 4K – - S 1 0% java
5693 root root 41 0.00s 0.02s 0K 0K 0K 8K – - S 2 0% java
3897 postgres postgres 1 0.00s 0.01s 0K 0K 0K 0K – - S 2 0% postgres
11056 root root 1 0.01s 0.00s 0K 0K 0K 0K – - S 1 0% apache2
3211 root root 3 0.00s 0.01s 0K 0K 0K 0K – - S 3 0% fail2ban-serve

J’ai la ligne SWP en rouge

Poustiquet · March 2, 2016, 12:23pm

Pas de surcharge en ce moment,
quel OS utilises tu ? serveur physique ou virtuel ?

Je vois un fail2ban,
comment est il configuré ?

isys-online · March 2, 2016, 12:26pm

Debian 7 sur une machine virtuelle

Euh je sais pas comment il est configurer le fail2ban tu veux une info particulière ?

Poustiquet · March 2, 2016, 12:31pm

ok , donc installation par défaut … donc uniquement en SSH …

Il faudrait arréter les services BM
=> redémarrer la Database et voir si elle se comporte bien dans les logs (/var/log/postgresql , de mémoire)

Si Ko => corriger le prob

Si OK => redémarrage des services BM
Et analyse de log BM et Database

Poustiquet · March 2, 2016, 12:32pm

Quel virtualisation utilises tu ?

Et le hosts d’hébergement et/ou son stockage ne serait il pas surchargé ?