canonical / multipass

Multipass orchestrates virtual Ubuntu instances
https://multipass.run
GNU General Public License v3.0
7.63k stars 635 forks source link

Multipass --cloud-init failing to pass over ssh key for defined user #3398

Closed ibiscardigan closed 6 months ago

ibiscardigan commented 6 months ago

Description I'm creating an ubuntu vm on MacOs using Multipass. When I pass the --cloud-init configuration for some reason it generates an unexpected ssh-rsa key for ubuntu@localhost but not for my defined user. this means I can't ssh into the new vm.

To Reproduce

  1. cloud-init.yml:
    
    #cloud-config

users:

write_files:

  1. multipass launch -n testvm --cloud-init cloud-init.yml
  2. multipass shell testvm
  3. nano /.ssh/authorized_keys

Expected behavior I would expect the provided ssh_rsa key for test user to exist and thus be able to ssh into the vm

Logs

[2024-02-03T21:26:28.391] [debug] [ssh session] Executing 'ip -brief -family inet address show scope global'
[2024-02-03T21:26:28.895] [debug] [qemu-system-aarch64] [90435] started: qemu-system-aarch64 --version
[2024-02-03T21:26:28.922] [debug] [qemu-img] [90436] started: qemu-img info /var/root/Library/Caches/multipassd/qemu/vault/images/jammy-20240126/ubuntu-22.04-server-cloudimg-arm64.img
[2024-02-03T21:26:28.935] [debug] [qemu-img] [90437] started: qemu-img resize /var/root/Library/Application Support/multipassd/qemu/vault/instances/testvm/ubuntu-22.04-server-cloudimg-arm64.img 8589934592
[2024-02-03T21:26:28.945] [debug] [qemu-img] [90438] started: qemu-img snapshot -l /var/root/Library/Application Support/multipassd/qemu/vault/instances/testvm/ubuntu-22.04-server-cloudimg-arm64.img
[2024-02-03T21:26:28.952] [debug] [qemu-img] [90439] started: qemu-img amend -o compat=1.1 /var/root/Library/Application Support/multipassd/qemu/vault/instances/testvm/ubuntu-22.04-server-cloudimg-arm64.img
[2024-02-03T21:26:28.959] [debug] [testvm] process working dir ''
[2024-02-03T21:26:28.959] [info] [testvm] process program 'qemu-system-aarch64'
[2024-02-03T21:26:28.959] [info] [testvm] process arguments '-machine, virt,gic-version=3, -accel, hvf, -drive, file=/Library/Application Support/com.canonical.multipass/bin/../Resources/qemu/edk2-aarch64-code.fd,if=pflash,format=raw,readonly=on, -cpu, host, -nic, vmnet-shared,model=virtio-net-pci,mac=52:54:00:c0:15:0c, -device, virtio-scsi-pci,id=scsi0, -drive, file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/testvm/ubuntu-22.04-server-cloudimg-arm64.img,if=none,format=qcow2,discard=unmap,id=hda, -device, scsi-hd,drive=hda,bus=scsi0.0, -smp, 1, -m, 1024M, -qmp, stdio, -chardev, null,id=char0, -serial, chardev:char0, -nographic, -cdrom, /var/root/Library/Application Support/multipassd/qemu/vault/instances/testvm/cloud-init-config.iso'
[2024-02-03T21:26:28.961] [debug] [qemu-system-aarch64] [90440] started: qemu-system-aarch64 -machine virt,gic-version=3 -nographic -dump-vmstate /private/var/folders/zz/zyxvpxvq6csfxvn_n0000000000000/T/multipassd.zswAbB
[2024-02-03T21:26:29.002] [info] [testvm] process state changed to Starting
[2024-02-03T21:26:29.003] [info] [testvm] process state changed to Running
[2024-02-03T21:26:29.003] [debug] [qemu-system-aarch64] [90441] started: qemu-system-aarch64 -machine virt,gic-version=3 -accel hvf -drive file=/Library/Application Support/com.canonical.multipass/bin/../Resources/qemu/edk2-aarch64-code.fd,if=pflash,format=raw,readonly=on -cpu host -nic vmnet-shared,model=virtio-net-pci,mac=52:54:00:c0:15:0c -device virtio-scsi-pci,id=scsi0 -drive file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/testvm/ubuntu-22.04-server-cloudimg-arm64.img,if=none,format=qcow2,discard=unmap,id=hda -device scsi-hd,drive=hda,bus=scsi0.0 -smp 1 -m 1024M -qmp stdio -chardev null,id=char0 -serial chardev:char0 -nographic -cdrom /var/root/Library/Application Support/multipassd/qemu/vault/instances/testvm/cloud-init-config.iso
[2024-02-03T21:26:29.003] [info] [testvm] process started
[2024-02-03T21:26:29.004] [debug] [testvm] Waiting for SSH to be up
[2024-02-03T21:26:29.034] [debug] [testvm] QMP: {"QMP": {"version": {"qemu": {"micro": 0, "minor": 0, "major": 8}, "package": ""}, "capabilities": ["oob"]}}

[2024-02-03T21:26:29.051] [debug] [testvm] QMP: {"return": {}}

[2024-02-03T21:26:41.914] [debug] [testvm] QMP: {"timestamp": {"seconds": 1706956001, "microseconds": 914578}, "event": "NIC_RX_FILTER_CHANGED", "data": {"path": "/machine/unattached/device[6]/virtio-backend"}}

[2024-02-03T21:26:46.187] [debug] [ssh session] Executing '[ -e /var/lib/cloud/instance/boot-finished ]'
[2024-02-03T21:26:48.294] [debug] [ssh session] Executing '[ -e /var/lib/cloud/instance/boot-finished ]'
[2024-02-03T21:26:49.488] [debug] [ssh session] Executing '[ -e /var/lib/cloud/instance/boot-finished ]'
[2024-02-03T21:26:50.664] [debug] [ssh session] Executing '[ -e /var/lib/cloud/instance/boot-finished ]'
[2024-02-03T21:26:51.792] [debug] [ssh session] Executing '[ -e /var/lib/cloud/instance/boot-finished ]'
[2024-02-03T21:26:52.911] [debug] [ssh session] Executing '[ -e /var/lib/cloud/instance/boot-finished ]'
[2024-02-03T21:26:54.021] [debug] [ssh session] Executing '[ -e /var/lib/cloud/instance/boot-finished ]'
[2024-02-03T21:26:54.326] [debug] [daemon] Deleting instance: worknow
[2024-02-03T21:26:54.327] [debug] [worknow] QMP: {"return": {}}

[2024-02-03T21:26:54.327] [debug] [worknow] QMP: {"timestamp": {"seconds": 1706956014, "microseconds": 327263}, "event": "POWERDOWN"}

[2024-02-03T21:26:54.327] [info] [worknow] VM powering down
[2024-02-03T21:26:57.879] [debug] [worknow] QMP: {"timestamp": {"seconds": 1706956017, "microseconds": 879360}, "event": "SHUTDOWN", "data": {"guest": true, "reason": "guest-shutdown"}}

[2024-02-03T21:26:57.879] [info] [worknow] VM shut down
[2024-02-03T21:26:57.891] [info] [worknow] process state changed to NotRunning
[2024-02-03T21:26:57.891] [info] [worknow] process finished with exit code 0
[2024-02-03T21:26:57.892] [debug] [daemon] Instance deleted: worknow
[2024-02-03T21:26:58.097] [debug] [daemon] Instance purged: worknow
[2024-02-03T21:27:29.740] [debug] [testvm] QMP: {"timestamp": {"seconds": 1706956049, "microseconds": 740497}, "event": "RTC_CHANGE", "data": {"offset": 1, "qom-path": "/machine/unattached/device[4]"}}

[2024-02-03T21:35:08.290] [debug] [async task] fetch manifest periodically
[2024-02-03T21:35:08.298] [info] [VMImageHost] Did not find any supported products in "appliance"
[2024-02-03T21:37:46.271] [debug] [ssh session] Executing 'cat /proc/loadavg | cut -d ' ' -f1-3'
[2024-02-03T21:37:46.506] [debug] [ssh session] Executing 'free -b | grep 'Mem:' | awk '{printf $3}''
[2024-02-03T21:37:46.513] [debug] [ssh session] Executing 'free -b | grep 'Mem:' | awk '{printf $2}''
[2024-02-03T21:37:46.519] [debug] [ssh session] Executing 'df -t ext4 -t vfat --total -B1 --output=used | tail -n 1'
[2024-02-03T21:37:46.524] [debug] [ssh session] Executing 'df -t ext4 -t vfat --total -B1 --output=size | tail -n 1'
[2024-02-03T21:37:46.528] [debug] [ssh session] Executing 'nproc'
[2024-02-03T21:37:46.565] [debug] [ssh session] Executing 'ip -brief -family inet address show scope global'
[2024-02-03T21:37:46.599] [debug] [ssh session] Executing 'cat /etc/os-release | grep 'PRETTY_NAME' | cut -d \" -f2'
[2024-02-03T21:38:38.676] [debug] [daemon] Returning setting local.driver=qemu
[2024-02-03T21:38:49.020] [debug] [testvm] QMP: {"timestamp": {"seconds": 1706956729, "microseconds": 20385}, "event": "RTC_CHANGE", "data": {"offset": 0, "qom-path": "/machine/unattached/device[4]"}}

Additional info

Name: testvm State: Running Snapshots: 0 IPv4: 192.168.64.29 Release: Ubuntu 22.04.3 LTS Image hash: dddfb1741f16 (Ubuntu 22.04 LTS) CPU(s): 1 Load: 0.01 0.01 0.00 Disk usage: 1.4GiB out of 7.7GiB Memory usage: 141.2MiB out of 962.3MiB Mounts: --

Additional context Add any other context about the problem here. Originally I was running this via ansible and has assumed there was an ansible issue but after I added the write file block to verify its getting the right arg it became clear this appears to be a Multipass issue.

townsend2010 commented 6 months ago

Hi @ibiscardigan,

Multipass supplies the ssh key for the ubuntu user inside the instance. Without this, Multipass would not be able to ssh into the instance to get status nor would multipass shell and multipass exec work. However, you should be able to ssh into the instance using testuser@.... Is this not working?

ibiscardigan commented 6 months ago

That is correct, it doesn’t create the test user key in the authorised keys file. this means I can still access via the multi pass shell testvm command, but if I want to automate this via something like ansible which relies on that ssh access it creates a real issue.

townsend2010 commented 6 months ago

Hi @ibiscardigan!

I tried your cloud-init file and it does what it is directed to do. I see a testuser user and in /home/testuser/.ssh/authorized_keys, I see the key there. Is this not what you are trying to accomplish?

ibiscardigan commented 6 months ago

I’m not getting that behaviour on my machines unfortunately. I have tried uninstalling and reinstalling multi pass to get this to work but despite my best efforts it’s not worked for me. Happy to try some other troubleshooting steps to better understand why multi pass behaviour in my machine has unexpected behaviour.

townsend2010 commented 6 months ago

From within your Multipass instance, could you please provide the contents of /var/log/cloud-init.log and /var/log/cloud-init-output.log? This should show what cloud-init is doing here. Thanks!

ibiscardigan commented 6 months ago

cloud-init.log

cloud-init-output.log

ibiscardigan commented 6 months ago

Also that's from a new vm that I was trying to spin up, desired user is 'hamson', machine name is 'please' (I was getting desperate at this stage).

Looks like this is creating the problem: Error: Cloud config schema errors: users.1: {'name': 'hamson', 'ssh_authorised_keys': ['ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9U7ibPiGbTNnAmDkcxa+/pTfIXt62/pxLN6Iu3fOR/rvXsvkfTKtsagymjPOIOerBusrV2aiakjH81uKVKNg3u4OwocvBoslGQRqoKLC1Ln7Tf30qItx2Nw0kJd+Ikl2YlLrrtwn9UtM8nACvT4hoWwKs/whJW6GWK3z4QniSBDQ9aPpFDJewhYOy4nF7OieTR/ADjkjiBoT8iW/msc6Ski6vlKOw0jme6O3Oj9H/tfRUwGcjqcwwBDl4iCGYf/ujWc+4uLdk/ehe8ewQxkyYPLL0PIjl0P0B6HA0PfRdTwNmy8V4DjV/yoD4vB4h9qnxZaHW9L5EUgpE2INtXao/ hamson'], 'sudo': 'ALL=(ALL) NOPASSWD:ALL'} is not of type 'string', users.1: {'name': 'hamson', 'ssh_authorised_keys': ['ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9U7ibPiGbTNnAmDkcxa+/pTfIXt62/pxLN6Iu3fOR/rvXsvkfTKtsagymjPOIOerBusrV2aiakjH81uKVKNg3u4OwocvBoslGQRqoKLC1Ln7Tf30qItx2Nw0kJd+Ikl2YlLrrtwn9UtM8nACvT4hoWwKs/whJW6GWK3z4QniSBDQ9aPpFDJewhYOy4nF7OieTR/ADjkjiBoT8iW/msc6Ski6vlKOw0jme6O3Oj9H/tfRUwGcjqcwwBDl4iCGYf/ujWc+4uLdk/ehe8ewQxkyYPLL0PIjl0P0B6HA0PfRdTwNmy8V4DjV/yoD4vB4h9qnxZaHW9L5EUgpE2INtXao/ hamson'], 'sudo': 'ALL=(ALL) NOPASSWD:ALL'} is not valid under any of the given schemas

townsend2010 commented 6 months ago

It looks cloud-init does not like the schema you provided. That looks different than the example you pasted in the original description, so I can't really tell. All I can see in the logs you provided is:

2024-02-02 11:49:22,224 - schema.py[WARNING]: Invalid cloud-config provided: Please run 'sudo cloud-init schema --system' to see the schema errors.
ibiscardigan commented 6 months ago

exact same schema as before just new ssh key and user name:

users:
  - default
  - name: hamson
    sudo: ALL=(ALL) NOPASSWD:ALL
    ssh_authorised_keys:
      - "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9U7ibPiGbTNnAmDkcxa+/pTfIXt62/pxLN6Iu3fOR/rvXsvkfTKtsagymjPOIOerBusrV2aiakjH81uKVKNg3u4OwocvBoslGQRqoKLC1Ln7Tf30qItx2Nw0kJd+Ikl2YlLrrtwn9UtM8nACvT4hoWwKs/whJW6GWK3z4QniSBDQ9aPpFDJewhYOy4nF7OieTR/ADjkjiBoT8iW/msc6Ski6vlKOw0jme6O3Oj9H/tfRUwGcjqcwwBDl4iCGYf/ujWc+4uLdk/ehe8ewQxkyYPLL0PIjl0P0B6HA0PfRdTwNmy8V4DjV/yoD4vB4h9qnxZaHW9L5EUgpE2INtXao/ hamson"
townsend2010 commented 6 months ago

Well, in the latest cloud-init you posted, I think cloud-init may prefer American English :zany_face: since the key is ssh_authorized_keys (with a z instead of s in authorized). See if that helps the current issue. I do see in the original example, you had z, but that one does work for me.

ibiscardigan commented 6 months ago

Interesting, when I recopied the template from the guides including using a z (good old freedom English) I didn't get the same Invalid cloud-config error despite the fact it still hadn't provisioned the ssh key. All relevant files attached: cloud-init.log cloud-init-output.log

cloud-init:

#cloud-config

users:
  - default
  - name: hamson
    sudo: ALL=(ALL) NOPASSWD:ALL
    ssh_authorized_keys:
      - "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQCzQVJnNSJA8SzDFdcgKylL9OPsT30jW+fypMFuq2kOI7W8MOVYGK7GGJQB2mnzEpsPMCghgv+KptQyyyZP28NhOCmGV2vGqXaliAVgLHuyvCaLr1N3p4rPKQ3XCtABhDW1GB3MWGw6kXPQ19UiD19c6hxmJk+G0azDvWVajF8UPLZs/407taBZcTvg5u8ArzpIORzfiQ9SsA7ANDC5zulfMiW9ywSkveszS5Qm63zco17wuch7mNqKw1OnZUZWWtmi5GkwTES67b4s8lSAcwTB6jrlZN1YHQ+fm2QM1oRaY31kRqqxjYqQmRWi8fvBTvsw5Puj0TRdMKQz+DKrTt8n hamson"

write_files:
- content: Validated Run | "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQCzQVJnNSJA8SzDFdcgKylL9OPsT30jW+fypMFuq2kOI7W8MOVYGK7GGJQB2mnzEpsPMCghgv+KptQyyyZP28NhOCmGV2vGqXaliAVgLHuyvCaLr1N3p4rPKQ3XCtABhDW1GB3MWGw6kXPQ19UiD19c6hxmJk+G0azDvWVajF8UPLZs/407taBZcTvg5u8ArzpIORzfiQ9SsA7ANDC5zulfMiW9ywSkveszS5Qm63zco17wuch7mNqKw1OnZUZWWtmi5GkwTES67b4s8lSAcwTB6jrlZN1YHQ+fm2QM1oRaY31kRqqxjYqQmRWi8fvBTvsw5Puj0TRdMKQz+DKrTt8n hamson"
  path: /tmp/test.txt

authorized-keys: ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDqPtuU0jc1xaPo5VhO5g/zvqx7mfUXXQRK3yC7prUW636hOhSvh31gLVwW8Sf84ph5q/Ig5CQvWtx4P2MRb9u4ywChqVEttB3I4WTifjS7v+nD3nVBDErpxVi5Vw2h4G+gFTlKLitmfDvyPwRlHWPlpyY7a0UPC2aPwsVx2mdKBHg8VwadtDc4PBdxl3GFGilX+AAh9pOYreJIh8VJO21sIHK8j5RB/iydcWDRAeZllHcQ3rVUPb7CooJKErQCnVUGcNJjHs0pLKh6wUOuuFyKUWCqmrmklm/iRbso1vhWa7XUzHIQhnA7ce4OgsfQVUuKoSja42AV/MrM/C7Ok6AT ubuntu@localhost

townsend2010 commented 6 months ago

I see in cloud-init.log that cloud-init wrote the key out:

2024-02-05 20:37:41,358 - util.py[DEBUG]: Writing to /home/hamson/.ssh/authorized_keys - wb: [600] 388 bytes

Are you saying that key is not in the instance?

ibiscardigan commented 6 months ago

Ahhhh, I think ive found where my troubleshooting has been going askew, when I was logging into the Multipass vm via shell I was assuming it was taking me to the new user and not thinking to valid I was actually in the /home/hamson dir before looking at the authorised keys file. Im happy you close this for now as I see the file there and the problem clould be (is likely to be) on my Mac side trying to authenticate into the vm.

Thank you so much for your help, I learnt a lot

townsend2010 commented 6 months ago

Hi @ibiscardigan!

Glad you are working it out! Please let us know if you any issues with Multipass.

margani commented 4 months ago

I had this issue, and realised that the file path for --cloud-init parameter was incorrect. Correcting the file path fixed it.

Using Multipass in Windows, the incorrect path:

multipass launch docker ... --cloud-init infrastructure/multipass/cloud-init.yaml

Correct one:

multipass launch docker ... --cloud-init .\infrastructure\multipass\cloud-init.yaml