You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@cloudstack.apache.org by Martin Emrich <ma...@empolis.com> on 2014/08/28 18:19:18 UTC

Stale datastores in database?

Hi!

I had to remove a XenServer host (the only one) from Cloudstack, removed it via GUI, worked well.

Now I added the replacement machine, and tried to fire up an instance. But I got the message "Unable to locate datastore with id 1".
In the database, the storage_pool table contained two entries, the old id 1 and the current id 2.
I removed the host (and then replaced the EXT storage with a LVM storage because I misconfigured it), and added it again. Now I have three entries in the database, and creating an instance still fails.

The database now looks like this:

mysql> select * from storage_pool;
+----+-----------------------------+--------------------------------------+-----------+------+----------------+--------+------------+------------+----------------+--------------+-----------+------+---------------------+---------------------+-------------+-------------+-----------------------+-------+------------+---------+---------------+
| id | name                        | uuid                                 | pool_type | port | data_center_id | pod_id | cluster_id | used_bytes | capacity_bytes | host_address | user_info | path | created             | removed             | update_time | status      | storage_provider_name | scope | hypervisor | managed | capacity_iops |
+----+-----------------------------+--------------------------------------+-----------+------+----------------+--------+------------+------------+----------------+--------------+-----------+------+---------------------+---------------------+-------------+-------------+-----------------------+-------+------------+---------+---------------+
|  1 | esc-compute01 Local Storage | NULL                                 | LVM       |    0 |              1 |      1 |       NULL |    4194304 |  1190452527104 | 10.8.0.65    | NULL      | lvm  | 2014-08-08 14:37:25 | 2014-08-18 08:33:43 | NULL        | Maintenance | DefaultPrimary        | HOST  | NULL       |       0 |          NULL |
|  2 | esc-compute01 Local Storage | NULL                                 | EXT       |    0 |              1 |      1 |       NULL | 6161043456 |  1171772600320 | 10.8.0.66    | NULL      | ext  | 2014-08-27 15:53:58 | 2014-08-28 15:50:41 | NULL        | Maintenance | DefaultPrimary        | HOST  | NULL       |       0 |          NULL |
|  3 | esc-compute01 Local Storage | c38b4fa3-4bd4-05a3-4a11-e5e0f15fb9f5 | LVM       |    0 |              1 |      1 |          1 |    4194304 |  1190452527104 | 10.8.0.66    | NULL      | lvm  | 2014-08-28 15:52:14 | NULL                | NULL        | Up          | DefaultPrimary        | HOST  | NULL       |       0 |          NULL |
+----+-----------------------------+--------------------------------------+-----------+------+----------------+--------+------------+------------+----------------+--------------+-----------+------+---------------------+---------------------+-------------+-------------+-----------------------+-------+------------+---------+---------------+
3 rows in set (0.00 sec)

In the GUI, I can only see one Primary Storage (the current "real" one, obviously ID 3).

How can I fix my Cloudstack? As there are no instances yet, I could reinstall, but I'd like to understand what's going on...

Thanks

Martin Emrich

AW: Stale datastores in database?

Posted by Martin Emrich <ma...@empolis.com>.
Hi!

Sorry, it is Cloudstack 4.4.0.

Here's a piece of the log file:

2014-08-29 09:06:15,853 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-d40f3eb8) Found 0 routers to update status.
2014-08-29 09:06:15,855 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-d40f3eb8) Found 0 networks to update RvR status.
2014-08-29 09:06:20,894 DEBUG [o.a.c.f.j.d.VmWorkJobDaoImpl] (Vm-Operations-Cleanup-1:ctx-53d42538) Expunge completed work job-4952
2014-08-29 09:06:20,897 DEBUG [o.a.c.f.j.d.VmWorkJobDaoImpl] (Vm-Operations-Cleanup-1:ctx-53d42538) Expunge completed work job-4953
2014-08-29 09:06:25,120 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-cc3c8ca6) Resetting hosts suitable for reconnect
2014-08-29 09:06:25,121 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-cc3c8ca6) Completed resetting hosts suitable for reconnect
2014-08-29 09:06:25,121 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-cc3c8ca6) Acquiring hosts for clusters already owned by this management server
2014-08-29 09:06:25,123 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-cc3c8ca6) Completed acquiring hosts for clusters already owned by this management server
2014-08-29 09:06:25,123 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-cc3c8ca6) Acquiring hosts for clusters not owned by any management server
2014-08-29 09:06:25,124 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-cc3c8ca6) Completed acquiring hosts for clusters not owned by any management server
2014-08-29 09:06:31,644 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-c9fb6895) StorageCollector is running...
2014-08-29 09:06:31,703 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-c9fb6895) Seq 11-6232137459350635412: Received:  { Ans: , MgmtId: 220037193816942, via: 11, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }
2014-08-29 09:06:31,707 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-210:ctx-6e881c4a) Seq 10-5576019288638097197: Executing request
2014-08-29 09:06:31,893 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-210:ctx-6e881c4a) Seq 10-5576019288638097197: Response Received:
2014-08-29 09:06:31,893 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-c9fb6895) Seq 10-5576019288638097197: Received:  { Ans: , MgmtId: 220037193816942, via: 10, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }
2014-08-29 09:06:32,444 DEBUG [c.c.s.StatsCollector] (StatsCollector-4:ctx-1099b9be) AutoScaling Monitor is running...
2014-08-29 09:06:32,750 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-1:null) Ping from 11
2014-08-29 09:06:33,603 DEBUG [c.c.c.ConsoleProxyManagerImpl] (consoleproxy-1:ctx-fc6cda67) Zone 1 is ready to launch console proxy
2014-08-29 09:06:33,604 DEBUG [c.c.c.ConsoleProxyManagerImpl] (consoleproxy-1:ctx-fc6cda67) Expand console proxy standby capacity for zone ESC-KL
2014-08-29 09:06:33,607 INFO  [c.c.c.ConsoleProxyManagerImpl] (consoleproxy-1:ctx-fc6cda67) Found a stopped console proxy, bring it up to running pool. proxy vm id : 36
2014-08-29 09:06:33,615 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] (secstorage-1:ctx-6d3000ae) Zone 1 is ready to launch secondary storage VM
2014-08-29 09:06:33,619 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (consoleproxy-1:ctx-fc6cda67) Sync job-4954 execution on object VmWorkJobQueue.36
2014-08-29 09:06:33,622 WARN  [c.c.u.d.Merovingian2] (consoleproxy-1:ctx-fc6cda67) Was unable to find lock for the key vm_instance36 and thread id 974875322
2014-08-29 09:06:33,852 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-35c0dfca) Execute sync-queue item: SyncQueueItemVO {id:4837, queueId: 2963, contentType: AsyncJob, contentId: 4954, lastProcessMsid: null, lastprocessNumber: null, lastProcessTime: null, created: Fri Aug 29 09:06:33 CEST 2014}
2014-08-29 09:06:33,854 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-35c0dfca) Schedule queued job-4954
2014-08-29 09:06:33,857 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-48:ctx-ffc7a4fc job-3068/job-4954) Add job-4954 into job monitoring
2014-08-29 09:06:33,857 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-48:ctx-ffc7a4fc job-3068/job-4954) Executing AsyncJobVO {id:4954, userId: 1, accountId: 1, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStart, cmdInfo: rO0ABXNyABhjb20uY2xvdWQudm0uVm1Xb3JrU3RhcnR9cMGsvxz73gIAC0oABGRjSWRMAAZhdm9pZHN0ADBMY29tL2Nsb3VkL2RlcGxveS9EZXBsb3ltZW50UGxhbm5lciRFeGNsdWRlTGlzdDtMAAljbHVzdGVySWR0ABBMamF2YS9sYW5nL0xvbmc7TAAGaG9zdElkcQB-AAJMAAtqb3VybmFsTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO0wAEXBoeXNpY2FsTmV0d29ya0lkcQB-AAJMAAdwbGFubmVycQB-AANMAAVwb2RJZHEAfgACTAAGcG9vbElkcQB-AAJMAAlyYXdQYXJhbXN0AA9MamF2YS91dGlsL01hcDtMAA1yZXNlcnZhdGlvbklkcQB-AAN4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1lcQB-AAN4cAAAAAAAAAABAAAAAAAAAAEAAAAAAAAAJHQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwAAAAAAAAAAHBwcHBwcHBwcHA, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 220037193816942, completeMsid: null, lastUpdated: null, lastPolled: null, created: Fri Aug 29 09:06:33 CEST 2014}
2014-08-29 09:06:33,858 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-48:ctx-ffc7a4fc job-3068/job-4954) Run VM work job: com.cloud.vm.VmWorkStart for VM 36, job origin: 3068
2014-08-29 09:06:33,859 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-48:ctx-ffc7a4fc job-3068/job-4954 ctx-264696c1) Execute VM work job: com.cloud.vm.VmWorkStart{"dcId":0,"userId":1,"accountId":1,"vmId":36,"handlerName":"VirtualMachineManagerImpl"}
2014-08-29 09:06:33,869 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-48:ctx-ffc7a4fc job-3068/job-4954 ctx-264696c1) VM state transitted from :Stopped to Starting with event: StartRequestedvm's original host id: 7 new host id: null host id before state transition: null
2014-08-29 09:06:33,869 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-48:ctx-ffc7a4fc job-3068/job-4954 ctx-264696c1) Successfully transitioned to start state for VM[ConsoleProxy|v-36-VM] reservation id = a9e64eeb-564a-46c6-87fd-4b7804e77fd5
2014-08-29 09:06:33,871 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-48:ctx-ffc7a4fc job-3068/job-4954 ctx-264696c1) Trying to deploy VM, vm has dcId: 1 and podId: 1
2014-08-29 09:06:33,871 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-48:ctx-ffc7a4fc job-3068/job-4954 ctx-264696c1) Deploy avoids pods: null, clusters: null, hosts: null
2014-08-29 09:06:33,880 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-48:ctx-ffc7a4fc job-3068/job-4954 ctx-264696c1) VM state transitted from :Starting to Stopped with event: OperationFailedvm's original host id: 7 new host id: null host id before state transition: null
2014-08-29 09:06:33,881 ERROR [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-48:ctx-ffc7a4fc job-3068/job-4954 ctx-264696c1) Invocation exception, caused by: com.cloud.utils.exception.CloudRuntimeException: Unable to locate datastore with id 2
2014-08-29 09:06:33,882 INFO  [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-48:ctx-ffc7a4fc job-3068/job-4954 ctx-264696c1) Rethrow exception com.cloud.utils.exception.CloudRuntimeException: Unable to locate datastore with id 2
2014-08-29 09:06:33,883 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-48:ctx-ffc7a4fc job-3068/job-4954) Done with run of VM work job: com.cloud.vm.VmWorkStart for VM 36, job origin: 3068
2014-08-29 09:06:33,883 ERROR [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-48:ctx-ffc7a4fc job-3068/job-4954) Unable to complete AsyncJobVO {id:4954, userId: 1, accountId: 1, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStart, cmdInfo: rO0ABXNyABhjb20uY2xvdWQudm0uVm1Xb3JrU3RhcnR9cMGsvxz73gIAC0oABGRjSWRMAAZhdm9pZHN0ADBMY29tL2Nsb3VkL2RlcGxveS9EZXBsb3ltZW50UGxhbm5lciRFeGNsdWRlTGlzdDtMAAljbHVzdGVySWR0ABBMamF2YS9sYW5nL0xvbmc7TAAGaG9zdElkcQB-AAJMAAtqb3VybmFsTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO0wAEXBoeXNpY2FsTmV0d29ya0lkcQB-AAJMAAdwbGFubmVycQB-AANMAAVwb2RJZHEAfgACTAAGcG9vbElkcQB-AAJMAAlyYXdQYXJhbXN0AA9MamF2YS91dGlsL01hcDtMAA1yZXNlcnZhdGlvbklkcQB-AAN4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1lcQB-AAN4cAAAAAAAAAABAAAAAAAAAAEAAAAAAAAAJHQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwAAAAAAAAAAHBwcHBwcHBwcHA, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 220037193816942, completeMsid: null, lastUpdated: null, lastPolled: null, created: Fri Aug 29 09:06:33 CEST 2014}, job origin:3068
com.cloud.utils.exception.CloudRuntimeException: Unable to locate datastore with id 2
        at org.apache.cloudstack.storage.datastore.manager.PrimaryDataStoreProviderManagerImpl.getPrimaryDataStore(PrimaryDataStoreProviderManagerImpl.java:61)
        at org.apache.cloudstack.storage.datastore.DataStoreManagerImpl.getPrimaryDataStore(DataStoreManagerImpl.java:96)
        at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:889)
        at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5190)
        at sun.reflect.GeneratedMethodAccessor254.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:606)
        at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
        at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5335)
        at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
        at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:503)
        at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
        at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
        at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:460)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
        at java.util.concurrent.FutureTask.run(FutureTask.java:262)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:745)
2014-08-29 09:06:33,885 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-48:ctx-ffc7a4fc job-3068/job-4954) Complete async job-4954, jobStatus: FAILED, resultCode: 0, result: rO0ABXNyABpqYXZhLmxhbmcuUnVudGltZUV4Y2VwdGlvbp5fBkcKNIPlAgAAeHIAE2phdmEubGFuZy5FeGNlcHRpb27Q_R8-GjscxAIAAHhyABNqYXZhLmxhbmcuVGhyb3dhYmxl1cY1Jzl3uMsDAARMAAVjYXVzZXQAFUxqYXZhL2xhbmcvVGhyb3dhYmxlO0wADWRldGFpbE1lc3NhZ2V0ABJMamF2YS9sYW5nL1N0cmluZztbAApzdGFja1RyYWNldAAeW0xqYXZhL2xhbmcvU3RhY2tUcmFjZUVsZW1lbnQ7TAAUc3VwcHJlc3NlZEV4Y2VwdGlvbnN0ABBMamF2YS91dGlsL0xpc3Q7eHBxAH4AB3QAQEpvYiBmYWlsZWQgZHVlIHRvIGV4Y2VwdGlvbiBVbmFibGUgdG8gbG9jYXRlIGRhdGFzdG9yZSB3aXRoIGlkIDJ1cgAeW0xqYXZhLmxhbmcuU3RhY2tUcmFjZUVsZW1lbnQ7AkYqPDz9IjkCAAB4cAAAAA1zcgAbamF2YS5sYW5nLlN0YWNrVHJhY2VFbGVtZW50YQnFmiY23YUCAARJAApsaW5lTnVtYmVyTAAOZGVjbGFyaW5nQ2xhc3NxAH4ABEwACGZpbGVOYW1lcQB-AARMAAptZXRob2ROYW1lcQB-AAR4cAAAAHJ0ACBjb20uY2xvdWQudm0uVm1Xb3JrSm9iRGlzcGF0Y2hlcnQAGFZtV29ya0pvYkRpc3BhdGNoZXIuamF2YXQABnJ1bkpvYnNxAH4ACwAAAfd0AD9vcmcuYXBhY2hlLmNsb3Vkc3RhY2suZnJhbWV3b3JrLmpvYnMuaW1wbC5Bc3luY0pvYk1hbmFnZXJJbXBsJDV0ABhBc3luY0pvYk1hbmFnZXJJbXBsLmphdmF0AAxydW5JbkNvbnRleHRzcQB-AAsAAAAxdAA-b3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5NYW5hZ2VkQ29udGV4dFJ1bm5hYmxlJDF0ABtNYW5hZ2VkQ29udGV4dFJ1bm5hYmxlLmphdmF0AANydW5zcQB-AAsAAAA4dABCb3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5pbXBsLkRlZmF1bHRNYW5hZ2VkQ29udGV4dCQxdAAaRGVmYXVsdE1hbmFnZWRDb250ZXh0LmphdmF0AARjYWxsc3EAfgALAAAAZ3QAQG9yZy5hcGFjaGUuY2xvdWRzdGFjay5tYW5hZ2VkLmNvbnRleHQuaW1wbC5EZWZhdWx0TWFuYWdlZENvbnRleHRxAH4AGnQAD2NhbGxXaXRoQ29udGV4dHNxAH4ACwAAADVxAH4AHXEAfgAadAAOcnVuV2l0aENvbnRleHRzcQB-AAsAAAAudAA8b3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5NYW5hZ2VkQ29udGV4dFJ1bm5hYmxlcQB-ABZxAH4AF3NxAH4ACwAAAcxxAH4AEXEAfgAScQB-ABdzcQB-AAsAAAHXdAAuamF2YS51dGlsLmNvbmN1cnJlbnQuRXhlY3V0b3JzJFJ1bm5hYmxlQWRhcHRlcnQADkV4ZWN1dG9ycy5qYXZhcQB-ABtzcQB-AAsAAAEGdAAfamF2YS51dGlsLmNvbmN1cnJlbnQuRnV0dXJlVGFza3QAD0Z1dHVyZVRhc2suamF2YXEAfgAXc3EAfgALAAAEeXQAJ2phdmEudXRpbC5jb25jdXJyZW50LlRocmVhZFBvb2xFeGVjdXRvcnQAF1RocmVhZFBvb2xFeGVjdXRvci5qYXZhdAAJcnVuV29ya2Vyc3EAfgALAAACZ3QALmphdmEudXRpbC5jb25jdXJyZW50LlRocmVhZFBvb2xFeGVjdXRvciRXb3JrZXJxAH4ALHEAfgAXc3EAfgALAAAC6XQAEGphdmEubGFuZy5UaHJlYWR0AAtUaHJlYWQuamF2YXEAfgAXc3IAJmphdmEudXRpbC5Db2xsZWN0aW9ucyRVbm1vZGlmaWFibGVMaXN0_A8lMbXsjhACAAFMAARsaXN0cQB-AAZ4cgAsamF2YS51dGlsLkNvbGxlY3Rpb25zJFVubW9kaWZpYWJsZUNvbGxlY3Rpb24ZQgCAy173HgIAAUwAAWN0ABZMamF2YS91dGlsL0NvbGxlY3Rpb247eHBzcgATamF2YS51dGlsLkFycmF5TGlzdHiB0h2Zx2GdAwABSQAEc2l6ZXhwAAAAAHcEAAAAAHhxAH4AOHg
2014-08-29 09:06:33,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-48:ctx-ffc7a4fc job-3068/job-4954) Done executing com.cloud.vm.VmWorkStart for job-4954
2014-08-29 09:06:33,899 DEBUG [o.a.c.f.j.i.SyncQueueManagerImpl] (Work-Job-Executor-48:ctx-ffc7a4fc job-3068/job-4954) Sync queue (2963) is currently empty
2014-08-29 09:06:33,900 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-48:ctx-ffc7a4fc job-3068/job-4954) Remove job-4954 from job monitoring
2014-08-29 09:06:33,900 WARN  [c.c.v.SystemVmLoadScanner] (consoleproxy-1:ctx-fc6cda67) Unexpected exception Job failed due to exception Unable to locate datastore with id 2
java.lang.RuntimeException: Job failed due to exception Unable to locate datastore with id 2
        at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:114)
        at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:503)
        at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
        at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
        at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:460)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
        at java.util.concurrent.FutureTask.run(FutureTask.java:262)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:745)
2014-08-29 09:06:34,758 DEBUG [c.c.s.StatsCollector] (StatsCollector-2:ctx-c95015af) VmStatsCollector is running...
2014-08-29 09:06:45,854 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-b3f7ebe7) Found 0 routers to update status.
2014-08-29 09:06:45,855 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-b3f7ebe7) Found 0 networks to update RvR status.
2014-08-29 09:07:00,823 DEBUG [c.c.s.StatsCollector] (StatsCollector-1:ctx-1485562a) HostStatsCollector is running...
2014-08-29 09:07:00,833 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-359:ctx-65752694) Seq 10-5576019288638097198: Executing request
2014-08-29 09:07:00,852 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-359:ctx-65752694) Seq 10-5576019288638097198: Response Received:
2014-08-29 09:07:00,852 DEBUG [c.c.a.t.Request] (StatsCollector-1:ctx-1485562a) Seq 10-5576019288638097198: Received:  { Ans: , MgmtId: 220037193816942, via: 10, Ver: v1, Flags: 10, { GetHostStatsAnswer } }


I did not do anything, apparently there are some regular jobs running that also try to access the wrong datastore.

Ciao

Martin

-----Ursprüngliche Nachricht-----
Von: Kirk Kosinski [mailto:kirkkosinski@gmail.com] 
Gesendet: Donnerstag, 28. August 2014 20:30
An: users@cloudstack.apache.org
Betreff: Re: Stale datastores in database?

Hi, what CS version is this, and can you upload more of the log?  It seems likely to be a bug since the storage with removed != NULL in the database should be ignored.

Best regards,
Kirk
 

Re: Stale datastores in database?

Posted by Kirk Kosinski <ki...@gmail.com>.
Hi, what CS version is this, and can you upload more of the log?  It
seems likely to be a bug since the storage with removed != NULL in the
database should be ignored.

Best regards,
Kirk

On 08/28/2014 09:19 AM, Martin Emrich wrote:
> Hi!
> 
> I had to remove a XenServer host (the only one) from Cloudstack, removed it via GUI, worked well.
> 
> Now I added the replacement machine, and tried to fire up an instance. But I got the message "Unable to locate datastore with id 1".
> In the database, the storage_pool table contained two entries, the old id 1 and the current id 2.
> I removed the host (and then replaced the EXT storage with a LVM storage because I misconfigured it), and added it again. Now I have three entries in the database, and creating an instance still fails.
> 
> The database now looks like this:
> 
> mysql> select * from storage_pool;
> +----+-----------------------------+--------------------------------------+-----------+------+----------------+--------+------------+------------+----------------+--------------+-----------+------+---------------------+---------------------+-------------+-------------+-----------------------+-------+------------+---------+---------------+
> | id | name                        | uuid                                 | pool_type | port | data_center_id | pod_id | cluster_id | used_bytes | capacity_bytes | host_address | user_info | path | created             | removed             | update_time | status      | storage_provider_name | scope | hypervisor | managed | capacity_iops |
> +----+-----------------------------+--------------------------------------+-----------+------+----------------+--------+------------+------------+----------------+--------------+-----------+------+---------------------+---------------------+-------------+-------------+-----------------------+-------+------------+---------+---------------+
> |  1 | esc-compute01 Local Storage | NULL                                 | LVM       |    0 |              1 |      1 |       NULL |    4194304 |  1190452527104 | 10.8.0.65    | NULL      | lvm  | 2014-08-08 14:37:25 | 2014-08-18 08:33:43 | NULL        | Maintenance | DefaultPrimary        | HOST  | NULL       |       0 |          NULL |
> |  2 | esc-compute01 Local Storage | NULL                                 | EXT       |    0 |              1 |      1 |       NULL | 6161043456 |  1171772600320 | 10.8.0.66    | NULL      | ext  | 2014-08-27 15:53:58 | 2014-08-28 15:50:41 | NULL        | Maintenance | DefaultPrimary        | HOST  | NULL       |       0 |          NULL |
> |  3 | esc-compute01 Local Storage | c38b4fa3-4bd4-05a3-4a11-e5e0f15fb9f5 | LVM       |    0 |              1 |      1 |          1 |    4194304 |  1190452527104 | 10.8.0.66    | NULL      | lvm  | 2014-08-28 15:52:14 | NULL                | NULL        | Up          | DefaultPrimary        | HOST  | NULL       |       0 |          NULL |
> +----+-----------------------------+--------------------------------------+-----------+------+----------------+--------+------------+------------+----------------+--------------+-----------+------+---------------------+---------------------+-------------+-------------+-----------------------+-------+------------+---------+---------------+
> 3 rows in set (0.00 sec)
> 
> In the GUI, I can only see one Primary Storage (the current "real" one, obviously ID 3).
> 
> How can I fix my Cloudstack? As there are no instances yet, I could reinstall, but I'd like to understand what's going on...
> 
> Thanks
> 
> Martin Emrich
>