colima icon indicating copy to clipboard operation
colima copied to clipboard

[hostagent] Waiting for the essential requirement 1 of 5: "ssh" on M1 Mac monterey

Open rjra2611 opened this issue 2 years ago • 49 comments
trafficstars

Description

Hey,

I'm trying to run colima start --cpu 4 --memory 8 after a fresh brew install on my M1 Mac monterey but it seems to hang

serial (9).log

Also tried colima start --cpu 4 --memory 8 --cpu-type qemu64 which gave error at 'creating and starting': exit status 1

image

Logs for colima start --cpu 4 --memory 8 --arch x86_64

serial (10).log

Tried using profile as well colima start test --verbose but it still hangs

image

Version

Colima Version:

  • colima version 0.5.4

Lima Version:

image

Qemu Version:

  • qemu-img version 8.0.0

image

Which colima

image

Which qemu-img

image

Operating System

  • [ ] macOS Intel <= 12 (Monterrey)
  • [ ] macOS Intel >= 13 (Ventura)
  • [X] macOS M1 <= 12 (Monterrey)
  • [ ] macOS M1 >= 13 (Ventura)
  • [ ] Linux

Output of colima status

FATA[0000] colima is not running

Reproduction Steps

  1. brew install colima
  2. colima start --cpu 4 --memory 8

Expected behaviour

colima start should not hang

Additional context

No response

rjra2611 avatar May 02 '23 20:05 rjra2611

Can you share the output of ~/.lima/colima/ha.stderr.log ?

abiosoft avatar May 04 '23 17:05 abiosoft

Sure, there you go, I believe this is from the latest run which was using the command colima start test --verbose

ha.stderr.log

rjra2611 avatar May 04 '23 17:05 rjra2611

Looking at the logs, I found this which seems like the qemu process is getting terminated abruptly somehow.

{"level":"debug","msg":"qemu[stderr]: qemu-system-aarch64: terminating on signal 2 from pid 2301 (\u003cunknown process\u003e)","time":"2023-05-02T21:13:50+01:00"}
{"level":"info","msg":"Received SIGINT, shutting down the host agent","time":"2023-05-02T21:13:50+01:00"}

abiosoft avatar May 04 '23 18:05 abiosoft

It's a bit strange that the qemu-system-aarch64 binary is being used since you are using the --arch x86_64.

abiosoft avatar May 04 '23 18:05 abiosoft

Looking at the logs, I found this which seems like the qemu process is getting terminated abruptly somehow.

Anything I can do to get better logs to identify the reason? Could it be the log of the keyboard interrupt to stop the process as it was waiting for too long

It's a bit strange that the qemu-system-aarch64 binary is being used since you are using the --arch x86_64.

As I mentioned above these logs seems to be from the latest run where I tried colima start test --verbose

ha.stderr.log

rjra2611 avatar May 04 '23 19:05 rjra2611

@rjra2611 just to confirm, this only happens when you're simulating x86_64 right?

abiosoft avatar May 04 '23 19:05 abiosoft

this only happens when you're simulating x86_64 right?

Nope, as shared in the issue description. I tried the following:

  1. colima start --cpu 4 --memory 8
  2. colima start --cpu 4 --memory 8 --arch x86_64
  3. colima start test --verbose

But got Waiting for the essential requirement 1 of 5: "ssh" for all of the above.

The only command which gave me a different result was colima start --cpu 4 --memory 8 --cpu-type qemu64 as shared in the issue description

image

rjra2611 avatar May 04 '23 19:05 rjra2611

You cannot change an architecture of an existing VM. If you initially created with --arch x86_64 and stopped the VM, the next start would not change the architecture even if you specify a --arch aarch64.

You will need to either create a new instance by specifying the profile name colima start profile2 or you delete the existing profile colima delete.

abiosoft avatar May 04 '23 19:05 abiosoft

@abiosoft I did a fresh install and tried stop/delete/status before running colima start profile2 --cpu 4 --memory 8 but got the same result. Sharing my logs for review:

  • terminal logs
  • serial logs
  • stderr.logs

ha.stderr (1).log

Terminal Saved Output.txt

serial (11).log

rjra2611 avatar May 04 '23 20:05 rjra2611

@rjra2611 you should probably also make sure you've done these when testing:

  • a successful brew upgrade
  • rm -r ~/.colima ~/.lima

I use colima 0.5.4 with limactl 0.15.1 every day on mac M1, so so do dozens or hundreds of other DDEV users, so there must be something odd going on. I don't have a place to test with Monterrey, but lots of people are using it.

The setup we recommend for DDEV is colima start --cpu 4 --memory 6 --disk 100 --vm-type=qemu --mount-type=sshfs --dns=1.1.1.1

rfay avatar May 04 '23 20:05 rfay

Thanks, @rfay

Something worked, something didn't. I tried:

  1. brew update, brew upgrade
  2. colima uninstall/reinstall
  3. rm -r ~/.colima ~/.lima
  4. colima start --cpu 4 --memory 6 --disk 100 --vm-type=qemu --mount-type=sshfs --dns=1.1.1.1

But it doesn't work and says --vm-type flag not found. The help doesn't show the option as well. Colima is 0.5.4

image

What worked was using --arch x86_64

Logs from colima start profile4 --cpu 4 --memory 8 --arch x86_64

serial.log ha.stderr.log

As may require is NOT to start VM in x86_64 I tried

colima start --cpu 4 --memory 6 --disk 100 --mount-type=sshfs --dns=1.1.1.1 -- whcih didnt' work. Below are the logs for same.

ha.stderr.log serial.log

NOTE: Used this after colima delete to start from fresh

CC @abiosoft

rjra2611 avatar May 04 '23 21:05 rjra2611

I didn't remember, maybe --vm-type only works on current Ventura.

But running with --arch x68_64 is something which would be very, very unusual to use on mac M1.

Can you please show the output of which colima and of file $(which colima) ?

rfay avatar May 04 '23 22:05 rfay

Sure, here you go @rfay

image

Also, output of colima start profile4 --cpu 4 --memory 8 --arch x86_64 if it helps

image

rjra2611 avatar May 04 '23 22:05 rjra2611

I'm glad you have the arm64 colima, that's good, and you have homebrew installed in the right place; lots of people have trouble when they move to mac M1 because they copy /usr/local/bin with amd64 homebrew over to the new mac, and it doesn't work at all.

Your situation makes no sense at all :(

You really don't want x86_64 right? You want to be running arm64? x86_64 will be nothing but trouble and poor performance for you unless there's some exotic reason you really have to run x86_64/amd64.

I know you've already done this, but colima start p5 just fails right, and hangs? That should bring up an arm64 profile (assuming you haven't used p5 before)

rfay avatar May 04 '23 22:05 rfay

Please show which limactl and file $(which limactl) as well. If those were wrong, you'd get bizarre results like this. They should be arm64. And really, there should be nothing in /usr/local/Homebrew .

rfay avatar May 04 '23 23:05 rfay

I didn't remember, maybe --vm-type only works on current Ventura.

Yeah, it only works on Ventura.

abiosoft avatar May 05 '23 04:05 abiosoft

I have the same issue. I just updated brew and Colima stopped working. I'm on an M1 Macbook Pro, and Colima worked just fine yesterday.

~ ()$ Colima start
INFO[0000] starting colima                              
INFO[0000] runtime: docker                              
INFO[0000] preparing network ...                         context=vm
INFO[0000] starting ...                                  context=vm
> [hostagent] Waiting for the essential requirement 1 of 5: "ssh"
> [hostagent] Waiting for the essential requirement 1 of 5: "ssh"
> [hostagent] Waiting for the essential requirement 1 of 5: "ssh"
> [hostagent] Waiting for the essential requirement 1 of 5: "ssh"
> [hostagent] Waiting for the essential requirement 1 of 5: "ssh"
> [hostagent] Waiting for the essential requirement 1 of 5: "ssh"

What worked for me is doing

colima delete
brew reinstall colima
colima start

It still hung on ssh for a minute or two. But it ended up working after that. But your mileage may vary.

JoeLyga avatar May 05 '23 15:05 JoeLyga

@rfay sure there you go

image

Yup, nothing in /usr/local/Homebrew .

image

I know you've already done this, but colima start p5 just fails right, and hangs? That should bring up an arm64 profile (assuming you haven't used p5 before)

Yup, tried it as shared above with logs, sharing the screenshot here as well.

image

@abiosoft can you please look into it too. My use case is to only run colima with arm64 but currently only works when using x86_64 which seems like a very popular solution as per the comment here

rjra2611 avatar May 05 '23 15:05 rjra2611

That is totally bizarre. Thanks for trying it out.

rfay avatar May 05 '23 15:05 rfay

It may also be weirdness on my machine / network. But FYI in case this is an issue for anyone else.

JoeLyga avatar May 05 '23 15:05 JoeLyga

I have upgraded to colima-0.5.4 and am having a similar issue as well. I am on an Intel MacOS, have done colima delete and am having this:

$ colima start --very-verbose

TRAC[0000] cmd ["limactl" "info"]
TRAC[0000] cmd ["limactl" "list" "colima" "--json"]
TRAC[0000] error retrieving running instance: instance 'colima' does not exist
INFO[0000] starting colima
INFO[0000] runtime: docker
INFO[0000] preparing network ...                         context=vm
TRAC[0000] cmd ["/nix/store/gra06z3s0ysxl1zzx11b5d6zi2z23pg5-colima-0.5.4/bin/colima" "daemon" "status" "default"]
TRAC[0000] cmd ["/nix/store/gra06z3s0ysxl1zzx11b5d6zi2z23pg5-colima-0.5.4/bin/colima" "daemon" "start" "default" "--gvproxy" "--verbose"]
INFO[0000] creating and starting ...                     context=vm
TRAC[0000] cmd ["limactl" "start" "--tty=false" "/tmp/colima.yaml"]
> Terminal is not available, proceeding without opening an editor
> "Attempting to download the image from \"https://github.com/abiosoft/alpine-lima/releases/download/colima-v0.5.0-2/alpine-lima-clm-3.16.2-x86_64.iso\"" digest="sha512:e9e118498f3a0745574ffc3686105d2c9777f7142164fe50ee47909dabd504c80ac29aeb76f9582706173310d1488d3b6f0ee9018e2a6aadc28eefb7767b63ec"
> Using cache "/Users/alexey/Library/Caches/lima/download/by-url-sha256/e1cbaef56fc8e75af106d934389a17618643fcecfa066302d45ffb0390709851/data"
> [hostagent] Starting QEMU (hint: to watch the boot progress, see "/Users/alexey/.lima/colima/serial.log")
> SSH Local Port: 50229
> [hostagent] Waiting for the essential requirement 1 of 5: "ssh"
> [hostagent] Driver stopped due to error: "exit status 255"
> [hostagent] Shutting down the host agent
> [hostagent] failed to exit SSH master
> [hostagent] Shutting down QEMU with ACPI
> [hostagent] failed to open the QMP socket "/Users/alexey/.lima/colima/qmp.sock", forcibly killing QEMU
> [hostagent] failed to kill QEMU
> [hostagent] Waiting for the essential requirement 1 of 5: "ssh"
> [hostagent] Waiting for the essential requirement 1 of 5: "ssh"
> [hostagent] Waiting for the essential requirement 1 of 5: "ssh"
> [hostagent] Waiting for the essential requirement 1 of 5: "ssh"
> [hostagent] Waiting for the essential requirement 1 of 5: "ssh"
> [hostagent] Waiting for the essential requirement 1 of 5: "ssh"
> [hostagent] Waiting for the essential requirement 1 of 5: "ssh"
> [hostagent] Waiting for the essential requirement 1 of 5: "ssh"
> [hostagent] Waiting for the essential requirement 1 of 5: "ssh"
> [hostagent] Waiting for the essential requirement 1 of 5: "ssh"

At the same time:

$ colima list
PROFILE    STATUS    ARCH      CPUS    MEMORY    DISK     RUNTIME    ADDRESS
default    Broken    x86_64    2       2GiB      60GiB

It said that it can't open the sock, but it seems to be there:

ls -al ~/.lima/colima
drwx------ alexey staff 448 B  Sat May  6 17:25:18 2023  .
drwx------ alexey staff 128 B  Sat May  6 17:20:54 2023  ..
.rw-r--r-- alexey staff 290 MB Sat May  6 17:20:54 2023  basedisk
.rw-r--r-- alexey staff  37 MB Sat May  6 17:20:55 2023  cidata.iso
.rw-r--r-- alexey staff 193 KB Sat May  6 17:20:55 2023  diffdisk
.rw-r--r-- alexey staff   5 B  Sat May  6 17:20:55 2023  ha.pid
srwxr-xr-x alexey staff   0 B  Sat May  6 17:20:55 2023  ha.sock
.rw-r--r-- alexey staff  48 KB Sat May  6 17:27:19 2023  ha.stderr.log
.rw-r--r-- alexey staff  76 B  Sat May  6 17:20:55 2023  ha.stdout.log
.rw-r--r-- alexey staff 3.1 KB Sat May  6 17:20:54 2023  lima.yaml
srwxr-xr-x alexey staff   0 B  Sat May  6 17:20:55 2023  qmp.sock
.rw-r--r-- alexey staff   0 B  Sat May  6 17:20:55 2023  serial.log
srwxr-xr-x alexey staff   0 B  Sat May  6 17:20:55 2023  serial.sock
.rw------- alexey staff 720 B  Sat May  6 17:20:55 2023  ssh.config

AlexeyRaga avatar May 06 '23 07:05 AlexeyRaga

What might be good is cleanup and restart - and yes, restart sounds not needed, but if you had a system running for a while, and updated software etc - a clean restart might not be a bad idea.

What might be good to do:

  1. Make sure no lima or colima VMs are running
  2. Cleanup ~/.colima and ~/.lima
  3. Cleanup the cache here - $HOME/Library/Caches/lima/download/
  4. Make sure you run "brew update; brew upgrade" and that all is on latest versions.
  5. Now close all terminals and apps and reboot.
  6. When reboot is done, and logged in give it a minute - let all the MacOs background processes start.

Now try a basic setup: colima start -c2 -d10 -m2 --very-verbose and see what happens.

Also if any issues - maybe post the following so all is 100% sure what versions are in use:

sw_vers
uname -a
colima version
lima --version
qemu-img -V
/opt/colima/bin/socket_vmnet -version

aelsnz avatar May 07 '23 20:05 aelsnz

No, it did not work still :(

$ sw_vers
ProductName:		macOS
ProductVersion:		13.3.1
ProductVersionExtra:	(a)
BuildVersion:		22E772610a

$ uname -a
Darwin MacBook-Pro.local 22.4.0 Darwin Kernel Version 22.4.0: Mon Mar  6 21:00:17 PST 2023; root:xnu-8796.101.5~3/RELEASE_X86_64 x86_64 i386 Darwin

$ colima version
colima version 0.5.4
git commit: feef417

$ lima --version
limactl version 0.15.1

$ qemu-img -V
qemu-img version 8.0.0
Copyright (c) 2003-2022 Fabrice Bellard and the QEMU Project developers

And here are logs:

$ colima start -c2 -d10 -m2 --very-verbose
TRAC[0000] cmd ["limactl" "info"]
TRAC[0000] cmd ["limactl" "list" "colima" "--json"]
TRAC[0000] error retrieving running instance: instance 'colima' does not exist
INFO[0000] starting colima
INFO[0000] runtime: docker
INFO[0000] preparing network ...                         context=vm
TRAC[0000] cmd ["ln" "-sf" "/nix/store/gra06z3s0ysxl1zzx11b5d6zi2z23pg5-colima-0.5.4/bin/.colima-wrapped" "/Users/alexey/.colima/_wrapper/d7f6c041b026e94787f11d5084bf50491a1e6e02/bin/qemu-system-aarch64"]
TRAC[0000] cmd ["ln" "-sf" "/nix/store/gra06z3s0ysxl1zzx11b5d6zi2z23pg5-colima-0.5.4/bin/.colima-wrapped" "/Users/alexey/.colima/_wrapper/d7f6c041b026e94787f11d5084bf50491a1e6e02/bin/qemu-system-x86_64"]
TRAC[0000] cmd ["ln" "-sf" "/nix/store/mwl0pjmcddcm7wfplyi581q645xfp1iz-qemu-8.0.0/share" "/Users/alexey/.colima/_wrapper/d7f6c041b026e94787f11d5084bf50491a1e6e02/share"]
TRAC[0000] cmd ["/nix/store/gra06z3s0ysxl1zzx11b5d6zi2z23pg5-colima-0.5.4/bin/colima" "daemon" "status" "default"]
TRAC[0000] cmd ["/nix/store/gra06z3s0ysxl1zzx11b5d6zi2z23pg5-colima-0.5.4/bin/colima" "daemon" "start" "default" "--gvproxy" "--verbose"]
INFO[0000] creating and starting ...                     context=vm
TRAC[0000] cmd ["limactl" "start" "--tty=false" "/tmp/colima.yaml"]
> Terminal is not available, proceeding without opening an editor
> "Attempting to download the image from \"https://github.com/abiosoft/alpine-lima/releases/download/colima-v0.5.0-2/alpine-lima-clm-3.16.2-x86_64.iso\"" digest="sha512:e9e118498f3a0745574ffc3686105d2c9777f7142164fe50ee47909dabd504c80ac29aeb76f9582706173310d1488d3b6f0ee9018e2a6aadc28eefb7767b63ec"
>
> 18.18 MiB / 290.00 MiB (6.27%) ? p/s
> 40.45 MiB / 290.00 MiB (13.95%) 4.45 MiB/s
> 62.61 MiB / 290.00 MiB (21.59%) 4.45 MiB/s
> 86.37 MiB / 290.00 MiB (29.78%) 4.47 MiB/s
> 108.07 MiB / 290.00 MiB (37.27%) 4.46 MiB/s
> 131.12 MiB / 290.00 MiB (45.21%) 4.47 MiB/s
> 151.78 MiB / 290.00 MiB (52.34%) 4.45 MiB/s
> 171.09 MiB / 290.00 MiB (59.00%) 4.41 MiB/s
> 194.01 MiB / 290.00 MiB (66.90%) 4.42 MiB/s
> 219.23 MiB / 290.00 MiB (75.60%) 4.46 MiB/s
> 243.12 MiB / 290.00 MiB (83.84%) 4.48 MiB/s
> 266.40 MiB / 290.00 MiB (91.86%) 4.50 MiB/s
> 287.43 MiB / 290.00 MiB (99.12%) 4.48 MiB/s
> 290.00 MiB / 290.00 MiB (100.00%) 4.79 MiB/stime="2023-05-08T17:03:05+10:00" level=info msg="Downloaded the image from \"https://github.com/abiosoft/alpine-lima/releases/download/colima-v0.5.0-2/alpine-lima-clm-3.16.2-x86_64.iso\""
> [hostagent] Starting QEMU (hint: to watch the boot progress, see "/Users/alexey/.lima/colima/serial.log")
> SSH Local Port: 56136
> [hostagent] Waiting for the essential requirement 1 of 5: "ssh"
> [hostagent] Driver stopped due to error: "exit status 255"
> [hostagent] Shutting down the host agent
> [hostagent] failed to exit SSH master
> [hostagent] Shutting down QEMU with ACPI
> [hostagent] failed to open the QMP socket "/Users/alexey/.lima/colima/qmp.sock", forcibly killing QEMU
> [hostagent] failed to kill QEMU
> [hostagent] Waiting for the essential requirement 1 of 5: "ssh"
> [hostagent] Waiting for the essential requirement 1 of 5: "ssh"

AlexeyRaga avatar May 08 '23 07:05 AlexeyRaga

It does look like you have qemu running already in this situation. We have asked about limactl current version a number of times, but not about qemu. You might want to brew uninstall all your qemu dependencies and reinstall them, and make sure qemu isn't running at all.

But these lines sure do seem to imply problems outside of colima:

> [hostagent] Driver stopped due to error: "exit status 255"
> [hostagent] Shutting down the host agent
> [hostagent] failed to exit SSH master
> [hostagent] Shutting down QEMU with ACPI
> [hostagent] failed to open the QMP socket "/Users/alexey/.lima/colima/qmp.sock", forcibly killing QEMU
> [hostagent] failed to kill QEMU

rfay avatar May 08 '23 14:05 rfay

My use case is to only run colima with arm64 but currently only works when using x86_64 which seems like a very popular solution as per the comment https://github.com/abiosoft/colima/issues/424#issuecomment-1335912905

@rfay As stated earlier that I'm only able to run Colima in x86_64 mode but my aim is to use an Amd64 image using the Colima VM. Would you recommend going ahead with this setup -> Colima x86_64 mode on Apple Silicom M1/M2 (arm64) trying to run an Amd64 image?

rjra2611 avatar May 10 '23 10:05 rjra2611

Hi @rjra2611 - All I can say is that your mileage may vary. In general, performance with emulated containers is awful and in many cases breaks unpredictably. For example, people are always trying to run Oracle DB and Oracle MySQL containers (only available in amd64) on arm64 and they run into complete blockers or random failures.

I would certainly recommend that you upgrade to macOS Ventura but I assume there's a reason you haven't done that. It would sure help to understand this issue. But my expectation is that there's something in your network or computer that is the problem, and it's probably not Monterrey.

But have you already tried temporarily disabling all firewall/VPN software? Have you tried using your computer on a different network?

rfay avatar May 10 '23 16:05 rfay

@rfay Thank you, that's very helpful

rjra2611 avatar May 11 '23 20:05 rjra2611

I faced this issue every time I set --memory x.

whaler-ragweed avatar Jun 03 '23 05:06 whaler-ragweed

I have this exact same issue, but on an intel 2020 macbook air.

$ colima start --arch x86_64
INFO[0000] starting colima
INFO[0000] runtime: docker
INFO[0000] preparing network ...                         context=vm
INFO[0000] creating and starting ...                     context=vm
> [hostagent] Shutting down the host agent
> [hostagent] failed to exit SSH master
> [hostagent] Shutting down QEMU with ACPI
> [hostagent] failed to open the QMP socket "/Users/reesericci/.lima/colima/qmp.sock", forcibly killing QEMU
> [hostagent] QEMU has already exited
> exiting, status={Running:false Degraded:false Exiting:true Errors:[] SSHLocalPort:0} (hint: see "/Users/reesericci/.lima/colima/ha.stderr.log")
FATA[0001] error starting vm: error at 'creating and starting': exit status 1

reesericci avatar Jun 04 '23 03:06 reesericci

Similar to the last two comments, I also run into this issue on an Intel MacBook Pro running 13.4 with 64gb RAM, but only whenever I run with --memory x where x is close to the free memory available (for me at the time, --memory 30 works but --memory 31 doesn't).

chrisRedwine avatar Jun 06 '23 17:06 chrisRedwine