[Résolu] Install impossible de la version Edge

Poustiquet · May 2, 2013, 12:11pm

Bonjour à tous,

Je suis entrain de tourner le problème dans tous les sens. mais là, je bloque

Aucun soucis d’install des paquets Edge 20130425
Par contre, lors de la configuration dans la 2ème phase - config du domaine, j’ai un joli popup “Opertion Failed”

Creating domain...
Domain for host 'telegramme.cloudma.fr' is 'cloudma.fr'
Trying to connect to bm-core (attempt 1)
Trying to connect to bm-core (attempt 2)
Trying to connect to bm-core (attempt 3)
Trying to connect to bm-core (attempt 4)

root@telegramme:~# ps -ef | grep bm-core
root     15714     1  7 14:03 pts/0    00:00:27 /usr/lib/jvm/bm-jdk/bin/java -Xrs -Xloggc:/var/log/garbage-collector/bm-core/gc.pause.log -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=4 -XX:GCLogFileSize=1M -XX:+PrintGCApplicationStoppedTime -server -Xms256m -Xmx256m -XX:MaxPermSize=128m -Xss1m -XX:+UseCompressedOops -XX:+UseG1GC -XX:MaxGCPauseMillis=500 -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/tmp -Djava.awt.headless=true -Dosgi.noShutdown=true -Duser.timezone=GMT -Djava.security.egd=file:/dev/./urandom -cp /usr/share/bm-core/plugins/org.eclipse.equinox.launcher_1.2.0.v20110502.jar org.eclipse.equinox.launcher.Main -application net.bluemind.core.launcher.core
root     16177  2228  0 14:08 pts/2    00:00:00 grep --color=auto bm-core
root@telegramme:~#

Même erreur sur Debian ou sur Ubuntu server …

Avez vous une idée ?

PS:
Je pense depuis le départ à une bête erreur de résolution de nom … Mais pour moi, Hostname et Hosts et resolv.conf sont OK …
Je relance une nouvelle installation et je profite pour vérifier les logs d’installation …

Crdt
Poustiquet

Toony · May 2, 2013, 12:16pm

Cette version n’est pas une version officielle. Elle n’aurait pas dû rester dans notre dépôt public (nous allons remédier à celà).
La nouvelle Edge devrait sortir cette fin de semaine.

Poustiquet · May 2, 2013, 6:30pm

Merci de l’info,

Je suis entrain de préparer par cette intall le tuto du [forum=362]Installation économique sur le plan énergétique et financier[/forum]

Alors je vais donc basculer sur http://pkg.blue-mind.net/edge/squeeze/main/

Merci de ton aide

Crdt
Poustiquet

Poustiquet · May 3, 2013, 5:14am

Le test d’installation de la stable fonctionne … .

Mais pour la version actuelle Egde (v 1.10.8573) , lors de son installation, m’indique un problème de dépendance (dsl, je n’ai plus les logs)

Je relance donc l’installation de la version précédente (v 1.8.8027 - en fonction sur un de mes serveurs de test).

Question (à la c… ):
dans le repository http://pkg.blue-mind.net, ne serait-ce pas plus utile d’ajouter un bon vieux lien symbolique vers la source voulue afin que l’on puisse retrouver les sources en cas de PRA (procédure de restauration par le “setup” ) ?

Crdt
Poustiquet

Poustiquet · May 3, 2013, 6:47am

Installation de la dernière stable, instalation sans aucun soucis

Installation HS Edge, défaut de dépendance sur bm-tomcat (Poue plus de log, je peux relancer les installs)

Installation HS de le version Edge précédente , la v 1.8.8027 (testée et fonctionelle sur un autre serveur)
apt => OK, sans erreur dans la console
Setup HTTP Phase A => OK
Setup HTTP Phase B - création domain => HS
Exactement le même symptôme que mon premier post

=======

Toony, aurais tu une piste de log à analyser ?
Je cherche en ce moment des infos plus précise

=======
Analyse de base:
hostname => ok
hostname -f => ok
désactivation Ipv6 => ok => depuis le test d’install de la version stable (et pour réaliser l’install) - j’ai supprimé la gestion de l’IPv6
resolv.conf => ok => search zozma.fr
Install nue sans iptable
Noyau utilisé => j’ai rechargé celui par défaut => 2.6.32-5.amd64 (sans supprimer complètement celui posé par OVH en 3.2, afin de recharger si nécéssaire)

tcataldo · May 3, 2013, 7:00pm

/var/log/bm/core.log et /var/log/bm-tomcat/bm-java.log pour diagnostiquer un pb lors du setup “phase B” (la création du domaine)

Je t’aurai bien fait tester /usr/bin/bm_send_report <mon_email> mais vu que ton setup échoue, ta messagerie n’est pas encore fonctionnelle.

Poustiquet · May 3, 2013, 10:07pm

Merci Thomas pour ll’info,
Je relance l’install avec la dernière edge …

Dans les logs précédents en les analysant, j’ai trouvé cette erreur …

Paramétrage de bm-tomcat (1.10.8573) ...
/usr/share/tomcat/conf/Catalina/localhost /
publish /usr/share/bm-tomcat/applis/adminconsole.xml into BM tomcat server...
publish /usr/share/bm-tomcat/applis/cal.xml into BM tomcat server...
publish /usr/share/bm-tomcat/applis/contact.xml into BM tomcat server...
publish /usr/share/bm-tomcat/applis/ROOT.xml into BM tomcat server...
publish /usr/share/bm-tomcat/applis/settings.xml into BM tomcat server...
publish /usr/share/bm-tomcat/applis/setup.xml into BM tomcat server...
publish /usr/share/bm-tomcat/applis/solr.xml into BM tomcat server...
/
insserv: Service bmcore has to be enabled to start service bm-tomcat
insserv: exiting now!
update-rc.d: error: insserv rejected the script header
dpkg : erreur de traitement de bm-tomcat (--configure) :
 le sous-processus script post-installation installé a retourné une erreur de sortie d'état 1
configured to not write apport reports
                                      dpkg : des problèmes de dépendances empêchent la configuration de bm-admin-console :
 bm-admin-console dépend de bm-tomcat (= 1.10.8573) ; cependant :
 Le paquet bm-tomcat n'est pas encore configuré.

Mais en analysant le debut de l’install, mon IPv6 n’est pas 100% déconfiguré … Pourtant mon /etc/hosts en fait toujours reférence …

Pas de soucis, avec la edge de 20130313 (v 1.8.8207) [Joli balayage dans votre serveur de pkg ], je ne trouve pas le même problème … .

PS :
depuis mon serveur en edge de 20130313 (securemail02) qui fonctionne parfaitement, il n’y a pas de bm_send_report, cela a été implanté quand ?

Crdt
Poustiquet

Poustiquet · May 3, 2013, 10:36pm

La fatigue ne fait pas bon ménage - problème header OK après l’install de linux-header…
J’ai relancé l’install en apt-get -f install …
Et le tomcat a fini son petit boulot …

Le reboot du serveur me semble aussi correct

Mais cela plante toujours en Phase B - les logs ci dessous pour info …
il y a des erreurs de connexions, je fouine …

root@telegramme:~# tail -F /var/log/bm/core.log /var/log/bm-tomcat/bm-java.log
==> /var/log/bm/core.log <==
2013-05-03 22:21:44,577 n.b.u.RunnableExtensionLoader INFO - Loaded 2 implementors of net.bluemind.pool.jdbcdriver
2013-05-03 22:21:44,583 n.b.p.i.BmConfIni WARN - /etc/bm/bm.ini does not exist.
2013-05-03 22:24:10,191 n.b.c.l.Main INFO - Starting Blue Core...
2013-05-03 22:24:10,243 n.b.c.CoreActivator INFO - Activate core.
2013-05-03 22:24:10,245 n.b.c.BMCore INFO - core starting...
2013-05-03 22:24:10,245 n.b.c.BMCore INFO - Loading JDBC pool
2013-05-03 22:24:10,294 n.b.u.RunnableExtensionLoader INFO - net.bluemind.jdbc.oracle.provider.OracleConnectionFactory loaded.
2013-05-03 22:24:10,302 n.b.u.RunnableExtensionLoader INFO - net.bluemind.jdbc.pgsql.provider.PgSQLConnectionFactory loaded.
2013-05-03 22:24:10,302 n.b.u.RunnableExtensionLoader INFO - Loaded 2 implementors of net.bluemind.pool.jdbcdriver
2013-05-03 22:24:10,306 n.b.p.i.BmConfIni WARN - /etc/bm/bm.ini does not exist.

==> /var/log/bm-tomcat/bm-java.log <==
2013-05-03 22:24:49,375 n.b.s.s.DbCreateProcess INFO -  ** Creating role 'bj' (pw: bj) & db 'bj' (lang: fr)...
2013-05-03 22:24:49,376 n.b.s.s.SystemHelper INFO -  ** Creating role 'bj' (pw: bj) & db 'bj' (lang: fr)...
2013-05-03 22:24:49,923 n.b.s.s.DbCreateProcess INFO - ALTER ROLE
2013-05-03 22:24:49,924 n.b.s.s.SystemHelper INFO - ALTER ROLE
2013-05-03 22:24:49,925 n.b.s.s.DbCreateProcess INFO -  ** Create new bj database
2013-05-03 22:24:49,926 n.b.s.s.SystemHelper INFO -  ** Create new bj database
2013-05-03 22:24:59,931 n.b.s.s.DbCreateProcess INFO - CREATE LANGUAGE
2013-05-03 22:24:59,932 n.b.s.s.SystemHelper INFO - CREATE LANGUAGE
2013-05-03 22:25:00,056 n.b.s.s.DbCreateProcess INFO - ALTER DATABASE
2013-05-03 22:25:00,057 n.b.s.s.SystemHelper INFO - ALTER DATABASE
2013-05-03 22:25:30,532 n.b.s.s.SystemHelper INFO - ---
2013-05-03 22:25:30,533 n.b.s.s.SystemHelper INFO - cmd '/usr/share/bm-installation-wizard/tpl/sql/install_bmdb_pgsql_0.sh bj bj bj fr full' exited (0)
2013-05-03 22:25:30,533 n.b.s.s.DbCreateProcess INFO - created db name is 'bj'
2013-05-03 22:25:30,871 n.b.s.s.SystemHelper INFO - --- /etc/init.d/bm-core start ---
2013-05-03 22:25:30,886 n.b.s.s.DbCreateProcess INFO - Blue Mind core Server started: 2227
2013-05-03 22:25:30,887 n.b.s.s.SystemHelper INFO - Blue Mind core Server started: 2227
2013-05-03 22:25:31,990 n.b.s.s.SystemHelper INFO - ---
2013-05-03 22:25:31,991 n.b.s.s.SystemHelper INFO - cmd '/etc/init.d/bm-core start' exited (0)
2013-05-03 22:25:31,992 n.b.s.s.SystemHelper INFO - --- /etc/init.d/apache2 start ---
2013-05-03 22:25:32,160 n.b.s.s.DbCreateProcess INFO - Starting web server: apache2.
2013-05-03 22:25:32,160 n.b.s.s.SystemHelper INFO - Starting web server: apache2.
2013-05-03 22:25:32,161 n.b.s.s.SystemHelper INFO - ---
2013-05-03 22:25:32,161 n.b.s.s.SystemHelper INFO - cmd '/etc/init.d/apache2 start' exited (0)
2013-05-03 22:25:32,162 n.b.s.s.SystemHelper INFO - --- /etc/init.d/bm-eas start ---
2013-05-03 22:25:32,186 n.b.s.s.DbCreateProcess INFO - Blue Mind EAS Server started: 2279
2013-05-03 22:25:32,187 n.b.s.s.SystemHelper INFO - Blue Mind EAS Server started: 2279
2013-05-03 22:25:32,188 n.b.s.s.SystemHelper INFO - ---
2013-05-03 22:25:32,188 n.b.s.s.SystemHelper INFO - cmd '/etc/init.d/bm-eas start' exited (0)
2013-05-03 22:25:32,189 n.b.s.s.SystemHelper INFO - --- /etc/init.d/bm-locator start ---
2013-05-03 22:25:32,247 n.b.s.s.DbCreateProcess INFO - Blue Mind locator Server started: 2299
2013-05-03 22:25:32,248 n.b.s.s.SystemHelper INFO - Blue Mind locator Server started: 2299
2013-05-03 22:25:32,249 n.b.s.s.SystemHelper INFO - ---
2013-05-03 22:25:32,249 n.b.s.s.SystemHelper INFO - cmd '/etc/init.d/bm-locator start' exited (0)

==> /var/log/bm/core.log <==
2013-05-03 22:25:41,959 n.b.c.l.Main INFO - Starting Blue Core...
2013-05-03 22:25:41,985 n.b.c.CoreActivator INFO - Activate core.
2013-05-03 22:25:41,988 n.b.c.BMCore INFO - core starting...
2013-05-03 22:25:41,988 n.b.c.BMCore INFO - Loading JDBC pool
2013-05-03 22:25:42,035 n.b.u.RunnableExtensionLoader INFO - net.bluemind.jdbc.oracle.provider.OracleConnectionFactory loaded.
2013-05-03 22:25:42,042 n.b.u.RunnableExtensionLoader INFO - net.bluemind.jdbc.pgsql.provider.PgSQLConnectionFactory loaded.
2013-05-03 22:25:42,043 n.b.u.RunnableExtensionLoader INFO - Loaded 2 implementors of net.bluemind.pool.jdbcdriver
2013-05-03 22:25:42,049 n.b.p.BMPoolActivator INFO - Starting connection pool 5.135.166.85/bj
2013-05-03 22:25:42,050 n.b.p.BMPoolActivator INFO - dbtype from bm.ini is PGSQL
2013-05-03 22:25:42,374 n.b.p.x.PoolActivator INFO - Pool bundle started.
2013-05-03 22:25:42,745 n.b.p.x.i.DataSource INFO - Starting pool...(jdbc:postgresql://5.135.166.85/bj)
2013-05-03 22:25:42,775 n.b.p.x.i.ConnectionPool INFO - Creating Physical connection...
2013-05-03 22:25:42,933 n.b.p.x.i.ConnectionPool INFO - Physical connection established.
2013-05-03 22:25:42,933 n.b.p.x.i.ConnectionPool INFO - Creating Physical connection...
2013-05-03 22:25:42,942 n.b.p.x.i.ConnectionPool INFO - Physical connection established.
2013-05-03 22:25:42,942 n.b.p.x.i.ConnectionPool INFO - Creating Physical connection...
2013-05-03 22:25:42,951 n.b.p.x.i.ConnectionPool INFO - Physical connection established.
2013-05-03 22:25:42,952 n.b.p.x.i.ConnectionPool INFO - Creating Physical connection...
2013-05-03 22:25:42,961 n.b.p.x.i.ConnectionPool INFO - Physical connection established.
2013-05-03 22:25:42,962 n.b.p.x.i.ConnectionPool INFO - Creating Physical connection...
2013-05-03 22:25:42,971 n.b.p.x.i.ConnectionPool INFO - Physical connection established.
2013-05-03 22:25:42,972 n.b.p.x.i.ConnectionPool INFO - Creating Physical connection...
2013-05-03 22:25:42,981 n.b.p.x.i.ConnectionPool INFO - Physical connection established.
2013-05-03 22:25:42,981 n.b.p.x.i.ConnectionPool INFO - Creating Physical connection...
2013-05-03 22:25:42,991 n.b.p.x.i.ConnectionPool INFO - Physical connection established.
2013-05-03 22:25:42,991 n.b.p.x.i.ConnectionPool INFO - Creating Physical connection...
2013-05-03 22:25:43,002 n.b.p.x.i.ConnectionPool INFO - Physical connection established.
2013-05-03 22:25:43,003 n.b.p.x.i.ConnectionPool INFO - Creating Physical connection...
2013-05-03 22:25:43,012 n.b.p.x.i.ConnectionPool INFO - Physical connection established.
2013-05-03 22:25:43,013 n.b.p.x.i.ConnectionPool INFO - Creating Physical connection...
2013-05-03 22:25:43,022 n.b.p.x.i.ConnectionPool INFO - Physical connection established.
2013-05-03 22:25:43,023 n.b.p.x.i.ConnectionPool INFO - Pool State after start is 0 used out of 10 connections
2013-05-03 22:25:43,024 n.b.p.x.i.PingThread INFO - created with 10 JDBC connections.
2013-05-03 22:25:43,035 n.b.c.BMCore INFO - Loading session store
2013-05-03 22:25:43,414 n.b.c.s.m.TimeOutMap INFO - Built session cache with a 1200000ms timeout.
2013-05-03 22:25:43,417 n.b.c.u.RunnableExtensionLoader INFO - MemorySessionStoreFactory loaded.
2013-05-03 22:25:43,418 n.b.c.u.RunnableExtensionLoader INFO - Loaded 1 implementors of net.bluemind.core.sessionstore
2013-05-03 22:25:43,437 n.b.c.s.m.MemorySessionStoreFactory INFO - init
2013-05-03 22:25:43,439 n.b.c.BMCore INFO - session factory will be SHARED (class net.bluemind.core.session.memory.MemorySessionStoreFactory)
2013-05-03 22:25:43,452 n.b.c.u.RunnableExtensionLoader INFO - NodeKeyHookFactory loaded.
2013-05-03 22:25:43,458 n.b.c.u.RunnableExtensionLoader INFO - WebmailHookFactory loaded.
2013-05-03 22:25:43,465 n.b.c.u.RunnableExtensionLoader INFO - PostfixHookFactory loaded.
2013-05-03 22:25:43,551 n.b.c.u.RunnableExtensionLoader INFO - DomainAliasHookFactory loaded.
2013-05-03 22:25:43,561 n.b.c.u.RunnableExtensionLoader INFO - ArchHookFactory loaded.
2013-05-03 22:25:43,577 n.b.c.u.RunnableExtensionLoader INFO - SystemNotificationHookFactory loaded.
2013-05-03 22:25:43,596 n.b.c.u.RunnableExtensionLoader INFO - AclHookFactory loaded.
2013-05-03 22:25:43,633 n.b.c.u.RunnableExtensionLoader INFO - HookFactory loaded.
2013-05-03 22:25:43,639 n.b.c.u.RunnableExtensionLoader INFO - NginxHookFactory loaded.
2013-05-03 22:25:43,645 n.b.c.u.RunnableExtensionLoader INFO - Loaded 9 implementors of net.bluemind.core.systemhookfactory
2013-05-03 22:25:43,662 n.b.c.s.d.PermanentTokenSystemHook INFO - PermanentTokenSystemHook loaded.
2013-05-03 22:25:43,666 n.b.c.h.HookRegistry INFO - *** PRIO: 2147483647 HOOK: net.bluemind.hook.node.NodeKeySystemHook
2013-05-03 22:25:43,672 n.b.c.h.HookRegistry INFO - *** PRIO: 2147483647 HOOK: net.bluemind.hook.domainalias.EmailTableUpdateHook
2013-05-03 22:25:43,976 n.b.c.h.HookRegistry INFO - *** PRIO: 2147483647 HOOK: net.bluemind.hook.acl.AclHook
2013-05-03 22:25:44,014 n.b.c.h.HookRegistry INFO - *** PRIO: 2 HOOK: net.bluemind.system.cyrus.CyrusSystemHook
2013-05-03 22:25:44,018 n.b.c.h.HookRegistry INFO - *** PRIO: 1 HOOK: net.bluemind.system.webmail.WebmailHook
2013-05-03 22:25:44,031 n.b.c.h.HookRegistry INFO - *** PRIO: 1 HOOK: net.bluemind.system.postfix.PostfixHook
2013-05-03 22:25:44,033 n.b.c.h.HookRegistry INFO - *** PRIO: 0 HOOK: net.bluemind.archive.core.ArchServerHook
2013-05-03 22:25:44,070 n.b.c.h.HookRegistry INFO - *** PRIO: 0 HOOK: net.bluemind.system.notification.SystemNotification
2013-05-03 22:25:44,072 n.b.c.h.HookRegistry INFO - *** PRIO: 0 HOOK: net.bluemind.system.nginx.NginxSystemHook
2013-05-03 22:25:44,083 n.b.c.u.RunnableExtensionLoader INFO - IcsHookFactory loaded.
2013-05-03 22:25:44,097 n.b.c.u.RunnableExtensionLoader INFO - CalendarChangeNotification loaded.
2013-05-03 22:25:44,098 n.b.c.u.RunnableExtensionLoader INFO - Loaded 2 implementors of net.bluemind.core.calendarhookfactory
2013-05-03 22:25:44,129 n.b.c.u.RunnableExtensionLoader INFO - ContactChangeNotification loaded.
2013-05-03 22:25:44,136 n.b.c.u.RunnableExtensionLoader INFO - ContactHookFactory loaded.
2013-05-03 22:25:44,137 n.b.c.u.RunnableExtensionLoader INFO - Loaded 2 implementors of net.bluemind.core.contacthookfactory
2013-05-03 22:25:45,218 n.b.c.u.RunnableExtensionLoader INFO - NodeClientFactory loaded.
2013-05-03 22:25:45,219 n.b.c.u.RunnableExtensionLoader INFO - Loaded 1 implementors of net.bluemind.core.nodeclientfactory
2013-05-03 22:25:45,282 n.b.c.u.RunnableExtensionLoader INFO - PostfixSC loaded.
2013-05-03 22:25:45,286 n.b.c.u.RunnableExtensionLoader INFO - MailshareSCF loaded.
2013-05-03 22:25:45,288 n.b.c.u.RunnableExtensionLoader INFO - DomainSCF loaded.
2013-05-03 22:25:45,290 n.b.c.u.RunnableExtensionLoader INFO - UserSCF loaded.
2013-05-03 22:25:45,301 n.b.c.u.RunnableExtensionLoader INFO - BackupHostSC loaded.
2013-05-03 22:25:45,302 n.b.c.u.RunnableExtensionLoader INFO - Loaded 5 implementors of net.bluemind.core.sanitycheckerfactory
2013-05-03 22:25:45,303 n.b.c.s.SanityChecksRegistry INFO - Registered 5 sanity check factories through plugins
2013-05-03 22:25:45,323 n.b.c.u.RunnableExtensionLoader INFO - PostfixCustomRequirements loaded.
2013-05-03 22:25:45,331 n.b.s.b.f.u.BackupFullPropertyRequirements INFO - Backup full properties requirement created.
2013-05-03 22:25:45,338 n.b.c.u.RunnableExtensionLoader INFO - BackupFullPropertyRequirements loaded.
2013-05-03 22:25:45,343 n.b.c.u.RunnableExtensionLoader INFO - ImapCustomRequirements loaded.
2013-05-03 22:25:45,347 n.b.s.b.u.c.BackupCommonPropertyRequirements INFO - Backup common UI properties requirement created.
2013-05-03 22:25:45,348 n.b.c.u.RunnableExtensionLoader INFO - BackupCommonPropertyRequirements loaded.
2013-05-03 22:25:45,349 n.b.c.u.RunnableExtensionLoader INFO - Loaded 4 implementors of net.bluemind.core.custompropertyrequirements
2013-05-03 22:25:45,350 n.b.c.c.p.CustomPropertyHome INFO - Providing requirements for plugin postfix
2013-05-03 22:25:45,428 n.b.c.c.p.CustomPropertyHome INFO - [postfix]: property domain::slave_relay provided.
2013-05-03 22:25:45,432 n.b.c.c.p.CustomPropertyHome INFO - [postfix]: property domain::split_relay provided.
2013-05-03 22:25:45,452 n.b.c.c.p.CustomPropertyHome INFO - Providing requirements for plugin net.bluemind.system.backup.full
2013-05-03 22:25:45,464 n.b.c.c.p.CustomPropertyHome INFO - [net.bluemind.system.backup.full]: property host::backup_full_server provided.
2013-05-03 22:25:45,476 n.b.c.c.p.CustomPropertyHome INFO - Providing requirements for plugin cyrus
2013-05-03 22:25:45,489 n.b.c.c.p.CustomPropertyHome INFO - [cyrus]: property domain::max_quota provided.
2013-05-03 22:25:45,492 n.b.c.c.p.CustomPropertyHome INFO - [cyrus]: property domain::mailshare_def_quota provided.
2013-05-03 22:25:45,496 n.b.c.c.p.CustomPropertyHome INFO - [cyrus]: property domain::def_quota provided.
2013-05-03 22:25:45,500 n.b.c.c.p.CustomPropertyHome INFO - [cyrus]: property domain::mailshare_max_quota provided.
2013-05-03 22:25:45,518 n.b.c.c.p.CustomPropertyHome INFO - Providing requirements for plugin net.bluemind.system.backup.ui.common
2013-05-03 22:25:45,529 n.b.c.c.p.CustomPropertyHome INFO - [net.bluemind.system.backup.ui.common]: property host::backup_root provided.
2013-05-03 22:25:45,567 n.b.c.u.RunnableExtensionLoader INFO - MailSettingsRequirements loaded.
2013-05-03 22:25:45,576 n.b.c.u.RunnableExtensionLoader INFO - GeneralSettingsRequirements loaded.
2013-05-03 22:25:45,585 n.b.c.u.RunnableExtensionLoader INFO - ContactSettingsRequirements loaded.
2013-05-03 22:25:45,598 n.b.c.u.RunnableExtensionLoader INFO - CalendarSettingsRequirements loaded.
2013-05-03 22:25:45,598 n.b.c.u.RunnableExtensionLoader INFO - Loaded 4 implementors of net.bluemind.core.customsettingrequirements
2013-05-03 22:25:45,599 n.b.c.c.s.CustomSettingHome INFO - reset stored settings
2013-05-03 22:25:45,790 n.b.c.c.s.CustomSettingHome INFO - Providing settings from net.bluemind.custom.settings.mail
2013-05-03 22:25:45,811 n.b.c.c.s.CustomSettingHome INFO - [acl]: setting provided.
2013-05-03 22:25:45,814 n.b.c.c.s.CustomSettingHome INFO - [vacation]: setting provided.
2013-05-03 22:25:45,817 n.b.c.c.s.CustomSettingHome INFO - [identities]: setting provided.
2013-05-03 22:25:45,820 n.b.c.c.s.CustomSettingHome INFO - [rc]: setting provided.
2013-05-03 22:25:45,823 n.b.c.c.s.CustomSettingHome INFO - [sieve]: setting provided.
2013-05-03 22:25:45,825 n.b.c.c.s.CustomSettingHome INFO - [forward]: setting provided.
2013-05-03 22:25:45,844 n.b.c.c.s.CustomSettingHome INFO - [acl]: add value admin
2013-05-03 22:25:45,845 n.b.c.c.s.CustomSettingHome INFO - [acl]: add value write
2013-05-03 22:25:45,846 n.b.c.c.s.CustomSettingHome INFO - [acl]: add value read
2013-05-03 22:25:45,847 n.b.c.c.s.CustomSettingHome INFO - [rc]: add value /webmail/?_task=settings&_action=
2013-05-03 22:25:45,869 n.b.c.c.s.CustomSettingHome INFO - Providing settings from net.bluemind.custom.settings.general
2013-05-03 22:25:45,879 n.b.c.c.s.CustomSettingHome INFO - [set_lang]: setting provided.
2013-05-03 22:25:45,882 n.b.c.c.s.CustomSettingHome INFO - [password]: setting provided.
2013-05-03 22:25:45,885 n.b.c.c.s.CustomSettingHome INFO - [default_app]: setting provided.
2013-05-03 22:25:45,902 n.b.c.c.s.CustomSettingHome INFO - [set_lang]: add value fr
2013-05-03 22:25:45,902 n.b.c.c.s.CustomSettingHome INFO - [set_lang]: add value en
2013-05-03 22:25:45,903 n.b.c.c.s.CustomSettingHome INFO - [default_app]: add value /webmail/
2013-05-03 22:25:45,903 n.b.c.c.s.CustomSettingHome INFO - [default_app]: add value /cal/
2013-05-03 22:25:45,924 n.b.c.c.s.CustomSettingHome INFO - Providing settings from net.bluemind.custom.settings.contact
2013-05-03 22:25:45,935 n.b.c.c.s.CustomSettingHome INFO - [foldermanagement]: setting provided.
2013-05-03 22:25:45,938 n.b.c.c.s.CustomSettingHome INFO - [foldersubscription]: setting provided.
2013-05-03 22:25:45,952 n.b.c.c.s.CustomSettingHome INFO - Providing settings from net.bluemind.custom.settings.calendar
2013-05-03 22:25:45,962 n.b.c.c.s.CustomSettingHome INFO - [set_date]: setting provided.
2013-05-03 22:25:45,965 n.b.c.c.s.CustomSettingHome INFO - [work_hours_end]: setting provided.
2013-05-03 22:25:45,968 n.b.c.c.s.CustomSettingHome INFO - [acl]: setting provided.
2013-05-03 22:25:45,971 n.b.c.c.s.CustomSettingHome INFO - [set_defaultview]: setting provided.
2013-05-03 22:25:45,974 n.b.c.c.s.CustomSettingHome INFO - [set_showweekends]: setting provided.
2013-05-03 22:25:45,976 n.b.c.c.s.CustomSettingHome INFO - [work_hours_start]: setting provided.
2013-05-03 22:25:45,978 n.b.c.c.s.CustomSettingHome INFO - [show_declined_events]: setting provided.
2013-05-03 22:25:45,980 n.b.c.c.s.CustomSettingHome INFO - [management]: setting provided.
2013-05-03 22:25:45,982 n.b.c.c.s.CustomSettingHome INFO - [set_day_weekstart]: setting provided.
2013-05-03 22:25:45,984 n.b.c.c.s.CustomSettingHome INFO - [subscription]: setting provided.
2013-05-03 22:25:45,985 n.b.c.c.s.CustomSettingHome INFO - [set_timeformat]: setting provided.
2013-05-03 22:25:45,987 n.b.c.c.s.CustomSettingHome INFO - [working_days]: setting provided.
2013-05-03 22:25:45,989 n.b.c.c.s.CustomSettingHome INFO - [set_timezone]: setting provided.
2013-05-03 22:25:46,011 n.b.c.c.s.CustomSettingHome INFO - [set_date]: add value MM/dd/yyyy
2013-05-03 22:25:46,012 n.b.c.c.s.CustomSettingHome INFO - [set_date]: add value dd/MM/yyyy
2013-05-03 22:25:46,013 n.b.c.c.s.CustomSettingHome INFO - [set_date]: add value yyyy-MM-dd
2013-05-03 22:25:46,014 n.b.c.c.s.CustomSettingHome INFO - [acl]: add value admin
2013-05-03 22:25:46,015 n.b.c.c.s.CustomSettingHome INFO - [acl]: add value write
2013-05-03 22:25:46,016 n.b.c.c.s.CustomSettingHome INFO - [acl]: add value read
2013-05-03 22:25:46,017 n.b.c.c.s.CustomSettingHome INFO - [acl]: add value access
2013-05-03 22:25:46,018 n.b.c.c.s.CustomSettingHome INFO - [set_defaultview]: add value agenda
2013-05-03 22:25:46,019 n.b.c.c.s.CustomSettingHome INFO - [set_defaultview]: add value month
2013-05-03 22:25:46,020 n.b.c.c.s.CustomSettingHome INFO - [set_defaultview]: add value day
2013-05-03 22:25:46,021 n.b.c.c.s.CustomSettingHome INFO - [set_defaultview]: add value week
2013-05-03 22:25:46,022 n.b.c.c.s.CustomSettingHome INFO - [set_showweekends]: add value yes
2013-05-03 22:25:46,022 n.b.c.c.s.CustomSettingHome INFO - [set_showweekends]: add value no
2013-05-03 22:25:46,023 n.b.c.c.s.CustomSettingHome INFO - [show_declined_events]: add value yes
2013-05-03 22:25:46,024 n.b.c.c.s.CustomSettingHome INFO - [show_declined_events]: add value no
2013-05-03 22:25:46,025 n.b.c.c.s.CustomSettingHome INFO - [set_day_weekstart]: add value monday
2013-05-03 22:25:46,026 n.b.c.c.s.CustomSettingHome INFO - [set_day_weekstart]: add value sunday
2013-05-03 22:25:46,027 n.b.c.c.s.CustomSettingHome INFO - [set_timeformat]: add value h:mma
2013-05-03 22:25:46,028 n.b.c.c.s.CustomSettingHome INFO - [set_timeformat]: add value HH:mm
2013-05-03 22:25:46,029 n.b.c.c.s.CustomSettingHome INFO - [working_days]: add value 6::sun
2013-05-03 22:25:46,030 n.b.c.c.s.CustomSettingHome INFO - [working_days]: add value 3::thu
2013-05-03 22:25:46,031 n.b.c.c.s.CustomSettingHome INFO - [working_days]: add value 5::sat
2013-05-03 22:25:46,032 n.b.c.c.s.CustomSettingHome INFO - [working_days]: add value 1::tue
2013-05-03 22:25:46,032 n.b.c.c.s.CustomSettingHome INFO - [working_days]: add value 2::wed
2013-05-03 22:25:46,033 n.b.c.c.s.CustomSettingHome INFO - [working_days]: add value 4::fri
2013-05-03 22:25:46,034 n.b.c.c.s.CustomSettingHome INFO - [working_days]: add value 0::mon
2013-05-03 22:25:46,136 n.b.u.RunnableExtensionLoader INFO - net.bluemind.system.postfix.NoSmtpProtect loaded.
2013-05-03 22:25:46,143 n.b.u.RunnableExtensionLoader INFO - net.bluemind.core.doc.crappystore.ProtectCrappyStore loaded.
2013-05-03 22:25:46,147 n.b.u.RunnableExtensionLoader INFO - net.bluemind.core.dataprotect.NoBackupTags loaded.
2013-05-03 22:25:46,154 n.b.u.RunnableExtensionLoader INFO - net.bluemind.archive.store.snappy.ProtectSnappyStore loaded.
2013-05-03 22:25:46,165 n.b.u.RunnableExtensionLoader INFO - net.bluemind.dataprotect.pgsql.ProtectPostgresql loaded.
2013-05-03 22:25:46,168 n.b.u.RunnableExtensionLoader INFO - net.bluemind.system.cyrus.ProtectMailImap loaded.
2013-05-03 22:25:46,171 n.b.u.RunnableExtensionLoader INFO - net.bluemind.system.cyrus.ProtectMailImapFrontend loaded.
2013-05-03 22:25:46,171 n.b.u.RunnableExtensionLoader INFO - Loaded 7 implementors of net.bluemind.dataprotect.worker
2013-05-03 22:25:46,172 n.b.u.RunnableExtensionLoader INFO - Loaded 0 implementors of net.bluemind.dataprotect.upgrade
2013-05-03 22:25:46,173 n.b.d.i.Workers WARN - Your Blue Mind lacks DataProtect upgrade support
2013-05-03 22:25:46,175 n.b.u.RunnableExtensionLoader INFO - net.bluemind.dataprotect.core.DataProtectJob loaded.
2013-05-03 22:25:46,181 n.b.u.RunnableExtensionLoader INFO - net.bluemind.archive.core.ArchiveJob loaded.
2013-05-03 22:25:46,186 n.b.u.RunnableExtensionLoader INFO - net.bluemind.system.backup.full.jobs.BackupFullJob loaded.
2013-05-03 22:25:46,203 n.b.u.RunnableExtensionLoader INFO - net.bluemind.core.jobs.event.EventAlertJob loaded.
2013-05-03 22:25:46,208 n.b.u.RunnableExtensionLoader INFO - net.bluemind.core.jobs.oof.VacationJob loaded.
2013-05-03 22:25:46,214 n.b.u.RunnableExtensionLoader INFO - net.bluemind.core.jobs.quota.QuotaGatheringJob loaded.
2013-05-03 22:25:46,219 n.b.u.RunnableExtensionLoader INFO - net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob loaded.
2013-05-03 22:25:46,220 n.b.u.RunnableExtensionLoader INFO - Loaded 7 implementors of net.bluemind.core.bluejob
2013-05-03 22:25:46,260 n.b.c.j.JobRegistry INFO - ******* First scheduler tick at Fri May 03 22:26:00 GMT 2013
2013-05-03 22:25:46,381 n.b.c.u.RunnableExtensionLoader INFO - Loaded 0 implementors of net.bluemind.core.authenticationservice
2013-05-03 22:25:46,387 n.b.c.s.a.i.AuthenticationRegistry INFO - Add default authentication service: class net.bluemind.core.server.auth.impl.DatabaseAuthenticationService
2013-05-03 22:25:46,389 n.b.c.u.RunnableExtensionLoader INFO - Loaded 0 implementors of net.bluemind.core.loginvalidation
2013-05-03 22:25:46,399 n.b.c.u.CoreProvider INFO - registered ICalendar calendar implementation: net.bluemind.core.calendar.CalendarBindingImpl@1610d6ac
2013-05-03 22:25:46,752 n.b.c.u.CoreProvider INFO - registered ICalendar todo implementation: net.bluemind.core.calendar.CalendarBindingImpl@4fabb2cd
2013-05-03 22:25:46,786 n.b.c.u.CoreProvider INFO - registered IAddressBook: net.bluemind.core.contact.AddressBookBindingImpl@4bdb635a
2013-05-03 22:25:46,904 n.b.c.u.CoreProvider INFO - registered ISetting implementation: net.bluemind.core.setting.SettingBindingImpl@62b81b64
2013-05-03 22:25:46,991 n.b.c.u.CoreProvider INFO - registered IGroup implementation: net.bluemind.core.group.GroupBindingImpl@2cdfaddd
2013-05-03 22:25:47,052 n.b.c.u.CoreProvider INFO - registered IAcl implementation: net.bluemind.core.acl.AclBindingImpl@5811031a
2013-05-03 22:25:47,131 n.b.c.u.CoreProvider INFO - registered IUser implementation: net.bluemind.core.user.UserBindingImpl@21ffbd3b
2013-05-03 22:25:47,183 n.b.c.u.CoreProvider INFO - registered IResource: net.bluemind.core.resource.ResourceBindingImpl@ac07edd
2013-05-03 22:25:47,216 n.b.c.u.CoreProvider INFO - registered IMailshare implementation: net.bluemind.core.mailshare.MailshareBindingImpl@776ebe1
2013-05-03 22:25:47,269 n.b.c.u.CoreProvider INFO - registered IDirectoryimplementation: net.bluemind.core.directory.DirectoryBindingImpl$1@2a379529
2013-05-03 22:25:48,176 n.b.c.r.RBACBindingImpl INFO - Permission role systemManagement created
2013-05-03 22:25:50,391 n.b.c.r.RBACBindingImpl INFO - Permission role userManagement created
2013-05-03 22:25:50,515 n.b.h.c.NonOsgiActivator WARN - failed to locate bm/mq server. falling back to localhost
2013-05-03 22:25:51,552 n.b.c.UserManagement INFO - MQ connection for push queues completed.
2013-05-03 22:25:52,438 n.b.c.s.m.MemorySessionStoreFactory INFO - MQ connection completed. Session replication activated
2013-05-03 22:25:54,044 n.b.c.r.RBACBindingImpl INFO - Permission role groupwareUsage created
2013-05-03 22:25:54,103 n.b.c.u.CoreProvider INFO - registered IDistributionList: net.bluemind.core.distributionlist.DistributionListBindingImpl@f544072
2013-05-03 22:25:54,156 n.b.c.u.CoreProvider INFO - registered IInfo: net.bluemind.core.info.InfoBindingImpl$1@5f6dad1a
2013-05-03 22:25:54,180 n.b.c.u.CoreProvider INFO - registered ISieveFilter: net.bluemind.core.sievefilter.SieveFilterBindingImpl@7532157
2013-05-03 22:25:54,201 n.b.c.u.CoreProvider INFO - registered IJob: net.bluemind.core.jobs.impl.JobBindingImpl@273aa934
2013-05-03 22:25:54,298 n.b.c.u.CoreProvider INFO - registered IIdentity: net.bluemind.core.mailidentity.IdentityBindingImpl@4f86f5f
2013-05-03 22:25:54,323 n.b.c.u.CoreProvider INFO - registered ITasks: net.bluemind.core.taskref.TaskBindingImpl@42532750
2013-05-03 22:25:54,348 n.b.c.u.RunnableExtensionLoader INFO - MailHandler loaded.
2013-05-03 22:25:54,357 n.b.c.u.CoreProvider INFO - registered IDataProtect: net.bluemind.dataprotect.core.impl.DataProtectBinding@32efcbc8
2013-05-03 22:25:54,367 n.b.c.u.RunnableExtensionLoader INFO - DPHandler loaded.
2013-05-03 22:25:54,390 n.b.c.u.RunnableExtensionLoader INFO - PrintHandler loaded.
2013-05-03 22:25:54,407 n.b.c.u.CoreProvider INFO - registered IHierarchicalStorage implementation: net.bluemind.archive.core.HierarchicalStorageImpl@5297df32
2013-05-03 22:25:54,428 n.b.c.u.RunnableExtensionLoader INFO - HSMHandler loaded.
2013-05-03 22:25:54,458 n.b.c.u.CoreProvider INFO - registered IBackupFull: net.bluemind.system.backup.full.corehandler.BackupFullBindingImpl@5145e5ac
2013-05-03 22:25:54,475 n.b.c.u.RunnableExtensionLoader INFO - BackupFullHandler loaded.
2013-05-03 22:25:54,490 n.b.c.u.RunnableExtensionLoader INFO - CrappyStoreFactory loaded.
2013-05-03 22:25:54,491 n.b.c.u.RunnableExtensionLoader INFO - Loaded 1 implementors of net.bluemind.core.handler.doc.documentstore
2013-05-03 22:25:54,504 n.b.c.u.CoreProvider INFO - registered IDocument: net.bluemind.core.handler.doc.DocBindingImpl@4167dd87
2013-05-03 22:25:54,522 n.b.c.h.d.DocHandler INFO - docHandler created
2013-05-03 22:25:54,523 n.b.c.u.RunnableExtensionLoader INFO - DocHandler loaded.
2013-05-03 22:25:54,550 n.b.c.u.RunnableExtensionLoader INFO - PostfixUiExtension loaded.
2013-05-03 22:25:54,555 n.b.c.u.RunnableExtensionLoader INFO - CyrusDomainUi loaded.
2013-05-03 22:25:54,559 n.b.s.b.u.c.BackupCommonPropertyRequirements INFO - Backup common UI properties requirement created.
2013-05-03 22:25:54,561 n.b.c.u.RunnableExtensionLoader INFO - BackupCommonUIHostExtensionProvider loaded.
2013-05-03 22:25:54,561 n.b.c.u.RunnableExtensionLoader INFO - Loaded 3 implementors of net.bluemind.core.handler.ui.extensionprovider
2013-05-03 22:25:54,603 n.b.c.u.RunnableExtensionLoader INFO - MailSettingsExtensionProvider loaded.
2013-05-03 22:25:54,607 n.b.c.u.RunnableExtensionLoader INFO - GeneralSettingsExtensionProvider loaded.
2013-05-03 22:25:54,621 n.b.c.u.RunnableExtensionLoader INFO - DLCTbirdSettingsExtensionProvider loaded.
2013-05-03 22:25:54,626 n.b.c.u.RunnableExtensionLoader INFO - ContactSettingsExtensionProvider loaded.
2013-05-03 22:25:54,638 n.b.c.u.RunnableExtensionLoader INFO - DLCOutlookSettingsExtensionProvider loaded.
2013-05-03 22:25:54,644 n.b.c.u.RunnableExtensionLoader INFO - CalendarSettingsExtensionProvider loaded.
2013-05-03 22:25:54,652 n.b.c.u.RunnableExtensionLoader INFO - DLCenterSettingsExtensionProvider loaded.
2013-05-03 22:25:54,652 n.b.c.u.RunnableExtensionLoader INFO - Loaded 7 implementors of net.bluemind.core.handler.ui.settingprovider
2013-05-03 22:25:54,677 n.b.c.u.RunnableExtensionLoader INFO - UiHandler loaded.
2013-05-03 22:25:54,688 n.b.c.u.RunnableExtensionLoader INFO - ArchiveTagProvider loaded.
2013-05-03 22:25:54,691 n.b.c.u.RunnableExtensionLoader INFO - BackupTagsProvider loaded.
2013-05-03 22:25:54,692 n.b.c.u.RunnableExtensionLoader INFO - Loaded 2 implementors of net.bluemind.core.handler.host.templatecustomizer
2013-05-03 22:25:54,696 n.b.c.h.h.SystemHandler INFO - system handler created.
2013-05-03 22:25:54,996 n.b.c.h.h.SystemBindingImpl INFO - system tag mail/smtp_in created.
2013-05-03 22:25:55,017 n.b.c.h.h.SystemBindingImpl INFO - system tag mail/smtp_out created.
2013-05-03 22:25:55,034 n.b.c.h.h.SystemBindingImpl INFO - system tag mail/imap created.
2013-05-03 22:25:55,051 n.b.c.h.h.SystemBindingImpl INFO - system tag mail/imap_frontend created.
2013-05-03 22:25:55,110 n.b.c.h.h.SystemBindingImpl INFO - system tag mail/archive created.
2013-05-03 22:25:55,126 n.b.c.h.h.SystemBindingImpl INFO - system tag solr/event created.
2013-05-03 22:25:55,142 n.b.c.h.h.SystemBindingImpl INFO - system tag solr/contact created.
2013-05-03 22:25:55,159 n.b.c.h.h.SystemBindingImpl INFO - system tag solr/webmail created.
2013-05-03 22:25:55,170 n.b.c.h.h.SystemBindingImpl INFO - system tag bm/core created.
2013-05-03 22:25:55,184 n.b.c.h.h.SystemBindingImpl INFO - system tag bm/mq created.
2013-05-03 22:25:55,196 n.b.c.h.h.SystemBindingImpl INFO - system tag bm/ac created.
2013-05-03 22:25:55,262 n.b.c.h.h.SystemBindingImpl INFO - system tag bm/cal created.
2013-05-03 22:25:55,276 n.b.c.h.h.SystemBindingImpl INFO - system tag bm/webmail created.
2013-05-03 22:25:55,287 n.b.c.h.h.SystemBindingImpl INFO - system tag bm/contact created.
2013-05-03 22:25:55,300 n.b.c.h.h.SystemBindingImpl INFO - system tag bm/settings created.
2013-05-03 22:25:55,312 n.b.c.h.h.SystemBindingImpl INFO - system tag bm/redirector created.
2013-05-03 22:25:55,326 n.b.c.h.h.SystemBindingImpl INFO - system tag bm/nginx created.
2013-05-03 22:25:55,337 n.b.c.h.h.SystemBindingImpl INFO - system tag bm/pgsql created.
2013-05-03 22:25:55,351 n.b.c.h.h.SystemBindingImpl INFO - system tag backup/server created.
2013-05-03 22:25:55,352 n.b.c.u.CoreProvider INFO - registered ISystem implementation: net.bluemind.core.handler.host.SystemBindingImpl$1@4c2b880a
2013-05-03 22:25:55,395 n.b.c.u.RunnableExtensionLoader INFO - SystemHandler loaded.
2013-05-03 22:25:55,395 n.b.c.u.RunnableExtensionLoader INFO - Loaded 8 implementors of net.bluemind.core.handler
2013-05-03 22:25:55,413 n.b.c.BMCore INFO - Started Blue Mind Core 1.10.8573 (Edge Branch)
2013-05-03 22:25:55,414 n.b.c.l.Main INFO - starting jetty...
2013-05-03 22:25:55,455 o.m.log INFO - Logging to Logger[org.mortbay.log] via org.mortbay.log.Slf4jLog
2013-05-03 22:25:55,751 o.m.log INFO - jetty-6.1.x
2013-05-03 22:25:55,867 o.m.log INFO - Started SelectChannelConnector@0.0.0.0:8085
2013-05-03 22:25:55,875 n.b.c.l.Main INFO - jetty started, loading servlets...
2013-05-03 22:25:55,927 n.b.c.s.SyncServlet INFO - init of SyncServlet
2013-05-03 22:25:56,161 n.b.c.l.Main INFO - Accepting queries on port 8085
2013-05-03 22:26:00,142 n.b.c.j.i.JobBindingImpl INFO - getJobFromId BackupFullJob
2013-05-03 22:26:00,161 n.b.c.j.i.JobHome INFO - Loaded 0 jobs from database.
2013-05-03 22:26:00,207 n.b.c.j.i.JobBindingImpl INFO - getJobFromId net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob
2013-05-03 22:26:00,217 n.b.c.j.i.JobHome INFO - Loaded 0 jobs from database.
2013-05-03 22:26:00,253 n.b.c.j.i.JobBindingImpl INFO - getJobFromId Vacation
2013-05-03 22:26:00,260 n.b.c.j.i.JobHome INFO - Loaded 0 jobs from database.
2013-05-03 22:26:00,290 n.b.c.j.i.JobBindingImpl INFO - getJobFromId EventAlert
2013-05-03 22:26:00,295 n.b.c.j.i.JobHome INFO - Loaded 0 jobs from database.
2013-05-03 22:26:00,319 n.b.c.j.i.JobBindingImpl INFO - getJobFromId net.bluemind.archive.core.ArchiveJob
2013-05-03 22:26:00,324 n.b.c.j.i.JobHome INFO - Loaded 0 jobs from database.
2013-05-03 22:26:00,326 n.b.c.j.i.Scheduler INFO - Finishing Vacation-global.virt-1367619960261
2013-05-03 22:26:00,326 n.b.c.j.i.Scheduler INFO - [Vacation-global.virt-1367619960261] progress is now 100%.
2013-05-03 22:26:00,333 n.b.c.j.i.ExecutionRecorder INFO - recording execution of Vacation-global.virt-1367619960261
2013-05-03 22:26:00,343 n.b.c.j.i.JobHome INFO - recording execution for Vacation-global.virt-1367619960261...
2013-05-03 22:26:00,347 n.b.c.j.i.Scheduler INFO - Finishing EventAlert-global.virt-1367619960296
2013-05-03 22:26:00,348 n.b.c.j.i.Scheduler INFO - [EventAlert-global.virt-1367619960296] progress is now 100%.
2013-05-03 22:26:00,351 n.b.c.j.i.ExecutionRecorder INFO - recording execution of EventAlert-global.virt-1367619960296
2013-05-03 22:26:00,361 n.b.c.j.i.JobHome INFO - run plan for Vacation@global.virt updated with last_run set to id 1 (start: Fri May 03 22:26:00 GMT 2013)
2013-05-03 22:26:00,362 n.b.c.j.i.JobHome INFO - saving 3 entries...
2013-05-03 22:26:00,361 n.b.c.j.i.JobHome INFO - recording execution for EventAlert-global.virt-1367619960296...
2013-05-03 22:26:00,367 n.b.c.j.i.JobBindingImpl INFO - getJobFromId net.bluemind.dataprotect.core.DataProtectJob
2013-05-03 22:26:00,374 n.b.c.j.i.JobHome INFO - Loaded 0 jobs from database.
2013-05-03 22:26:00,375 n.b.c.j.i.JobHome INFO - run plan for EventAlert@global.virt updated with last_run set to id 2 (start: Fri May 03 22:26:00 GMT 2013)
2013-05-03 22:26:00,375 n.b.c.j.i.JobHome INFO - saving 3 entries...
2013-05-03 22:26:00,378 n.b.d.c.DataProtectJob INFO - not planned, last run was 14secs ago.
2013-05-03 22:26:00,379 n.b.d.c.DataProtectJob INFO - less than one day ago, skipping execution.
2013-05-03 22:26:00,380 n.b.c.j.i.Scheduler INFO - [Vacation-global.virt-1367619960261] finished and recorded: SUCCESS, duration: 65ms.
2013-05-03 22:26:00,392 n.b.c.j.i.Scheduler INFO - [EventAlert-global.virt-1367619960296] finished and recorded: SUCCESS, duration: 51ms.
2013-05-03 22:26:00,397 n.b.c.j.i.JobBindingImpl INFO - getJobFromId net.bluemind.core.jobs.quota.QuotaGatheringJob
2013-05-03 22:26:00,403 n.b.c.j.i.JobHome INFO - Loaded 0 jobs from database.
2013-05-03 22:26:14,082 n.b.s.n.SystemNotification INFO - Producer on jms.topic.bm.system.notification created.
2013-05-03 22:26:14,111 n.b.c.n.CalendarChangeNotification INFO - Producer on jms.topic.bm.calendar.notification created.
2013-05-03 22:26:14,140 n.b.c.n.ContactChangeNotification INFO - Producer on jms.topic.bm.contact.notification created.
2013-05-03 22:27:00,040 n.b.c.j.i.JobBindingImpl INFO - getJobFromId BackupFullJob
2013-05-03 22:27:00,046 n.b.c.j.i.JobHome INFO - Loaded 0 jobs from database.
2013-05-03 22:27:00,068 n.b.c.j.i.JobBindingImpl INFO - getJobFromId net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob
2013-05-03 22:27:00,075 n.b.c.j.i.JobHome INFO - Loaded 0 jobs from database.
2013-05-03 22:27:00,100 n.b.c.j.i.JobBindingImpl INFO - getJobFromId Vacation
2013-05-03 22:27:00,109 n.b.c.j.i.JobHome INFO - Loaded 1 jobs from database.
2013-05-03 22:27:00,130 n.b.c.j.i.JobBindingImpl INFO - getJobFromId EventAlert
2013-05-03 22:27:00,138 n.b.c.j.i.JobHome INFO - Loaded 1 jobs from database.
2013-05-03 22:27:00,164 n.b.c.j.i.JobBindingImpl INFO - getJobFromId net.bluemind.archive.core.ArchiveJob
2013-05-03 22:27:00,169 n.b.c.j.i.JobHome INFO - Loaded 0 jobs from database.
2013-05-03 22:27:00,178 n.b.c.j.i.Scheduler INFO - Finishing EventAlert-global.virt-1367620020140
2013-05-03 22:27:00,179 n.b.c.j.i.Scheduler INFO - [EventAlert-global.virt-1367620020140] progress is now 100%.
2013-05-03 22:27:00,180 n.b.c.j.i.ExecutionRecorder INFO - recording execution of EventAlert-global.virt-1367620020140
2013-05-03 22:27:00,185 n.b.c.j.i.JobHome INFO - recording execution for EventAlert-global.virt-1367620020140...
2013-05-03 22:27:00,193 n.b.c.j.i.JobHome INFO - run plan for EventAlert@global.virt updated with last_run set to id 3 (start: Fri May 03 22:27:00 GMT 2013)
2013-05-03 22:27:00,194 n.b.c.j.i.JobHome INFO - saving 3 entries...
2013-05-03 22:27:00,198 n.b.c.j.i.JobBindingImpl INFO - getJobFromId net.bluemind.dataprotect.core.DataProtectJob
2013-05-03 22:27:00,203 n.b.c.j.i.JobHome INFO - Loaded 0 jobs from database.
2013-05-03 22:27:00,204 n.b.d.c.DataProtectJob INFO - not planned, last run was 74secs ago.
2013-05-03 22:27:00,205 n.b.d.c.DataProtectJob INFO - less than one day ago, skipping execution.
2013-05-03 22:27:00,220 n.b.c.j.i.JobBindingImpl INFO - getJobFromId net.bluemind.core.jobs.quota.QuotaGatheringJob
2013-05-03 22:27:00,226 n.b.c.j.i.JobHome INFO - Loaded 0 jobs from database.
2013-05-03 22:27:00,234 n.b.c.j.i.Scheduler INFO - Finishing Vacation-global.virt-1367620020110
2013-05-03 22:27:00,234 n.b.c.j.i.Scheduler INFO - [Vacation-global.virt-1367620020110] progress is now 100%.
2013-05-03 22:27:00,235 n.b.c.j.i.ExecutionRecorder INFO - recording execution of Vacation-global.virt-1367620020110
2013-05-03 22:27:00,238 n.b.c.j.i.JobHome INFO - recording execution for Vacation-global.virt-1367620020110...
2013-05-03 22:27:00,242 n.b.c.j.i.Scheduler INFO - [EventAlert-global.virt-1367620020140] finished and recorded: SUCCESS, duration: 39ms.
2013-05-03 22:27:00,246 n.b.c.j.i.JobHome INFO - run plan for Vacation@global.virt updated with last_run set to id 4 (start: Fri May 03 22:27:00 GMT 2013)
2013-05-03 22:27:00,246 n.b.c.j.i.JobHome INFO - saving 3 entries...
2013-05-03 22:27:00,259 n.b.c.j.i.Scheduler INFO - [Vacation-global.virt-1367620020110] finished and recorded: SUCCESS, duration: 124ms.

==> /var/log/bm-tomcat/bm-java.log <==
2013-05-03 22:27:21,540 n.b.s.s.TestExternalUrl INFO - test external url called !
2013-05-03 22:27:21,578 n.b.s.s.NetworkManagerImpl INFO - isUrlJoinable(telegramme.zozma.fr)
2013-05-03 22:27:40,484 n.b.s.s.IniFileManagerImpl INFO - /etc/bm/bm.ini [global] / external-url set to 'telegramme.zozma.fr'
2013-05-03 22:27:40,485 n.b.s.s.SystemHelper INFO - --- touch /usr/share/tomcat/conf/Catalina/localhost/cal.xml ---
2013-05-03 22:27:40,487 n.b.s.s.SystemHelper INFO - ---
2013-05-03 22:27:40,488 n.b.s.s.SystemHelper INFO - cmd 'touch /usr/share/tomcat/conf/Catalina/localhost/cal.xml' exited (0)
2013-05-03 22:27:40,489 n.b.s.s.SystemHelper INFO - --- touch /usr/share/tomcat/conf/Catalina/localhost/settings.xml ---
2013-05-03 22:27:40,491 n.b.s.s.SystemHelper INFO - ---
2013-05-03 22:27:40,493 n.b.s.s.SystemHelper INFO - cmd 'touch /usr/share/tomcat/conf/Catalina/localhost/settings.xml' exited (0)
2013-05-03 22:27:40,494 n.b.s.s.SystemHelper INFO - --- touch /usr/share/tomcat/conf/Catalina/localhost/ROOT.xml ---
2013-05-03 22:27:40,496 n.b.s.s.SystemHelper INFO - ---
2013-05-03 22:27:40,497 n.b.s.s.SystemHelper INFO - cmd 'touch /usr/share/tomcat/conf/Catalina/localhost/ROOT.xml' exited (0)
2013-05-03 22:27:40,498 n.b.s.s.SystemHelper INFO - --- touch /usr/share/tomcat/conf/Catalina/localhost/contact.xml ---
2013-05-03 22:27:40,500 n.b.s.s.SystemHelper INFO - ---
2013-05-03 22:27:40,501 n.b.s.s.SystemHelper INFO - cmd 'touch /usr/share/tomcat/conf/Catalina/localhost/contact.xml' exited (0)
2013-05-03 22:27:40,501 n.b.s.s.SystemHelper INFO - --- touch /usr/share/tomcat/conf/Catalina/localhost/adminconsole.xml ---
2013-05-03 22:27:40,504 n.b.s.s.SystemHelper INFO - ---
2013-05-03 22:27:40,505 n.b.s.s.SystemHelper INFO - cmd 'touch /usr/share/tomcat/conf/Catalina/localhost/adminconsole.xml' exited (0)
2013-05-03 22:27:42,654 n.b.s.s.HostDomainAdminTask INFO - Creating domain...
2013-05-03 22:27:42,655 n.b.s.s.HostDomainAdminTask INFO - #progress 10
2013-05-03 22:27:42,655 n.b.s.s.HostDomainAdminTask INFO - core hostname from session is telegramme.zozma.fr
2013-05-03 22:27:42,656 n.b.s.s.HostDomainAdminTask INFO - Domain for host 'telegramme.zozma.fr' is 'zozma.fr'
2013-05-03 22:27:43,042 o.a.c.s.HostConfig INFO - Undeploying context ]
2013-05-03 22:27:43,054 o.a.c.s.HostConfig INFO - Undeploying context [/settings]
2013-05-03 22:27:43,056 o.a.c.s.HostConfig INFO - Undeploying context [/contact]
2013-05-03 22:27:43,059 o.a.c.s.HostConfig INFO - Undeploying context [/adminconsole]
2013-05-03 22:27:43,061 o.a.c.s.HostConfig INFO - Undeploying context [/cal]
2013-05-03 22:27:43,064 o.a.c.s.HostConfig INFO - Deploying configuration descriptor cal.xml
2013-05-03 22:27:43,222 n.b.s.s.HostDomainAdminTask INFO - Trying to connect to bm-core (attempt 1)
2013-05-03 22:27:43,439 o.a.c.s.HostConfig INFO - Deploying configuration descriptor contact.xml
2013-05-03 22:27:43,833 o.a.c.s.HostConfig INFO - Deploying configuration descriptor adminconsole.xml

==> /var/log/bm/core.log <==
2013-05-03 22:27:44,381 n.b.c.s.a.i.AuthenticationRegistry INFO - Validate password using service net.bluemind.core.server.auth.impl.DatabaseAuthenticationService: YES in 14ms.
2013-05-03 22:27:44,616 n.b.c.UserManagement INFO - Created push queue bm.push.1.514cf000-cd43-466e-836e-3b5f0daf51ed
2013-05-03 22:27:44,619 n.b.c.UserManagement INFO - admin0@global.virt logged in from setup-wizard. auth type: BM DB (mail: null) on bm-core 1.10.8573

==> /var/log/bm-tomcat/bm-java.log <==
2013-05-03 22:27:44,666 o.a.c.s.HostConfig INFO - Deploying configuration descriptor settings.xml

==> /var/log/bm/core.log <==
2013-05-03 22:27:44,711 n.b.c.UserManagement INFO - User access loaded for admin0
2013-05-03 22:27:44,832 n.b.c.s.SyncServlet INFO - handler responded to login/doLogin in 539ms.
2013-05-03 22:27:45,052 n.b.c.h.h.SystemSanityCheckHome WARN - FIXME BJR(40) if name is set, must validate a regepx
2013-05-03 22:27:45,180 n.b.c.s.SyncServlet ERROR - sending ServerFault: Can't connect to Node Server at 5.135.166.85
net.bluemind.core.api.fault.ServerFault: Can't connect to Node Server at 5.135.166.85
        at net.bluemind.node.client.pool.SessionPool.newSession(SessionPool.java:88) ~[na:na]
        at net.bluemind.node.client.pool.SessionPool.get(SessionPool.java:71) ~[na:na]
        at net.bluemind.node.client.SChNodeClient.newSession(SChNodeClient.java:68) ~[na:na]
        at net.bluemind.node.client.SChNodeClient.ping(SChNodeClient.java:144) ~[na:na]
        at net.bluemind.core.handler.host.SystemBindingImpl.postCreateHost(SystemBindingImpl.java:319) ~[na:na]
        at net.bluemind.core.handler.host.SystemBindingImpl.create(SystemBindingImpl.java:302) ~[na:na]
        at net.bluemind.core.handler.host.SystemHandler$13.execute(SystemHandler.java:269) ~[na:na]
        at net.bluemind.core.server.SecureMethod.execute(SecureMethod.java:54) ~[na:na]
        at net.bluemind.core.server.AbstractSyncHandler.handle(AbstractSyncHandler.java:94) ~[na:na]
        at net.bluemind.core.server.SyncServlet.handleQuery(SyncServlet.java:139) ~[na:na]
        at net.bluemind.core.server.SyncServlet.service(SyncServlet.java:98) ~[na:na]
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:820) [javax.servlet_2.5.0.v201103041518.jar:na]
        at org.eclipse.equinox.http.registry.internal.ServletManager$ServletWrapper.service(ServletManager.java:180) [org.eclipse.equinox.http.registry_1.1.100.v20110502.jar:na]
        at org.eclipse.equinox.http.servlet.internal.ServletRegistration.service(ServletRegistration.java:61) [org.eclipse.equinox.http.servlet_1.1.200.v20110502.jar:na]
        at org.eclipse.equinox.http.servlet.internal.ProxyServlet.processAlias(ProxyServlet.java:126) [org.eclipse.equinox.http.servlet_1.1.200.v20110502.jar:na]
        at org.eclipse.equinox.http.servlet.internal.ProxyServlet.service(ProxyServlet.java:68) [org.eclipse.equinox.http.servlet_1.1.200.v20110502.jar:na]
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:820) [javax.servlet_2.5.0.v201103041518.jar:na]
        at org.eclipse.equinox.http.jetty.internal.HttpServerManager$InternalHttpServiceServlet.service(HttpServerManager.java:317) [org.eclipse.equinox.http.jetty_2.0.100.v20110502.jar:na]
        at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:511) [org.mortbay.jetty.server_6.1.23.v201012071420.jar:na]
        at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:390) [org.mortbay.jetty.server_6.1.23.v201012071420.jar:na]
        at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:182) [org.mortbay.jetty.server_6.1.23.v201012071420.jar:na]
        at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:765) [org.mortbay.jetty.server_6.1.23.v201012071420.jar:na]
        at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152) [org.mortbay.jetty.server_6.1.23.v201012071420.jar:na]
        at org.mortbay.jetty.Server.handle(Server.java:326) [org.mortbay.jetty.server_6.1.23.v201012071420.jar:na]
        at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:542) [org.mortbay.jetty.server_6.1.23.v201012071420.jar:na]
        at org.mortbay.jetty.HttpConnection$RequestHandler.content(HttpConnection.java:939) [org.mortbay.jetty.server_6.1.23.v201012071420.jar:na]
        at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:756) [org.mortbay.jetty.server_6.1.23.v201012071420.jar:na]
        at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:218) [org.mortbay.jetty.server_6.1.23.v201012071420.jar:na]
        at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404) [org.mortbay.jetty.server_6.1.23.v201012071420.jar:na]
        at org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:409) [org.mortbay.jetty.server_6.1.23.v201012071420.jar:na]
        at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:582) [org.mortbay.jetty.util_6.1.23.v201012071420.jar:na]
Caused by: com.jcraft.jsch.JSchException: java.net.ConnectException: Connection refused
        at com.jcraft.jsch.Util.createSocket(Util.java:386) ~[na:na]
        at com.jcraft.jsch.Session.connect(Session.java:194) ~[na:na]
        at net.bluemind.node.client.pool.SessionPool.newSession(SessionPool.java:84) ~[na:na]
        ... 30 common frames omitted

==> /var/log/bm-tomcat/bm-java.log <==
2013-05-03 22:27:46,087 n.b.u.s.s.DownloadServlet INFO - bm-core url: http://null:8085/services
2013-05-03 22:27:46,653 n.b.u.s.s.DownloadServlet INFO - CommonGWT servlet initialized for null
2013-05-03 22:27:46,671 n.b.u.s.s.RepackOtlkConnectors INFO - file /usr/share/bm-settings/WEB-INF/bm-connector-otlk-x86.exe not found: nothing to repack
2013-05-03 22:27:46,671 n.b.u.s.s.RepackOtlkConnectors INFO - file /usr/share/bm-settings/WEB-INF/bm-connector-otlk-x64.exe not found: nothing to repack
2013-05-03 22:27:46,694 o.a.c.s.HostConfig INFO - Deploying configuration descriptor ROOT.xml

==> /var/log/bm/core.log <==
2013-05-03 22:28:00,039 n.b.c.j.i.JobBindingImpl INFO - getJobFromId BackupFullJob
2013-05-03 22:28:00,044 n.b.c.j.i.JobHome INFO - Loaded 0 jobs from database.
2013-05-03 22:28:00,062 n.b.c.j.i.JobBindingImpl INFO - getJobFromId net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob
2013-05-03 22:28:00,065 n.b.c.j.i.JobHome INFO - Loaded 0 jobs from database.
2013-05-03 22:28:00,085 n.b.c.j.i.JobBindingImpl INFO - getJobFromId Vacation
2013-05-03 22:28:00,090 n.b.c.j.i.JobHome INFO - Loaded 1 jobs from database.
2013-05-03 22:28:00,119 n.b.c.j.i.JobBindingImpl INFO - getJobFromId EventAlert
2013-05-03 22:28:00,123 n.b.c.j.i.JobHome INFO - Loaded 1 jobs from database.
2013-05-03 22:28:00,131 n.b.c.j.i.Scheduler INFO - Finishing Vacation-global.virt-1367620080091
2013-05-03 22:28:00,132 n.b.c.j.i.Scheduler INFO - [Vacation-global.virt-1367620080091] progress is now 100%.
2013-05-03 22:28:00,133 n.b.c.j.i.ExecutionRecorder INFO - recording execution of Vacation-global.virt-1367620080091
2013-05-03 22:28:00,137 n.b.c.j.i.JobHome INFO - recording execution for Vacation-global.virt-1367620080091...
2013-05-03 22:28:00,148 n.b.c.j.i.JobBindingImpl INFO - getJobFromId net.bluemind.archive.core.ArchiveJob
2013-05-03 22:28:00,148 n.b.c.j.i.JobHome INFO - run plan for Vacation@global.virt updated with last_run set to id 5 (start: Fri May 03 22:28:00 GMT 2013)
2013-05-03 22:28:00,149 n.b.c.j.i.JobHome INFO - saving 3 entries...
2013-05-03 22:28:00,153 n.b.c.j.i.Scheduler INFO - Finishing EventAlert-global.virt-1367620080124
2013-05-03 22:28:00,154 n.b.c.j.i.Scheduler INFO - [EventAlert-global.virt-1367620080124] progress is now 100%.
2013-05-03 22:28:00,155 n.b.c.j.i.ExecutionRecorder INFO - recording execution of EventAlert-global.virt-1367620080124
2013-05-03 22:28:00,158 n.b.c.j.i.JobHome INFO - recording execution for EventAlert-global.virt-1367620080124...
2013-05-03 22:28:00,160 n.b.c.j.i.JobHome INFO - Loaded 0 jobs from database.
2013-05-03 22:28:00,167 n.b.c.j.i.JobHome INFO - run plan for EventAlert@global.virt updated with last_run set to id 6 (start: Fri May 03 22:28:00 GMT 2013)
2013-05-03 22:28:00,168 n.b.c.j.i.JobHome INFO - saving 3 entries...
2013-05-03 22:28:00,173 n.b.c.j.i.Scheduler INFO - [Vacation-global.virt-1367620080091] finished and recorded: SUCCESS, duration: 41ms.
2013-05-03 22:28:00,184 n.b.c.j.i.JobBindingImpl INFO - getJobFromId net.bluemind.dataprotect.core.DataProtectJob
2013-05-03 22:28:00,186 n.b.c.j.i.Scheduler INFO - [EventAlert-global.virt-1367620080124] finished and recorded: SUCCESS, duration: 30ms.
2013-05-03 22:28:00,189 n.b.c.j.i.JobHome INFO - Loaded 0 jobs from database.
2013-05-03 22:28:00,191 n.b.d.c.DataProtectJob INFO - not planned, last run was 134secs ago.
2013-05-03 22:28:00,191 n.b.d.c.DataProtectJob INFO - less than one day ago, skipping execution.
2013-05-03 22:28:00,206 n.b.c.j.i.JobBindingImpl INFO - getJobFromId net.bluemind.core.jobs.quota.QuotaGatheringJob
2013-05-03 22:28:00,210 n.b.c.j.i.JobHome INFO - Loaded 0 jobs from database.
2013-05-03 22:29:00,040 n.b.c.j.i.JobBindingImpl INFO - getJobFromId BackupFullJob
2013-05-03 22:29:00,046 n.b.c.j.i.JobHome INFO - Loaded 0 jobs from database.
2013-05-03 22:29:00,066 n.b.c.j.i.JobBindingImpl INFO - getJobFromId net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob
2013-05-03 22:29:00,071 n.b.c.j.i.JobHome INFO - Loaded 0 jobs from database.
2013-05-03 22:29:00,091 n.b.c.j.i.JobBindingImpl INFO - getJobFromId Vacation
2013-05-03 22:29:00,097 n.b.c.j.i.JobHome INFO - Loaded 1 jobs from database.
2013-05-03 22:29:00,120 n.b.c.j.i.JobBindingImpl INFO - getJobFromId EventAlert
2013-05-03 22:29:00,125 n.b.c.j.i.JobHome INFO - Loaded 1 jobs from database.
2013-05-03 22:29:00,144 n.b.c.j.i.JobBindingImpl INFO - getJobFromId net.bluemind.archive.core.ArchiveJob
2013-05-03 22:29:00,149 n.b.c.j.i.JobHome INFO - Loaded 0 jobs from database.
2013-05-03 22:29:00,153 n.b.c.j.i.Scheduler INFO - Finishing Vacation-global.virt-1367620140098
2013-05-03 22:29:00,153 n.b.c.j.i.Scheduler INFO - [Vacation-global.virt-1367620140098] progress is now 100%.
2013-05-03 22:29:00,154 n.b.c.j.i.ExecutionRecorder INFO - recording execution of Vacation-global.virt-1367620140098
2013-05-03 22:29:00,154 n.b.c.j.i.Scheduler INFO - Finishing EventAlert-global.virt-1367620140127
2013-05-03 22:29:00,155 n.b.c.j.i.Scheduler INFO - [EventAlert-global.virt-1367620140127] progress is now 100%.
2013-05-03 22:29:00,156 n.b.c.j.i.ExecutionRecorder INFO - recording execution of EventAlert-global.virt-1367620140127
2013-05-03 22:29:00,158 n.b.c.j.i.JobHome INFO - recording execution for Vacation-global.virt-1367620140098...
2013-05-03 22:29:00,161 n.b.c.j.i.JobHome INFO - recording execution for EventAlert-global.virt-1367620140127...
2013-05-03 22:29:00,166 n.b.c.j.i.JobHome INFO - run plan for Vacation@global.virt updated with last_run set to id 7 (start: Fri May 03 22:29:00 GMT 2013)
2013-05-03 22:29:00,166 n.b.c.j.i.JobHome INFO - saving 3 entries...
2013-05-03 22:29:00,175 n.b.c.j.i.JobHome INFO - run plan for EventAlert@global.virt updated with last_run set to id 8 (start: Fri May 03 22:29:00 GMT 2013)
2013-05-03 22:29:00,175 n.b.c.j.i.JobBindingImpl INFO - getJobFromId net.bluemind.dataprotect.core.DataProtectJob
2013-05-03 22:29:00,175 n.b.c.j.i.JobHome INFO - saving 3 entries...
2013-05-03 22:29:00,179 n.b.c.j.i.JobHome INFO - Loaded 0 jobs from database.
2013-05-03 22:29:00,181 n.b.d.c.DataProtectJob INFO - not planned, last run was 194secs ago.
2013-05-03 22:29:00,182 n.b.d.c.DataProtectJob INFO - less than one day ago, skipping execution.
2013-05-03 22:29:00,183 n.b.c.j.i.Scheduler INFO - [Vacation-global.virt-1367620140098] finished and recorded: SUCCESS, duration: 55ms.
2013-05-03 22:29:00,194 n.b.c.j.i.Scheduler INFO - [EventAlert-global.virt-1367620140127] finished and recorded: SUCCESS, duration: 28ms.
2013-05-03 22:29:00,197 n.b.c.j.i.JobBindingImpl INFO - getJobFromId net.bluemind.core.jobs.quota.QuotaGatheringJob
2013-05-03 22:29:00,202 n.b.c.j.i.JobHome INFO - Loaded 0 jobs from database.

tcataldo · May 4, 2013, 9:48am

Que donne un jps -ml ?

Y a t’il assez de ram sur la machine pour que tout démarre correctement ?

tcataldo · May 4, 2013, 12:05pm

Dans les dernières edge, et sera dans le 2.0beta1 pour laquelle nous finissons les derniers tests.

Ca fait un tar des logs qui vont bien + quelques infos que l’on demande souvent

De notre côté ça permet d’industrialiser plus le bug reporting et de construire des outils pour analyser le comportement d’une install donnée.

Poustiquet · May 4, 2013, 1:44pm

?!?

Voilà le résultat

root@telegramme:~# jps -ml
1525 org.apache.catalina.startup.Bootstrap start
2299 org.eclipse.equinox.launcher.Main -application net.bluemind.locator.app
2279 org.eclipse.equinox.launcher.Main -application net.bluemind.eas.push
3923 org.eclipse.equinox.launcher.Main -application net.bluemind.lmtp.id1
2227 org.eclipse.equinox.launcher.Main -application net.bluemind.core.launcher.core
1542 org.eclipse.equinox.launcher.Main -application net.bluemind.ysnp.ysnp
1296 org.eclipse.equinox.launcher.Main -application net.bluemind.hornetq.mqsrv
3842 org.eclipse.equinox.launcher.Main -application net.bluemind.proxy.http.launcher.hpslauncher
14365 sun.tools.jps.Jps -ml
root@telegramme:~#

Pour la RAM, juste 4Go sur une machine dédié, mes VM de dev sont à 6Go …
Je vais donc tester sur une machine avec 8Go, je te retiens au courant
4 Go pour la V1, aucun soucis d’installation et les premiers tests d’utilisation sont plutôt agréablement rapide (par rapport au perf que je pensais)

Bien pour bm_send_report … . Et en plus, au premier coup d’œil, il n’ a pas l’air d’être fermé et exclusivement pour votre support
C’est un outil qui peut donc servir de reporting régulier par des sysadmin

tcataldo · May 4, 2013, 2:08pm

[quote=Poustiquet]Voilà le résultat root@telegramme:~# jps -ml
[/quote]
Ok il manque bm-node. /etc/init.d/bm-node start devrait régler le pb.

[quote=Poustiquet]Pour la RAM, juste 4Go sur une machine dédié, mes VM de dev sont à 6Go …
Je vais donc tester sur une machine avec 8Go, je te retiens au courant
4 Go pour la V1, aucun soucis d’installation et les premiers tests d’utilisation sont plutôt agréablement rapide (par rapport au perf que je pensais)
[/quote]

C’était pour être sur, ça ressemblait tellement à un composant pas démarré / stoppé par un oom kill.

[quote=Poustiquet]Bien pour bm_send_report … . Et en plus, au premier coup d’œil, il n’ a pas l’air d’être fermé et exclusivement pour votre support
C’est un outil qui peut donc servir de reporting régulier par des sysadmin[/quote]

Indeed, ce n’est pas utile que pour nous. Pour l’instant l’outil d’analyse n’est pas public, je tatonne un peu sur les analyses à faire dessus. Le truc parse tous les logs et les injecte dans un postgresql. Ensuite il consolide différentes infos, genre tous les logs “handler responded to Y in Tms.” pour extraire ce qui est le plus sollicité, lent, etc.

S’il y a un interêt on publiera surement ce truc là, c’est un truc que j’ai mis en place pour analyser le comportement d’un bluemind pour une période de temps sur laquelle je n’avais pas de yourkit. Ca reste super roots et se contente de bourrer un postgresql, les analyses se faisant au besoin avec des requêtes sql.

Poustiquet · May 4, 2013, 2:24pm

Yes, je relance une installation vierge … A force de la tourner dans tous les sens, la machine est en tout étourdi …
C’est plus pour réaliser une procédure simple d’installation, sur un petit serveur …

Je regarde coté bm-node …
Pas à pas pour analyser quand est ce qu’il s’arrête …
Je te tiens au jus …

…

Pour le générateur de rapport, je te comprends .
Maintenant un tel commande permet de gérer un certain nombre de problème par les sysadmin, simplement il y a une forte probabilité de trouver les logs utiles dans le tar.
J’exploite déjà ce type d’outil sur de gros logiciels industriels, et cela est fort utile !

Poustiquet · May 4, 2013, 3:23pm

Avant le lancement du Wizard … bm-node est présent

root@telegramme:/etc#  jps -ml
10701 org.eclipse.equinox.launcher.Main -application net.bluemind.proxy.http.launcher.hpslauncher
10446 org.eclipse.equinox.launcher.Main -application net.bluemind.ysnp.ysnp
11392 sun.tools.jps.Jps -ml
10597 org.eclipse.equinox.launcher.Main -application net.bluemind.eas.push
8227 org.eclipse.equinox.launcher.Main -application net.bluemind.hornetq.mqsrv
11325 org.apache.catalina.startup.Bootstrap start
8183 org.eclipse.equinox.launcher.Main -application net.bluemind.node.server.nodelauncher
10655 org.eclipse.equinox.launcher.Main -application net.bluemind.lmtp.id1
10386 org.eclipse.equinox.launcher.Main -application net.bluemind.core.launcher.core
9271 org.eclipse.equinox.launcher.Main -application net.bluemind.locator.app
root@telegramme:/etc#

après reboot … Plus de node

root@telegramme:~#  jps -ml
1564 org.eclipse.equinox.launcher.Main -application net.bluemind.ysnp.ysnp
1561 org.apache.catalina.startup.Bootstrap start
1324 org.eclipse.equinox.launcher.Main -application net.bluemind.core.launcher.core
1491 org.eclipse.equinox.launcher.Main -application net.bluemind.eas.push
1506 org.eclipse.equinox.launcher.Main -application net.bluemind.lmtp.id1
1308 org.eclipse.equinox.launcher.Main -application net.bluemind.hornetq.mqsrv
1317 org.eclipse.equinox.launcher.Main -application net.bluemind.locator.app
1499 org.eclipse.equinox.launcher.Main -application net.bluemind.proxy.http.launcher.hpslauncher
1978 sun.tools.jps.Jps -ml
root@telegramme:~#

bmctl restart n’a pas redémarré le bm-node

root@telegramme:~# bmctl restart
Stop Blue Mind Services
Waiting for Blue Mind core Server shutdown..
Waiting for Blue Mind locator Server shutdown..
Waiting for Blue Mind lmtpd server shutdown..
Waiting for Blue Mind MQ Server shutdown..
Waiting for Blue Mind hps Server shutdown..
Waiting for Blue Mind EAS Server shutdown..
Waiting for Blue Mind Tomcat shutdown...
Waiting for Blue Mind ysnp Server shutdown.
Start Blue Mind Services
Blue Mind core Server started: 2505
Blue Mind locator Server started: 2545
Blue Mind lmtpd server started: 2551
Blue Mind MQ Server started: 2560
Blue Mind hps Server started: 2570
Blue Mind EAS Server started: 2586
Using CATALINA_BASE:   /usr/share/tomcat
Using CATALINA_HOME:   /usr/share/tomcat
Using CATALINA_TMPDIR: /tmp
Using JRE_HOME:       /usr/lib/jvm/bm-jdk
Blue Mind ysnp started: 2634
root@telegramme:~#  jps -ml
2560 org.eclipse.equinox.launcher.Main -application net.bluemind.hornetq.mqsrv
2505 org.eclipse.equinox.launcher.Main -application net.bluemind.core.launcher.core
2621 org.apache.catalina.startup.Bootstrap start
2634 org.eclipse.equinox.launcher.Main -application net.bluemind.ysnp.ysnp
2551 org.eclipse.equinox.launcher.Main -application net.bluemind.lmtp.id1
2741 sun.tools.jps.Jps -ml
2545 org.eclipse.equinox.launcher.Main -application net.bluemind.locator.app
2570 org.eclipse.equinox.launcher.Main -application net.bluemind.proxy.http.launcher.hpslauncher
2586 org.eclipse.equinox.launcher.Main -application net.bluemind.eas.push

root@telegramme:~# /etc/init.d/bm-node restart
Blue Mind node Server not running.
Blue Mind node Server started: 2937
root@telegramme:~# 
root@telegramme:~#  jps -ml
2560 org.eclipse.equinox.launcher.Main -application net.bluemind.hornetq.mqsrv
2505 org.eclipse.equinox.launcher.Main -application net.bluemind.core.launcher.core
2937 org.eclipse.equinox.launcher.Main -application net.bluemind.node.server.nodelauncher
2621 org.apache.catalina.startup.Bootstrap start
2634 org.eclipse.equinox.launcher.Main -application net.bluemind.ysnp.ysnp
2551 org.eclipse.equinox.launcher.Main -application net.bluemind.lmtp.id1
2545 org.eclipse.equinox.launcher.Main -application net.bluemind.locator.app
2570 org.eclipse.equinox.launcher.Main -application net.bluemind.proxy.http.launcher.hpslauncher
3063 sun.tools.jps.Jps -ml
2586 org.eclipse.equinox.launcher.Main -application net.bluemind.eas.push
root@telegramme:~#

Test de rédémarrage manuel des services:

root@telegramme:~# /etc/init.d/restart_bm_all.ksh
Stopping nginx: nginx.
Stopping Postfix Mail Transport Agent: postfix.
Waiting for Blue Mind Tomcat shutdown...
Waiting for Blue Mind node Server shutdown..
Waiting for Blue Mind lmtpd server shutdown..
Waiting for Blue Mind hps Server shutdown..
Waiting for Blue Mind EAS Server shutdown..
Waiting for Blue Mind core Server shutdown..
Waiting for Blue Mind locator Server shutdown..
Waiting for Blue Mind MQ Server shutdown.
Stopping PostgreSQL 8.4 database server: main.
sleep 10
Starting PostgreSQL 8.4 database server: main.
Blue Mind MQ Server started: 5807
Blue Mind locator Server started: 5816
Blue Mind core Server started: 5829
Blue Mind EAS Server started: 5894
Blue Mind hps Server started: 5899
Blue Mind lmtpd server started: 5908
Blue Mind node Server started: 5920
Using CATALINA_BASE:   /usr/share/tomcat
Using CATALINA_HOME:   /usr/share/tomcat
Using CATALINA_TMPDIR: /tmp
Using JRE_HOME:       /usr/lib/jvm/bm-jdk
Starting Postfix Mail Transport Agent: postfix.
Starting nginx: nginx.
root@telegramme:~#  jps -ml
6312 sun.tools.jps.Jps -ml
5899 org.eclipse.equinox.launcher.Main -application net.bluemind.proxy.http.launcher.hpslauncher
5829 org.eclipse.equinox.launcher.Main -application net.bluemind.core.launcher.core
5955 org.apache.catalina.startup.Bootstrap start
5807 org.eclipse.equinox.launcher.Main -application net.bluemind.hornetq.mqsrv
5894 org.eclipse.equinox.launcher.Main -application net.bluemind.eas.push
2634 org.eclipse.equinox.launcher.Main -application net.bluemind.ysnp.ysnp
5908 org.eclipse.equinox.launcher.Main -application net.bluemind.lmtp.id1
5920 org.eclipse.equinox.launcher.Main -application net.bluemind.node.server.nodelauncher
5816 org.eclipse.equinox.launcher.Main -application net.bluemind.locator.app
root@telegramme:~#

Installation par le wizard OK

Poustiquet · May 4, 2013, 3:43pm

Tout a l’air d’être OK !
Merci Thomas !

Je relance l’installation de mon serveur en mode Pas à Pas, pour en faire une micro procédure (à mettre dans le Forum)

Passage en résolu !

Test de Reboot tout de même