Voici le log (j’ai tronqué les parties sans erreurs) :
2013-09-12 18:21:39,785 n.b.c.l.Main INFO - Starting Blue Core...
2013-09-12 18:21:39,790 n.b.c.CoreActivator INFO - Activate core.
2013-09-12 18:21:39,790 n.b.c.BMCore INFO - core starting...
2013-09-12 18:21:39,790 n.b.c.BMCore INFO - Loading JDBC pool
2013-09-12 18:21:39,799 n.b.u.RunnableExtensionLoader INFO - net.bluemind.jdbc.oracle.provider.OracleConnectionFactory loaded.
2013-09-12 18:21:39,801 n.b.u.RunnableExtensionLoader INFO - net.bluemind.jdbc.pgsql.provider.PgSQLConnectionFactory loaded.
2013-09-12 18:21:39,801 n.b.u.RunnableExtensionLoader INFO - Loaded 2 implementors of net.bluemind.pool.jdbcdriver
2013-09-12 18:21:39,802 n.b.p.i.BmConfIni WARN - /etc/bm/bm.ini does not exist.
2013-09-12 18:25:05,598 n.b.c.l.Main INFO - Starting Blue Core...
2013-09-12 18:25:05,603 n.b.c.CoreActivator INFO - Activate core.
2013-09-12 18:25:05,603 n.b.c.BMCore INFO - core starting...
2013-09-12 18:25:05,603 n.b.c.BMCore INFO - Loading JDBC pool
2013-09-12 18:25:05,622 n.b.u.RunnableExtensionLoader INFO - net.bluemind.jdbc.oracle.provider.OracleConnectionFactory loaded.
2013-09-12 18:25:05,628 n.b.u.RunnableExtensionLoader INFO - net.bluemind.jdbc.pgsql.provider.PgSQLConnectionFactory loaded.
2013-09-12 18:25:05,628 n.b.u.RunnableExtensionLoader INFO - Loaded 2 implementors of net.bluemind.pool.jdbcdriver
2013-09-12 18:25:05,632 n.b.p.BMPoolActivator INFO - Starting connection pool 172.20.102.237/bj
2013-09-12 18:25:05,632 n.b.p.BMPoolActivator INFO - dbtype from bm.ini is PGSQL
2013-09-12 18:25:05,735 n.b.p.x.PoolActivator INFO - Pool bundle started.
2013-09-12 18:25:05,900 n.b.p.x.i.DataSource INFO - Starting pool...(jdbc:postgresql://172.20.102.237/bj)
2013-09-12 18:25:05,903 n.b.p.x.i.ConnectionPool INFO - Creating Physical connection...
2013-09-12 18:25:05,959 n.b.p.x.i.ConnectionPool INFO - Physical connection established.
2013-09-12 18:25:05,959 n.b.p.x.i.ConnectionPool INFO - Creating Physical connection...
2013-09-12 18:25:05,968 n.b.p.x.i.ConnectionPool INFO - Physical connection established.
2013-09-12 18:25:05,969 n.b.p.x.i.ConnectionPool INFO - Creating Physical connection...
2013-09-12 18:25:05,977 n.b.p.x.i.ConnectionPool INFO - Physical connection established.
2013-09-12 18:25:05,977 n.b.p.x.i.ConnectionPool INFO - Creating Physical connection...
2013-09-12 18:25:05,986 n.b.p.x.i.ConnectionPool INFO - Physical connection established.
2013-09-12 18:25:05,986 n.b.p.x.i.ConnectionPool INFO - Creating Physical connection...
2013-09-12 18:25:05,995 n.b.p.x.i.ConnectionPool INFO - Physical connection established.
2013-09-12 18:25:05,995 n.b.p.x.i.ConnectionPool INFO - Creating Physical connection...
2013-09-12 18:25:06,004 n.b.p.x.i.ConnectionPool INFO - Physical connection established.
2013-09-12 18:25:06,004 n.b.p.x.i.ConnectionPool INFO - Pool State after start is 0 used out of 6 connections
2013-09-12 18:25:06,004 n.b.p.x.i.PingThread INFO - created with 6 JDBC connections.
2013-09-12 18:25:06,008 n.b.c.BMCore INFO - Loading session store
2013-09-12 18:25:06,096 n.b.c.s.m.TimeOutMap INFO - Built session cache with a 1200000ms timeout.
2013-09-12 18:25:06,097 n.b.c.u.RunnableExtensionLoader INFO - MemorySessionStoreFactory loaded.
2013-09-12 18:25:06,098 n.b.c.u.RunnableExtensionLoader INFO - Loaded 1 implementors of net.bluemind.core.sessionstore
2013-09-12 18:25:06,101 n.b.c.s.m.MemorySessionStoreFactory INFO - init
2013-09-12 18:25:06,101 n.b.c.BMCore INFO - session factory will be SHARED (class net.bluemind.core.session.memory.MemorySessionStoreFactory)
2013-09-12 18:25:06,104 n.b.c.u.RunnableExtensionLoader INFO - PostfixHookFactory loaded.
2013-09-12 18:25:06,106 n.b.c.u.RunnableExtensionLoader INFO - AclHookFactory loaded.
2013-09-12 18:25:06,107 n.b.c.u.RunnableExtensionLoader INFO - NginxHookFactory loaded.
2013-09-12 18:25:06,113 n.b.c.u.RunnableExtensionLoader INFO - HookFactory loaded.
2013-09-12 18:25:06,113 n.b.c.u.RunnableExtensionLoader INFO - NodeKeyHookFactory loaded.
2013-09-12 18:25:06,115 n.b.c.u.RunnableExtensionLoader INFO - ArchHookFactory loaded.
2013-09-12 18:25:06,116 n.b.c.u.RunnableExtensionLoader INFO - WebmailHookFactory loaded.
2013-09-12 18:25:06,117 n.b.c.u.RunnableExtensionLoader INFO - ImportADSystemHookFactory loaded.
2013-09-12 18:25:06,118 n.b.c.u.RunnableExtensionLoader INFO - SystemNotificationHookFactory loaded.
2013-09-12 18:25:06,119 n.b.c.u.RunnableExtensionLoader INFO - DomainAliasHookFactory loaded.
2013-09-12 18:25:06,120 n.b.c.u.RunnableExtensionLoader INFO - Loaded 10 implementors of net.bluemind.core.systemhookfactory
2013-09-12 18:25:06,122 n.b.c.s.d.PermanentTokenSystemHook INFO - PermanentTokenSystemHook loaded.
2013-09-12 18:25:06,193 n.b.c.h.HookRegistry INFO - *** PRIO: 2147483647 HOOK: net.bluemind.hook.acl.AclHook
2013-09-12 18:25:06,194 n.b.c.h.HookRegistry INFO - *** PRIO: 2147483647 HOOK: net.bluemind.hook.node.NodeKeySystemHook
2013-09-12 18:25:06,195 n.b.c.h.HookRegistry INFO - *** PRIO: 2147483647 HOOK: net.bluemind.hook.domainalias.EmailTableUpdateHook
2013-09-12 18:25:06,205 n.b.c.h.HookRegistry INFO - *** PRIO: 2 HOOK: net.bluemind.system.cyrus.CyrusSystemHook
2013-09-12 18:25:06,207 n.b.c.h.HookRegistry INFO - *** PRIO: 2 HOOK: net.bluemind.system.ad.importation.hooks.ImportADSystemHook
2013-09-12 18:25:06,210 n.b.c.h.HookRegistry INFO - *** PRIO: 1 HOOK: net.bluemind.system.postfix.PostfixHook
2013-09-12 18:25:06,210 n.b.c.h.HookRegistry INFO - *** PRIO: 1 HOOK: net.bluemind.system.webmail.WebmailHook
2013-09-12 18:25:06,211 n.b.c.h.HookRegistry INFO - *** PRIO: 0 HOOK: net.bluemind.system.nginx.NginxSystemHook
2013-09-12 18:25:06,211 n.b.c.h.HookRegistry INFO - *** PRIO: 0 HOOK: net.bluemind.archive.core.ArchServerHook
2013-09-12 18:25:06,220 n.b.c.h.HookRegistry INFO - *** PRIO: 0 HOOK: net.bluemind.system.notification.SystemNotification
2013-09-12 18:25:06,222 n.b.c.u.RunnableExtensionLoader INFO - IcsHookFactory loaded.
2013-09-12 18:25:06,224 n.b.c.u.RunnableExtensionLoader INFO - CalendarChangeNotification loaded.
2013-09-12 18:25:06,224 n.b.c.u.RunnableExtensionLoader INFO - Loaded 2 implementors of net.bluemind.core.calendarhookfactory
2013-09-12 18:25:06,230 n.b.c.u.RunnableExtensionLoader INFO - ContactHookFactory loaded.
2013-09-12 18:25:06,232 n.b.c.u.RunnableExtensionLoader INFO - ContactChangeNotification loaded.
2013-09-12 18:25:06,232 n.b.c.u.RunnableExtensionLoader INFO - Loaded 2 implementors of net.bluemind.core.contacthookfactory
2013-09-12 18:25:06,414 n.b.c.u.RunnableExtensionLoader INFO - NodeClientFactory loaded.
2013-09-12 18:25:06,414 n.b.c.u.RunnableExtensionLoader INFO - Loaded 1 implementors of net.bluemind.core.nodeclientfactory
2013-09-12 18:25:06,416 n.b.c.u.RunnableExtensionLoader INFO - PostfixSC loaded.
2013-09-12 18:25:06,417 n.b.c.u.RunnableExtensionLoader INFO - MailshareSCF loaded.
2013-09-12 18:25:06,417 n.b.c.u.RunnableExtensionLoader INFO - DomainSCF loaded.
2013-09-12 18:25:06,417 n.b.c.u.RunnableExtensionLoader INFO - UserSCF loaded.
2013-09-12 18:25:06,418 n.b.c.u.RunnableExtensionLoader INFO - ADDomainSC loaded.
2013-09-12 18:25:06,418 n.b.c.u.RunnableExtensionLoader INFO - Loaded 5 implementors of net.bluemind.core.sanitycheckerfactory
2013-09-12 18:25:06,418 n.b.c.s.SanityChecksRegistry INFO - Registered 5 sanity check factories through plugins
2013-09-12 18:25:06,419 n.b.c.u.RunnableExtensionLoader INFO - Loaded 0 implementors of net.bluemind.core.passwordpolicyfactory
2013-09-12 18:25:06,423 n.b.c.u.RunnableExtensionLoader INFO - PostfixCustomRequirements loaded.
2013-09-12 18:25:06,424 n.b.c.u.RunnableExtensionLoader INFO - ImapCustomRequirements loaded.
2013-09-12 18:25:06,425 n.b.s.a.i.u.ADImportationPropertyRequirements INFO - AD properties requirement created.
2013-09-12 18:25:06,425 n.b.c.u.RunnableExtensionLoader INFO - ADImportationPropertyRequirements loaded.
2013-09-12 18:25:06,425 n.b.c.u.RunnableExtensionLoader INFO - Loaded 3 implementors of net.bluemind.core.custompropertyrequirements
2013-09-12 18:25:06,425 n.b.c.c.p.CustomPropertyHome INFO - Providing requirements for plugin postfix
2013-09-12 18:25:06,436 n.b.c.c.p.CustomPropertyHome INFO - [postfix]: property domain::slave_relay provided.
2013-09-12 18:25:06,437 n.b.c.c.p.CustomPropertyHome INFO - [postfix]: property domain::split_relay provided.
2013-09-12 18:25:06,450 n.b.c.c.p.CustomPropertyHome INFO - Providing requirements for plugin cyrus
2013-09-12 18:25:06,455 n.b.c.c.p.CustomPropertyHome INFO - [cyrus]: property domain::max_quota provided.
2013-09-12 18:25:06,456 n.b.c.c.p.CustomPropertyHome INFO - [cyrus]: property domain::mailshare_def_quota provided.
2013-09-12 18:25:06,457 n.b.c.c.p.CustomPropertyHome INFO - [cyrus]: property domain::def_quota provided.
2013-09-12 18:25:06,457 n.b.c.c.p.CustomPropertyHome INFO - [cyrus]: property domain::mailshare_max_quota provided.
2013-09-12 18:25:06,467 n.b.c.c.p.CustomPropertyHome INFO - Providing requirements for plugin net.bluemind.system.ad.importation
2013-09-12 18:25:06,473 n.b.c.c.p.CustomPropertyHome INFO - [net.bluemind.system.ad.importation]: property domain::import_ad_password provided.
2013-09-12 18:25:06,477 n.b.c.c.p.CustomPropertyHome INFO - [net.bluemind.system.ad.importation]: property domain::import_ad_login provided.
2013-09-12 18:25:06,477 n.b.c.c.p.CustomPropertyHome INFO - [net.bluemind.system.ad.importation]: property domain::import_ad_lastupdate provided.
2013-09-12 18:25:06,478 n.b.c.c.p.CustomPropertyHome INFO - [net.bluemind.system.ad.importation]: property domain::import_ad_relay_mailbox_group provided.
2013-09-12 18:25:06,479 n.b.c.c.p.CustomPropertyHome INFO - [net.bluemind.system.ad.importation]: property domain::import_ad_hostname provided.
2013-09-12 18:25:06,479 n.b.c.c.p.CustomPropertyHome INFO - [net.bluemind.system.ad.importation]: property domain::import_ad_user_filter provided.
2013-09-12 18:25:06,480 n.b.c.c.p.CustomPropertyHome INFO - [net.bluemind.system.ad.importation]: property domain::import_ad_base_dn provided.
2013-09-12 18:25:06,480 n.b.c.c.p.CustomPropertyHome INFO - [net.bluemind.system.ad.importation]: property domain::import_ad_group_filter provided.
2013-09-12 18:25:06,496 n.b.c.u.RunnableExtensionLoader INFO - ContactSettingsRequirements loaded.
2013-09-12 18:25:06,498 n.b.c.u.RunnableExtensionLoader INFO - MailSettingsRequirements loaded.
2013-09-12 18:25:06,500 n.b.c.u.RunnableExtensionLoader INFO - CalendarSettingsRequirements loaded.
2013-09-12 18:25:06,501 n.b.c.u.RunnableExtensionLoader INFO - GeneralSettingsRequirements loaded.
2013-09-12 18:25:06,501 n.b.c.u.RunnableExtensionLoader INFO - Loaded 4 implementors of net.bluemind.core.customsettingrequirements
2013-09-12 18:25:06,501 n.b.c.c.s.CustomSettingHome INFO - reset stored settings
2013-09-12 18:25:06,676 n.b.c.c.s.CustomSettingHome INFO - Providing settings from net.bluemind.custom.settings.contact
2013-09-12 18:25:06,681 n.b.c.c.s.CustomSettingHome INFO - [foldermanagement]: setting provided.
2013-09-12 18:25:06,682 n.b.c.c.s.CustomSettingHome INFO - [foldersubscription]: setting provided.
2013-09-12 18:25:06,688 n.b.c.c.s.CustomSettingHome INFO - Providing settings from net.bluemind.custom.settings.mail
2013-09-12 18:25:06,692 n.b.c.c.s.CustomSettingHome INFO - [acl]: setting provided.
2013-09-12 18:25:06,693 n.b.c.c.s.CustomSettingHome INFO - [vacation]: setting provided.
2013-09-12 18:25:06,694 n.b.c.c.s.CustomSettingHome INFO - [identities]: setting provided.
2013-09-12 18:25:06,694 n.b.c.c.s.CustomSettingHome INFO - [rc]: setting provided.
2013-09-12 18:25:06,695 n.b.c.c.s.CustomSettingHome INFO - [sieve]: setting provided.
... pas d'erreur...]
2013-09-12 18:25:09,790 n.b.l.s.ServoRegistry INFO - Built NumberFieldMonitor{config=MonitorConfig{name=totalQueries, tags=type=SyncServlet, policy=DefaultPublishingPolicy}, field=private java.util.concurren
t.atomic.AtomicLong net.bluemind.core.server.SyncServlet.totalQueries}
2013-09-12 18:25:09,790 n.b.l.s.ServoRegistry INFO - Building for net.bluemind.core.server.SyncServlet@1beaded, id: SyncServlet
2013-09-12 18:25:09,790 n.b.l.s.ServoRegistry INFO - Built NumberFieldMonitor{config=MonitorConfig{name=totalTimeMs, tags=type=SyncServlet, policy=DefaultPublishingPolicy}, field=private java.util.concurrent
.atomic.AtomicLong net.bluemind.core.server.SyncServlet.totalTime}
2013-09-12 18:25:09,791 n.b.l.s.ServoRegistry INFO - Building for net.bluemind.core.server.SyncServlet@1beaded, id: SyncServlet
2013-09-12 18:25:09,791 n.b.l.s.ServoRegistry INFO - Built NumberFieldMonitor{config=MonitorConfig{name=responseTime, tags=type=SyncServlet, policy=DefaultPublishingPolicy}, field=private java.util.concurren
t.atomic.AtomicInteger net.bluemind.core.server.SyncServlet.responseTime}
2013-09-12 18:25:09,799 n.b.c.l.Main INFO - Accepting queries on port 8085
2013-09-12 18:25:11,369 n.b.h.c.NonOsgiActivator WARN - failed to locate bm/mq server. falling back to localhost
2013-09-12 18:25:11,556 n.b.c.s.m.MemorySessionStoreFactory INFO - MQ connection completed. Session replication activated
2013-09-12 18:25:11,813 n.b.c.UserManagement INFO - MQ connection for push queues completed.
2013-09-12 18:25:36,229 n.b.s.n.SystemNotification INFO - Producer on jms.topic.bm.system.notification created.
2013-09-12 18:25:36,241 n.b.c.n.CalendarChangeNotification INFO - Producer on jms.topic.bm.calendar.notification created.
2013-09-12 18:25:36,248 n.b.c.n.ContactChangeNotification INFO - Producer on jms.topic.bm.contact.notification created.
2013-09-12 18:25:42,524 n.b.c.s.a.i.AuthenticationRegistry INFO - Validate password using service net.bluemind.core.server.auth.impl.DatabaseAuthenticationService: YES in 4ms.
2013-09-12 18:25:42,563 n.b.c.UserManagement INFO - admin0@global.virt logged in from setup-wizard. auth type: BM DB (mail: null) on bm-core 2.0.9987
2013-09-12 18:25:42,588 n.b.c.UserManagement INFO - User access loaded for admin0
2013-09-12 18:25:42,603 n.b.c.s.SyncServlet INFO - handler responded to login/doLogin in 139ms.
2013-09-12 18:25:42,631 n.b.c.h.h.SystemSanityCheckHome WARN - FIXME BJR(40) if name is set, must validate a regepx
2013-09-12 18:25:46,120 n.b.n.c.SchListFiles INFO - Run listfiles /tmp/nodeclient1925118217091417641.myself
2013-09-12 18:25:46,210 n.b.c.s.SyncServlet INFO - handler responded to system/createHost in 3582ms.
2013-09-12 18:25:46,239 n.b.c.c.ContactFoldersHome ERROR - Couldn't set Admin right on folder 1
2013-09-12 18:25:46,241 n.b.c.c.AddressBookBindingImpl INFO - [admin0] AdrressBook : folder[users 1 1] created
2013-09-12 18:25:46,245 n.b.c.a.AclHome INFO - setConsumerRights entity addressbook #1 consumer user #1 access: 1 read: 1 write: 1 admin: 1
2013-09-12 18:25:46,246 n.b.c.a.AclHome INFO - update right entity addressbook #1consumer null #null read 1
2013-09-12 18:25:46,247 n.b.c.a.AclHome INFO - insert right entity addressbook #1consumer null #null read 1
2013-09-12 18:25:46,247 n.b.h.a.AclHook INFO - run onAclSetRight Hook
2013-09-12 18:25:46,247 n.b.c.h.h.SystemBindingImpl INFO - Users folder created with id: 1
2013-09-12 18:25:46,252 n.b.c.g.GroupBindingImpl INFO - [admin0] Group : create(user)
2013-09-12 18:25:46,252 n.b.c.g.GroupHome INFO - create with token e8229af4-fad4-4092-a785-845754adddf8 from setup-wizard
2013-09-12 18:25:46,262 n.b.c.r.RBACBindingImpl INFO - Profile user created
2013-09-12 18:25:46,265 n.b.c.g.GroupBindingImpl INFO - [admin0] Group : create(admin)
2013-09-12 18:25:46,265 n.b.c.g.GroupHome INFO - create with token e8229af4-fad4-4092-a785-845754adddf8 from setup-wizard
2013-09-12 18:25:46,269 n.b.c.r.RBACBindingImpl INFO - Profile admin created
2013-09-12 18:25:46,276 n.b.c.a.AclHome INFO - setConsumerRights entity addressbook #1 consumer group #2 access: 0 read: 0 write: 0 admin: 1
2013-09-12 18:25:46,283 n.b.c.a.AclHome INFO - setConsumerRights entity addressbook #2 consumer group #2 access: 0 read: 0 write: 0 admin: 1
2013-09-12 18:25:46,284 n.b.c.c.AddressBookBindingImpl INFO - [admin0] AdrressBook : folder[deleted_users 2 null] created
2013-09-12 18:25:46,285 n.b.c.a.AclHome INFO - update right entity addressbook #2consumer null #null read 1
2013-09-12 18:25:46,285 n.b.c.a.AclHome INFO - insert right entity addressbook #2consumer null #null read 1
2013-09-12 18:25:46,285 n.b.h.a.AclHook INFO - run onAclSetRight Hook
2013-09-12 18:25:46,285 n.b.c.h.h.SystemBindingImpl INFO - Deleted users folder created with id: 2
2013-09-12 18:25:46,292 n.b.c.a.AclHome INFO - setConsumerRights entity addressbook #3 consumer group #2 access: 0 read: 0 write: 0 admin: 1
2013-09-12 18:25:46,293 n.b.c.c.AddressBookBindingImpl INFO - [admin0] AdrressBook : folder[public_collected 3 null] created
2013-09-12 18:25:46,294 n.b.c.a.AclHome INFO - update right entity addressbook #3consumer null #null read 1
2013-09-12 18:25:46,294 n.b.c.a.AclHome INFO - insert right entity addressbook #3consumer null #null read 1
2013-09-12 18:25:46,294 n.b.h.a.AclHook INFO - run onAclSetRight Hook
2013-09-12 18:25:46,295 n.b.c.h.h.SystemBindingImpl INFO - Public collected folder created with id: 3
2013-09-12 18:25:46,297 n.b.c.c.ContactHome INFO - users folder is 1
2013-09-12 18:25:46,330 n.b.c.s.SolrHelper WARN - no solr/contact
2013-09-12 18:25:46,330 n.b.c.u.UserHome INFO - contact created with id: 2 eid: 10
2013-09-12 18:25:46,330 n.b.c.u.UserHome INFO - ** inserting with contactId: u.getId() => 2
2013-09-12 18:25:46,332 n.b.c.u.UserHome INFO - insert 1 row(s)
2013-09-12 18:25:46,333 n.b.c.u.UserHome INFO - user id: 2
2013-09-12 18:25:46,338 n.b.s.n.SystemNotification INFO - Notification for domain.created sent.
2013-09-12 18:25:46,341 n.b.c.d.c.CrappyStore INFO - stored content to /var/spool/bm-docs/7b38927e-1fd6-4d3b-930f-60bf660886ad.b64
2013-09-12 18:25:46,342 n.b.c.d.c.CrappyStore INFO - stored meta to /var/spool/bm-docs/7b38927e-1fd6-4d3b-930f-60bf660886ad.meta.xml
2013-09-12 18:25:46,347 n.b.c.r.ResourceSanityCheckHome INFO - r.domain: 2 name: mix-buffet.com
2013-09-12 18:25:46,349 n.b.c.d.c.CrappyStore INFO - stored content to /var/spool/bm-docs/edfce83f-c6b1-4e1c-97f2-ccff7b8e3d6a.b64
2013-09-12 18:25:46,350 n.b.c.d.c.CrappyStore INFO - stored meta to /var/spool/bm-docs/edfce83f-c6b1-4e1c-97f2-ccff7b8e3d6a.meta.xml
2013-09-12 18:25:46,352 n.b.c.r.ResourceSanityCheckHome INFO - r.domain: 2 name: mix-buffet.com
2013-09-12 18:25:46,353 n.b.c.d.c.CrappyStore INFO - stored content to /var/spool/bm-docs/2ab55e06-e29a-4292-85e7-76d909934596.b64
2013-09-12 18:25:46,354 n.b.c.d.c.CrappyStore INFO - stored meta to /var/spool/bm-docs/2ab55e06-e29a-4292-85e7-76d909934596.meta.xml
2013-09-12 18:25:46,356 n.b.c.r.ResourceSanityCheckHome INFO - r.domain: 2 name: mix-buffet.com
2013-09-12 18:25:46,358 n.b.c.d.c.CrappyStore INFO - stored content to /var/spool/bm-docs/07d7f872-f553-4daf-915a-967147bca905.b64
2013-09-12 18:25:46,358 n.b.c.d.c.CrappyStore INFO - stored meta to /var/spool/bm-docs/07d7f872-f553-4daf-915a-967147bca905.meta.xml
2013-09-12 18:25:46,366 n.b.c.r.ResourceSanityCheckHome INFO - r.domain: 2 name: mix-buffet.com
2013-09-12 18:25:46,377 n.b.c.s.SyncServlet INFO - handler responded to system/createDomain in 162ms.
2013-09-12 18:25:46,394 n.b.c.s.SyncServlet INFO - handler responded to system/getDomainTemplate in 13ms.
2013-09-12 18:25:46,423 n.b.n.c.SChNodeClient INFO - Opening stream on /etc/bm/bm-core.tok...
2013-09-12 18:25:46,443 n.b.n.c.ScpReader ERROR - [ServerFault]: net.bluemind.node.server.FSFile@634be93a: no such file or directory
net.bluemind.core.api.fault.ServerFault: net.bluemind.node.server.FSFile@634be93a: no such file or directory
at net.bluemind.node.client.AbstractSshWorker.checkAck(AbstractSshWorker.java:84) ~[na:na]
at net.bluemind.node.client.ScpReader.read(ScpReader.java:66) ~[na:na]
at net.bluemind.node.client.SChNodeClient.openStream(SChNodeClient.java:123) ~[na:na]
at net.bluemind.node.client.SChNodeClient.read(SChNodeClient.java:75) ~[na:na]
at net.bluemind.core.session.database.PermanentTokenSystemHook.writeTokenIfNeeded(PermanentTokenSystemHook.java:88) ~[na:na]
at net.bluemind.core.session.database.PermanentTokenSystemHook.onHostTagged(PermanentTokenSystemHook.java:66) ~[na:na]
at net.bluemind.core.handler.host.SystemBindingImpl.tag(SystemBindingImpl.java:213) ~[na:na]
at net.bluemind.core.handler.host.SystemHandler$9.execute(SystemHandler.java:208) ~[na:na]
at net.bluemind.core.server.SecureMethod.execute(SecureMethod.java:56) ~[na:na]
at net.bluemind.core.server.AbstractSyncHandler.handle(AbstractSyncHandler.java:94) ~[na:na]
at net.bluemind.core.server.SyncServlet.handleQuery(SyncServlet.java:141) ~[na:na]
at net.bluemind.core.server.SyncServlet.service(SyncServlet.java:99) ~[na:na]
at javax.servlet.http.HttpServlet.service(HttpServlet.java:820) ~[na:na]
at org.eclipse.equinox.http.registry.internal.ServletManager$ServletWrapper.service(ServletManager.java:180) ~[na:na]
at org.eclipse.equinox.http.servlet.internal.ServletRegistration.service(ServletRegistration.java:61) ~[na:na]
at org.eclipse.equinox.http.servlet.internal.ProxyServlet.processAlias(ProxyServlet.java:126) ~[na:na]
at org.eclipse.equinox.http.servlet.internal.ProxyServlet.service(ProxyServlet.java:68) ~[na:na]
at javax.servlet.http.HttpServlet.service(HttpServlet.java:820) ~[na:na]
at org.eclipse.equinox.http.jetty.internal.HttpServerManager$InternalHttpServiceServlet.service(HttpServerManager.java:317) ~[na:na]
at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:511) ~[na:na]
at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:390) ~[na:na]
at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:182) ~[na:na]
at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:765) ~[na:na]
at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152) ~[na:na]
at org.mortbay.jetty.Server.handle(Server.java:326) ~[na:na]
at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:542) ~[na:na]
at org.mortbay.jetty.HttpConnection$RequestHandler.content(HttpConnection.java:939) ~[na:na]
at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:756) ~[na:na]
at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:218) ~[na:na]
at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404) ~[na:na]
at org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:409) ~[na:na]
at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:582) ~[na:na]
2013-09-12 18:25:46,449 n.b.c.s.d.PermanentTokenSystemHook INFO - Generate permanent token for host: mixmind, address: 172.20.102.237
2013-09-12 18:25:46,466 n.b.c.s.d.PermanentTokenSystemHook INFO - Writing permanent token on host mixmind, address:172.20.102.237 into file: /etc/bm/bm-core.tok
2013-09-12 18:25:46,655 n.b.n.c.SchExecTask INFO - Run cmd mkdir -p /etc/bm/bm-node.client
2013-09-12 18:25:46,717 n.b.h.n.NodeKeySystemHook INFO - Generate local RSA key on node: 172.20.102.237
2013-09-12 18:25:46,717 n.b.n.c.SchExecTask INFO - Run cmd ssh-keygen -t rsa -b 4096 -f /etc/bm/bm-node.client/local.bm.node.id_rsa -N ''
2013-09-12 18:25:47,074 n.b.c.s.SyncServlet INFO - handler responded to system/tag in 659ms.
2013-09-12 18:25:47,092 n.b.c.s.SyncServlet INFO - handler responded to system/assignToDomain in 14ms.
2013-09-12 18:25:47,143 n.b.n.c.NodeClientFactory WARN - Fail to authenticate using local authentication keys
2013-09-12 18:25:47,143 n.b.n.c.SChNodeClient INFO - Opening stream on /etc/bm/bm-core.tok...
2013-09-12 18:25:47,146 n.b.n.c.ScpReader INFO - Streaming bm-core.tok size: 36...
2013-09-12 18:25:47,228 n.b.c.s.SyncServlet INFO - handler responded to system/tag in 132ms.
2013-09-12 18:25:47,246 n.b.c.s.SyncServlet INFO - handler responded to system/assignToDomain in 15ms.
2013-09-12 18:25:47,299 n.b.n.c.NodeClientFactory WARN - Fail to authenticate using local authentication keys
2013-09-12 18:25:47,299 n.b.n.c.SChNodeClient INFO - Opening stream on /etc/bm/bm-core.tok...
2013-09-12 18:25:47,311 n.b.n.c.ScpReader INFO - Streaming bm-core.tok size: 36...
2013-09-12 18:25:47,378 n.b.c.s.SyncServlet INFO - handler responded to system/tag in 127ms.
2013-09-12 18:25:47,395 n.b.c.s.SyncServlet INFO - handler responded to system/assignToDomain in 14ms.
2013-09-12 18:25:47,444 n.b.n.c.NodeClientFactory WARN - Fail to authenticate using local authentication keys
2013-09-12 18:25:47,444 n.b.n.c.SChNodeClient INFO - Opening stream on /etc/bm/bm-core.tok...
2013-09-12 18:25:47,447 n.b.n.c.ScpReader INFO - Streaming bm-core.tok size: 36...
2013-09-12 18:25:47,544 n.b.n.c.NodeClientFactory WARN - Fail to authenticate using local authentication keys
2013-09-12 18:25:47,550 n.b.n.c.SchExecTask INFO - Run cmd mkdir -p /etc/bm-node
2013-09-12 18:25:47,612 n.b.h.n.NodeKeySystemHook INFO - Copy local RSA public key: /etc/bm/bm-node.client/local.bm.node.id_rsa.pub to node: 172.20.102.237
2013-09-12 18:25:47,735 n.b.c.s.SyncServlet INFO - handler responded to system/tag in 336ms.
2013-09-12 18:25:47,747 n.b.c.s.SyncServlet INFO - handler responded to system/assignToDomain in 8ms.
2013-09-12 18:25:48,062 n.b.n.c.SChNodeClient INFO - Opening stream on /etc/bm/bm-core.tok...
2013-09-12 18:25:48,341 n.b.n.c.ScpReader INFO - Streaming bm-core.tok size: 36...
2013-09-12 18:25:48,386 n.b.n.c.SchExecTask INFO - Run cmd mkdir -p /etc/bm-node
2013-09-12 18:25:48,436 n.b.h.n.NodeKeySystemHook INFO - Copy local RSA public key: /etc/bm/bm-node.client/local.bm.node.id_rsa.pub to node: 172.20.102.237
2013-09-12 18:25:48,545 n.b.c.s.SyncServlet INFO - handler responded to system/tag in 795ms.
2013-09-12 18:25:48,557 n.b.c.s.SyncServlet INFO - handler responded to system/assignToDomain in 8ms.
2013-09-12 18:25:48,565 n.b.n.c.SChNodeClient INFO - Opening stream on /etc/bm/bm-core.tok...
2013-09-12 18:25:48,568 n.b.n.c.ScpReader INFO - Streaming bm-core.tok size: 36...
2013-09-12 18:25:48,613 n.b.n.c.SchExecTask INFO - Run cmd mkdir -p /etc/bm-node
2013-09-12 18:25:48,663 n.b.h.n.NodeKeySystemHook INFO - Copy local RSA public key: /etc/bm/bm-node.client/local.bm.node.id_rsa.pub to node: 172.20.102.237
2013-09-12 18:25:48,754 n.b.c.s.SyncServlet INFO - handler responded to system/tag in 193ms.
2013-09-12 18:25:48,766 n.b.c.s.SyncServlet INFO - handler responded to system/assignToDomain in 8ms.
2013-09-12 18:25:48,773 n.b.n.c.SChNodeClient INFO - Opening stream on /etc/bm/bm-core.tok...
2013-09-12 18:25:48,786 n.b.n.c.ScpReader INFO - Streaming bm-core.tok size: 36...
2013-09-12 18:25:48,831 n.b.n.c.SchExecTask INFO - Run cmd mkdir -p /etc/bm-node
2013-09-12 18:25:48,883 n.b.h.n.NodeKeySystemHook INFO - Copy local RSA public key: /etc/bm/bm-node.client/local.bm.node.id_rsa.pub to node: 172.20.102.237
2013-09-12 18:25:48,981 n.b.c.s.SyncServlet INFO - handler responded to system/tag in 211ms.
2013-09-12 18:25:48,992 n.b.c.s.SyncServlet INFO - handler responded to system/assignToDomain in 8ms.
2013-09-12 18:25:49,001 n.b.n.c.SChNodeClient INFO - Opening stream on /etc/bm/bm-core.tok...
2013-09-12 18:25:49,004 n.b.n.c.ScpReader INFO - Streaming bm-core.tok size: 36...
2013-09-12 18:25:49,048 n.b.n.c.SchExecTask INFO - Run cmd mkdir -p /etc/bm-node
2013-09-12 18:25:49,100 n.b.h.n.NodeKeySystemHook INFO - Copy local RSA public key: /etc/bm/bm-node.client/local.bm.node.id_rsa.pub to node: 172.20.102.237
2013-09-12 18:25:49,208 n.b.n.c.SchExecTask INFO - Run cmd /bin/mkdir -p /etc/postfix
2013-09-12 18:25:49,260 n.b.s.w.WebmailHook INFO - host 172.20.102.237 tagged as bm/webmail. (Over)writing main & master.cf
2013-09-12 18:25:49,262 n.b.n.c.SchListFiles INFO - Run listfiles /etc/apache2/sites-available/bm-ui
2013-09-12 18:25:49,309 n.b.n.c.SchListFiles INFO - Run listfiles /etc/init.d/apache2
2013-09-12 18:25:49,353 n.b.n.c.SchExecTask INFO - Run cmd /etc/init.d/apache2 reload
2013-09-12 18:25:49,451 n.b.c.s.SyncServlet INFO - handler responded to system/tag in 455ms.
2013-09-12 18:25:49,472 n.b.c.s.SyncServlet INFO - handler responded to system/assignToDomain in 16ms.
2013-09-12 18:25:49,500 n.b.n.c.SChNodeClient INFO - Opening stream on /etc/bm/bm-core.tok...
2013-09-12 18:25:49,512 n.b.n.c.ScpReader INFO - Streaming bm-core.tok size: 36...
2013-09-12 18:25:49,568 n.b.n.c.SchExecTask INFO - Run cmd mkdir -p /etc/bm-node
2013-09-12 18:25:49,620 n.b.h.n.NodeKeySystemHook INFO - Copy local RSA public key: /etc/bm/bm-node.client/local.bm.node.id_rsa.pub to node: 172.20.102.237
2013-09-12 18:25:49,725 n.b.c.s.SyncServlet INFO - handler responded to system/tag in 236ms.
2013-09-12 18:25:49,744 n.b.c.s.SyncServlet INFO - handler responded to system/assignToDomain in 15ms.
2013-09-12 18:25:49,760 n.b.n.c.SChNodeClient INFO - Opening stream on /etc/bm/bm-core.tok...
2013-09-12 18:25:49,763 n.b.n.c.ScpReader INFO - Streaming bm-core.tok size: 36...
2013-09-12 18:25:49,807 n.b.n.c.SchExecTask INFO - Run cmd mkdir -p /etc/bm-node
2013-09-12 18:25:49,870 n.b.h.n.NodeKeySystemHook INFO - Copy local RSA public key: /etc/bm/bm-node.client/local.bm.node.id_rsa.pub to node: 172.20.102.237
2013-09-12 18:25:49,976 n.b.c.s.SyncServlet INFO - handler responded to system/tag in 227ms.
2013-09-12 18:25:49,994 n.b.c.s.SyncServlet INFO - handler responded to system/assignToDomain in 13ms.
2013-09-12 18:25:50,005 n.b.n.c.SChNodeClient INFO - Opening stream on /etc/bm/bm-core.tok...
2013-09-12 18:25:50,008 n.b.n.c.ScpReader INFO - Streaming bm-core.tok size: 36...
2013-09-12 18:25:50,063 n.b.n.c.SchExecTask INFO - Run cmd mkdir -p /etc/bm-node
2013-09-12 18:25:50,114 n.b.h.n.NodeKeySystemHook INFO - Copy local RSA public key: /etc/bm/bm-node.client/local.bm.node.id_rsa.pub to node: 172.20.102.237
2013-09-12 18:25:50,220 n.b.c.s.SyncServlet INFO - handler responded to system/tag in 222ms.
2013-09-12 18:25:50,244 n.b.c.s.SyncServlet INFO - handler responded to system/assignToDomain in 19ms.
2013-09-12 18:25:50,254 n.b.n.c.SChNodeClient INFO - Opening stream on /etc/bm/bm-core.tok...
2013-09-12 18:25:50,257 n.b.n.c.ScpReader INFO - Streaming bm-core.tok size: 36...
2013-09-12 18:25:50,302 n.b.n.c.SchExecTask INFO - Run cmd mkdir -p /etc/bm-node
2013-09-12 18:25:50,354 n.b.h.n.NodeKeySystemHook INFO - Copy local RSA public key: /etc/bm/bm-node.client/local.bm.node.id_rsa.pub to node: 172.20.102.237
2013-09-12 18:25:50,453 n.b.c.s.SyncServlet INFO - handler responded to system/tag in 204ms.
2013-09-12 18:25:50,471 n.b.c.s.SyncServlet INFO - handler responded to system/assignToDomain in 14ms.
2013-09-12 18:25:50,479 n.b.n.c.SChNodeClient INFO - Opening stream on /etc/bm/bm-core.tok...
2013-09-12 18:25:50,483 n.b.n.c.ScpReader INFO - Streaming bm-core.tok size: 36...
2013-09-12 18:25:50,527 n.b.n.c.SchExecTask INFO - Run cmd mkdir -p /etc/bm-node
2013-09-12 18:25:50,578 n.b.h.n.NodeKeySystemHook INFO - Copy local RSA public key: /etc/bm/bm-node.client/local.bm.node.id_rsa.pub to node: 172.20.102.237
2013-09-12 18:25:50,679 n.b.c.s.SyncServlet INFO - handler responded to system/tag in 205ms.
2013-09-12 18:25:50,697 n.b.c.s.SyncServlet INFO - handler responded to system/assignToDomain in 13ms.
2013-09-12 18:25:50,706 n.b.n.c.SChNodeClient INFO - Opening stream on /etc/bm/bm-core.tok...
2013-09-12 18:25:50,710 n.b.n.c.ScpReader INFO - Streaming bm-core.tok size: 36...
2013-09-12 18:25:50,764 n.b.n.c.SchExecTask INFO - Run cmd mkdir -p /etc/bm-node
2013-09-12 18:25:50,817 n.b.h.n.NodeKeySystemHook INFO - Copy local RSA public key: /etc/bm/bm-node.client/local.bm.node.id_rsa.pub to node: 172.20.102.237
2013-09-12 18:25:50,925 n.b.n.c.SchExecTask INFO - Run cmd /bin/mkdir -p /etc/postfix
2013-09-12 18:25:50,976 n.b.s.p.PostfixHook INFO - host 172.20.102.237 tagged as mail/smtp_in. (Over)writing main & master.cf
2013-09-12 18:25:50,979 n.b.n.c.SchListFiles INFO - Run listfiles /etc/system-release
2013-09-12 18:25:51,212 n.b.n.c.SchExecTask INFO - Run cmd hostname -f
2013-09-12 18:25:51,264 n.b.s.p.PostfixHook INFO - out(0): mixmind.mixbuff
2013-09-12 18:25:51,384 n.b.n.c.SchExecTask INFO - Run cmd /usr/sbin/postconf -e 'mynetworks=127.0.0.0/8, 172.20.102.0/24'
2013-09-12 18:25:51,500 n.b.n.c.SchExecTask INFO - Run cmd /usr/sbin/postconf -e 'mailbox_size_limit=10485760'
2013-09-12 18:25:51,613 n.b.n.c.SchExecTask INFO - Run cmd /usr/sbin/postconf -e 'message_size_limit=10485760'
2013-09-12 18:25:51,717 n.b.n.c.SchExecTask INFO - Run cmd mkdir -p /var/lib/bm-ca
2013-09-12 18:25:51,863 n.b.n.c.SchExecTask INFO - Run cmd mkdir -p /etc/ssl/certs
2013-09-12 18:25:52,006 n.b.n.c.SchExecTask INFO - Run cmd /bin/mkdir -p /etc/postfix/sasl
2013-09-12 18:25:52,151 n.b.n.c.SchExecTask INFO - Run cmd /etc/init.d/ysnp stop
2013-09-12 18:25:52,720 n.b.n.c.SchExecTask INFO - Run cmd /etc/init.d/ysnp start
2013-09-12 18:25:52,795 n.b.n.c.SChNodeClient INFO - Opening stream on /etc/postfix/transport...
2013-09-12 18:25:52,798 n.b.n.c.ScpReader INFO - Streaming transport size: 12500...
2013-09-12 18:25:52,872 n.b.n.c.SchExecTask INFO - Run cmd /usr/sbin/postmap /etc/postfix/transport
2013-09-12 18:25:53,603 n.b.n.c.SChNodeClient INFO - Opening stream on /etc/postfix/virtual_alias...
2013-09-12 18:25:53,640 n.b.n.c.ScpReader ERROR - [ServerFault]: net.bluemind.node.server.FSFile@131548ee: no such file or directory
net.bluemind.core.api.fault.ServerFault: net.bluemind.node.server.FSFile@131548ee: no such file or directory
at net.bluemind.node.client.AbstractSshWorker.checkAck(AbstractSshWorker.java:84) ~[na:na]
at net.bluemind.node.client.ScpReader.read(ScpReader.java:66) ~[na:na]
at net.bluemind.node.client.SChNodeClient.openStream(SChNodeClient.java:123) ~[na:na]
at net.bluemind.node.client.SChNodeClient.read(SChNodeClient.java:75) ~[na:na]
at net.bluemind.system.postfix.cf.VirtualAlias.<init>(VirtualAlias.java:59) ~[na:na]
at net.bluemind.system.postfix.PostfixHook.onHostTagged(PostfixHook.java:141) ~[na:na]
at net.bluemind.core.handler.host.SystemBindingImpl.tag(SystemBindingImpl.java:213) ~[na:na]
at net.bluemind.core.handler.host.SystemHandler$9.execute(SystemHandler.java:208) ~[na:na]
at net.bluemind.core.server.SecureMethod.execute(SecureMethod.java:56) ~[na:na]
at net.bluemind.core.server.AbstractSyncHandler.handle(AbstractSyncHandler.java:94) ~[na:na]
at net.bluemind.core.server.SyncServlet.handleQuery(SyncServlet.java:141) ~[na:na]
at net.bluemind.core.server.SyncServlet.service(SyncServlet.java:99) ~[na:na]
at javax.servlet.http.HttpServlet.service(HttpServlet.java:820) ~[na:na]
at org.eclipse.equinox.http.registry.internal.ServletManager$ServletWrapper.service(ServletManager.java:180) ~[na:na]
at org.eclipse.equinox.http.servlet.internal.ServletRegistration.service(ServletRegistration.java:61) ~[na:na]
at org.eclipse.equinox.http.servlet.internal.ProxyServlet.processAlias(ProxyServlet.java:126) ~[na:na]
at org.eclipse.equinox.http.servlet.internal.ProxyServlet.service(ProxyServlet.java:68) ~[na:na]
at javax.servlet.http.HttpServlet.service(HttpServlet.java:820) ~[na:na]
at org.eclipse.equinox.http.jetty.internal.HttpServerManager$InternalHttpServiceServlet.service(HttpServerManager.java:317) ~[na:na]
at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:511) ~[na:na]
at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:390) ~[na:na]
at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:182) ~[na:na]
at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:765) ~[na:na]
at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152) ~[na:na]
at org.mortbay.jetty.Server.handle(Server.java:326) ~[na:na]
at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:542) ~[na:na]
at org.mortbay.jetty.HttpConnection$RequestHandler.content(HttpConnection.java:939) ~[na:na]
at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:756) ~[na:na]
at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:218) ~[na:na]
at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404) ~[na:na]
at org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:409) ~[na:na]
at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:582) ~[na:na]
2013-09-12 18:25:54,057 n.b.n.c.SchExecTask INFO - Run cmd /usr/sbin/postmap /etc/postfix/virtual_alias
2013-09-12 18:25:54,203 n.b.n.c.SChNodeClient INFO - Opening stream on /etc/postfix/virtual_domains...
2013-09-12 18:25:54,223 n.b.n.c.ScpReader ERROR - [ServerFault]: net.bluemind.node.server.FSFile@4d2e434b: no such file or directory
net.bluemind.core.api.fault.ServerFault: net.bluemind.node.server.FSFile@4d2e434b: no such file or directory
at net.bluemind.node.client.AbstractSshWorker.checkAck(AbstractSshWorker.java:84) ~[na:na]
at net.bluemind.node.client.ScpReader.read(ScpReader.java:66) ~[na:na]
at net.bluemind.node.client.SChNodeClient.openStream(SChNodeClient.java:123) ~[na:na]
at net.bluemind.node.client.SChNodeClient.read(SChNodeClient.java:75) ~[na:na]
at net.bluemind.system.postfix.cf.VirtualDomains.<init>(VirtualDomains.java:49) ~[na:na]
at net.bluemind.system.postfix.PostfixHook.onHostTagged(PostfixHook.java:145) ~[na:na]
at net.bluemind.core.handler.host.SystemBindingImpl.tag(SystemBindingImpl.java:213) ~[na:na]
at net.bluemind.core.handler.host.SystemHandler$9.execute(SystemHandler.java:208) ~[na:na]
at net.bluemind.core.server.SecureMethod.execute(SecureMethod.java:56) ~[na:na]
at net.bluemind.core.server.AbstractSyncHandler.handle(AbstractSyncHandler.java:94) ~[na:na]
at net.bluemind.core.server.SyncServlet.handleQuery(SyncServlet.java:141) ~[na:na]
at net.bluemind.core.server.SyncServlet.service(SyncServlet.java:99) ~[na:na]
at javax.servlet.http.HttpServlet.service(HttpServlet.java:820) ~[na:na]
at org.eclipse.equinox.http.registry.internal.ServletManager$ServletWrapper.service(ServletManager.java:180) ~[na:na]
at org.eclipse.equinox.http.servlet.internal.ServletRegistration.service(ServletRegistration.java:61) ~[na:na]
at org.eclipse.equinox.http.servlet.internal.ProxyServlet.processAlias(ProxyServlet.java:126) ~[na:na]
at org.eclipse.equinox.http.servlet.internal.ProxyServlet.service(ProxyServlet.java:68) ~[na:na]
at javax.servlet.http.HttpServlet.service(HttpServlet.java:820) ~[na:na]
at org.eclipse.equinox.http.jetty.internal.HttpServerManager$InternalHttpServiceServlet.service(HttpServerManager.java:317) ~[na:na]
at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:511) ~[na:na]
at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:390) ~[na:na]
at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:182) ~[na:na]
at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:765) ~[na:na]
at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152) ~[na:na]
at org.mortbay.jetty.Server.handle(Server.java:326) ~[na:na]
at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:542) ~[na:na]
at org.mortbay.jetty.HttpConnection$RequestHandler.content(HttpConnection.java:939) ~[na:na]
at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:756) ~[na:na]
at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:218) ~[na:na]
at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404) ~[na:na]
at org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:409) ~[na:na]
at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:582) ~[na:na]
2013-09-12 18:25:54,692 n.b.n.c.SchExecTask INFO - Run cmd /usr/sbin/postmap /etc/postfix/virtual_domains
2013-09-12 18:25:54,814 n.b.n.c.SChNodeClient INFO - Opening stream on /etc/postfix/virtual_mailbox...
2013-09-12 18:25:54,826 n.b.n.c.ScpReader ERROR - [ServerFault]: net.bluemind.node.server.FSFile@c77d241: no such file or directory
net.bluemind.core.api.fault.ServerFault: net.bluemind.node.server.FSFile@c77d241: no such file or directory
at net.bluemind.node.client.AbstractSshWorker.checkAck(AbstractSshWorker.java:84) ~[na:na]
at net.bluemind.node.client.ScpReader.read(ScpReader.java:66) ~[na:na]
at net.bluemind.node.client.SChNodeClient.openStream(SChNodeClient.java:123) ~[na:na]
at net.bluemind.node.client.SChNodeClient.read(SChNodeClient.java:75) ~[na:na]
at net.bluemind.system.postfix.cf.VirtualMailbox.<init>(VirtualMailbox.java:48) ~[na:na]
at net.bluemind.system.postfix.PostfixHook.onHostTagged(PostfixHook.java:149) ~[na:na]
at net.bluemind.core.handler.host.SystemBindingImpl.tag(SystemBindingImpl.java:213) ~[na:na]
at net.bluemind.core.handler.host.SystemHandler$9.execute(SystemHandler.java:208) ~[na:na]
at net.bluemind.core.server.SecureMethod.execute(SecureMethod.java:56) ~[na:na]
at net.bluemind.core.server.AbstractSyncHandler.handle(AbstractSyncHandler.java:94) ~[na:na]
at net.bluemind.core.server.SyncServlet.handleQuery(SyncServlet.java:141) ~[na:na]
at net.bluemind.core.server.SyncServlet.service(SyncServlet.java:99) ~[na:na]
at javax.servlet.http.HttpServlet.service(HttpServlet.java:820) ~[na:na]
at org.eclipse.equinox.http.registry.internal.ServletManager$ServletWrapper.service(ServletManager.java:180) ~[na:na]
at org.eclipse.equinox.http.servlet.internal.ServletRegistration.service(ServletRegistration.java:61) ~[na:na]
at org.eclipse.equinox.http.servlet.internal.ProxyServlet.processAlias(ProxyServlet.java:126) ~[na:na]
at org.eclipse.equinox.http.servlet.internal.ProxyServlet.service(ProxyServlet.java:68) ~[na:na]
at javax.servlet.http.HttpServlet.service(HttpServlet.java:820) ~[na:na]
at org.eclipse.equinox.http.jetty.internal.HttpServerManager$InternalHttpServiceServlet.service(HttpServerManager.java:317) ~[na:na]
at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:511) ~[na:na]
at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:390) ~[na:na]
at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:182) ~[na:na]
at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:765) ~[na:na]
at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152) ~[na:na]
at org.mortbay.jetty.Server.handle(Server.java:326) ~[na:na]
at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:542) ~[na:na]
at org.mortbay.jetty.HttpConnection$RequestHandler.content(HttpConnection.java:939) ~[na:na]
at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:756) ~[na:na]
at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:218) ~[na:na]
at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404) ~[na:na]
at org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:409) ~[na:na]
at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:582) ~[na:na]
2013-09-12 18:25:55,148 n.b.n.c.SchExecTask INFO - Run cmd /usr/sbin/postmap /etc/postfix/virtual_mailbox
2013-09-12 18:25:55,286 n.b.n.c.SChNodeClient INFO - Opening stream on /etc/postfix/master_relay_transport...
2013-09-12 18:25:55,297 n.b.n.c.ScpReader ERROR - [ServerFault]: net.bluemind.node.server.FSFile@1359808a: no such file or directory
net.bluemind.core.api.fault.ServerFault: net.bluemind.node.server.FSFile@1359808a: no such file or directory
at net.bluemind.node.client.AbstractSshWorker.checkAck(AbstractSshWorker.java:84) ~[na:na]
at net.bluemind.node.client.ScpReader.read(ScpReader.java:66) ~[na:na]
at net.bluemind.node.client.SChNodeClient.openStream(SChNodeClient.java:123) ~[na:na]
at net.bluemind.node.client.SChNodeClient.read(SChNodeClient.java:75) ~[na:na]
at net.bluemind.system.postfix.cf.MasterRelayTransport.<init>(MasterRelayTransport.java:48) ~[na:na]
at net.bluemind.system.postfix.PostfixHook.onHostTagged(PostfixHook.java:153) ~[na:na]
at net.bluemind.core.handler.host.SystemBindingImpl.tag(SystemBindingImpl.java:213) ~[na:na]
at net.bluemind.core.handler.host.SystemHandler$9.execute(SystemHandler.java:208) ~[na:na]
at net.bluemind.core.server.SecureMethod.execute(SecureMethod.java:56) ~[na:na]
at net.bluemind.core.server.AbstractSyncHandler.handle(AbstractSyncHandler.java:94) ~[na:na]
at net.bluemind.core.server.SyncServlet.handleQuery(SyncServlet.java:141) ~[na:na]
at net.bluemind.core.server.SyncServlet.service(SyncServlet.java:99) ~[na:na]
at javax.servlet.http.HttpServlet.service(HttpServlet.java:820) ~[na:na]
at org.eclipse.equinox.http.registry.internal.ServletManager$ServletWrapper.service(ServletManager.java:180) ~[na:na]
at org.eclipse.equinox.http.servlet.internal.ServletRegistration.service(ServletRegistration.java:61) ~[na:na]
at org.eclipse.equinox.http.servlet.internal.ProxyServlet.processAlias(ProxyServlet.java:126) ~[na:na]
at org.eclipse.equinox.http.servlet.internal.ProxyServlet.service(ProxyServlet.java:68) ~[na:na]
at javax.servlet.http.HttpServlet.service(HttpServlet.java:820) ~[na:na]
at org.eclipse.equinox.http.jetty.internal.HttpServerManager$InternalHttpServiceServlet.service(HttpServerManager.java:317) ~[na:na]
at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:511) ~[na:na]
at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:390) ~[na:na]
at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:182) ~[na:na]
at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:765) ~[na:na]
at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152) ~[na:na]
at org.mortbay.jetty.Server.handle(Server.java:326) ~[na:na]
at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:542) ~[na:na]
at org.mortbay.jetty.HttpConnection$RequestHandler.content(HttpConnection.java:939) ~[na:na]
at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:756) ~[na:na]
at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:218) ~[na:na]
at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404) ~[na:na]
at org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:409) ~[na:na]
at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:582) ~[na:na]
2013-09-12 18:25:55,643 n.b.n.c.SchExecTask INFO - Run cmd /usr/sbin/postmap /etc/postfix/master_relay_transport
2013-09-12 18:25:55,891 n.b.n.c.SchExecTask INFO - Run cmd /usr/bin/newaliases
2013-09-12 18:25:56,087 n.b.n.c.SchExecTask INFO - Run cmd /etc/init.d/postfix restart
2013-09-12 18:25:57,033 n.b.c.s.SyncServlet INFO - handler responded to system/tag in 6331ms.
2013-09-12 18:25:57,043 n.b.s.p.PostfixHook INFO - host 172.20.102.237 assigned as mail/smtp_in to mix-buffet.com
2013-09-12 18:25:57,044 n.b.n.c.SChNodeClient INFO - Opening stream on /etc/postfix/virtual_domains...
2013-09-12 18:25:57,046 n.b.n.c.ScpReader INFO - Streaming virtual_domains size: 0...
2013-09-12 18:25:57,150 n.b.n.c.SchExecTask INFO - Run cmd /usr/sbin/postmap /etc/postfix/virtual_domains
2013-09-12 18:25:57,321 n.b.n.c.SChNodeClient INFO - Opening stream on /etc/postfix/virtual_mailbox...
2013-09-12 18:25:57,323 n.b.n.c.ScpReader INFO - Streaming virtual_mailbox size: 0...
2013-09-12 18:25:57,375 n.b.n.c.SChNodeClient INFO - Opening stream on /etc/postfix/virtual_alias...
2013-09-12 18:25:57,379 n.b.n.c.ScpReader INFO - Streaming virtual_alias size: 0...
2013-09-12 18:25:57,432 n.b.n.c.SChNodeClient INFO - Opening stream on /etc/postfix/transport...
2013-09-12 18:25:57,435 n.b.n.c.ScpReader INFO - Streaming transport size: 0...
2013-09-12 18:25:57,521 n.b.n.c.SchExecTask INFO - Run cmd /usr/sbin/postmap /etc/postfix/virtual_mailbox
2013-09-12 18:25:57,717 n.b.n.c.SchExecTask INFO - Run cmd /usr/sbin/postmap /etc/postfix/transport
2013-09-12 18:25:57,876 n.b.n.c.SchExecTask INFO - Run cmd /usr/sbin/postmap /etc/postfix/virtual_alias
2013-09-12 18:25:57,997 n.b.c.g.GroupBindingImpl INFO - [admin0] Group : find()
2013-09-12 18:25:58,013 n.b.c.s.SyncServlet INFO - handler responded to system/assignToDomain in 976ms.
2013-09-12 18:25:58,021 n.b.n.c.SChNodeClient INFO - Opening stream on /etc/bm/bm-core.tok...
2013-09-12 18:25:58,025 n.b.n.c.ScpReader INFO - Streaming bm-core.tok size: 36...
2013-09-12 18:25:58,069 n.b.n.c.SchExecTask INFO - Run cmd mkdir -p /etc/bm-node
2013-09-12 18:25:58,123 n.b.h.n.NodeKeySystemHook INFO - Copy local RSA public key: /etc/bm/bm-node.client/local.bm.node.id_rsa.pub to node: 172.20.102.237
2013-09-12 18:25:58,225 n.b.s.c.CyrusSystemHook INFO - new imap backend tagged, (over)writing imapd.conf
2013-09-12 18:25:58,227 n.b.n.c.SchExecTask INFO - Run cmd /usr/share/bm-cyrus/resetCyrus.sh
2013-09-12 18:26:00,023 n.b.c.j.i.JobBindingImpl INFO - getJobFromId net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob
2013-09-12 18:26:00,027 n.b.c.j.i.JobHome INFO - Loaded 0 jobs from database.
2013-09-12 18:26:00,053 n.b.c.j.i.JobBindingImpl INFO - getJobFromId Vacation
2013-09-12 18:26:00,056 n.b.c.j.i.JobHome INFO - Loaded 0 jobs from database.
2013-09-12 18:26:00,071 n.b.c.j.i.JobBindingImpl INFO - getJobFromId EventAlert
2013-09-12 18:26:00,072 n.b.c.j.i.JobHome INFO - Loaded 0 jobs from database.
2013-09-12 18:26:00,083 n.b.c.j.i.Scheduler INFO - Finishing EventAlert-global.virt-1379010360073
2013-09-12 18:26:00,083 n.b.c.j.i.Scheduler INFO - [EventAlert-global.virt-1379010360073] progress is now 100%.
2013-09-12 18:26:00,097 n.b.c.j.i.JobBindingImpl INFO - getJobFromId net.bluemind.archive.core.ArchiveJob
2013-09-12 18:26:00,102 n.b.c.j.i.JobHome INFO - Loaded 0 jobs from database.
2013-09-12 18:26:00,105 n.b.c.j.i.ExecutionRecorder INFO - recording execution of EventAlert-global.virt-1379010360073
2013-09-12 18:26:00,107 n.b.c.j.i.JobHome INFO - recording execution for EventAlert-global.virt-1379010360073...
2013-09-12 18:26:00,111 n.b.c.j.i.JobHome INFO - run plan for EventAlert@global.virt updated with last_run set to id 1 (start: Thu Sep 12 18:26:00 GMT 2013)
2013-09-12 18:26:00,111 n.b.c.j.i.JobHome INFO - saving 3 entries...
2013-09-12 18:26:00,118 n.b.a.c.ArchiveJob INFO - not forced, last run was 0secs ago.
2013-09-12 18:26:00,118 n.b.a.c.ArchiveJob INFO - less than one day ago, skipping execution.
2013-09-12 18:26:00,120 n.b.c.j.i.Scheduler INFO - Finishing Vacation-global.virt-1379010360057
2013-09-12 18:26:00,120 n.b.c.j.i.Scheduler INFO - [Vacation-global.virt-1379010360057] progress is now 100%.
2013-09-12 18:26:00,126 n.b.c.j.i.JobBindingImpl INFO - getJobFromId net.bluemind.dataprotect.core.DataProtectJob
2013-09-12 18:26:00,126 n.b.c.j.i.ExecutionRecorder INFO - recording execution of Vacation-global.virt-1379010360057
2013-09-12 18:26:00,128 n.b.c.j.i.JobHome INFO - Loaded 0 jobs from database.
2013-09-12 18:26:00,130 n.b.d.c.DataProtectJob INFO - not planned, last run was 53secs ago.
2013-09-12 18:26:00,131 n.b.d.c.DataProtectJob INFO - less than one day ago, skipping execution.
2013-09-12 18:26:00,131 n.b.c.j.i.JobHome INFO - recording execution for Vacation-global.virt-1379010360057...
2013-09-12 18:26:00,133 n.b.c.j.i.JobHome INFO - run plan for Vacation@global.virt updated with last_run set to id 2 (start: Thu Sep 12 18:26:00 GMT 2013)
2013-09-12 18:26:00,133 n.b.c.j.i.JobHome INFO - saving 3 entries...
2013-09-12 18:26:00,143 n.b.c.j.i.JobBindingImpl INFO - getJobFromId net.bluemind.core.jobs.quota.QuotaGatheringJob
2013-09-12 18:26:00,145 n.b.c.j.i.JobHome INFO - Loaded 0 jobs from database.
2013-09-12 18:26:00,146 n.b.c.j.q.QuotaGatheringJob INFO - not forced, last run was 53secs ago.
2013-09-12 18:26:00,146 n.b.c.j.q.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2013-09-12 18:26:00,153 n.b.c.j.i.JobBindingImpl INFO - getJobFromId ImportADJob
2013-09-12 18:26:00,155 n.b.c.j.i.JobHome INFO - Loaded 0 jobs from database.
2013-09-12 18:26:00,157 n.b.c.j.i.Scheduler INFO - [EventAlert-global.virt-1379010360073] finished and recorded: SUCCESS, duration: 10ms.
2013-09-12 18:26:00,163 n.b.c.j.i.Scheduler INFO - [Vacation-global.virt-1379010360057] finished and recorded: SUCCESS, duration: 63ms.
2013-09-12 18:26:02,130 n.b.s.c.CyrusSystemHook INFO - Generate permanent token for host: mixmind, address: 172.20.102.237
2013-09-12 18:26:02,388 n.b.n.c.SchExecTask INFO - Run noout /etc/init.d/cyrus-imapd restart
2013-09-12 18:26:47,190 n.b.c.s.SyncServlet INFO - handler responded to system/tag in 49173ms.
2013-09-12 18:27:00,016 n.b.c.j.i.JobBindingImpl INFO - getJobFromId net.bluemind.core.jobs.cleanup.JobExecutionsCleanJob
2013-09-12 18:27:00,020 n.b.c.j.i.JobHome INFO - Loaded 0 jobs from database.
2013-09-12 18:27:00,032 n.b.c.j.i.JobBindingImpl INFO - getJobFromId Vacation
2013-09-12 18:27:00,035 n.b.c.j.i.JobHome INFO - Loaded 1 jobs from database.
2013-09-12 18:27:00,056 n.b.c.j.i.JobBindingImpl INFO - getJobFromId EventAlert
2013-09-12 18:27:00,058 n.b.c.j.i.JobHome INFO - Loaded 1 jobs from database.
2013-09-12 18:27:00,075 n.b.c.j.i.Scheduler INFO - Finishing EventAlert-global.virt-1379010420058
2013-09-12 18:27:00,076 n.b.c.j.i.Scheduler INFO - [EventAlert-global.virt-1379010420058] progress is now 100%.
2013-09-12 18:27:00,076 n.b.c.j.i.ExecutionRecorder INFO - recording execution of EventAlert-global.virt-1379010420058
2013-09-12 18:27:00,077 n.b.c.j.i.JobHome INFO - recording execution for EventAlert-global.virt-1379010420058...
2013-09-12 18:27:00,080 n.b.c.j.i.JobHome INFO - run plan for EventAlert@global.virt updated with last_run set to id 3 (start: Thu Sep 12 18:27:00 GMT 2013)
2013-09-12 18:27:00,080 n.b.c.j.i.JobHome INFO - saving 3 entries...
2013-09-12 18:27:00,085 n.b.c.j.i.JobBindingImpl INFO - getJobFromId net.bluemind.archive.core.ArchiveJob
2013-09-12 18:27:00,088 n.b.c.j.i.JobHome INFO - Loaded 0 jobs from database.
2013-09-12 18:27:00,090 n.b.a.c.ArchiveJob INFO - not forced, last run was 59secs ago.
2013-09-12 18:27:00,090 n.b.a.c.ArchiveJob INFO - less than one day ago, skipping execution.
2013-09-12 18:27:00,099 n.b.c.j.i.JobBindingImpl INFO - getJobFromId net.bluemind.dataprotect.core.DataProtectJob
2013-09-12 18:27:00,100 n.b.c.j.i.JobHome INFO - Loaded 0 jobs from database.
2013-09-12 18:27:00,102 n.b.d.c.DataProtectJob INFO - not planned, last run was 113secs ago.
2013-09-12 18:27:00,102 n.b.d.c.DataProtectJob INFO - less than one day ago, skipping execution.
2013-09-12 18:27:00,112 n.b.c.j.i.JobBindingImpl INFO - getJobFromId net.bluemind.core.jobs.quota.QuotaGatheringJob
2013-09-12 18:27:00,113 n.b.c.j.i.JobHome INFO - Loaded 0 jobs from database.
2013-09-12 18:27:00,115 n.b.c.j.q.QuotaGatheringJob INFO - not forced, last run was 113secs ago.
2013-09-12 18:27:00,115 n.b.c.j.q.QuotaGatheringJob INFO - less than one day ago, skipping execution.
2013-09-12 18:27:00,125 n.b.c.j.i.JobBindingImpl INFO - getJobFromId ImportADJob
2013-09-12 18:27:00,126 n.b.c.j.i.JobHome INFO - Loaded 0 jobs from database.
2013-09-12 18:27:00,153 n.b.c.j.i.Scheduler INFO - Finishing Vacation-global.virt-1379010420037
2013-09-12 18:27:00,154 n.b.c.j.i.Scheduler INFO - [Vacation-global.virt-1379010420037] progress is now 100%.
2013-09-12 18:27:00,154 n.b.c.j.i.ExecutionRecorder INFO - recording execution of Vacation-global.virt-1379010420037
2013-09-12 18:27:00,155 n.b.c.j.i.JobHome INFO - recording execution for Vacation-global.virt-1379010420037...
2013-09-12 18:27:00,157 n.b.c.j.i.JobHome INFO - run plan for Vacation@global.virt updated with last_run set to id 4 (start: Thu Sep 12 18:27:00 GMT 2013)
2013-09-12 18:27:00,157 n.b.c.j.i.JobHome INFO - saving 3 entries...
2013-09-12 18:27:00,207 n.b.c.j.i.Scheduler INFO - [EventAlert-global.virt-1379010420058] finished and recorded: SUCCESS, duration: 18ms.
...]