You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@cloudstack.apache.org by David Comerford <da...@gmail.com> on 2012/12/17 00:56:04 UTC
Damn time travel
Hey,
Due to some clocks being a few months forward for a while I'm stuck back in
the present with a number of VMs that just won't expunge.
Logs suggest there's some concurrent operations on said VM which I think
basically means theres some job that lives in the future which is blocking
the current ones.
My questions:
1) From the logs below, does my guess sound plausible?
2) Where in the database is the queue for jobs I need to take a hammer to?
Cheers guys,
Dave
2012-12-16 23:44:01,132 WARN [cloud.vm.UserVmManagerImpl]
(AccountChecker-1:null) Concurrent operations on expunging
VM[User|a1a470ef-368b-45fe-99c7-1b92ea333d78]
com.cloud.exception.ConcurrentOperationException: Failed to transit state
at
com.cloud.storage.StorageManagerImpl.destroyVolume(StorageManagerImpl.java:2060)
at
com.cloud.utils.db.DatabaseCallback.intercept(DatabaseCallback.java:30)
at
com.cloud.storage.StorageManagerImpl.cleanupVolumes(StorageManagerImpl.java:3486)
at
com.cloud.utils.db.DatabaseCallback.intercept(DatabaseCallback.java:30)
at
com.cloud.vm.VirtualMachineManagerImpl.advanceExpunge(VirtualMachineManagerImpl.java:391)
at
com.cloud.vm.UserVmManagerImpl.expunge(UserVmManagerImpl.java:1160)
at
com.cloud.user.AccountManagerImpl.cleanupAccount(AccountManagerImpl.java:518)
at
com.cloud.user.AccountManagerImpl$AccountCleanupTask.run(AccountManagerImpl.java:1291)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at
java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:351)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:165)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:267)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
at java.lang.Thread.run(Thread.java:679)
2012-12-16 23:44:01,132 ERROR [cloud.user.AccountManagerImpl]
(AccountChecker-1:null) Unable to expunge vm: 620
Re: Damn time travel
Posted by David Comerford <da...@gmail.com>.
I found what looks like the job queue and it has some future created jobs
in there.
Can they be safely deleted and/or have their date changed to the present?
mysql> select job_cmd,created,last_updated from cloud.async_job ;
+------------------------------------------+---------------------+---------------------+
| job_cmd | created |
last_updated |
+------------------------------------------+---------------------+---------------------+
| com.cloud.api.commands.DeployVMCmd | 2012-12-29 15:24:22 |
2012-12-29 15:26:09 |
| com.cloud.api.commands.DeployVMCmd | 2012-12-29 15:39:01 |
2012-12-29 15:39:27 |
| com.cloud.api.commands.DeployVMCmd | 2012-12-29 15:45:13 |
2012-12-29 15:46:23 |
| com.cloud.api.commands.CreateVolumeCmd | 2012-12-29 15:47:50 |
2012-12-29 15:47:50 |
| com.cloud.api.commands.AttachVolumeCmd | 2012-12-29 15:48:04 |
2012-12-29 15:48:05 |
| com.cloud.api.commands.AttachVolumeCmd | 2012-12-29 15:48:27 |
2012-12-29 15:48:27 |
| com.cloud.api.commands.AttachVolumeCmd | 2012-12-29 15:50:07 |
2012-12-29 15:50:07 |
| com.cloud.api.commands.AttachVolumeCmd | 2012-12-29 15:51:39 |
2012-12-29 15:51:40 |
| com.cloud.api.commands.CreateSnapshotCmd | 2012-12-29 15:52:46 |
2012-12-29 15:57:11 |
+------------------------------------------+---------------------+---------------------+
9 rows in set (0.00 sec)
Regards,
Dave
Re: Damn time travel
Posted by David Comerford <da...@gmail.com>.
Hey Kirk,
In answer to your question...
mysql> select * from vm_instance where id = 620 \G;
*************************** 1. row ***************************
id: 620
name: a1a470ef-368b-45fe-99c7-1b92eabd3d78
uuid: a1a470ef-368b-45fe-99c7-1b92eabd3d78
instance_name: i-75-620-VM
state: Expunging
vm_template_id: 329
guest_os_id: 54
private_mac_address: 02:00:36:f4:00:0a
private_ip_address: 10.10.4.252
pod_id: 1
data_center_id: 1
host_id: NULL
last_host_id: 3
proxy_id: NULL
proxy_assign_time: NULL
vnc_password: kDMRgyJht3Lvx1UKDUv9MIxPkmRt1GyZusCvl8DbnRw=
ha_enabled: 1
limit_cpu_use: 0
update_count: 25263
update_time: 2012-12-17 00:20:04
created: 2012-12-04 14:46:54
removed: NULL
type: User
vm_type: User
account_id: 75
domain_id: 53
service_offering_id: 31
reservation_id: NULL
hypervisor_type: XenServer
1 row in set (0.00 sec)
mysql> select * from volumes where instance_id = 620 \G;
*************************** 1. row ***************************
id: 654
account_id: 75
domain_id: 53
pool_id: 203
last_pool_id: NULL
instance_id: 620
device_id: 0
name: ROOT-620
uuid: 562b17fe-3d17-48e4-8690-1169dc137862
size: 64424509440
folder: /vol/primary4
path: ec060ab6-fdf6-4696-b8b3-75723a289c42
pod_id: 1
data_center_id: 1
iscsi_name: NULL
host_ip: NULL
volume_type: ROOT
pool_type: NetworkFilesystem
disk_offering_id: 31
template_id: 329
first_snapshot_backup_uuid: NULL
recreatable: 0
created: 2012-12-04 14:46:54
attached: NULL
updated: 2012-12-04 14:51:52
removed: NULL
state: Ready
chain_info: NULL
update_count: 3
1 row in set (0.00 sec)
On 17 December 2012 00:19, Kirk Kosinski <ki...@gmail.com> wrote:
> select * from vm_instance where id = 620;
Re: Damn time travel
Posted by Kirk Kosinski <ki...@gmail.com>.
Hi, Dave. What does the VM and it's volumes look like in the database?
select * from vm_instance where id = 620;
select * from volumes where instance_id = 620;
Best regards,
Kirk
On 12/16/2012 03:56 PM, David Comerford wrote:
> Hey,
>
> Due to some clocks being a few months forward for a while I'm stuck back in
> the present with a number of VMs that just won't expunge.
> Logs suggest there's some concurrent operations on said VM which I think
> basically means theres some job that lives in the future which is blocking
> the current ones.
>
> My questions:
> 1) From the logs below, does my guess sound plausible?
> 2) Where in the database is the queue for jobs I need to take a hammer to?
>
> Cheers guys,
> Dave
>
> 2012-12-16 23:44:01,132 WARN [cloud.vm.UserVmManagerImpl]
> (AccountChecker-1:null) Concurrent operations on expunging
> VM[User|a1a470ef-368b-45fe-99c7-1b92ea333d78]
> com.cloud.exception.ConcurrentOperationException: Failed to transit state
> at
> com.cloud.storage.StorageManagerImpl.destroyVolume(StorageManagerImpl.java:2060)
> at
> com.cloud.utils.db.DatabaseCallback.intercept(DatabaseCallback.java:30)
> at
> com.cloud.storage.StorageManagerImpl.cleanupVolumes(StorageManagerImpl.java:3486)
> at
> com.cloud.utils.db.DatabaseCallback.intercept(DatabaseCallback.java:30)
> at
> com.cloud.vm.VirtualMachineManagerImpl.advanceExpunge(VirtualMachineManagerImpl.java:391)
> at
> com.cloud.vm.UserVmManagerImpl.expunge(UserVmManagerImpl.java:1160)
> at
> com.cloud.user.AccountManagerImpl.cleanupAccount(AccountManagerImpl.java:518)
> at
> com.cloud.user.AccountManagerImpl$AccountCleanupTask.run(AccountManagerImpl.java:1291)
> at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
> at
> java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:351)
> at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:165)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:267)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
> at java.lang.Thread.run(Thread.java:679)
> 2012-12-16 23:44:01,132 ERROR [cloud.user.AccountManagerImpl]
> (AccountChecker-1:null) Unable to expunge vm: 620
>