You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@cloudstack.apache.org by "Sangeetha Hariharan (JIRA)" <ji...@apache.org> on 2014/01/08 02:03:07 UTC

[jira] [Closed] (CLOUDSTACK-5385) Management server not able start when there ~15 snapshot policies.

     [ https://issues.apache.org/jira/browse/CLOUDSTACK-5385?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Sangeetha Hariharan closed CLOUDSTACK-5385.
-------------------------------------------


Tested with latest build from 4.3

I have 18 Hourly scheduled snapshots.

Tried to restart management server multiple times. I am not seeing this issue reported in the bug. Management server was able to schedule snapshots for all the 18 entries and also start successfully after this.
 

management server schedules snapshot entries :

2014-01-07 19:55:02,330 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (main:null) Current time is 2014-01-08 00:54:40 GMT. NextScheduledTime of policyId 1 is 20
14-01-08 01:55:00 GMT
2014-01-07 19:55:02,360 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (main:null) Current time is 2014-01-08 00:54:40 GMT. NextScheduledTime of policyId 2 is 20
14-01-08 01:55:00 GMT
2014-01-07 19:55:02,375 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (main:null) Current time is 2014-01-08 00:54:40 GMT. NextScheduledTime of policyId 3 is 20
14-01-08 01:55:00 GMT
2014-01-07 19:55:02,392 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (main:null) Current time is 2014-01-08 00:54:40 GMT. NextScheduledTime of policyId 4 is 20
14-01-08 01:55:00 GMT
2014-01-07 19:55:02,410 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (main:null) Current time is 2014-01-08 00:54:40 GMT. NextScheduledTime of policyId 5 is 20
14-01-08 01:55:00 GMT
2014-01-07 19:55:02,432 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (main:null) Current time is 2014-01-08 00:54:40 GMT. NextScheduledTime of policyId 6 is 20
14-01-08 01:55:00 GMT
2014-01-07 19:55:02,450 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (main:null) Current time is 2014-01-08 00:54:40 GMT. NextScheduledTime of policyId 7 is 20
14-01-08 01:55:00 GMT
2014-01-07 19:55:02,467 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (main:null) Current time is 2014-01-08 00:54:40 GMT. NextScheduledTime of policyId 8 is 20
14-01-08 01:55:00 GMT
2014-01-07 19:55:02,485 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (main:null) Current time is 2014-01-08 00:54:40 GMT. NextScheduledTime of policyId 9 is 20
14-01-08 01:55:00 GMT
2014-01-07 19:55:02,509 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (main:null) Current time is 2014-01-08 00:54:40 GMT. NextScheduledTime of policyId 10 is 2
014-01-08 01:55:00 GMT
2014-01-07 19:55:02,519 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (main:null) Current time is 2014-01-08 00:54:40 GMT. NextScheduledTime of policyId 11 is 2
014-01-08 01:55:00 GMT
2014-01-07 19:55:02,540 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (main:null) Current time is 2014-01-08 00:54:40 GMT. NextScheduledTime of policyId 12 is 2
014-01-08 01:55:00 GMT
2014-01-07 19:55:02,550 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (main:null) Current time is 2014-01-08 00:54:40 GMT. NextScheduledTime of policyId 13 is 2
014-01-08 01:55:00 GMT
2014-01-07 19:55:02,560 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (main:null) Current time is 2014-01-08 00:54:40 GMT. NextScheduledTime of policyId 14 is 2
014-01-08 01:55:00 GMT
2014-01-07 19:55:02,571 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (main:null) Current time is 2014-01-08 00:54:40 GMT. NextScheduledTime of policyId 15 is 2
014-01-08 01:55:00 GMT
2014-01-07 19:55:02,582 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (main:null) Current time is 2014-01-08 00:54:40 GMT. NextScheduledTime of policyId 16 is 2
014-01-08 01:55:00 GMT
2014-01-07 19:55:02,607 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (main:null) Current time is 2014-01-08 00:54:40 GMT. NextScheduledTime of policyId 17 is 2
014-01-08 01:55:00 GMT
2014-01-07 19:55:02,620 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (main:null) Current time is 2014-01-08 00:54:40 GMT. NextScheduledTime of policyId 18 is 2
014-01-08 01:55:00 GMT

management server starts successfully:

2014-01-07 19:55:03,749 DEBUG [c.c.u.d.ConnectionConcierge] (Cluster-Heartbeat-1:ctx-2472dc64) Registering a database connection for ClusterManagerHeartbeat2
2014-01-07 19:55:03,761 INFO  [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:ctx-2472dc64) We are good, no orphan management server msid in host table is found
2014-01-07 19:55:03,765 INFO  [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:ctx-2472dc64) No inactive management server node found
2014-01-07 19:55:03,772 DEBUG [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:ctx-2472dc64) Detected management node joined, id:1, nodeIP:10.223.49.5
2014-01-07 19:55:03,787 INFO  [o.a.c.s.l.CloudStackExtendedLifeCycle] (main:null) Configuring CloudStack Components
2014-01-07 19:55:03,787 INFO  [o.a.c.s.l.CloudStackExtendedLifeCycle] (main:null) Done Configuring CloudStack Components
2014


Closing this issue for now. If I see this issue surface again , I will provide the thread dumps as requested.

> 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.5#6160)