[
https://issues.apache.org/jira/browse/CLOUDSTACK-5385?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13845248#comment-13845248
]
Koushik Das commented on CLOUDSTACK-5385:
-----------------------------------------
Log snippet indicating 15 snapshot policies are configured:
2013-12-11 15:28:56,872 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (main:null)
Current time is 2013-12-11 09:58:45 GMT. NextScheduledTime of policyId 1 is
2013-12-11 10:31:00 GMT
2013-12-11 15:28:56,912 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (main:null)
Current time is 2013-12-11 09:58:45 GMT. NextScheduledTime of policyId 2 is
2013-12-11 10:31:00 GMT
2013-12-11 15:28:56,968 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (main:null)
Current time is 2013-12-11 09:58:45 GMT. NextScheduledTime of policyId 3 is
2013-12-11 10:31:00 GMT
2013-12-11 15:28:56,984 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (main:null)
Current time is 2013-12-11 09:58:45 GMT. NextScheduledTime of policyId 4 is
2013-12-11 10:31:00 GMT
2013-12-11 15:28:56,998 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (main:null)
Current time is 2013-12-11 09:58:45 GMT. NextScheduledTime of policyId 5 is
2013-12-11 10:31:00 GMT
2013-12-11 15:28:57,009 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (main:null)
Current time is 2013-12-11 09:58:45 GMT. NextScheduledTime of policyId 6 is
2013-12-11 10:31:00 GMT
2013-12-11 15:28:57,024 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (main:null)
Current time is 2013-12-11 09:58:45 GMT. NextScheduledTime of policyId 7 is
2013-12-11 10:31:00 GMT
2013-12-11 15:28:57,037 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (main:null)
Current time is 2013-12-11 09:58:45 GMT. NextScheduledTime of policyId 8 is
2013-12-11 10:31:00 GMT
2013-12-11 15:28:57,048 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (main:null)
Current time is 2013-12-11 09:58:45 GMT. NextScheduledTime of policyId 9 is
2013-12-11 10:31:00 GMT
2013-12-11 15:28:57,059 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (main:null)
Current time is 2013-12-11 09:58:45 GMT. NextScheduledTime of policyId 10 is
2013-12-11 10:31:00 GMT
2013-12-11 15:28:57,069 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (main:null)
Current time is 2013-12-11 09:58:45 GMT. NextScheduledTime of policyId 11 is
2013-12-11 10:31:00 GMT
2013-12-11 15:28:57,081 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (main:null)
Current time is 2013-12-11 09:58:45 GMT. NextScheduledTime of policyId 12 is
2013-12-11 10:31:00 GMT
2013-12-11 15:28:57,095 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (main:null)
Current time is 2013-12-11 09:58:45 GMT. NextScheduledTime of policyId 13 is
2013-12-11 10:31:00 GMT
2013-12-11 15:28:57,107 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (main:null)
Current time is 2013-12-11 09:58:45 GMT. NextScheduledTime of policyId 14 is
2013-12-11 10:31:00 GMT
2013-12-11 15:28:57,120 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (main:null)
Current time is 2013-12-11 09:58:45 GMT. NextScheduledTime of policyId 15 is
2013-12-11 10:31:00 GMT
Log snippet indicating that the MS started without issues:
2013-12-11 15:28:58,316 INFO [c.c.c.ClusterManagerImpl]
(Cluster-Heartbeat-1:ctx-e7227e69) We are good, no orphan management server
msid in host table is found
2013-12-11 15:28:58,316 INFO [c.c.c.ClusterManagerImpl]
(Cluster-Heartbeat-1:ctx-e7227e69) No inactive management server node found
2013-12-11 15:28:58,320 DEBUG [c.c.c.ClusterManagerImpl]
(Cluster-Heartbeat-1:ctx-e7227e69) Detected management node joined, id:1,
nodeIP:127.0.0.1
2013-12-11 15:28:59,809 DEBUG [c.c.c.ClusterManagerImpl]
(Cluster-Notification-1:ctx-1b333c06) Notify management server node join to
listeners.
2013-12-11 15:28:59,811 DEBUG [c.c.c.ClusterManagerImpl]
(Cluster-Notification-1:ctx-1b333c06) Joining node, IP: 127.0.0.1, msid: 1
2013-12-11 15:28:59,812 DEBUG [c.c.a.ClusterAlertAdapter]
(Cluster-Notification-1:ctx-1b333c06) Receive cluster alert, EventArgs:
com.cloud.cluster.ClusterNodeJoinEventArgs
2013-12-11 15:28:59,813 DEBUG [c.c.a.ClusterAlertAdapter]
(Cluster-Notification-1:ctx-1b333c06) Handle cluster node join alert, joined
node: 127.0.0.1, msidL: 1
2013-12-11 15:28:59,813 DEBUG [c.c.a.ClusterAlertAdapter]
(Cluster-Notification-1:ctx-1b333c06) Management server node 127.0.0.1 is up,
send alert
> Management server not able start when there ~15 snapshot policies.
> ------------------------------------------------------------------
>
> Key: CLOUDSTACK-5385
> URL: https://issues.apache.org/jira/browse/CLOUDSTACK-5385
> Project: CloudStack
> Issue Type: Bug
> Security Level: Public(Anyone can view this level - this is the
> default.)
> Components: Management Server
> Affects Versions: 4.3.0
> Environment: Build from 4.3
> Reporter: Sangeetha Hariharan
> Assignee: Koushik Das
> Priority: Critical
> Fix For: 4.3.0
>
> Attachments: 1205logs.rar, test.rar
>
>
> Management server not able start when there ~15 snapshot policies.
> Management server was up and running fine.
> I had snapshot policies configured for 15 ROOT volumes.
> Stopped and started the management server.
> Management server does not start up successfully.
> Following is what I see in management serve logs:
> It is stuck after this:
> 2013-12-04 20:35:24,132 INFO [c.c.c.ClusterManagerImpl] (main:null)
> Management server 112516401760401 is being started
> 2013-12-04 20:35:24,138 INFO [c.c.c.ClusterManagerImpl] (main:null)
> Management server (host id : 1) is being started at 10.223.49.5:9090
> 2013-12-04 20:35:24,152 INFO [c.c.c.ClusterManagerImpl] (main:null) Cluster
> manager was started successfully
> 2013-12-04 20:35:24,153 INFO [c.c.s.s.SecondaryStorageManagerImpl]
> (main:null) Start secondary storage vm manager
> 2013-12-04 20:35:24,159 INFO [c.c.h.HighAvailabilityManagerImpl]
> (HA-Worker-0:null) Starting work
> 2013-12-04 20:35:24,162 INFO [c.c.h.HighAvailabilityManagerImpl]
> (HA-Worker-1:null) Starting work
> 2013-12-04 20:35:24,165 INFO [c.c.h.HighAvailabilityManagerImpl]
> (HA-Worker-4:null) Starting work
> 2013-12-04 20:35:24,162 INFO [c.c.h.HighAvailabilityManagerImpl]
> (HA-Worker-3:null) Starting work
> 2013-12-04 20:35:24,162 INFO [c.c.h.HighAvailabilityManagerImpl]
> (HA-Worker-2:null) Starting work
> 2013-12-04 20:35:24,236 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (main:null)
> Current time is 2013-12-05 01:35:03 GMT. NextScheduledTime of policyId 1 is
> 2013-12-05 01:40:00 GMT
> 2013-12-04 20:35:24,297 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (main:null)
> Current time is 2013-12-05 01:35:03 GMT. NextScheduledTime of policyId 2 is
> 2013-12-05 01:40:00 GMT
> 2013-12-04 20:35:24,314 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (main:null)
> Current time is 2013-12-05 01:35:03 GMT. NextScheduledTime of policyId 3 is
> 2013-12-05 01:40:00 GMT
> 2013-12-04 20:35:24,334 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (main:null)
> Current time is 2013-12-05 01:35:03 GMT. NextScheduledTime of policyId 4 is
> 2013-12-05 01:40:00 GMT
> 2013-12-04 20:35:24,354 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (main:null)
> Current time is 2013-12-05 01:35:03 GMT. NextScheduledTime of policyId 5 is
> 2013-12-05 01:40:00 GMT
> 2013-12-04 20:35:24,379 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (main:null)
> Current time is 2013-12-05 01:35:03 GMT. NextScheduledTime of policyId 6 is
> 2013-12-05 01:40:00 GMT
> 2013-12-04 20:35:24,434 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (main:null)
> Current time is 2013-12-05 01:35:03 GMT. NextScheduledTime of policyId 7 is
> 2013-12-05 01:40:00 GMT
> 2013-12-04 20:35:24,454 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (main:null)
> Current time is 2013-12-05 01:35:03 GMT. NextScheduledTime of policyId 8 is
> 2013-12-05 01:40:00 GMT
> 2013-12-04 20:35:24,472 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (main:null)
> Current time is 2013-12-05 01:35:03 GMT. NextScheduledTime of policyId 9 is
> 2013-12-05 01:40:00 GMT
> 2013-12-04 20:35:24,493 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (main:null)
> Current time is 2013-12-05 01:35:03 GMT. NextScheduledTime of policyId 10 is
> 2013-12-05 01:40:00 GMT
> 2013-12-04 20:35:24,510 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (main:null)
> Current time is 2013-12-05 01:35:03 GMT. NextScheduledTime of policyId 11 is
> 2013-12-05 01:40:00 GMT
> 2013-12-04 20:35:24,526 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (main:null)
> Current time is 2013-12-05 01:35:03 GMT. NextScheduledTime of policyId 13 is
> 2013-12-05 01:40:00 GMT
> 2013-12-04 20:35:24,543 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (main:null)
> Current time is 2013-12-05 01:35:03 GMT. NextScheduledTime of policyId 14 is
> 2013-12-05 01:40:00 GMT
> 2013-12-04 20:35:24,565 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (main:null)
> Current time is 2013-12-05 01:35:03 GMT. NextScheduledTime of policyId 15 is
> 2013-12-05 01:40:00 GMT
> 2013-12-04 20:35:37,364 INFO [c.c.u.c.ComponentContext] (main:null)
> Configuring
> com.cloud.bridge.persist.dao.OfferingDaoImpl_EnhancerByCloudStack_e5b26cda
> 2013-12-04 20:35:37,384 INFO [c.c.u.c.ComponentContext] (main:null)
> Configuring
> com.cloud.bridge.persist.dao.CloudStackAccountDaoImpl_EnhancerByCloudStack_50a7fd80
> 2013-12-04 20:35:37,387 INFO [c.c.u.c.ComponentContext] (main:null)
> Configuring
> com.cloud.bridge.persist.dao.SMetaDaoImpl_EnhancerByCloudStack_2595cd2
> 2013-12-04 20:35:37,388 INFO [c.c.u.c.ComponentContext] (main:null)
> Configuring
> com.cloud.bridge.persist.dao.UserCredentialsDaoImpl_EnhancerByCloudStack_a35b27f1
> 2013-12-04 20:35:37,389 INFO [c.c.u.c.ComponentContext] (main:null)
> Configuring
> com.cloud.bridge.persist.dao.MultipartMetaDaoImpl_EnhancerByCloudStack_e9c1df91
> 2013-12-04 20:35:37,389 INFO [c.c.u.c.ComponentContext] (main:null)
> Configuring
> com.cloud.bridge.persist.dao.CloudStackConfigurationDaoImpl_EnhancerByCloudStack_118d6faf
> 2013-12-04 20:35:37,390 INFO [c.c.u.c.ComponentContext] (main:null)
> Configuring
> com.cloud.bridge.persist.dao.BucketPolicyDaoImpl_EnhancerByCloudStack_6927d974
> 2013-12-04 20:35:37,391 INFO [c.c.u.c.ComponentContext] (main:null)
> Configuring
> com.cloud.bridge.persist.dao.SObjectItemDaoImpl_EnhancerByCloudStack_4d3a913d
> 2013-12-04 20:35:37,392 INFO [c.c.u.c.ComponentContext] (main:null)
> Configuring
> com.cloud.bridge.persist.dao.MHostMountDaoImpl_EnhancerByCloudStack_a23dc54c
> 2013-12-04 20:35:37,392 INFO [c.c.u.c.ComponentContext] (main:null)
> Configuring
> com.cloud.bridge.persist.dao.MHostDaoImpl_EnhancerByCloudStack_1425e78d
> 2013-12-04 20:35:37,395 INFO [c.c.u.c.ComponentContext] (main:null)
> Configuring
> com.cloud.bridge.persist.dao.MultiPartUploadsDaoImpl_EnhancerByCloudStack_cf9a8cba
> 2013-12-04 20:35:37,396 INFO [c.c.u.c.ComponentContext] (main:null)
> Configuring
> Following error seen in catalina.out:
> WARNING: No transportReceiver for
> org.apache.axis2.transport.http.AxisServletListener found. An instance for
> HTTP will be configured automatically. Please update your axis2.xml file!
> Dec 04, 2013 8:35:49 PM
> org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor
> <init>
> INFO: JSR-330 'javax.inject.Inject' annotation found and supported for
> autowiring
> Dec 04, 2013 8:35:49 PM org.apache.coyote.http11.Http11NioProtocol start
> INFO: Starting Coyote HTTP/1.1 on http-7080
> Dec 04, 2013 8:35:49 PM org.apache.catalina.startup.Catalina start
> INFO: Server startup in 101830 ms
> Exception in thread "Timer-1" java.lang.NullPointerException
> at org.slf4j.impl.Log4jLoggerAdapter.info(Log4jLoggerAdapter.java:304)
> at
> org.apache.cloudstack.managed.context.ManagedContextRunnable.getContext(ManagedContextRunnable.java:66)
> at
> org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
> at
> org.apache.cloudstack.managed.context.ManagedContextTimerTask.run(ManagedContextTimerTask.java:27)
> at java.util.TimerThread.mainLoop(Timer.java:555)
> at java.util.TimerThread.run(Timer.java:505)
> Exception in thread "HA-Worker-0" java.lang.NullPointerException
> at
> org.slf4j.impl.Log4jLoggerAdapter.error(Log4jLoggerAdapter.java:538)
> at
> org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:117)
> at
> org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
> at
> com.cloud.ha.HighAvailabilityManagerImpl$WorkerThread.run(HighAvailabilityManagerImpl.java:806)
> Exception in thread "HA-Worker-1" java.lang.NullPointerException
> at
> org.slf4j.impl.Log4jLoggerAdapter.error(Log4jLoggerAdapter.java:538)
> at
> org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:117)
> at
> org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
> at
> com.cloud.ha.HighAvailabilityManagerImpl$WorkerThread.run(HighAvailabilityManagerImpl.java:806)
> Exception in thread "HA-Worker-3" java.lang.NullPointerException
> at
> org.slf4j.impl.Log4jLoggerAdapter.error(Log4jLoggerAdapter.java:538)
> at
> org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:117)
> at
> org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
> at
> com.cloud.ha.HighAvailabilityManagerImpl$WorkerThread.run(HighAvailabilityManagerImpl.java:806)
> Exception in thread "HA-Worker-2" java.lang.NullPointerException
> at
> org.slf4j.impl.Log4jLoggerAdapter.error(Log4jLoggerAdapter.java:538)
> at
> org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:117)
> at
> org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
> at
> com.cloud.ha.HighAvailabilityManagerImpl$WorkerThread.run(HighAvailabilityManagerImpl.java:806)
> Exception in thread "HA-Worker-4" java.lang.NullPointerException
> at
> org.slf4j.impl.Log4jLoggerAdapter.error(Log4jLoggerAdapter.java:538)
> at
> org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:117)
> at
> org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
> at
> com.cloud.ha.HighAvailabilityManagerImpl$WorkerThread.run(HighAvailabilityManagerImpl.java:806)
> com.cloud.bridge.persist.dao.SBucketDaoImpl_EnhancerByCloudStack_a0d6c985
> 2013-12-04 20:35:37,396 INFO [c.c.u.c.ComponentContext] (main:null)
> Configuring
> com.cloud.bridge.persist.dao.SAclDaoImpl_EnhancerByCloudStack_13c5a201
> 2013-12-04 20:35:37,397 INFO [c.c.u.c.ComponentContext] (main:null)
> Configuring
> com.cloud.bridge.persist.dao.MultiPartPartsDaoImpl_EnhancerByCloudStack_9b94b73c
> 2013-12-04 20:35:37,398 INFO [c.c.u.c.ComponentContext] (main:null)
> Configuring
> com.cloud.bridge.persist.dao.CloudStackSvcOfferingDaoImpl_EnhancerByCloudStack_9aeaa39f
> 2013-12-04 20:35:37,398 INFO [c.c.u.c.ComponentContext] (main:null)
> Configuring
> com.cloud.bridge.persist.dao.SHostDaoImpl_EnhancerByCloudStack_3cb85dd7
> 2013-12-04 20:35:37,399 INFO [c.c.u.c.ComponentContext] (main:null)
> Configuring
> com.cloud.bridge.persist.dao.CloudStackUserDaoImpl_EnhancerByCloudStack_1ee15322
> 2013-12-04 20:35:37,403 INFO [c.c.u.c.ComponentContext] (main:null)
> Configuring
> com.cloud.bridge.persist.dao.SObjectDaoImpl_EnhancerByCloudStack_2392cdc8
> 2013-12-04 20:35:37,404 INFO [c.c.u.c.ComponentContext] (main:null)
> Configuring
> com.cloud.bridge.service.core.ec2.EC2Engine_EnhancerByCloudStack_761fb278
> 2013-12-04 20:35:37,552 INFO [c.c.u.c.ComponentContext] (main:null)
> Configuring
> com.cloud.bridge.service.controller.s3.ServiceProvider_EnhancerByCloudStack_a1504ced
> Note - I was able to get around this issue by deleting all the snapshot
> policies.
> After deleting all the snapshot policies , i am able to start the management
> server successfully.
--
This message was sent by Atlassian JIRA
(v6.1.4#6159)
