[REST API] Delete OCCI infrastructure: Volume deleting returns forbidden and takes too long

[victorsndvg]

Hi IM team,

I'm using IM REST API to try to manage deployment and undeployment of single virtual machines using an OCCI endpoint.

When I undeploy the virtual machine it tries to remove the attached volumes (in my case only disk.0, I'm not the owner of the disk) in a loop and it can take minutes.

The debug output I get is the following:

2018-09-07 09:30:39,546 - InfrastructureManager - INFO - Listing the user infrastructures
2018-09-07 09:30:39,768 - InfrastructureManager - INFO - Destroying the Inf ID: 40433104-b27d-11e8-b4df-0242ac120002
2018-09-07 09:30:39,867 - InfrastructureManager - INFO - Inf ID: 40433104-b27d-11e8-b4df-0242ac120002: Finalizing the VM id: 43600
2018-09-07 09:30:47,587 - CloudConnector - INFO - Inf ID: 40433104-b27d-11e8-b4df-0242ac120002: Detaching volume: /storage/335
2018-09-07 09:30:52,381 - CloudConnector - INFO - Inf ID: 40433104-b27d-11e8-b4df-0242ac120002: Volume link //link/storagelink/compute_43600_disk_0 exists. Try to delete it.
2018-09-07 09:30:53,953 - CloudConnector - INFO - Inf ID: 40433104-b27d-11e8-b4df-0242ac120002: Successfully detached. Wait it to be deleted.
2018-09-07 09:30:58,960 - CloudConnector - INFO - Inf ID: 40433104-b27d-11e8-b4df-0242ac120002: Detaching volume: /storage/335
2018-09-07 09:31:00,879 - CloudConnector - INFO - Inf ID: 40433104-b27d-11e8-b4df-0242ac120002: Successfully detached
2018-09-07 09:31:06,317 - CloudConnector - INFO - Inf ID: 40433104-b27d-11e8-b4df-0242ac120002: Delete storage: /storage/335
2018-09-07 09:31:09,185 - CloudConnector - INFO - Inf ID: 40433104-b27d-11e8-b4df-0242ac120002: Storage /storage/335 exists. Try to delete it.
2018-09-07 09:31:10,979 - CloudConnector - WARNING - Inf ID: 40433104-b27d-11e8-b4df-0242ac120002: Error deleting the Volume: Forbidden
[ImageDelete] User [241] : Not authorized to perform MANAGE IMAGE [335].
2018-09-07 09:31:15,986 - CloudConnector - INFO - Inf ID: 40433104-b27d-11e8-b4df-0242ac120002: Delete storage: /storage/335
...
2018-09-07 09:31:17,756 - CloudConnector - INFO - Inf ID: 40433104-b27d-11e8-b4df-0242ac120002: Storage /storage/335 exists. Try to delete it.
2018-09-07 09:31:19,420 - CloudConnector - WARNING - Inf ID: 40433104-b27d-11e8-b4df-0242ac120002: Error deleting the Volume: Forbidden
[ImageDelete] User [241] : Not authorized to perform MANAGE IMAGE [335].
...
2018-09-07 09:36:17,240 - CloudConnector - ERROR - Inf ID: 40433104-b27d-11e8-b4df-0242ac120002: Error deleting the Volume: Timeout

Is there a way to reduce the timeout or to catch "forbidden" (or other 40X-50X errors) to not try to delete it again?

Thanks in advance!

[micafer]

Hi @victorsndvg ,

This process is made because the disks cannot be deleted until the VM is totally terminated.
So we get similar error in case of disks that must be deleted.
We have to check if there is a way of differentiating the error codes in each case.

Best regards.

[micafer]

I have updated the 1.7.4-dev docker image version to add this patch.
Could you try it?

[victorsndvg]

I have tested a little this version. I've to say that in general is much more faster than 1.7.3. Great!

My particular problem while deleting volumes still there. The logs show the same messages. It finishes with a timeout after 5 minutes of trying to delete de volume:

2018-09-07 12:06:37,424 - CloudConnector - INFO - Inf ID: 48b1795a-b295-11e8-bbff-0242ac120002: Delete storage: /storage/335
2018-09-07 12:06:39,064 - CloudConnector - INFO - Inf ID: 48b1795a-b295-11e8-bbff-0242ac120002: Storage /storage/335 exists. Try to delete it.
2018-09-07 12:06:40,575 - CloudConnector - WARNING - Inf ID: 48b1795a-b295-11e8-bbff-0242ac120002: Error deleting the Volume: Forbidden
[ImageDelete] User [241] : Not authorized to perform MANAGE IMAGE [335].
2018-09-07 12:06:45,580 - CloudConnector - ERROR - Inf ID: 48b1795a-b295-11e8-bbff-0242ac120002: Error deleting the Volume: Timeout
2018-09-07 12:06:45,620 - InfrastructureManager - INFO - Inf ID: 48b1795a-b295-11e8-bbff-0242ac120002: Successfully destroyed

I wonder if the "Forbidden" keyword is more relates with 403 error code (I saw it in the rocci-http-api web page, but I'm not able to find it again). What do you think?

Thanks anyway! :)

[micafer]

You are right I have to add also the 403 code.

[micafer]

I have updated, again, the 1.7.4-dev docker image version to add the last patch.
Could you try it?

[victorsndvg]

Perfect, It works!

Now logs are more clean and removing VMs seems more agile. Logs look like this now:

2018-09-10 09:25:09,986 - InfrastructureManager - INFO - Destroying the Inf ID: c393ba2a-b4d9-11e8-8e2e-0242ac120002
2018-09-10 09:25:10,077 - InfrastructureManager - INFO - Inf ID: c393ba2a-b4d9-11e8-8e2e-0242ac120002: Finalizing the VM id: 44046
2018-09-10 09:26:17,830 - CloudConnector - INFO - Inf ID: c393ba2a-b4d9-11e8-8e2e-0242ac120002: Detaching volume: /storage/335
2018-09-10 09:27:09,945 - CloudConnector - INFO - Inf ID: c393ba2a-b4d9-11e8-8e2e-0242ac120002: Successfully detached
2018-09-10 09:28:22,707 - CloudConnector - INFO - Inf ID: c393ba2a-b4d9-11e8-8e2e-0242ac120002: Delete storage: /storage/335
2018-09-10 09:28:50,776 - CloudConnector - INFO - Inf ID: c393ba2a-b4d9-11e8-8e2e-0242ac120002: Storage /storage/335 exists. Try to delete it.
2018-09-10 09:29:06,443 - CloudConnector - INFO - Inf ID: c393ba2a-b4d9-11e8-8e2e-0242ac120002: You are not authorized to delete it. Ignore.
2018-09-10 09:29:06,481 - InfrastructureManager - INFO - Inf ID: c393ba2a-b4d9-11e8-8e2e-0242ac120002: Successfully destroyed

Thanks @micafer !

[micafer]

Thanks you to test it.