podman icon indicating copy to clipboard operation
podman copied to clipboard

Fix machines failing to start when a volume's path contains spaces

Open l0rd opened this issue 7 months ago • 1 comments
trafficstars

~Hyper-V~ Machines failed to start when the path of a volume contained a space. To avoid that we are surrounding the path name with quotation marks before invoking podman machine ssh.

Fixes https://github.com/containers/podman/issues/25500

Does this PR introduce a user-facing change?

Fix Hyper-V based podman machines failing to start when a volume's path contains spaces

l0rd avatar Mar 28 '25 16:03 l0rd

[NON-BLOCKING] Packit jobs failed. @containers/packit-build please check. Everyone else, feel free to ignore.

Please note that I still have an error with this patch:

GOROOT=C:\Users\Jeff Maury\.gvm\versions\go1.24.1.windows.amd64 #gosetup
GOPATH=C:\Users\Jeff Maury\go #gosetup
"C:\Users\Jeff Maury\.gvm\versions\go1.24.1.windows.amd64\bin\go.exe" build --tags "remote exclude_graphdriver_btrfs btrfs_noversion exclude_graphdriver_devicemapper containers_image_openpgp" -o "C:\Users\Jeff Maury\AppData\Local\JetBrains\GoLand2024.3\tmp\GoLand\___1go_build_github_com_containers_podman_v5_cmd_podman.exe" . #gosetup
"C:\Users\Jeff Maury\AppData\Local\JetBrains\GoLand2024.3\tmp\GoLand\___1go_build_github_com_containers_podman_v5_cmd_podman.exe" machine start --log-level debug h1 #gosetup
time="2025-04-24T19:44:35+02:00" level=info msg="C:\\Users\\Jeff Maury\\AppData\\Local\\JetBrains\\GoLand2024.3\\tmp\\GoLand\\___1go_build_github_com_containers_podman_v5_cmd_podman.exe filtering at log level debug"
time="2025-04-24T19:44:35+02:00" level=debug msg="Using Podman machine with `hyperv` virtualization provider"
time="2025-04-24T19:44:35+02:00" level=debug msg="socket length for C:\\Users\\Jeff Maury\\.config\\containers\\podman\\machine\\hyperv is 60"
time="2025-04-24T19:44:35+02:00" level=debug msg="socket length for C:\\Users\\Jeff Maury\\.local\\share\\containers\\podman\\machine\\hyperv is 65"
time="2025-04-24T19:44:35+02:00" level=debug msg="socket length for C:\\Users\\Jeff Maury\\.local\\share\\containers\\podman\\machine\\hyperv\\cache is 71"
time="2025-04-24T19:44:35+02:00" level=debug msg="socket length for C:\\Users\\JEFFMA~1\\AppData\\Local\\Temp\\podman is 43"
time="2025-04-24T19:44:35+02:00" level=debug msg="socket length for C:\\Users\\Jeff Maury\\.config\\containers\\podman\\machine\\hyperv\\h1.json is 68"
time="2025-04-24T19:44:35+02:00" level=debug msg="socket length for C:\\Users\\Jeff Maury\\.config\\containers\\podman\\machine\\wsl is 57"
time="2025-04-24T19:44:35+02:00" level=debug msg="socket length for C:\\Users\\Jeff Maury\\.local\\share\\containers\\podman\\machine\\wsl is 62"
time="2025-04-24T19:44:35+02:00" level=debug msg="socket length for C:\\Users\\Jeff Maury\\.local\\share\\containers\\podman\\machine\\wsl\\cache is 68"
time="2025-04-24T19:44:35+02:00" level=debug msg="socket length for C:\\Users\\JEFFMA~1\\AppData\\Local\\Temp\\podman is 43"
time="2025-04-24T19:44:35+02:00" level=debug msg="socket length for C:\\Users\\Jeff Maury\\.config\\containers\\podman\\machine\\hyperv is 60"
time="2025-04-24T19:44:35+02:00" level=debug msg="socket length for C:\\Users\\Jeff Maury\\.local\\share\\containers\\podman\\machine\\hyperv is 65"
time="2025-04-24T19:44:35+02:00" level=debug msg="socket length for C:\\Users\\Jeff Maury\\.local\\share\\containers\\podman\\machine\\hyperv\\cache is 71"
time="2025-04-24T19:44:35+02:00" level=debug msg="socket length for C:\\Users\\JEFFMA~1\\AppData\\Local\\Temp\\podman is 43"
time="2025-04-24T19:44:35+02:00" level=debug msg="socket length for C:\\Users\\Jeff Maury\\.config\\containers\\podman\\machine\\hyperv\\h1.json is 68"
Starting machine "h1"
time="2025-04-24T19:44:35+02:00" level=debug msg="writing configuration file \"C:\\\\Users\\\\Jeff Maury\\\\.config\\\\containers\\\\podman\\\\machine\\\\hyperv\\\\h1.json\""
time="2025-04-24T19:44:35+02:00" level=debug msg="socket length for C:\\Users\\JEFFMA~1\\AppData\\Local\\Temp\\podman\\gvproxy.pid is 55"
time="2025-04-24T19:44:35+02:00" level=debug msg="socket length for C:\\Users\\Jeff Maury\\.config\\containers\\podman\\machine\\hyperv is 60"
time="2025-04-24T19:44:35+02:00" level=debug msg="socket length for C:\\Users\\Jeff Maury\\.local\\share\\containers\\podman\\machine\\hyperv is 65"
time="2025-04-24T19:44:35+02:00" level=debug msg="socket length for C:\\Users\\Jeff Maury\\.local\\share\\containers\\podman\\machine\\hyperv\\cache is 71"
time="2025-04-24T19:44:35+02:00" level=debug msg="socket length for C:\\Users\\JEFFMA~1\\AppData\\Local\\Temp\\podman is 43"
time="2025-04-24T19:44:35+02:00" level=debug msg="socket length for C:\\Users\\JEFFMA~1\\AppData\\Local\\Temp\\podman\\h1-api.sock is 55"
time="2025-04-24T19:44:35+02:00" level=debug msg="{true 1500 map[forward-dest:[/run/user/1000/podman/podman.sock /run/user/1000/podman/podman.sock /run/user/1000/podman/podman.sock] forward-identity:[C:\\Users\\Jeff Maury\\.local\\share\\containers\\podman\\machine\\machine C:\\Users\\Jeff Maury\\.local\\share\\containers\\podman\\machine\\machine C:\\Users\\Jeff Maury\\.local\\share\\containers\\podman\\machine\\machine] forward-sock:[npipe:////./pipe/podman-h1 npipe:////./pipe/docker_engine unix:///C:/Users/JEFFMA~1/AppData/Local/Temp/podman/h1-api.sock] forward-user:[core core core]] [] [] map[] C:\\Users\\JEFFMA~1\\AppData\\Local\\Temp\\podman\\gvproxy.log C:\\Users\\JEFFMA~1\\AppData\\Local\\Temp\\podman\\gvproxy.pid 56058}"
time="2025-04-24T19:44:35+02:00" level=debug msg="gvproxy command-line: C:\\Users\\Jeff Maury\\work\\containers\\podman\\bin\\windows\\gvproxy.exe -listen vsock://0000DB1C-FACB-11E6-BD58-64006A7986D3 -debug -mtu 1500 -ssh-port 56058 -forward-user core -forward-user core -forward-user core -forward-identity C:\\Users\\Jeff Maury\\.local\\share\\containers\\podman\\machine\\machine -forward-identity C:\\Users\\Jeff Maury\\.local\\share\\containers\\podman\\machine\\machine -forward-identity C:\\Users\\Jeff Maury\\.local\\share\\containers\\podman\\machine\\machine -forward-sock npipe:////./pipe/podman-h1 -forward-sock npipe:////./pipe/docker_engine -forward-sock unix:///C:/Users/JEFFMA~1/AppData/Local/Temp/podman/h1-api.sock -forward-dest /run/user/1000/podman/podman.sock -forward-dest /run/user/1000/podman/podman.sock -forward-dest /run/user/1000/podman/podman.sock -pid-file C:\\Users\\JEFFMA~1\\AppData\\Local\\Temp\\podman\\gvproxy.pid -log-file C:\\Users\\JEFFMA~1\\AppData\\Local\\Temp\\podman\\gvproxy.log"
time="2025-04-24T19:44:35+02:00" level=debug msg="socket length for C:\\Users\\Jeff Maury\\.config\\containers\\podman\\machine\\hyperv\\h1.ign is 67"
time="2025-04-24T19:44:36+02:00" level=info msg="Going to stop gvproxy (PID 3852)"
time="2025-04-24T19:44:36+02:00" level=debug msg="Closing windows on thread 13932"
time="2025-04-24T19:44:36+02:00" level=debug msg="Closing windows on thread 10904"
time="2025-04-24T19:44:36+02:00" level=debug msg="Closing windows on thread 33072"
time="2025-04-24T19:44:36+02:00" level=debug msg="Closing windows on thread 6372"
time="2025-04-24T19:44:36+02:00" level=debug msg="Closing windows on thread 27064"
time="2025-04-24T19:44:36+02:00" level=debug msg="Closing windows on thread 13296"
time="2025-04-24T19:44:36+02:00" level=debug msg="Closing windows on thread 12752"
time="2025-04-24T19:44:36+02:00" level=debug msg="Closing windows on thread 25128"
time="2025-04-24T19:44:36+02:00" level=debug msg="Closing windows on thread 26704"
time="2025-04-24T19:44:36+02:00" level=debug msg="Closing windows on thread 36332"
time="2025-04-24T19:44:36+02:00" level=debug msg="Closing windows on thread 22264"
time="2025-04-24T19:44:36+02:00" level=debug msg="Closing windows on thread 33592"
time="2025-04-24T19:44:36+02:00" level=debug msg="Closing windows on thread 3524"
time="2025-04-24T19:44:36+02:00" level=debug msg="Closing windows on thread 24836"
time="2025-04-24T19:44:36+02:00" level=debug msg="completed grace quit || kill of gvproxy (PID 3852)"
time="2025-04-24T19:44:36+02:00" level=debug msg="verified gvproxy termination (PID 3852)"
time="2025-04-24T19:44:36+02:00" level=debug msg="writing configuration file \"C:\\\\Users\\\\Jeff Maury\\\\.config\\\\containers\\\\podman\\\\machine\\\\hyperv\\\\h1.json\""
Error: Illegal argument (key already exists?) (32773)
time="2025-04-24T19:44:36+02:00" level=debug msg="Shutting down engines"

Process finished with the exit code 125

jeffmaury avatar Apr 24 '25 17:04 jeffmaury

@jeffmaury Thank you for testing! The problem you get doesn't seem related to the problem this PR is trying to solve. In this case, machine start fails with error:

Error: Illegal argument (key already exists?) (32773)

Looking at the code, for some reason, the podman client is trying to add the ignition keys/values in the registry (as if it was the first start) but the keys/values are already there. You can try to do a machine reset or use a different name for the machine.

l0rd avatar Apr 25 '25 10:04 l0rd

@jeffmaury Thank you for testing! The problem you get doesn't seem related to the problem this PR is trying to solve. In this case, machine start fails with error:

Error: Illegal argument (key already exists?) (32773)

Looking at the code, for some reason, the podman client is trying to add the ignition keys/values in the registry (as if it was the first start) but the keys/values are already there. You can try to do a machine reset or use a different name for the machine.

Same error with:

  • podman machine reset
  • podman machine init --rootful h11
  • podman machine start h11

jeffmaury avatar Apr 25 '25 11:04 jeffmaury

When you say same error you mean "key already exist" or "accepts 2 arg(s), received 3"?

l0rd avatar Apr 25 '25 13:04 l0rd

When you say same error you mean "key already exist" or "accepts 2 arg(s), received 3"?

$ podman machine start h11 --log-level debug
time="2025-04-25T17:27:39+02:00" level=info msg="C:\\Users\\Jeff Maury\\work\\containers\\podman\\bin\\windows\\podman.exe filtering at log level debug"
time="2025-04-25T17:27:39+02:00" level=debug msg="Using Podman machine with `hyperv` virtualization provider"
time="2025-04-25T17:27:39+02:00" level=debug msg="socket length for C:\\Users\\Jeff Maury\\.config\\containers\\podman\\machine\\hyperv is 60"
time="2025-04-25T17:27:39+02:00" level=debug msg="socket length for C:\\Users\\Jeff Maury\\.local\\share\\containers\\podman\\machine\\hyperv is 65"
time="2025-04-25T17:27:39+02:00" level=debug msg="socket length for C:\\Users\\Jeff Maury\\.local\\share\\containers\\podman\\machine\\hyperv\\cache is 71"
time="2025-04-25T17:27:39+02:00" level=debug msg="socket length for C:\\Users\\JEFFMA~1\\AppData\\Local\\Temp\\podman is 43"
time="2025-04-25T17:27:39+02:00" level=debug msg="socket length for C:\\Users\\Jeff Maury\\.config\\containers\\podman\\machine\\hyperv\\h11.json is 69"
Starting machine "h11"
time="2025-04-25T17:27:39+02:00" level=debug msg="socket length for C:\\Users\\Jeff Maury\\.config\\containers\\podman\\machine\\wsl is 57"
time="2025-04-25T17:27:39+02:00" level=debug msg="socket length for C:\\Users\\Jeff Maury\\.local\\share\\containers\\podman\\machine\\wsl is 62"
time="2025-04-25T17:27:39+02:00" level=debug msg="socket length for C:\\Users\\Jeff Maury\\.local\\share\\containers\\podman\\machine\\wsl\\cache is 68"
time="2025-04-25T17:27:39+02:00" level=debug msg="socket length for C:\\Users\\JEFFMA~1\\AppData\\Local\\Temp\\podman is 43"
time="2025-04-25T17:27:39+02:00" level=debug msg="socket length for C:\\Users\\Jeff Maury\\.config\\containers\\podman\\machine\\wsl\\podman-machine-default.json is 85"
time="2025-04-25T17:27:39+02:00" level=debug msg="socket length for C:\\Users\\Jeff Maury\\.config\\containers\\podman\\machine\\hyperv is 60"
time="2025-04-25T17:27:39+02:00" level=debug msg="socket length for C:\\Users\\Jeff Maury\\.local\\share\\containers\\podman\\machine\\hyperv is 65"
time="2025-04-25T17:27:39+02:00" level=debug msg="socket length for C:\\Users\\Jeff Maury\\.local\\share\\containers\\podman\\machine\\hyperv\\cache is 71"
time="2025-04-25T17:27:39+02:00" level=debug msg="socket length for C:\\Users\\JEFFMA~1\\AppData\\Local\\Temp\\podman is 43"
time="2025-04-25T17:27:39+02:00" level=debug msg="socket length for C:\\Users\\Jeff Maury\\.config\\containers\\podman\\machine\\hyperv\\h11.json is 69"
time="2025-04-25T17:27:39+02:00" level=debug msg="writing configuration file \"C:\\\\Users\\\\Jeff Maury\\\\.config\\\\containers\\\\podman\\\\machine\\\\hyperv\\\\h11.json\""
time="2025-04-25T17:27:39+02:00" level=debug msg="socket length for C:\\Users\\JEFFMA~1\\AppData\\Local\\Temp\\podman\\gvproxy.pid is 55"
time="2025-04-25T17:27:39+02:00" level=debug msg="socket length for C:\\Users\\Jeff Maury\\.config\\containers\\podman\\machine\\hyperv is 60"
time="2025-04-25T17:27:39+02:00" level=debug msg="socket length for C:\\Users\\Jeff Maury\\.local\\share\\containers\\podman\\machine\\hyperv is 65"
time="2025-04-25T17:27:39+02:00" level=debug msg="socket length for C:\\Users\\Jeff Maury\\.local\\share\\containers\\podman\\machine\\hyperv\\cache is 71"
time="2025-04-25T17:27:39+02:00" level=debug msg="socket length for C:\\Users\\JEFFMA~1\\AppData\\Local\\Temp\\podman is 43"
time="2025-04-25T17:27:39+02:00" level=debug msg="socket length for C:\\Users\\JEFFMA~1\\AppData\\Local\\Temp\\podman\\h11-api.sock is 56"
time="2025-04-25T17:27:39+02:00" level=debug msg="{true 1500 map[forward-dest:[/run/podman/podman.sock /run/podman/podman.sock /run/podman/podman.sock] forward-identity:[C:\\Users\\Jeff Maury\\.local\\share\\containers\\podman\\machine\\machine C:\\Users\\Jeff Maury\\.local\\share\\containers\\podman\\machine\\machine C:\\Users\\Jeff Maury\\.local\\share\\containers\\podman\\machine\\machine] forward-sock:[npipe:////./pipe/podman-h11 npipe:////./pipe/docker_engine unix:///C:/Users/JEFFMA~1/AppData/Local/Temp/podman/h11-api.sock] forward-user:[root root root]] [] [] map[] C:\\Users\\JEFFMA~1\\AppData\\Local\\Temp\\podman\\gvproxy.log C:\\Users\\JEFFMA~1\\AppData\\Local\\Temp\\podman\\gvproxy.pid 51254}"
time="2025-04-25T17:27:39+02:00" level=debug msg="gvproxy command-line: C:\\Users\\Jeff Maury\\work\\containers\\podman\\bin\\windows\\gvproxy.exe -listen vsock://0000C881-FACB-11E6-BD58-64006A7986D3 -debug -mtu 1500 -ssh-port 51254 -forward-sock npipe:////./pipe/podman-h11 -forward-sock npipe:////./pipe/docker_engine -forward-sock unix:///C:/Users/JEFFMA~1/AppData/Local/Temp/podman/h11-api.sock -forward-dest /run/podman/podman.sock -forward-dest /run/podman/podman.sock -forward-dest /run/podman/podman.sock -forward-user root -forward-user root -forward-user root -forward-identity C:\\Users\\Jeff Maury\\.local\\share\\containers\\podman\\machine\\machine -forward-identity C:\\Users\\Jeff Maury\\.local\\share\\containers\\podman\\machine\\machine -forward-identity C:\\Users\\Jeff Maury\\.local\\share\\containers\\podman\\machine\\machine -pid-file C:\\Users\\JEFFMA~1\\AppData\\Local\\Temp\\podman\\gvproxy.pid -log-file C:\\Users\\JEFFMA~1\\AppData\\Local\\Temp\\podman\\gvproxy.log"
time="2025-04-25T17:27:40+02:00" level=debug msg="socket length for C:\\Users\\Jeff Maury\\.config\\containers\\podman\\machine\\hyperv\\h11.ign is 68"
time="2025-04-25T17:27:40+02:00" level=info msg="Going to stop gvproxy (PID 39616)"
time="2025-04-25T17:27:40+02:00" level=debug msg="Closing windows on thread 27584"
time="2025-04-25T17:27:40+02:00" level=debug msg="Closing windows on thread 32808"
time="2025-04-25T17:27:40+02:00" level=debug msg="Closing windows on thread 35000"
time="2025-04-25T17:27:40+02:00" level=debug msg="Closing windows on thread 40096"
time="2025-04-25T17:27:40+02:00" level=debug msg="Closing windows on thread 14076"
time="2025-04-25T17:27:40+02:00" level=debug msg="Closing windows on thread 19140"
time="2025-04-25T17:27:40+02:00" level=debug msg="Closing windows on thread 38240"
time="2025-04-25T17:27:40+02:00" level=debug msg="Closing windows on thread 39820"
time="2025-04-25T17:27:40+02:00" level=debug msg="Closing windows on thread 37988"
time="2025-04-25T17:27:40+02:00" level=debug msg="Closing windows on thread 11832"
time="2025-04-25T17:27:40+02:00" level=debug msg="Closing windows on thread 37168"
time="2025-04-25T17:27:40+02:00" level=debug msg="Closing windows on thread 12160"
time="2025-04-25T17:27:40+02:00" level=debug msg="Closing windows on thread 35180"
time="2025-04-25T17:27:40+02:00" level=debug msg="completed grace quit || kill of gvproxy (PID 39616)"
time="2025-04-25T17:27:40+02:00" level=debug msg="verified gvproxy termination (PID 39616)"
time="2025-04-25T17:27:40+02:00" level=debug msg="writing configuration file \"C:\\\\Users\\\\Jeff Maury\\\\.config\\\\containers\\\\podman\\\\machine\\\\hyperv\\\\h11.json\""
Error: Illegal argument (key already exists?) (32773)
time="2025-04-25T17:27:40+02:00" level=debug msg="Shutting down engines"

jeffmaury avatar Apr 25 '25 15:04 jeffmaury

Opened a distinct issue for the Error: Illegal argument (key already exists?) (32773) problem (that is unrelated to this PR).

l0rd avatar Apr 30 '25 08:04 l0rd

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: l0rd, Luap99

The full list of commands accepted by this bot can be found here.

The pull request process is described here

Needs approval from an approver in each of these files:

Approvers can indicate their approval by writing /approve in a comment Approvers can cancel approval by writing /approve cancel in a comment

openshift-ci[bot] avatar Apr 30 '25 11:04 openshift-ci[bot]

@containers/podman-maintainers PTAL The tests are green, and we have verified with @jeffmaury that the PR fixes the problem that prevented running HyperV on his laptop.

l0rd avatar May 02 '25 12:05 l0rd

/lgtm

mheon avatar May 02 '25 13:05 mheon

@mheon I am adding the 5.5 label as it would be nice to include this fix in the next release.

l0rd avatar May 07 '25 17:05 l0rd

/cherry-pick v5.5

Luap99 avatar May 07 '25 17:05 Luap99

@Luap99: new pull request created: #26093

In response to this:

/cherry-pick v5.5

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes-sigs/prow repository.