Fix docker cp on a mounted volume

This is a work around docker's bug, see moby/moby#47964.

Resolves #18

Co-authored-by: Nikolai Nechaev <[email protected]>

Author: AnderG

activemount.go

@@ -0,0 +1,21 @@
+package main
+
+import (
+	"encoding/json"
+)
+
+// activeMount is used to count the number of active mounts of a volume by a container.
+// Multiple mounts may be created, e.g., if `docker cp` is performed on a running container
+// with the volume mounted. Such requests are supposed to have unique mount IDs, however, due to
+// a bug in dockerd, they don't: https://github.com/moby/moby/issues/47964
+type activeMount struct {
+	UsageCount int
+}
+
+func (am *activeMount) mustMarshal() []byte {
+	payload, err := json.Marshal(am)
+	if err != nil {
+		panic(err)
+	}
+	return payload
+}

driver.go

@@ -1,6 +1,7 @@
 package main
 
 import (
+	"encoding/json"
 	"errors"
 	"fmt"
 	"io"
@@ -166,9 +167,11 @@ func (d *DockerOnTop) Remove(request *volume.RemoveRequest) error {
 	} else if os.IsNotExist(err) {
 		// That's the default case: mountpoint does not exist
 	} else if err != nil {
+		log.Errorf("Volume %s to be removed does not seem mounted but the mountpoint exists and cannot be removed: %v",
+			request.Name, err)
 		log.Errorf("Volume %s to be removed does not seem mounted but still cannot be removed: %v",
 			request.Name, err)
-		return internalError("failed to remove the mountpoint directory of a seemingly unmounted volume",
+		return internalError("failed to remove the mountpoint directory of a volume, which seems unmounted",
 			err)
 	}
 
@@ -310,22 +313,47 @@ func (d *DockerOnTop) activateVolume(volumeName string, requestId string, active
 		return internalError("failed to list activemounts/", err)
 	}
 
+	var activeMountInfo activeMount
 	activemountFilePath := d.activemountsdir(volumeName) + requestId
-	f, err := os.Create(activemountFilePath)
+	payload, err := os.ReadFile(activemountFilePath)
 	if err == nil {
-		// We don't care about the file's contents
-		_ = f.Close()
-	} else if os.IsExist(err) {
-		// Super weird. I can't imagine why this would happen.
-		log.Warningf("Active mount %s already exists (but it shouldn't...)", activemountFilePath)
+		// The file may exists from a previous mount when doing a docker cp on an already running
+		// container. Thus, no need to mount, just increment the counter.
+		err = json.Unmarshal(payload, &activeMountInfo)
+		if err != nil {
+			log.Errorf("Failed to decode active mount file %s : %v", activemountFilePath, err)
+			return internalError("failed to decode active mount file", err)
+		}
+	} else if os.IsNotExist(err) {
+		// Default case, we need to create a new active mount
+		activeMountInfo = activeMount{UsageCount: 0}
 	} else {
+		log.Errorf("Failed to read active mount file %s : %v", activemountFilePath, err)
+		return internalError("failed to read active mount file", err)
+	}
+
+	activeMountInfo.UsageCount++
+
+	// Here, intentionally separating file creation and writing (instead of using `os.WriteFile`)
+	// to perform more careful error handling
+	activemountFile, err := os.Create(activemountFilePath)
+	if err != nil {
 		// We have successfully mounted the overlay but failed to mark that we are using it.
 		// If we use the volume now, we break the guarantee that we shall provide according
 		// to the above note. Thus, refusing with an error.
 		// We leave the overlay mounted as a harmless side effect.
 		log.Errorf("While mounting volume %s, failed to create active mount file: %v", volumeName, err)
 		return internalError("failed to create active mount file while mounting volume", err)
 	}
+	defer activemountFile.Close()
+
+	_, err = activemountFile.Write(activeMountInfo.mustMarshal())
+	if err != nil {
+		// This is an unfortunate situation. We have either created or truncated the active
+		// mounts file, rendering it unreadable on future requests. There is not much we can do.
+		log.Errorf("Failed to write to the active mount file %s : %v", activemountFilePath, err)
+		return internalError("failed to write to the active mount file", err)
+	}
 
 	return nil
 }
@@ -347,15 +375,47 @@ func (d *DockerOnTop) deactivateVolume(volumeName string, requestId string, acti
 
 	activemountFilePath := d.activemountsdir(volumeName) + requestId
 
-	err := os.Remove(activemountFilePath)
+	var activeMountInfo activeMount
+	payload, err := os.ReadFile(activemountFilePath)
 	if os.IsNotExist(err) {
-		log.Warningf("Failed to remove %s because it does not exist (but it should...)", activemountFilePath)
+		log.Warningf("Failed to read&remove %s because it does not exist (but it should...)", activemountFilePath)
+		// Assuming we are the only user with this mount ID
+		activeMountInfo = activeMount{UsageCount: 1}
 	} else if err != nil {
-		log.Errorf("Failed to remove active mounts file %s. The volume %s is now stuck in the active state",
+		log.Errorf("Failed to read active mounts file %s . The volume %s is now stuck in the active state",
 			activemountFilePath, volumeName)
-		// The user most likely won't see this error message due to daemon not showing unmount errors to the
+		// The user most likely won't see this error message because daemon does not show unmount errors to the
 		// `docker run` clients :((
-		return internalError("failed to remove the active mount file; the volume is now stuck in the active state", err)
+		return internalError("failed to read the active mouint file; the volume is now stuck in the active state", err)
+	} else {
+		err = json.Unmarshal(payload, &activeMountInfo)
+		if err != nil {
+			log.Errorf("Failed to decode active mount file %s : %v", activemountFilePath, err)
+			return internalError("failed to decode active mount file", err)
+		}
+	}
+
+	activeMountInfo.UsageCount--
+	if activeMountInfo.UsageCount == 0 {
+		err = os.Remove(activemountFilePath)
+		if os.IsNotExist(err) {
+			// It's ok, already logged above
+		} else if err != nil {
+			log.Errorf("Failed to remove active mounts file %s : %v; the volume is now stuck in the active state",
+				activemountFilePath, err)
+			// The user most likely won't see this error message because the daemon does not show unmount errors
+			// to the `docker run` clients :((
+			return internalError("failed to remove the active mount file; the volume is now stuck in the active state", err)
+		}
+	} else {
+		err = os.WriteFile(activemountFilePath, activeMountInfo.mustMarshal(), 0o644)
+		if err != nil {
+			log.Errorf("Failed to write to active mount file %s : %v; the file may have been corrupted")
+			return internalError("failed to write to active mount file (potentially corrupting)", err)
+		}
+		log.Debugf("Volume %s is still used by the same container. Indicating success without unmounting",
+			volumeName)
+		return nil
 	}
 
 	_, err = activemountsdir.ReadDir(1) // Check if there is any container using the volume (after us)

tests/docker_cp.bats

@@ -0,0 +1,36 @@
+#!/usr/bin/env bats
+
+# For `CONTAINER_CMD_*`
+load common.sh
+
+@test "Docker cp-ing from a container" {
+    # https://github.com/kolayne/docker-on-top/issues/18
+
+    BASE="$(mktemp --directory)"
+    NAME="$(basename "$BASE")"
+    docker volume create --driver docker-on-top "$NAME" -o base="$BASE" -o volatile=true
+
+    # Deferred cleanup
+    trap 'rm -rf "$BASE"; docker container rm -f "$CONTAINER_ID"; docker volume rm "$NAME"; trap - RETURN' RETURN
+
+    CONTAINER_ID=$(docker run --name "$NAME" -d -v "$NAME":/dot alpine:latest sh -e -c '
+        echo 123 > /dot/b
+        sleep 1
+        # What the following checks is that after the second container is started, the overlay upperdir
+        # is not cleared (which is what was happening before the issue was fixed). However, there is no
+        # reliable way to test this, since what exactly happens in the errorneous case depends on the
+        # implementation of the overlay filesystem.
+        # For me, this seems to work (but just `cat /dot/b` does not fail):
+        ls /dot | grep b && cat /dot/b
+    ')
+
+    sleep 0.5
+
+    # It does not matter where we copy to, but I put it on the volume
+    # to simplify the cleanup.
+    docker cp "$NAME":/etc/passwd "$BASE/"
+
+    docker run --rm -v "$NAME":/dot alpine:latest true
+
+    [ 0 -eq "$(docker wait "$CONTAINER_ID")" ]
+}