Merge lp:~rvb/gwacl/delete-disk-fix into lp:gwacl

[Raphaël Badin]

Use a poller in ManagementAPI.DeleteDisk() to work around Windows Azure's bug.

This branch adds a poller used to delete a disk in order to work around a Windows Azure bug: it takes an indeterminate time for a disk previously attached to a deleted VM to become "not in use" and thus be available for deletion.

I refactored the poller: isDone() now also takes the error returned by poll(). This was done because I needed it for this branch obviously but this simply makes the poller more generic: isDone() can also decide whether or not the polling should stop using the error returned by poll() (and not only using the 'response' returned by poll()).

I've made all I could to keep this workaround contained. The goal was that, once the bug will be fixed in Windows Azure, only minimal changes will be required to revert to the old implementation. That's why the test TestManagementAPIDeleteDiskPolls is in deletedisk_test.go file. All we will have to do when the Azure bug is fixed is:
- remove the existing DeleteDisk() method and rename _DeleteDisk() into DeleteDisk()
- delete the files deletedisk.go and deletedisk_test.go.
- remove the tweak to deleteDiskInterval in managementapi_test.go (the variable deleteDiskInterval is in deletedisk.go so once that file is removed, the need to remove its usage in managementapi_test.go will become clear (i.e. managementapi_test.go won't compile))

[Gavin Panella (allenap)]

Looks good :)

[1]

+func isInUseError(errString string, diskName string) bool {
+    pattern := fmt.Sprintf("BadRequest - A disk with name %s is currently in use by virtual machine.*", regexp.QuoteMeta(diskName))
+    res, err := regexp.MatchString(pattern, errString)

Do you think it's necessary to check the disk name in the error message?

It might be clearer to check that the response status is 400, and that
the body contains the phrases "A disk with name" and "is currently in
use by virtual machine".

[2]

+    res, err := regexp.MatchString(pattern, errString)
+    if err != nil {
+        panic(fmt.Sprintf("can not compile regular expression: %v", pattern))
+    }

Fwiw, there's regexp.MustCompile for these kinds of situations; saves
having to do the 3-line-dance.

review: Approve

[lp:~rvb/gwacl/delete-disk-fix]

94. By Raphaël Badin on 2013-04-17

Use regexp.MustCompile.

[Raphaël Badin (rvb)]

Thanks for the review!

> [1]
>
> +func isInUseError(errString string, diskName string) bool {
> +    pattern := fmt.Sprintf("BadRequest - A disk with name %s is currently in
> use by virtual machine.*", regexp.QuoteMeta(diskName))
> +    res, err := regexp.MatchString(pattern, errString)
>
> Do you think it's necessary to check the disk name in the error message?

I think it's better to keep the disk name in the error message just to be 100% certain that the error is about the disk that we're trying to delete. This might look a bit like "belt and braces" but I'd like to be on the safe side with Azure.

>
> [2]
>
> +    res, err := regexp.MatchString(pattern, errString)
> +    if err != nil {
> +        panic(fmt.Sprintf("can not compile regular expression: %v", pattern))
> +    }
>
> Fwiw, there's regexp.MustCompile for these kinds of situations; saves
> having to do the 3-line-dance.

Good point, done.

=== modified file '.bzrignore'
--- .bzrignore	2013-04-10 10:40:01 +0000
+++ .bzrignore	2013-04-17 08:28:24 +0000
@@ -1,2 +1,3 @@
 ./example/live_example_managementapi
 ./example/storage_example
+./tags

=== added file 'deletedisk.go'
--- deletedisk.go	1970-01-01 00:00:00 +0000
+++ deletedisk.go	2013-04-17 08:28:24 +0000
@@ -0,0 +1,64 @@
+// Copyright 2013 Canonical Ltd.  This software is licensed under the
+// GNU Lesser General Public License version 3 (see the file COPYING).
+
+// A poller object used to delete a disk.
+//
+// It takes an indeterminate time for a disk previously attached to a
+// deleted VM to become "not in use" and thus be available for deletion.
+// When we receive the "disk is still attached" error, we try again every
+// 10 seconds until it succeeds, with a timeout of 30 minutes).
+// This bug might be related to:
+// http://social.msdn.microsoft.com/Forums/en-US/WAVirtualMachinesforWindows/thread/4394c75d-59ff-4634-8212-2ad71bf6fbd5/
+//
+// Once this bug is fixed in Windows Azure, this file and the related tests
+// can safely be removed, and ManagementAPI._DeleteDisk() can replace the
+// current implementation of ManagementAPI.DeleteDisk() (which uses this
+// poller).
+
+package gwacl
+
+import (
+    "fmt"
+    "regexp"
+    "time"
+)
+
+var deleteDiskTimeout = 30 * time.Minute
+var deleteDiskInterval = 10 * time.Second
+
+type diskDeletePoller struct {
+    api      *ManagementAPI
+    diskName string
+}
+
+var _ poller = &diskDeletePoller{}
+
+func (poller diskDeletePoller) poll() (*x509Response, error) {
+    return nil, poller.api._DeleteDisk(poller.diskName)
+}
+
+// isInUseError returns whether or not the given string is of the "disk in use"
+// type.
+// Here is a real-world example of the error in question:
+// "BadRequest - A disk with name gwacldiske5w7lkj is currently in use
+// by virtual machine gwaclrolemvo1yab running within hosted service
+// gwacl623yosxtppsa9577xy5, deployment gwaclmachinewes4n64f. (http
+// code 400: Bad Request)"
+func isInUseError(errString string, diskName string) bool {
+    pattern := fmt.Sprintf("BadRequest - A disk with name %s is currently in use by virtual machine.*", regexp.QuoteMeta(diskName))
+    reg := regexp.MustCompile(pattern)
+    return reg.MatchString(errString)
+}
+
+func (poller diskDeletePoller) isDone(response *x509Response, pollerErr error) (bool, error) {
+    if pollerErr == nil {
+        return true, nil
+    }
+    if isInUseError(pollerErr.Error(), poller.diskName) {
+        // The error is of the "disk in use" type: continue polling.
+        return false, nil
+    }
+    // The error is *not* of the "disk in use" type: stop polling and return
+    // the error.
+    return true, pollerErr
+}

=== added file 'deletedisk_test.go'
--- deletedisk_test.go	1970-01-01 00:00:00 +0000
+++ deletedisk_test.go	2013-04-17 08:28:24 +0000
@@ -0,0 +1,103 @@
+// Copyright 2013 Canonical Ltd.  This software is licensed under the
+// GNU Lesser General Public License version 3 (see the file COPYING).
+
+package gwacl
+
+import (
+    "fmt"
+    . "launchpad.net/gocheck"
+    "net/http"
+    "time"
+)
+
+type deleteDiskSuite struct{}
+
+var _ = Suite(&deleteDiskSuite{})
+
+// Real-world error messages and names.
+const (
+    diskInUseErrorTemplate = "BadRequest - A disk with name %s is currently in use by virtual machine gwaclrolemvo1yab running within hosted service gwacl623yosxtppsa9577xy5, deployment gwaclmachinewes4n64f. (http code 400: Bad Request)"
+    diskName               = "gwacldiske5w7lkj"
+    diskDoesNotExistError  = "DELETE request failed: ResourceNotFound - The disk with the specified name does not exist. (http code 404: Not Found)"
+)
+
+func (suite *deleteDiskSuite) TestIsInUseError(c *C) {
+    var testValues = []struct {
+        errorString    string
+        diskName       string
+        expectedResult bool
+    }{
+        {fmt.Sprintf(diskInUseErrorTemplate, diskName), diskName, true},
+        {fmt.Sprintf(diskInUseErrorTemplate, diskName), "another-disk", false},
+        {"unknown error", diskName, false},
+        {diskDoesNotExistError, diskName, false},
+    }
+    for _, test := range testValues {
+        c.Check(isInUseError(test.errorString, test.diskName), Equals, test.expectedResult)
+    }
+}
+
+func (suite *deleteDiskSuite) TestIsDoneReturnsTrueIfNilError(c *C) {
+    poller := diskDeletePoller{nil, ""}
+    randomResponse := x509Response{StatusCode: http.StatusAccepted}
+    done, err := poller.isDone(&randomResponse, nil)
+    c.Check(done, Equals, true)
+    c.Check(err, IsNil)
+}
+
+func (suite *deleteDiskSuite) TestIsDoneReturnsFalseIfDiskInUseError(c *C) {
+    diskName := "gwacldiske5w7lkj"
+    diskInUseError := fmt.Errorf(diskInUseErrorTemplate, diskName)
+    poller := diskDeletePoller{nil, diskName}
+    done, err := poller.isDone(nil, diskInUseError)
+    c.Check(done, Equals, false)
+    c.Check(err, IsNil)
+}
+
+func (suite *deleteDiskSuite) TestIsDoneReturnsTrueIfAnotherError(c *C) {
+    anotherError := fmt.Errorf("Unknown error")
+    poller := diskDeletePoller{nil, "disk-name"}
+    done, err := poller.isDone(nil, anotherError)
+    c.Check(done, Equals, true)
+    c.Check(err, Equals, anotherError)
+}
+
+func (suite *deleteDiskSuite) TestPollCallsDeleteDisk(c *C) {
+    api := makeAPI(c)
+    recordedRequests := setUpDispatcher("operationID")
+    diskName := "gwacldiske5w7lkj"
+    poller := diskDeletePoller{api, diskName}
+
+    response, err := poller.poll()
+
+    c.Assert(response, IsNil)
+    c.Assert(err, IsNil)
+    expectedURL := api.session.composeURL("services/disks/" + diskName)
+    checkOneRequest(c, recordedRequests, expectedURL, []byte{}, "DELETE")
+}
+
+func (suite *deleteDiskSuite) TestManagementAPIDeleteDiskPolls(c *C) {
+    firstResponse := DispatcherResponse{
+        response:    &x509Response{},
+        errorObject: fmt.Errorf(diskInUseErrorTemplate, diskName)}
+    secondResponse := DispatcherResponse{
+        response:    &x509Response{StatusCode: http.StatusOK},
+        errorObject: nil}
+    responses := []DispatcherResponse{firstResponse, secondResponse}
+    rigPreparedResponseDispatcher(responses)
+    recordedRequests := make([]*x509Request, 0)
+    rigRecordingDispatcher(&recordedRequests)
+
+    api := makeAPI(c)
+    diskName := "gwacldiske5w7lkj"
+    poller := diskDeletePoller{api, diskName}
+
+    response, err := performPolling(poller, time.Nanosecond, time.Minute)
+
+    c.Assert(response, IsNil)
+    c.Assert(err, IsNil)
+    expectedURL := api.session.composeURL("services/disks/" + diskName)
+    c.Check(len(recordedRequests), Equals, 2)
+    checkRequest(c, recordedRequests[0], expectedURL, []byte{}, "DELETE")
+    checkRequest(c, recordedRequests[1], expectedURL, []byte{}, "DELETE")
+}

=== modified file 'example/live_example_managementapi.go'
--- example/live_example_managementapi.go	2013-04-02 03:44:55 +0000
+++ example/live_example_managementapi.go	2013-04-17 08:28:24 +0000
@@ -147,10 +147,6 @@
     checkError(err)
     fmt.Println("Done deleting deployment\n")
 
-    // TODO: it takes some time for a disk previously attached to a deleted VM 
-    // to become "not in use" and thus be available for deletion.
-    time.Sleep(3 * time.Minute)
-
     fmt.Println("Deleting VM disk...")
     err = api.DeleteDisk(diskName)
     checkError(err)

=== modified file 'managementapi.go'
--- managementapi.go	2013-04-10 15:14:32 +0000
+++ managementapi.go	2013-04-17 08:28:24 +0000
@@ -225,6 +225,14 @@
 }
 
 func (api *ManagementAPI) DeleteDisk(diskName string) error {
+    // Use the disk deletion poller to work around a bug in Windows Azure.
+    // See the documentation in the file deletedisk.go for details.
+    poller := diskDeletePoller{api, diskName}
+    _, err := performPolling(poller, deleteDiskInterval, deleteDiskTimeout)
+    return err
+}
+
+func (api *ManagementAPI) _DeleteDisk(diskName string) error {
     response, err := api.session.delete("services/disks/" + diskName)
     if err != nil {
         return err

=== modified file 'managementapi_test.go'
--- managementapi_test.go	2013-04-03 11:20:20 +0000
+++ managementapi_test.go	2013-04-17 08:28:24 +0000
@@ -507,6 +507,11 @@
 }
 
 func (suite *managementAPISuite) TestDeleteDisk(c *C) {
+    // The current implementation of DeleteDisk() works around a bug in
+    // Windows Azure by polling the server.  See the documentation in the file
+    // deletedisk.go for details.
+    // Change the polling interval to speed up the tests:
+    deleteDiskInterval = time.Nanosecond
     api := makeAPI(c)
     recordedRequests := setUpDispatcher("operationID")
     diskName := "diskName"

=== modified file 'poller.go'
--- poller.go	2013-04-03 11:20:20 +0000
+++ poller.go	2013-04-17 08:28:24 +0000
@@ -14,7 +14,7 @@
 // the response given by the server means that the polling is finished. 
 type poller interface {
     poll() (*x509Response, error)
-    isDone(*x509Response) (bool, error)
+    isDone(*x509Response, error) (bool, error)
 }
 
 // performPolling calls the poll() method of the given 'poller' object every
@@ -29,11 +29,8 @@
         case <-timeoutChannel:
             return nil, fmt.Errorf("polling timed out waiting for an asynchronous operation")
         default:
-            response, err := poller.poll()
-            if err != nil {
-                return nil, err
-            }
-            done, err := poller.isDone(response)
+            response, pollerErr := poller.poll()
+            done, err := poller.isDone(response, pollerErr)
             if err != nil {
                 return nil, err
             }
@@ -89,9 +86,12 @@
 // IsDone returns true if the given response has a status code indicating
 // success and if the returned XML response corresponds to a valid Operation
 // with a status indicating that the operation is completed.
-func (poller operationPoller) isDone(response *x509Response) (bool, error) {
+func (poller operationPoller) isDone(response *x509Response, pollerError error) (bool, error) {
     // TODO: Add a timeout so that polling won't continue forever if the
     // server cannot be reached.
+    if pollerError != nil {
+        return true, pollerError
+    }
     if response.StatusCode >= 200 && response.StatusCode < 300 {
         operation := Operation{}
         err := operation.Deserialize(response.Body)

=== modified file 'poller_test.go'
--- poller_test.go	2013-04-03 11:20:20 +0000
+++ poller_test.go	2013-04-17 08:28:24 +0000
@@ -51,7 +51,10 @@
     return &testPollerResponse, nil
 }
 
-func (poller *testPoller) isDone(response *x509Response) (bool, error) {
+func (poller *testPoller) isDone(response *x509Response, pollerError error) (bool, error) {
+    if pollerError != nil {
+        return true, pollerError
+    }
     if poller.notDoneCalls == 0 {
         return true, nil
     }
@@ -128,7 +131,7 @@
             StatusCode: http.StatusOK,
         }
 
-        isDone, err := poller.isDone(&response)
+        isDone, err := poller.isDone(&response, nil)
         c.Assert(err, IsNil)
         c.Assert(isDone, Equals, true)
     }
@@ -148,7 +151,7 @@
         {StatusCode: http.StatusInternalServerError},
     }
     for _, response := range notDoneResponses {
-        isDone, _ := poller.isDone(&response)
+        isDone, _ := poller.isDone(&response, nil)
         c.Assert(isDone, Equals, false)
     }
 }
@@ -160,7 +163,7 @@
         Body:       []byte("><invalid XML"),
         StatusCode: http.StatusOK,
     }
-    _, err := poller.isDone(&response)
+    _, err := poller.isDone(&response, nil)
     c.Assert(err, NotNil)
     c.Check(err, FitsTypeOf, new(xml.SyntaxError))
 }