search

lima-vm / lima

Linux virtual machines, with a focus on running containers
https://lima-vm.io/
Apache License 2.0
14.97k stars 582 forks source link

vz: Has been stuck in Waiting for the essential requirement 1 of 3: "ssh" on Start lima #1200

Open kj-creater opened 1 year ago

kj-creater commented 1 year ago

Description

{"level":"info","msg":"Replacing \"http_proxy\" value \"http://127.0.0.1:7890\" with \"http://192.168.5.2:7890\"","time":"2022-11-24T19:59:23+08:00"}
{"level":"info","msg":"Replacing \"https_proxy\" value \"http://127.0.0.1:7890\" with \"http://192.168.5.2:7890\"","time":"2022-11-24T19:59:23+08:00"}
{"level":"debug","msg":"Creating iso file /Users/xxx/.lima/oracle/cidata.iso","time":"2022-11-24T19:59:23+08:00"}
{"level":"debug","msg":"Using /var/folders/56/5j82q2lx34vcm7zxrp_m11hh0000gn/T/diskfs_iso3912373468 as workspace","time":"2022-11-24T19:59:23+08:00"}
{"level":"debug","msg":"OpenSSH version 9.0.1 detected","time":"2022-11-24T19:59:23+08:00"}
{"level":"debug","msg":"AES accelerator seems available, prioritizing aes128-gcm@openssh.com and aes256-gcm@openssh.com","time":"2022-11-24T19:59:23+08:00"}
{"level":"info","msg":"Starting VZ (hint: to watch the boot progress, see \"/Users/xxx/.lima/oracle/serial.log\")","time":"2022-11-24T19:59:23+08:00"}
{"level":"debug","msg":"Start tcp server listening on: 127.0.0.1:49936","time":"2022-11-24T19:59:23+08:00"}
{"level":"info","msg":"Setting up Rosetta share","time":"2022-11-24T19:59:23+08:00"}
{"level":"debug","msg":"Start udp server listening on: 127.0.0.1:54440","time":"2022-11-24T19:59:23+08:00"}
{"level":"debug","msg":"[VZ] - vm state change: \"VirtualMachineStateStarting\"","time":"2022-11-24T19:59:23+08:00"}
{"level":"info","msg":"new connection from  to ","time":"2022-11-24T19:59:23+08:00"}
{"level":"info","msg":"[VZ] - vm state change: running","time":"2022-11-24T19:59:23+08:00"}
{"level":"info","msg":"Waiting for the essential requirement 1 of 3: \"ssh\"","time":"2022-11-24T19:59:23+08:00"}
{"level":"debug","msg":"executing script \"ssh\"","time":"2022-11-24T19:59:23+08:00"}
{"level":"debug","msg":"executing ssh for script \"ssh\": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile=\"/Users/xxx/.lima/_config/user\" -o IdentityFile=\"/Users/xxx/.ssh/github_rsa\" -o IdentityFile=\"/Users/xxx/.ssh/id_rsa\" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers=\"^aes128-gcm@openssh.com,aes256-gcm@openssh.com\" -o User=xxx -o ControlMaster=auto -o ControlPath=\"/Users/xxx/.lima/oracle/ssh.sock\" -o ControlPersist=5m -p 49935 127.0.0.1 -- /bin/bash]","time":"2022-11-24T19:59:23+08:00"}
2022/11/24 19:59:26 tcpproxy: for incoming conn 127.0.0.1:49937, error dialing "192.168.5.15:22": connect tcp 192.168.5.15:22: no route
{"level":"debug","msg":"stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\", err=failed to execute script \"ssh\": stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\": exit status 255","time":"2022-11-24T19:59:26+08:00"}
{"level":"info","msg":"Waiting for the essential requirement 1 of 3: \"ssh\"","time":"2022-11-24T19:59:36+08:00"}
{"level":"debug","msg":"executing script \"ssh\"","time":"2022-11-24T19:59:36+08:00"}
{"level":"debug","msg":"executing ssh for script \"ssh\": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile=\"/Users/xxx/.lima/_config/user\" -o IdentityFile=\"/Users/xxx/.ssh/github_rsa\" -o IdentityFile=\"/Users/xxx/.ssh/id_rsa\" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers=\"^aes128-gcm@openssh.com,aes256-gcm@openssh.com\" -o User=xxx -o ControlMaster=auto -o ControlPath=\"/Users/xxx/.lima/oracle/ssh.sock\" -o ControlPersist=5m -p 49935 127.0.0.1 -- /bin/bash]","time":"2022-11-24T19:59:36+08:00"}
2022/11/24 19:59:36 tcpproxy: for incoming conn 127.0.0.1:49957, error dialing "192.168.5.15:22": connect tcp 192.168.5.15:22: connection was refused
{"level":"debug","msg":"stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\", err=failed to execute script \"ssh\": stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\": exit status 255","time":"2022-11-24T19:59:36+08:00"}
{"level":"info","msg":"Waiting for the essential requirement 1 of 3: \"ssh\"","time":"2022-11-24T19:59:46+08:00"}
{"level":"debug","msg":"executing script \"ssh\"","time":"2022-11-24T19:59:46+08:00"}
{"level":"debug","msg":"executing ssh for script \"ssh\": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile=\"/Users/xxx/.lima/_config/user\" -o IdentityFile=\"/Users/xxx/.ssh/github_rsa\" -o IdentityFile=\"/Users/xxx/.ssh/id_rsa\" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers=\"^aes128-gcm@openssh.com,aes256-gcm@openssh.com\" -o User=xxx -o ControlMaster=auto -o ControlPath=\"/Users/xxx/.lima/oracle/ssh.sock\" -o ControlPersist=5m -p 49935 127.0.0.1 -- /bin/bash]","time":"2022-11-24T19:59:46+08:00"}
2022/11/24 19:59:46 tcpproxy: for incoming conn 127.0.0.1:49958, error dialing "192.168.5.15:22": connect tcp 192.168.5.15:22: connection was refused
{"level":"debug","msg":"stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\", err=failed to execute script \"ssh\": stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\": exit status 255","time":"2022-11-24T19:59:46+08:00"}
{"level":"info","msg":"Waiting for the essential requirement 1 of 3: \"ssh\"","time":"2022-11-24T19:59:57+08:00"}
{"level":"debug","msg":"executing script \"ssh\"","time":"2022-11-24T19:59:57+08:00"}
{"level":"debug","msg":"executing ssh for script \"ssh\": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile=\"/Users/xxx/.lima/_config/user\" -o IdentityFile=\"/Users/xxx/.ssh/github_rsa\" -o IdentityFile=\"/Users/xxx/.ssh/id_rsa\" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers=\"^aes128-gcm@openssh.com,aes256-gcm@openssh.com\" -o User=xxx -o ControlMaster=auto -o ControlPath=\"/Users/xxx/.lima/oracle/ssh.sock\" -o ControlPersist=5m -p 49935 127.0.0.1 -- /bin/bash]","time":"2022-11-24T19:59:57+08:00"}
2022/11/24 19:59:57 tcpproxy: for incoming conn 127.0.0.1:49959, error dialing "192.168.5.15:22": connect tcp 192.168.5.15:22: connection was refused
{"level":"debug","msg":"stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\", err=failed to execute script \"ssh\": stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\": exit status 255","time":"2022-11-24T19:59:57+08:00"}
{"level":"info","msg":"Waiting for the essential requirement 1 of 3: \"ssh\"","time":"2022-11-24T20:00:07+08:00"}
{"level":"debug","msg":"executing script \"ssh\"","time":"2022-11-24T20:00:07+08:00"}
{"level":"debug","msg":"executing ssh for script \"ssh\": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile=\"/Users/xxx/.lima/_config/user\" -o IdentityFile=\"/Users/xxx/.ssh/github_rsa\" -o IdentityFile=\"/Users/xxx/.ssh/id_rsa\" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers=\"^aes128-gcm@openssh.com,aes256-gcm@openssh.com\" -o User=xxx -o ControlMaster=auto -o ControlPath=\"/Users/xxx/.lima/oracle/ssh.sock\" -o ControlPersist=5m -p 49935 127.0.0.1 -- /bin/bash]","time":"2022-11-24T20:00:07+08:00"}
2022/11/24 20:00:07 tcpproxy: for incoming conn 127.0.0.1:49960, error dialing "192.168.5.15:22": connect tcp 192.168.5.15:22: connection was refused
{"level":"debug","msg":"stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\", err=failed to execute script \"ssh\": stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\": exit status 255","time":"2022-11-24T20:00:07+08:00"}
{"level":"info","msg":"Waiting for the essential requirement 1 of 3: \"ssh\"","time":"2022-11-24T20:00:17+08:00"}
{"level":"debug","msg":"executing script \"ssh\"","time":"2022-11-24T20:00:17+08:00"}
{"level":"debug","msg":"executing ssh for script \"ssh\": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile=\"/Users/xxx/.lima/_config/user\" -o IdentityFile=\"/Users/xxx/.ssh/github_rsa\" -o IdentityFile=\"/Users/xxx/.ssh/id_rsa\" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers=\"^aes128-gcm@openssh.com,aes256-gcm@openssh.com\" -o User=xxx -o ControlMaster=auto -o ControlPath=\"/Users/xxx/.lima/oracle/ssh.sock\" -o ControlPersist=5m -p 49935 127.0.0.1 -- /bin/bash]","time":"2022-11-24T20:00:17+08:00"}
2022/11/24 20:00:17 tcpproxy: for incoming conn 127.0.0.1:49961, error dialing "192.168.5.15:22": connect tcp 192.168.5.15:22: connection was refused
{"level":"debug","msg":"stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\", err=failed to execute script \"ssh\": stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\": exit status 255","time":"2022-11-24T20:00:17+08:00"}
{"level":"info","msg":"Waiting for the essential requirement 1 of 3: \"ssh\"","time":"2022-11-24T20:00:27+08:00"}
{"level":"debug","msg":"executing script \"ssh\"","time":"2022-11-24T20:00:27+08:00"}
{"level":"debug","msg":"executing ssh for script \"ssh\": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile=\"/Users/xxx/.lima/_config/user\" -o IdentityFile=\"/Users/xxx/.ssh/github_rsa\" -o IdentityFile=\"/Users/xxx/.ssh/id_rsa\" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers=\"^aes128-gcm@openssh.com,aes256-gcm@openssh.com\" -o User=xxx -o ControlMaster=auto -o ControlPath=\"/Users/xxx/.lima/oracle/ssh.sock\" -o ControlPersist=5m -p 49935 127.0.0.1 -- /bin/bash]","time":"2022-11-24T20:00:27+08:00"}
2022/11/24 20:00:27 tcpproxy: for incoming conn 127.0.0.1:49962, error dialing "192.168.5.15:22": connect tcp 192.168.5.15:22: connection was refused
{"level":"debug","msg":"stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\", err=failed to execute script \"ssh\": stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\": exit status 255","time":"2022-11-24T20:00:27+08:00"}
{"level":"info","msg":"Waiting for the essential requirement 1 of 3: \"ssh\"","time":"2022-11-24T20:00:37+08:00"}
{"level":"debug","msg":"executing script \"ssh\"","time":"2022-11-24T20:00:37+08:00"}
{"level":"debug","msg":"executing ssh for script \"ssh\": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile=\"/Users/xxx/.lima/_config/user\" -o IdentityFile=\"/Users/xxx/.ssh/github_rsa\" -o IdentityFile=\"/Users/xxx/.ssh/id_rsa\" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers=\"^aes128-gcm@openssh.com,aes256-gcm@openssh.com\" -o User=xxx -o ControlMaster=auto -o ControlPath=\"/Users/xxx/.lima/oracle/ssh.sock\" -o ControlPersist=5m -p 49935 127.0.0.1 -- /bin/bash]","time":"2022-11-24T20:00:37+08:00"}
2022/11/24 20:00:37 tcpproxy: for incoming conn 127.0.0.1:49963, error dialing "192.168.5.15:22": connect tcp 192.168.5.15:22: connection was refused
{"level":"debug","msg":"stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\", err=failed to execute script \"ssh\": stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\": exit status 255","time":"2022-11-24T20:00:37+08:00"}
{"level":"info","msg":"Waiting for the essential requirement 1 of 3: \"ssh\"","time":"2022-11-24T20:00:47+08:00"}
{"level":"debug","msg":"executing script \"ssh\"","time":"2022-11-24T20:00:47+08:00"}
{"level":"debug","msg":"executing ssh for script \"ssh\": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile=\"/Users/xxx/.lima/_config/user\" -o IdentityFile=\"/Users/xxx/.ssh/github_rsa\" -o IdentityFile=\"/Users/xxx/.ssh/id_rsa\" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers=\"^aes128-gcm@openssh.com,aes256-gcm@openssh.com\" -o User=xxx -o ControlMaster=auto -o ControlPath=\"/Users/xxx/.lima/oracle/ssh.sock\" -o ControlPersist=5m -p 49935 127.0.0.1 -- /bin/bash]","time":"2022-11-24T20:00:47+08:00"}
2022/11/24 20:00:47 tcpproxy: for incoming conn 127.0.0.1:49964, error dialing "192.168.5.15:22": connect tcp 192.168.5.15:22: connection was refused
{"level":"debug","msg":"stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\", err=failed to execute script \"ssh\": stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\": exit status 255","time":"2022-11-24T20:00:47+08:00"}
{"level":"info","msg":"Waiting for the essential requirement 1 of 3: \"ssh\"","time":"2022-11-24T20:00:57+08:00"}
{"level":"debug","msg":"executing script \"ssh\"","time":"2022-11-24T20:00:57+08:00"}
{"level":"debug","msg":"executing ssh for script \"ssh\": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile=\"/Users/xxx/.lima/_config/user\" -o IdentityFile=\"/Users/xxx/.ssh/github_rsa\" -o IdentityFile=\"/Users/xxx/.ssh/id_rsa\" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers=\"^aes128-gcm@openssh.com,aes256-gcm@openssh.com\" -o User=xxx -o ControlMaster=auto -o ControlPath=\"/Users/xxx/.lima/oracle/ssh.sock\" -o ControlPersist=5m -p 49935 127.0.0.1 -- /bin/bash]","time":"2022-11-24T20:00:57+08:00"}
2022/11/24 20:00:57 tcpproxy: for incoming conn 127.0.0.1:49969, error dialing "192.168.5.15:22": connect tcp 192.168.5.15:22: connection was refused
{"level":"debug","msg":"stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\", err=failed to execute script \"ssh\": stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\": exit status 255","time":"2022-11-24T20:00:57+08:00"}
{"level":"info","msg":"Waiting for the essential requirement 1 of 3: \"ssh\"","time":"2022-11-24T20:01:07+08:00"}
{"level":"debug","msg":"executing script \"ssh\"","time":"2022-11-24T20:01:07+08:00"}
{"level":"debug","msg":"executing ssh for script \"ssh\": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile=\"/Users/xxx/.lima/_config/user\" -o IdentityFile=\"/Users/xxx/.ssh/github_rsa\" -o IdentityFile=\"/Users/xxx/.ssh/id_rsa\" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers=\"^aes128-gcm@openssh.com,aes256-gcm@openssh.com\" -o User=xxx -o ControlMaster=auto -o ControlPath=\"/Users/xxx/.lima/oracle/ssh.sock\" -o ControlPersist=5m -p 49935 127.0.0.1 -- /bin/bash]","time":"2022-11-24T20:01:07+08:00"}
2022/11/24 20:01:07 tcpproxy: for incoming conn 127.0.0.1:49974, error dialing "192.168.5.15:22": connect tcp 192.168.5.15:22: connection was refused
{"level":"debug","msg":"stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\", err=failed to execute script \"ssh\": stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\": exit status 255","time":"2022-11-24T20:01:07+08:00"}
{"level":"info","msg":"Waiting for the essential requirement 1 of 3: \"ssh\"","time":"2022-11-24T20:01:17+08:00"}
{"level":"debug","msg":"executing script \"ssh\"","time":"2022-11-24T20:01:17+08:00"}
{"level":"debug","msg":"executing ssh for script \"ssh\": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile=\"/Users/xxx/.lima/_config/user\" -o IdentityFile=\"/Users/xxx/.ssh/github_rsa\" -o IdentityFile=\"/Users/xxx/.ssh/id_rsa\" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers=\"^aes128-gcm@openssh.com,aes256-gcm@openssh.com\" -o User=xxx -o ControlMaster=auto -o ControlPath=\"/Users/xxx/.lima/oracle/ssh.sock\" -o ControlPersist=5m -p 49935 127.0.0.1 -- /bin/bash]","time":"2022-11-24T20:01:17+08:00"}
2022/11/24 20:01:17 tcpproxy: for incoming conn 127.0.0.1:49975, error dialing "192.168.5.15:22": connect tcp 192.168.5.15:22: connection was refused
{"level":"debug","msg":"stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\", err=failed to execute script \"ssh\": stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\": exit status 255","time":"2022-11-24T20:01:17+08:00"}
{"level":"info","msg":"Waiting for the essential requirement 1 of 3: \"ssh\"","time":"2022-11-24T20:01:27+08:00"}
{"level":"debug","msg":"executing script \"ssh\"","time":"2022-11-24T20:01:27+08:00"}
{"level":"debug","msg":"executing ssh for script \"ssh\": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile=\"/Users/xxx/.lima/_config/user\" -o IdentityFile=\"/Users/xxx/.ssh/github_rsa\" -o IdentityFile=\"/Users/xxx/.ssh/id_rsa\" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers=\"^aes128-gcm@openssh.com,aes256-gcm@openssh.com\" -o User=xxx -o ControlMaster=auto -o ControlPath=\"/Users/xxx/.lima/oracle/ssh.sock\" -o ControlPersist=5m -p 49935 127.0.0.1 -- /bin/bash]","time":"2022-11-24T20:01:27+08:00"}
2022/11/24 20:01:27 tcpproxy: for incoming conn 127.0.0.1:49982, error dialing "192.168.5.15:22": connect tcp 192.168.5.15:22: connection was refused
{"level":"debug","msg":"stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\", err=failed to execute script \"ssh\": stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\": exit status 255","time":"2022-11-24T20:01:27+08:00"}
{"level":"debug","msg":"Stopping udp proxy (read udp 185.125.190.57:123: i/o timeout)","time":"2022-11-24T20:01:30+08:00"}
{"level":"info","msg":"Waiting for the essential requirement 1 of 3: \"ssh\"","time":"2022-11-24T20:01:37+08:00"}
{"level":"debug","msg":"executing script \"ssh\"","time":"2022-11-24T20:01:37+08:00"}
{"level":"debug","msg":"executing ssh for script \"ssh\": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile=\"/Users/xxx/.lima/_config/user\" -o IdentityFile=\"/Users/xxx/.ssh/github_rsa\" -o IdentityFile=\"/Users/xxx/.ssh/id_rsa\" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers=\"^aes128-gcm@openssh.com,aes256-gcm@openssh.com\" -o User=xxx -o ControlMaster=auto -o ControlPath=\"/Users/xxx/.lima/oracle/ssh.sock\" -o ControlPersist=5m -p 49935 127.0.0.1 -- /bin/bash]","time":"2022-11-24T20:01:37+08:00"}
2022/11/24 20:01:37 tcpproxy: for incoming conn 127.0.0.1:49989, error dialing "192.168.5.15:22": connect tcp 192.168.5.15:22: connection was refused
{"level":"debug","msg":"stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\", err=failed to execute script \"ssh\": stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\": exit status 255","time":"2022-11-24T20:01:37+08:00"}
{"level":"debug","msg":"Stopping udp proxy (read udp 185.125.190.56:123: i/o timeout)","time":"2022-11-24T20:01:40+08:00"}
{"level":"info","msg":"Waiting for the essential requirement 1 of 3: \"ssh\"","time":"2022-11-24T20:01:47+08:00"}
{"level":"debug","msg":"executing script \"ssh\"","time":"2022-11-24T20:01:47+08:00"}
{"level":"debug","msg":"executing ssh for script \"ssh\": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile=\"/Users/xxx/.lima/_config/user\" -o IdentityFile=\"/Users/xxx/.ssh/github_rsa\" -o IdentityFile=\"/Users/xxx/.ssh/id_rsa\" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers=\"^aes128-gcm@openssh.com,aes256-gcm@openssh.com\" -o User=xxx -o ControlMaster=auto -o ControlPath=\"/Users/xxx/.lima/oracle/ssh.sock\" -o ControlPersist=5m -p 49935 127.0.0.1 -- /bin/bash]","time":"2022-11-24T20:01:47+08:00"}
2022/11/24 20:01:47 tcpproxy: for incoming conn 127.0.0.1:49992, error dialing "192.168.5.15:22": connect tcp 192.168.5.15:22: connection was refused
{"level":"debug","msg":"stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\", err=failed to execute script \"ssh\": stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\": exit status 255","time":"2022-11-24T20:01:47+08:00"}
{"level":"info","msg":"Waiting for the essential requirement 1 of 3: \"ssh\"","time":"2022-11-24T20:01:57+08:00"}
{"level":"debug","msg":"executing script \"ssh\"","time":"2022-11-24T20:01:57+08:00"}
{"level":"debug","msg":"executing ssh for script \"ssh\": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile=\"/Users/xxx/.lima/_config/user\" -o IdentityFile=\"/Users/xxx/.ssh/github_rsa\" -o IdentityFile=\"/Users/xxx/.ssh/id_rsa\" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers=\"^aes128-gcm@openssh.com,aes256-gcm@openssh.com\" -o User=xxx -o ControlMaster=auto -o ControlPath=\"/Users/xxx/.lima/oracle/ssh.sock\" -o ControlPersist=5m -p 49935 127.0.0.1 -- /bin/bash]","time":"2022-11-24T20:01:57+08:00"}
2022/11/24 20:01:57 tcpproxy: for incoming conn 127.0.0.1:49993, error dialing "192.168.5.15:22": connect tcp 192.168.5.15:22: connection was refused
{"level":"debug","msg":"stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\", err=failed to execute script \"ssh\": stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\": exit status 255","time":"2022-11-24T20:01:57+08:00"}
{"level":"info","msg":"Waiting for the essential requirement 1 of 3: \"ssh\"","time":"2022-11-24T20:02:07+08:00"}
{"level":"debug","msg":"executing script \"ssh\"","time":"2022-11-24T20:02:07+08:00"}
{"level":"debug","msg":"executing ssh for script \"ssh\": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile=\"/Users/xxx/.lima/_config/user\" -o IdentityFile=\"/Users/xxx/.ssh/github_rsa\" -o IdentityFile=\"/Users/xxx/.ssh/id_rsa\" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers=\"^aes128-gcm@openssh.com,aes256-gcm@openssh.com\" -o User=xxx -o ControlMaster=auto -o ControlPath=\"/Users/xxx/.lima/oracle/ssh.sock\" -o ControlPersist=5m -p 49935 127.0.0.1 -- /bin/bash]","time":"2022-11-24T20:02:07+08:00"}
2022/11/24 20:02:07 tcpproxy: for incoming conn 127.0.0.1:49994, error dialing "192.168.5.15:22": connect tcp 192.168.5.15:22: connection was refused
{"level":"debug","msg":"stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\", err=failed to execute script \"ssh\": stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\": exit status 255","time":"2022-11-24T20:02:07+08:00"}
{"level":"info","msg":"Waiting for the essential requirement 1 of 3: \"ssh\"","time":"2022-11-24T20:02:17+08:00"}
{"level":"debug","msg":"executing script \"ssh\"","time":"2022-11-24T20:02:17+08:00"}
{"level":"debug","msg":"executing ssh for script \"ssh\": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile=\"/Users/xxx/.lima/_config/user\" -o IdentityFile=\"/Users/xxx/.ssh/github_rsa\" -o IdentityFile=\"/Users/xxx/.ssh/id_rsa\" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers=\"^aes128-gcm@openssh.com,aes256-gcm@openssh.com\" -o User=xxx -o ControlMaster=auto -o ControlPath=\"/Users/xxx/.lima/oracle/ssh.sock\" -o ControlPersist=5m -p 49935 127.0.0.1 -- /bin/bash]","time":"2022-11-24T20:02:17+08:00"}
2022/11/24 20:02:17 tcpproxy: for incoming conn 127.0.0.1:50009, error dialing "192.168.5.15:22": connect tcp 192.168.5.15:22: connection was refused
{"level":"debug","msg":"stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\", err=failed to execute script \"ssh\": stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\": exit status 255","time":"2022-11-24T20:02:17+08:00"}
{"level":"info","msg":"Waiting for the essential requirement 1 of 3: \"ssh\"","time":"2022-11-24T20:02:27+08:00"}
{"level":"debug","msg":"executing script \"ssh\"","time":"2022-11-24T20:02:27+08:00"}
{"level":"debug","msg":"executing ssh for script \"ssh\": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile=\"/Users/xxx/.lima/_config/user\" -o IdentityFile=\"/Users/xxx/.ssh/github_rsa\" -o IdentityFile=\"/Users/xxx/.ssh/id_rsa\" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers=\"^aes128-gcm@openssh.com,aes256-gcm@openssh.com\" -o User=xxx -o ControlMaster=auto -o ControlPath=\"/Users/xxx/.lima/oracle/ssh.sock\" -o ControlPersist=5m -p 49935 127.0.0.1 -- /bin/bash]","time":"2022-11-24T20:02:27+08:00"}
2022/11/24 20:02:27 tcpproxy: for incoming conn 127.0.0.1:50010, error dialing "192.168.5.15:22": connect tcp 192.168.5.15:22: connection was refused
{"level":"debug","msg":"stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\", err=failed to execute script \"ssh\": stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\": exit status 255","time":"2022-11-24T20:02:27+08:00"}
{"level":"debug","msg":"Stopping udp proxy (read udp 185.125.190.56:123: i/o timeout)","time":"2022-11-24T20:02:28+08:00"}
{"level":"info","msg":"Waiting for the essential requirement 1 of 3: \"ssh\"","time":"2022-11-24T20:02:37+08:00"}
{"level":"debug","msg":"executing script \"ssh\"","time":"2022-11-24T20:02:37+08:00"}
{"level":"debug","msg":"executing ssh for script \"ssh\": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile=\"/Users/xxx/.lima/_config/user\" -o IdentityFile=\"/Users/xxx/.ssh/github_rsa\" -o IdentityFile=\"/Users/xxx/.ssh/id_rsa\" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers=\"^aes128-gcm@openssh.com,aes256-gcm@openssh.com\" -o User=xxx -o ControlMaster=auto -o ControlPath=\"/Users/xxx/.lima/oracle/ssh.sock\" -o ControlPersist=5m -p 49935 127.0.0.1 -- /bin/bash]","time":"2022-11-24T20:02:37+08:00"}
2022/11/24 20:02:37 tcpproxy: for incoming conn 127.0.0.1:50013, error dialing "192.168.5.15:22": connect tcp 192.168.5.15:22: connection was refused
{"level":"debug","msg":"stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\", err=failed to execute script \"ssh\": stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\": exit status 255","time":"2022-11-24T20:02:37+08:00"}
{"level":"info","msg":"Waiting for the essential requirement 1 of 3: \"ssh\"","time":"2022-11-24T20:02:47+08:00"}
{"level":"debug","msg":"executing script \"ssh\"","time":"2022-11-24T20:02:47+08:00"}
{"level":"debug","msg":"executing ssh for script \"ssh\": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile=\"/Users/xxx/.lima/_config/user\" -o IdentityFile=\"/Users/xxx/.ssh/github_rsa\" -o IdentityFile=\"/Users/xxx/.ssh/id_rsa\" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers=\"^aes128-gcm@openssh.com,aes256-gcm@openssh.com\" -o User=xxx -o ControlMaster=auto -o ControlPath=\"/Users/xxx/.lima/oracle/ssh.sock\" -o ControlPersist=5m -p 49935 127.0.0.1 -- /bin/bash]","time":"2022-11-24T20:02:47+08:00"}
2022/11/24 20:02:47 tcpproxy: for incoming conn 127.0.0.1:50024, error dialing "192.168.5.15:22": connect tcp 192.168.5.15:22: connection was refused
{"level":"debug","msg":"stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\", err=failed to execute script \"ssh\": stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\": exit status 255","time":"2022-11-24T20:02:47+08:00"}
{"level":"info","msg":"Waiting for the essential requirement 1 of 3: \"ssh\"","time":"2022-11-24T20:02:57+08:00"}
{"level":"debug","msg":"executing script \"ssh\"","time":"2022-11-24T20:02:57+08:00"}
{"level":"debug","msg":"executing ssh for script \"ssh\": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile=\"/Users/xxx/.lima/_config/user\" -o IdentityFile=\"/Users/xxx/.ssh/github_rsa\" -o IdentityFile=\"/Users/xxx/.ssh/id_rsa\" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers=\"^aes128-gcm@openssh.com,aes256-gcm@openssh.com\" -o User=xxx -o ControlMaster=auto -o ControlPath=\"/Users/xxx/.lima/oracle/ssh.sock\" -o ControlPersist=5m -p 49935 127.0.0.1 -- /bin/bash]","time":"2022-11-24T20:02:57+08:00"}
2022/11/24 20:02:57 tcpproxy: for incoming conn 127.0.0.1:50029, error dialing "192.168.5.15:22": connect tcp 192.168.5.15:22: connection was refused
{"level":"debug","msg":"stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\", err=failed to execute script \"ssh\": stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\": exit status 255","time":"2022-11-24T20:02:57+08:00"}
{"level":"debug","msg":"Stopping udp proxy (read udp 185.125.190.56:123: i/o timeout)","time":"2022-11-24T20:03:01+08:00"}
{"level":"info","msg":"Waiting for the essential requirement 1 of 3: \"ssh\"","time":"2022-11-24T20:03:07+08:00"}
{"level":"debug","msg":"executing script \"ssh\"","time":"2022-11-24T20:03:07+08:00"}
{"level":"debug","msg":"executing ssh for script \"ssh\": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile=\"/Users/xxx/.lima/_config/user\" -o IdentityFile=\"/Users/xxx/.ssh/github_rsa\" -o IdentityFile=\"/Users/xxx/.ssh/id_rsa\" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers=\"^aes128-gcm@openssh.com,aes256-gcm@openssh.com\" -o User=xxx -o ControlMaster=auto -o ControlPath=\"/Users/xxx/.lima/oracle/ssh.sock\" -o ControlPersist=5m -p 49935 127.0.0.1 -- /bin/bash]","time":"2022-11-24T20:03:07+08:00"}
2022/11/24 20:03:07 tcpproxy: for incoming conn 127.0.0.1:50034, error dialing "192.168.5.15:22": connect tcp 192.168.5.15:22: connection was refused
{"level":"debug","msg":"stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\", err=failed to execute script \"ssh\": stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\": exit status 255","time":"2022-11-24T20:03:07+08:00"}
{"level":"info","msg":"Waiting for the essential requirement 1 of 3: \"ssh\"","time":"2022-11-24T20:03:17+08:00"}
{"level":"debug","msg":"executing script \"ssh\"","time":"2022-11-24T20:03:17+08:00"}
{"level":"debug","msg":"executing ssh for script \"ssh\": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile=\"/Users/xxx/.lima/_config/user\" -o IdentityFile=\"/Users/xxx/.ssh/github_rsa\" -o IdentityFile=\"/Users/xxx/.ssh/id_rsa\" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers=\"^aes128-gcm@openssh.com,aes256-gcm@openssh.com\" -o User=xxx -o ControlMaster=auto -o ControlPath=\"/Users/xxx/.lima/oracle/ssh.sock\" -o ControlPersist=5m -p 49935 127.0.0.1 -- /bin/bash]","time":"2022-11-24T20:03:17+08:00"}
2022/11/24 20:03:17 tcpproxy: for incoming conn 127.0.0.1:50049, error dialing "192.168.5.15:22": connect tcp 192.168.5.15:22: connection was refused
{"level":"debug","msg":"stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\", err=failed to execute script \"ssh\": stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\": exit status 255","time":"2022-11-24T20:03:17+08:00"}
{"level":"info","msg":"Waiting for the essential requirement 1 of 3: \"ssh\"","time":"2022-11-24T20:03:27+08:00"}
{"level":"debug","msg":"executing script \"ssh\"","time":"2022-11-24T20:03:27+08:00"}
{"level":"debug","msg":"executing ssh for script \"ssh\": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile=\"/Users/xxx/.lima/_config/user\" -o IdentityFile=\"/Users/xxx/.ssh/github_rsa\" -o IdentityFile=\"/Users/xxx/.ssh/id_rsa\" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers=\"^aes128-gcm@openssh.com,aes256-gcm@openssh.com\" -o User=xxx -o ControlMaster=auto -o ControlPath=\"/Users/xxx/.lima/oracle/ssh.sock\" -o ControlPersist=5m -p 49935 127.0.0.1 -- /bin/bash]","time":"2022-11-24T20:03:27+08:00"}
2022/11/24 20:03:27 tcpproxy: for incoming conn 127.0.0.1:50050, error dialing "192.168.5.15:22": connect tcp 192.168.5.15:22: connection was refused
{"level":"debug","msg":"stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\", err=failed to execute script \"ssh\": stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\": exit status 255","time":"2022-11-24T20:03:27+08:00"}
{"level":"debug","msg":"Stopping udp proxy (read udp 185.125.190.56:123: i/o timeout)","time":"2022-11-24T20:03:33+08:00"}
{"level":"info","msg":"Waiting for the essential requirement 1 of 3: \"ssh\"","time":"2022-11-24T20:03:37+08:00"}
{"level":"debug","msg":"executing script \"ssh\"","time":"2022-11-24T20:03:37+08:00"}
{"level":"debug","msg":"executing ssh for script \"ssh\": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile=\"/Users/xxx/.lima/_config/user\" -o IdentityFile=\"/Users/xxx/.ssh/github_rsa\" -o IdentityFile=\"/Users/xxx/.ssh/id_rsa\" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers=\"^aes128-gcm@openssh.com,aes256-gcm@openssh.com\" -o User=xxx -o ControlMaster=auto -o ControlPath=\"/Users/xxx/.lima/oracle/ssh.sock\" -o ControlPersist=5m -p 49935 127.0.0.1 -- /bin/bash]","time":"2022-11-24T20:03:37+08:00"}
2022/11/24 20:03:37 tcpproxy: for incoming conn 127.0.0.1:50051, error dialing "192.168.5.15:22": connect tcp 192.168.5.15:22: connection was refused
{"level":"debug","msg":"stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\", err=failed to execute script \"ssh\": stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\": exit status 255","time":"2022-11-24T20:03:37+08:00"}
{"level":"info","msg":"Waiting for the essential requirement 1 of 3: \"ssh\"","time":"2022-11-24T20:03:47+08:00"}
{"level":"debug","msg":"executing script \"ssh\"","time":"2022-11-24T20:03:47+08:00"}
{"level":"debug","msg":"executing ssh for script \"ssh\": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile=\"/Users/xxx/.lima/_config/user\" -o IdentityFile=\"/Users/xxx/.ssh/github_rsa\" -o IdentityFile=\"/Users/xxx/.ssh/id_rsa\" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers=\"^aes128-gcm@openssh.com,aes256-gcm@openssh.com\" -o User=xxx -o ControlMaster=auto -o ControlPath=\"/Users/xxx/.lima/oracle/ssh.sock\" -o ControlPersist=5m -p 49935 127.0.0.1 -- /bin/bash]","time":"2022-11-24T20:03:47+08:00"}
2022/11/24 20:03:47 tcpproxy: for incoming conn 127.0.0.1:50068, error dialing "192.168.5.15:22": connect tcp 192.168.5.15:22: connection was refused
{"level":"debug","msg":"stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\", err=failed to execute script \"ssh\": stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\": exit status 255","time":"2022-11-24T20:03:47+08:00"}
{"level":"info","msg":"Waiting for the essential requirement 1 of 3: \"ssh\"","time":"2022-11-24T20:03:57+08:00"}
{"level":"debug","msg":"executing script \"ssh\"","time":"2022-11-24T20:03:57+08:00"}
{"level":"debug","msg":"executing ssh for script \"ssh\": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile=\"/Users/xxx/.lima/_config/user\" -o IdentityFile=\"/Users/xxx/.ssh/github_rsa\" -o IdentityFile=\"/Users/xxx/.ssh/id_rsa\" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers=\"^aes128-gcm@openssh.com,aes256-gcm@openssh.com\" -o User=xxx -o ControlMaster=auto -o ControlPath=\"/Users/xxx/.lima/oracle/ssh.sock\" -o ControlPersist=5m -p 49935 127.0.0.1 -- /bin/bash]","time":"2022-11-24T20:03:57+08:00"}
2022/11/24 20:03:57 tcpproxy: for incoming conn 127.0.0.1:50069, error dialing "192.168.5.15:22": connect tcp 192.168.5.15:22: connection was refused
{"level":"debug","msg":"stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\", err=failed to execute script \"ssh\": stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\": exit status 255","time":"2022-11-24T20:03:57+08:00"}
{"level":"info","msg":"Waiting for the essential requirement 1 of 3: \"ssh\"","time":"2022-11-24T20:04:07+08:00"}
{"level":"debug","msg":"executing script \"ssh\"","time":"2022-11-24T20:04:07+08:00"}
{"level":"debug","msg":"executing ssh for script \"ssh\": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile=\"/Users/xxx/.lima/_config/user\" -o IdentityFile=\"/Users/xxx/.ssh/github_rsa\" -o IdentityFile=\"/Users/xxx/.ssh/id_rsa\" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers=\"^aes128-gcm@openssh.com,aes256-gcm@openssh.com\" -o User=xxx -o ControlMaster=auto -o ControlPath=\"/Users/xxx/.lima/oracle/ssh.sock\" -o ControlPersist=5m -p 49935 127.0.0.1 -- /bin/bash]","time":"2022-11-24T20:04:07+08:00"}
2022/11/24 20:04:08 tcpproxy: for incoming conn 127.0.0.1:50070, error dialing "192.168.5.15:22": connect tcp 192.168.5.15:22: connection was refused
{"level":"debug","msg":"stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\", err=failed to execute script \"ssh\": stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\": exit status 255","time":"2022-11-24T20:04:08+08:00"}
{"level":"info","msg":"Waiting for the essential requirement 1 of 3: \"ssh\"","time":"2022-11-24T20:04:18+08:00"}
{"level":"debug","msg":"executing script \"ssh\"","time":"2022-11-24T20:04:18+08:00"}
{"level":"debug","msg":"executing ssh for script \"ssh\": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile=\"/Users/xxx/.lima/_config/user\" -o IdentityFile=\"/Users/xxx/.ssh/github_rsa\" -o IdentityFile=\"/Users/xxx/.ssh/id_rsa\" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers=\"^aes128-gcm@openssh.com,aes256-gcm@openssh.com\" -o User=xxx -o ControlMaster=auto -o ControlPath=\"/Users/xxx/.lima/oracle/ssh.sock\" -o ControlPersist=5m -p 49935 127.0.0.1 -- /bin/bash]","time":"2022-11-24T20:04:18+08:00"}
2022/11/24 20:04:18 tcpproxy: for incoming conn 127.0.0.1:50089, error dialing "192.168.5.15:22": connect tcp 192.168.5.15:22: connection was refused
{"level":"debug","msg":"stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\", err=failed to execute script \"ssh\": stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\": exit status 255","time":"2022-11-24T20:04:18+08:00"}
{"level":"info","msg":"Waiting for the essential requirement 1 of 3: \"ssh\"","time":"2022-11-24T20:04:28+08:00"}
{"level":"debug","msg":"executing script \"ssh\"","time":"2022-11-24T20:04:28+08:00"}
{"level":"debug","msg":"executing ssh for script \"ssh\": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile=\"/Users/xxx/.lima/_config/user\" -o IdentityFile=\"/Users/xxx/.ssh/github_rsa\" -o IdentityFile=\"/Users/xxx/.ssh/id_rsa\" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers=\"^aes128-gcm@openssh.com,aes256-gcm@openssh.com\" -o User=xxx -o ControlMaster=auto -o ControlPath=\"/Users/xxx/.lima/oracle/ssh.sock\" -o ControlPersist=5m -p 49935 127.0.0.1 -- /bin/bash]","time":"2022-11-24T20:04:28+08:00"}
2022/11/24 20:04:28 tcpproxy: for incoming conn 127.0.0.1:50090, error dialing "192.168.5.15:22": connect tcp 192.168.5.15:22: connection was refused
{"level":"debug","msg":"stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\", err=failed to execute script \"ssh\": stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\": exit status 255","time":"2022-11-24T20:04:28+08:00"}
{"level":"debug","msg":"Stopping udp proxy (read udp 185.125.190.56:123: i/o timeout)","time":"2022-11-24T20:04:37+08:00"}
{"level":"info","msg":"Waiting for the essential requirement 1 of 3: \"ssh\"","time":"2022-11-24T20:04:38+08:00"}
{"level":"debug","msg":"executing script \"ssh\"","time":"2022-11-24T20:04:38+08:00"}
{"level":"debug","msg":"executing ssh for script \"ssh\": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile=\"/Users/xxx/.lima/_config/user\" -o IdentityFile=\"/Users/xxx/.ssh/github_rsa\" -o IdentityFile=\"/Users/xxx/.ssh/id_rsa\" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers=\"^aes128-gcm@openssh.com,aes256-gcm@openssh.com\" -o User=xxx -o ControlMaster=auto -o ControlPath=\"/Users/xxx/.lima/oracle/ssh.sock\" -o ControlPersist=5m -p 49935 127.0.0.1 -- /bin/bash]","time":"2022-11-24T20:04:38+08:00"}
2022/11/24 20:04:38 tcpproxy: for incoming conn 127.0.0.1:50096, error dialing "192.168.5.15:22": connect tcp 192.168.5.15:22: connection was refused
{"level":"debug","msg":"stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\", err=failed to execute script \"ssh\": stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\": exit status 255","time":"2022-11-24T20:04:38+08:00"}
{"level":"info","msg":"Waiting for the essential requirement 1 of 3: \"ssh\"","time":"2022-11-24T20:04:48+08:00"}
{"level":"debug","msg":"executing script \"ssh\"","time":"2022-11-24T20:04:48+08:00"}
{"level":"debug","msg":"executing ssh for script \"ssh\": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile=\"/Users/xxx/.lima/_config/user\" -o IdentityFile=\"/Users/xxx/.ssh/github_rsa\" -o IdentityFile=\"/Users/xxx/.ssh/id_rsa\" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers=\"^aes128-gcm@openssh.com,aes256-gcm@openssh.com\" -o User=xxx -o ControlMaster=auto -o ControlPath=\"/Users/xxx/.lima/oracle/ssh.sock\" -o ControlPersist=5m -p 49935 127.0.0.1 -- /bin/bash]","time":"2022-11-24T20:04:48+08:00"}
2022/11/24 20:04:48 tcpproxy: for incoming conn 127.0.0.1:50108, error dialing "192.168.5.15:22": connect tcp 192.168.5.15:22: connection was refused
{"level":"debug","msg":"stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\", err=failed to execute script \"ssh\": stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\": exit status 255","time":"2022-11-24T20:04:48+08:00"}
{"level":"info","msg":"Waiting for the essential requirement 1 of 3: \"ssh\"","time":"2022-11-24T20:04:58+08:00"}
{"level":"debug","msg":"executing script \"ssh\"","time":"2022-11-24T20:04:58+08:00"}
{"level":"debug","msg":"executing ssh for script \"ssh\": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile=\"/Users/xxx/.lima/_config/user\" -o IdentityFile=\"/Users/xxx/.ssh/github_rsa\" -o IdentityFile=\"/Users/xxx/.ssh/id_rsa\" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers=\"^aes128-gcm@openssh.com,aes256-gcm@openssh.com\" -o User=xxx -o ControlMaster=auto -o ControlPath=\"/Users/xxx/.lima/oracle/ssh.sock\" -o ControlPersist=5m -p 49935 127.0.0.1 -- /bin/bash]","time":"2022-11-24T20:04:58+08:00"}
2022/11/24 20:04:58 tcpproxy: for incoming conn 127.0.0.1:50111, error dialing "192.168.5.15:22": connect tcp 192.168.5.15:22: connection was refused
{"level":"debug","msg":"stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\", err=failed to execute script \"ssh\": stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\": exit status 255","time":"2022-11-24T20:04:58+08:00"}
{"level":"info","msg":"Waiting for the essential requirement 1 of 3: \"ssh\"","time":"2022-11-24T20:05:08+08:00"}
{"level":"debug","msg":"executing script \"ssh\"","time":"2022-11-24T20:05:08+08:00"}
{"level":"debug","msg":"executing ssh for script \"ssh\": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile=\"/Users/xxx/.lima/_config/user\" -o IdentityFile=\"/Users/xxx/.ssh/github_rsa\" -o IdentityFile=\"/Users/xxx/.ssh/id_rsa\" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers=\"^aes128-gcm@openssh.com,aes256-gcm@openssh.com\" -o User=xxx -o ControlMaster=auto -o ControlPath=\"/Users/xxx/.lima/oracle/ssh.sock\" -o ControlPersist=5m -p 49935 127.0.0.1 -- /bin/bash]","time":"2022-11-24T20:05:08+08:00"}
2022/11/24 20:05:08 tcpproxy: for incoming conn 127.0.0.1:50124, error dialing "192.168.5.15:22": connect tcp 192.168.5.15:22: connection was refused
{"level":"debug","msg":"stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\", err=failed to execute script \"ssh\": stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\": exit status 255","time":"2022-11-24T20:05:08+08:00"}
{"level":"info","msg":"Waiting for the essential requirement 1 of 3: \"ssh\"","time":"2022-11-24T20:05:18+08:00"}
{"level":"debug","msg":"executing script \"ssh\"","time":"2022-11-24T20:05:18+08:00"}
{"level":"debug","msg":"executing ssh for script \"ssh\": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile=\"/Users/xxx/.lima/_config/user\" -o IdentityFile=\"/Users/xxx/.ssh/github_rsa\" -o IdentityFile=\"/Users/xxx/.ssh/id_rsa\" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers=\"^aes128-gcm@openssh.com,aes256-gcm@openssh.com\" -o User=xxx -o ControlMaster=auto -o ControlPath=\"/Users/xxx/.lima/oracle/ssh.sock\" -o ControlPersist=5m -p 49935 127.0.0.1 -- /bin/bash]","time":"2022-11-24T20:05:18+08:00"}
2022/11/24 20:05:18 tcpproxy: for incoming conn 127.0.0.1:50127, error dialing "192.168.5.15:22": connect tcp 192.168.5.15:22: connection was refused
{"level":"debug","msg":"stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\", err=failed to execute script \"ssh\": stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\": exit status 255","time":"2022-11-24T20:05:18+08:00"}
{"level":"info","msg":"Waiting for the essential requirement 1 of 3: \"ssh\"","time":"2022-11-24T20:05:28+08:00"}
{"level":"debug","msg":"executing script \"ssh\"","time":"2022-11-24T20:05:28+08:00"}
{"level":"debug","msg":"executing ssh for script \"ssh\": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile=\"/Users/xxx/.lima/_config/user\" -o IdentityFile=\"/Users/xxx/.ssh/github_rsa\" -o IdentityFile=\"/Users/xxx/.ssh/id_rsa\" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers=\"^aes128-gcm@openssh.com,aes256-gcm@openssh.com\" -o User=xxx -o ControlMaster=auto -o ControlPath=\"/Users/xxx/.lima/oracle/ssh.sock\" -o ControlPersist=5m -p 49935 127.0.0.1 -- /bin/bash]","time":"2022-11-24T20:05:28+08:00"}
2022/11/24 20:05:28 tcpproxy: for incoming conn 127.0.0.1:50130, error dialing "192.168.5.15:22": connect tcp 192.168.5.15:22: connection was refused
{"level":"debug","msg":"stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\", err=failed to execute script \"ssh\": stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\": exit status 255","time":"2022-11-24T20:05:28+08:00"}
{"level":"info","msg":"Waiting for the essential requirement 1 of 3: \"ssh\"","time":"2022-11-24T20:05:38+08:00"}
{"level":"debug","msg":"executing script \"ssh\"","time":"2022-11-24T20:05:38+08:00"}
{"level":"debug","msg":"executing ssh for script \"ssh\": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile=\"/Users/xxx/.lima/_config/user\" -o IdentityFile=\"/Users/xxx/.ssh/github_rsa\" -o IdentityFile=\"/Users/xxx/.ssh/id_rsa\" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers=\"^aes128-gcm@openssh.com,aes256-gcm@openssh.com\" -o User=xxx -o ControlMaster=auto -o ControlPath=\"/Users/xxx/.lima/oracle/ssh.sock\" -o ControlPersist=5m -p 49935 127.0.0.1 -- /bin/bash]","time":"2022-11-24T20:05:38+08:00"}
2022/11/24 20:05:38 tcpproxy: for incoming conn 127.0.0.1:50135, error dialing "192.168.5.15:22": connect tcp 192.168.5.15:22: connection was refused
{"level":"debug","msg":"stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\", err=failed to execute script \"ssh\": stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\": exit status 255","time":"2022-11-24T20:05:38+08:00"}
{"level":"info","msg":"Waiting for the essential requirement 1 of 3: \"ssh\"","time":"2022-11-24T20:05:48+08:00"}
{"level":"debug","msg":"executing script \"ssh\"","time":"2022-11-24T20:05:48+08:00"}
{"level":"debug","msg":"executing ssh for script \"ssh\": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile=\"/Users/xxx/.lima/_config/user\" -o IdentityFile=\"/Users/xxx/.ssh/github_rsa\" -o IdentityFile=\"/Users/xxx/.ssh/id_rsa\" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers=\"^aes128-gcm@openssh.com,aes256-gcm@openssh.com\" -o User=xxx -o ControlMaster=auto -o ControlPath=\"/Users/xxx/.lima/oracle/ssh.sock\" -o ControlPersist=5m -p 49935 127.0.0.1 -- /bin/bash]","time":"2022-11-24T20:05:48+08:00"}
2022/11/24 20:05:48 tcpproxy: for incoming conn 127.0.0.1:50136, error dialing "192.168.5.15:22": connect tcp 192.168.5.15:22: connection was refused
{"level":"debug","msg":"stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\", err=failed to execute script \"ssh\": stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\": exit status 255","time":"2022-11-24T20:05:48+08:00"}
{"level":"info","msg":"Waiting for the essential requirement 1 of 3: \"ssh\"","time":"2022-11-24T20:05:58+08:00"}
{"level":"debug","msg":"executing script \"ssh\"","time":"2022-11-24T20:05:58+08:00"}
{"level":"debug","msg":"executing ssh for script \"ssh\": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile=\"/Users/xxx/.lima/_config/user\" -o IdentityFile=\"/Users/xxx/.ssh/github_rsa\" -o IdentityFile=\"/Users/xxx/.ssh/id_rsa\" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers=\"^aes128-gcm@openssh.com,aes256-gcm@openssh.com\" -o User=xxx -o ControlMaster=auto -o ControlPath=\"/Users/xxx/.lima/oracle/ssh.sock\" -o ControlPersist=5m -p 49935 127.0.0.1 -- /bin/bash]","time":"2022-11-24T20:05:58+08:00"}
2022/11/24 20:05:58 tcpproxy: for incoming conn 127.0.0.1:50143, error dialing "192.168.5.15:22": connect tcp 192.168.5.15:22: connection was refused
{"level":"debug","msg":"stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\", err=failed to execute script \"ssh\": stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\": exit status 255","time":"2022-11-24T20:05:58+08:00"}
{"level":"info","msg":"Waiting for the essential requirement 1 of 3: \"ssh\"","time":"2022-11-24T20:06:08+08:00"}
{"level":"debug","msg":"executing script \"ssh\"","time":"2022-11-24T20:06:08+08:00"}
{"level":"debug","msg":"executing ssh for script \"ssh\": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile=\"/Users/xxx/.lima/_config/user\" -o IdentityFile=\"/Users/xxx/.ssh/github_rsa\" -o IdentityFile=\"/Users/xxx/.ssh/id_rsa\" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers=\"^aes128-gcm@openssh.com,aes256-gcm@openssh.com\" -o User=xxx -o ControlMaster=auto -o ControlPath=\"/Users/xxx/.lima/oracle/ssh.sock\" -o ControlPersist=5m -p 49935 127.0.0.1 -- /bin/bash]","time":"2022-11-24T20:06:08+08:00"}
2022/11/24 20:06:08 tcpproxy: for incoming conn 127.0.0.1:50158, error dialing "192.168.5.15:22": connect tcp 192.168.5.15:22: connection was refused
{"level":"debug","msg":"stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\", err=failed to execute script \"ssh\": stdout=\"\", stderr=\"kex_exchange_identification: read: Connection reset by peer\\r\\nConnection reset by 127.0.0.1 port 49935\\r\\n\": exit status 255","time":"2022-11-24T20:06:08+08:00"}
{"level":"info","msg":"Received SIGINT, shutting down the host agent","time":"2022-11-24T20:06:16+08:00"}
{"level":"info","msg":"Shutting down the host agent","time":"2022-11-24T20:06:16+08:00"}
{"level":"debug","msg":"shutting down the SSH master","time":"2022-11-24T20:06:16+08:00"}
{"level":"debug","msg":"executing ssh for exiting the master: /usr/bin/ssh [ssh -F /dev/null -o IdentityFile=\"/Users/xxx/.lima/_config/user\" -o IdentityFile=\"/Users/xxx/.ssh/github_rsa\" -o IdentityFile=\"/Users/xxx/.ssh/id_rsa\" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers=\"^aes128-gcm@openssh.com,aes256-gcm@openssh.com\" -o User=xxx -o ControlMaster=auto -o ControlPath=\"/Users/xxx/.lima/oracle/ssh.sock\" -o ControlPersist=5m -O exit -p 49935 127.0.0.1]","time":"2022-11-24T20:06:16+08:00"}
{"error":"failed to execute `ssh -O exit -p 49935 127.0.0.1`, out=\"Control socket connect(/Users/xxx/.lima/oracle/ssh.sock): No such file or directory\\r\\n\": exit status 255","level":"warning","msg":"failed to exit SSH master","time":"2022-11-24T20:06:16+08:00"}
{"level":"info","msg":"Shutting down VZ","time":"2022-11-24T20:06:16+08:00"}
panic: runtime/cgo: misuse of an invalid Handle

goroutine 1 [running]:
runtime/cgo.Handle.Value(...)
    /opt/homebrew/Cellar/go/1.19.3/libexec/src/runtime/cgo/handle.go:124
github.com/Code-Hex/vz/v3.changeStateOnObserver(0x7, 0x1048c3ee8?)
    /Users/xxx/.cache/go/pkg/mod/github.com/!code-!hex/vz/v3@v3.0.1/virtualization.go:158 +0xec
github.com/Code-Hex/vz/v3._Cfunc_stopWithCompletionHandler(0x600002e35ee0, 0x600003b3f300, 0x140000421d8)
    _cgo_gotypes.go:1942 +0x34
github.com/Code-Hex/vz/v3.(*VirtualMachine).Stop.func1(0x14000050180, 0x140004f27d0?)
    /Users/xxx/.cache/go/pkg/mod/github.com/!code-!hex/vz/v3@v3.0.1/virtualization.go:330 +0xbc
github.com/Code-Hex/vz/v3.(*VirtualMachine).Stop(0x140001fe000?)
    /Users/xxx/.cache/go/pkg/mod/github.com/!code-!hex/vz/v3@v3.0.1/virtualization.go:330 +0xe8
github.com/lima-vm/lima/pkg/vz.(*LimaVzDriver).Stop(0x1400012e3c0, {0x14000000004?, 0x140005e3a18?})
    /Users/xxx/Developer/git/lima/pkg/vz/vz_driver_darwin.go:69 +0x78
github.com/lima-vm/lima/pkg/hostagent.(*HostAgent).Run(0x14000122000, {0x1052ad9b0?, 0x140001ac008})
    /Users/xxx/Developer/git/lima/pkg/hostagent/hostagent.go:295 +0x6fc
main.hostagentAction(0x14000300600, {0x1400018e870, 0x1, 0x5?})
    /Users/xxx/Developer/git/lima/cmd/limactl/hostagent.go:99 +0x650
github.com/spf13/cobra.(*Command).execute(0x14000300600, {0x1400018e820, 0x5, 0x5})
    /Users/xxx/.cache/go/pkg/mod/github.com/spf13/cobra@v1.6.1/command.go:916 +0x5c8
github.com/spf13/cobra.(*Command).ExecuteC(0x1400024c600)
    /Users/xxx/.cache/go/pkg/mod/github.com/spf13/cobra@v1.6.1/command.go:1044 +0x35c
github.com/spf13/cobra.(*Command).Execute(...)
    /Users/xxx/.cache/go/pkg/mod/github.com/spf13/cobra@v1.6.1/command.go:968
main.main()
    /Users/xxx/Developer/git/lima/cmd/limactl/main.go:23 +0x20

oracle-vz.zip

OS: macOS 13.0.1 M1

balajiv113 commented 1 year ago

I just tried this template, it works fine for me. I am running macOS 13.1 Beta M1

Have you tried from source (or) the release build ?

kj-creater commented 1 year ago

I tried to release and compile v0.14.0-beta.1, and the problem is the same. What can I do to help this issue?

balajiv113 commented 1 year ago

Is running limactl start template://experimental/vz working ??

abiosoft commented 1 year ago

I actually do experience something similar and I suspect it is related to GVisor network.

I have only experienced a frozen startup once or twice, but what I do experience more frequently is frozen SSH sessions. When it happens, everything still works with the exception of SSH and everything linked to it e.g. port forwarding.

I am still unable to pin-point the cause, and it does happen with multiple distros including the default vz template.

balajiv113 commented 1 year ago

I actually do experience something similar and I suspect it is related to GVisor network.

I have only experienced a frozen startup once or twice, but what I do experience more frequently is frozen SSH sessions. When it happens, everything still works with the exception of SSH and everything linked to it e.g. port forwarding.

I am still unable to pin-point the cause, and it does happen with multiple distros including the default vz template.

Ah !! That's bad. I haven't tested on long running yet. Will give a try.

There might be a very slight possibility that the issue is related to dgram sockpair that is created as well.

kj-creater commented 1 year ago

I tested template://experimental/vz and using this template to customize CPU, Memory and Disk and got different results

balajiv113 commented 1 year ago

@kj-creater - Thanks for the video. i was able to reproduce this issue.

Looks like the disk size is too low for vm to start even. I was able to reproduce this same issue with qemu driver as well with disk size being 2GiB. Please increase the disk size to maybe 5GiB. This worked fine for me.

Code-Hex commented 1 year ago

I have this issue and I believe the same reason with @abiosoft

I suspect it is related to GVisor network.

This hang has not occurred in network communication without gvisor-tap-vsock (e.g. examples in vz repository)

spacedub commented 1 year ago

Facing this as well.

These seem related:

FWIW, while tinkering with start / stop, I managed to SIGSEGV:


INFO[0000] Using the existing instance "default"
INFO[0000] Attempting to download the nerdctl archive from "https://github.com/containerd/nerdctl/releases/download/v1.1.0/nerdctl-full-1.1.0-linux-arm64.tar.gz"  digest="sha256:3b613a1be5a24460c44bb93a3609b790ada94e06efd1a86467d45bec7da8b449"
INFO[0000] Using cache "/Users/dmp/Library/Caches/lima/download/by-url-sha256/c69be86b3e48430e3d687d54361cf15b90e2c067fae6a294ca6292d41f42bf0e/data"
INFO[0000] [hostagent] Starting VZ (hint: to watch the boot progress, see "/Users/dmp/.codecomet/run/vm/default/serial.log")
INFO[0000] [hostagent] Setting up Rosetta share
INFO[0000] SSH Local Port: 60022
INFO[0000] [hostagent] panic: runtime error: invalid memory address or nil pointer dereference
INFO[0000] [hostagent] [signal SIGSEGV: segmentation violation code=0x2 addr=0x20 pc=0x104964cdc]
INFO[0000] [hostagent] goroutine 132 [running]:
INFO[0000] [hostagent] github.com/containers/gvisor-tap-vsock/pkg/tap.(*Switch).Accept(0x14000156000, {0x104f48ed8, 0x1400060c080}, {0x104f50910, 0x140000ca1f0})
INFO[0000] [hostagent]  /Users/dmp/go/pkg/mod/github.com/containers/gvisor-tap-vsock@v0.4.1-0.20220920072955-5b1aff8ba743/pkg/tap/switch.go:83
INFO[0000] [hostagent]  +
INFO[0000] [hostagent] github.com/containers/gvisor-tap-vsock/pkg/virtualnetwork.(*VirtualNetwork).AcceptBess(...)
INFO[0000] [hostagent]  /Users/dmp/go/pkg/mod/github.com/containers/gvisor-tap-vsock@v0.4.1-0.20220920072955-5b1aff8ba743/pkg/virtualnetwork/bess.go:9
INFO[0000] [hostagent] github.com/lima-vm/lima/pkg/networks.run.func1()
INFO[0000] [hostagent]  /Users/dmp/Projects/GitHub/codecomet/isovaline/dependencies/lima-vm/lima/pkg/networks/gvisor.go:90 +0x64
INFO[0000] [hostagent] golang.org/x/sync/errgroup.(*Group).Go.func1()
INFO[0000] [hostagent]  /Users/dmp/go/pkg/mod/golang.org/x/sync@v0.1.0/errgroup/errgroup.go:75 +0x5c
INFO[0000] [hostagent] created by
INFO[0000] [hostagent] :72 +0xa4
FATA[0000] host agent process has exited: exit status 2
jlujan commented 1 year ago

Hang on VM stop from https://github.com/lima-vm/lima/issues/1358

OUTPUT:

$ limactl stop
INFO[0000] Sending SIGINT to hostagent process 55657
INFO[0000] Waiting for the host agent and the driver processes to shut down
INFO[0000] [hostagent] 2023/02/10 08:40:10 tcpproxy: for incoming conn 127.0.0.1:52490, error dialing "192.168.5.15:22": connect tcp 192.168.5.15:22: no route
INFO[0000] [hostagent] Received SIGINT, shutting down the host agent
INFO[0000] [hostagent] Shutting down the host agent
INFO[0000] [hostagent] Stopping forwarding "/run/user/501/buildkit-default/buildkitd.sock" (guest) to "/Users/jlujan/.lima/default/sock/buildkitd.sock" (host)
INFO[0000] [hostagent] Stopping forwarding "/run/lima-guestagent.sock" (guest) to "/Users/jlujan/.lima/default/ga.sock" (host)
WARN[0000] [hostagent] failed to exit SSH master
WARN[0000] [hostagent] an error during shutting down the host agent
INFO[0000] [hostagent] Shutting down VZ
INFO[0001] [hostagent] panic: runtime/cgo: misuse of an invalid Handle
INFO[0001] [hostagent] goroutine 17 [running, locked to thread]:
INFO[0001] [hostagent] runtime/cgo.Handle.Value(...)
INFO[0001] [hostagent]  /opt/homebrew/Cellar/go/1.19.5/libexec/src/runtime/cgo/handle.go:124
INFO[0001] [hostagent] github.com/Code-Hex/vz/v3.changeStateOnObserver(0x0, 0x14000002680?)
INFO[0001] [hostagent]  /Users/jlujan/Library/Caches/Homebrew/go_mod_cache/pkg/mod/github.com/!code-!hex/vz/v3@v3.0.4/virtualization.go:160 +0xec
balajiv113 commented 1 year ago

I tried to reproduce this with #1383 and in a random case current running instance froze (ssh didn't work)

Looks like its related to gvisor (as abiosoft mentioned).

As once freezed i tried to start a new instance but even that didn't work. The connection was successful with gvisor-tap-vsock but no response

Will try to debug more with this information

Edit: The above observation is wrong. I was able to start new instances. Looks like the problem is with unixgram pair. My guess is conn.Read is freezing indefinitely because the underlying socket is closed. But not sure on why its getting closed

mmcheck24 commented 1 year ago

I had a somewhat similar error while stopping colima. In some cases, that I unfortunately can't reproduce, this happends while running in the background too. Sometimes every 10 minutes, sometimes after 2 hours.


{"level":"debug","msg":"guest agent event: {Time:2023-04-25 15:27:05.833653967 +0000 UTC LocalPortsAdded:[] LocalPortsRemoved:[{IP:0.0.0.0 Port:49153} {IP:0.0.0.0 Port:80} {IP::: Port:49153} {IP::: Port:80}] Errors:[]}","time":"2023-04-25T17:27:05+02:00"}
{"level":"info","msg":"Stopping forwarding TCP from 0.0.0.0:49153 to 0.0.0.0:49153","time":"2023-04-25T17:27:05+02:00"}
{"level":"info","msg":"Stopping forwarding TCP from 0.0.0.0:80 to 0.0.0.0:80","time":"2023-04-25T17:27:05+02:00"}
{"level":"info","msg":"Stopping forwarding TCP from [::]:49153 to 0.0.0.0:49153","time":"2023-04-25T17:27:05+02:00"}
{"level":"info","msg":"Stopping forwarding TCP from [::]:80 to 0.0.0.0:80","time":"2023-04-25T17:27:06+02:00"}
{"level":"debug","msg":"guest agent event: {Time:2023-04-25 15:27:08.833860635 +0000 UTC LocalPortsAdded:[] LocalPortsRemoved:[{IP:0.0.0.0 Port:11211} {IP::: Port:11211}] Errors:[]}","time":"2023-04-25T17:27:08+02:00"}
{"level":"info","msg":"Stopping forwarding TCP from 0.0.0.0:11211 to 0.0.0.0:11211","time":"2023-04-25T17:27:08+02:00"}
{"level":"info","msg":"Stopping forwarding TCP from [::]:11211 to 0.0.0.0:11211","time":"2023-04-25T17:27:08+02:00"}
{"level":"debug","msg":"guest agent event: {Time:2023-04-25 15:27:14.832182054 +0000 UTC LocalPortsAdded:[] LocalPortsRemoved:[{IP::: Port:5672} {IP:0.0.0.0 Port:5672}] Errors:[]}","time":"2023-04-25T17:27:14+02:00"}
{"level":"info","msg":"Stopping forwarding TCP from [::]:5672 to 0.0.0.0:5672","time":"2023-04-25T17:27:14+02:00"}
{"level":"info","msg":"Stopping forwarding TCP from 0.0.0.0:5672 to 0.0.0.0:5672","time":"2023-04-25T17:27:14+02:00"}
{"level":"info","msg":"Received SIGINT, shutting down the host agent","time":"2023-04-25T17:27:19+02:00"}
{"level":"info","msg":"Shutting down the host agent","time":"2023-04-25T17:27:19+02:00"}
{"level":"debug","msg":"Stop forwarding unix sockets","time":"2023-04-25T17:27:19+02:00"}
{"level":"info","msg":"Stopping forwarding \"/var/run/docker.sock\" (guest) to \"/Users/marvin.mohs/.colima/default/docker.sock\" (host)","time":"2023-04-25T17:27:19+02:00"}
{"level":"info","msg":"Stopping forwarding \"/var/run/docker.sock\" (guest) to \"/Users/marvin.mohs/.colima/docker.sock\" (host)","time":"2023-04-25T17:27:19+02:00"}
{"level":"info","msg":"Stopping forwarding \"/run/lima-guestagent.sock\" (guest) to \"/Users/marvin.mohs/.lima/colima/ga.sock\" (host)","time":"2023-04-25T17:27:19+02:00"}
{"level":"debug","msg":"shutting down the SSH master","time":"2023-04-25T17:27:19+02:00"}
{"level":"debug","msg":"executing ssh for exiting the master: /usr/bin/ssh [ssh -F /dev/null -o IdentityFile=\"/Users/marvin.mohs/.lima/_config/user\" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers=\"^aes128-gcm@openssh.com,aes256-gcm@openssh.com\" -o User=lima -o ControlMaster=auto -o ControlPath=\"/Users/marvin.mohs/.lima/colima/ssh.sock\" -o ControlPersist=5m -O exit -p 51178 127.0.0.1]","time":"2023-04-25T17:27:19+02:00"}
{"level":"info","msg":"Shutting down VZ","time":"2023-04-25T17:27:19+02:00"}
{"level":"error","msg":"dhcp: unhandled message type: RELEASE","time":"2023-04-25T17:27:21+02:00"}
panic: runtime/cgo: misuse of an invalid Handle

goroutine 17 [running, locked to thread]:
runtime/cgo.Handle.Value(...)
    /opt/homebrew/Cellar/go/1.20.3/libexec/src/runtime/cgo/handle.go:124
github.com/Code-Hex/vz/v3.changeStateOnObserver(0x0, 0x14000002680?)
    /Users/brew/Library/Caches/Homebrew/go_mod_cache/pkg/mod/github.com/!code-!hex/vz/v3@v3.0.5/virtualization.go:160 +0xb0```
kalikiana commented 1 year ago

So I saw this, too, for the first time. Same template that had been working fine suddenly would no longer start with this error. Prepared a new instance under another name and that worked fine. It seems as though something is retained about the network state of the instance which the new one doesn't have. Unfortunately I couldn't find anything relevant besides old pid files and logs which don't seem to affect this at all 🤔

GianlucaCesari commented 1 year ago

Any news on this ? I have the same problem while using trellis new lima based vm

balajiv113 commented 1 year ago

@GianlucaCesari Is vm stuck during start-up ??

Could you share your lima configuration if yes. If possible, give a try with latest lima master as well.

GianlucaCesari commented 1 year ago

Yes, i use the command trellis vm start which calls limactl start <machine name> Lima was installed with brew on a m1 pro mac, i tried to upgrade but ended up installing manually, it seems to be working for now.

This is the lima.yaml of my vm 

vmType: "vz"
rosetta:
  enabled: false
images:
- location: https://cloud-images.ubuntu.com/jammy/current/jammy-server-cloudimg-amd64.img
  arch: x86_64
- location: https://cloud-images.ubuntu.com/jammy/current/jammy-server-cloudimg-arm64.img
  arch: aarch64

mounts:
- location: <path>/site
  mountPoint: <path>/current
  writable: true

mountType: "virtiofs"
networks:
- vzNAT: true
containerd:  
  user: false
provision:
- mode: system
  script: |
    #!/bin/bash
    echo "127.0.0.1 $(hostname)" >> /etc/hosts
GianlucaCesari commented 1 year ago

Just kidding, it gave me a 4hour of error-free work and now it hangs, the vm says its running but if i try to shell into the vm it keeps hanging, and when i try to limactl start after limactl stop -f this is what it's giving me

Running command => limactl start whuis.com
INFO[0000] Using the existing instance "whuis.com"      
INFO[0000] [hostagent] Starting VZ (hint: to watch the boot progress, see "/Users/gianlucacesari/.lima/whuis.com/serial.log") 
INFO[0000] SSH Local Port: 49530                        
INFO[0000] [hostagent] new connection from  to          
INFO[0000] [hostagent] [VZ] - vm state change: running  
INFO[0000] [hostagent] Waiting for the essential requirement 1 of 3: "ssh" 
INFO[0003] [hostagent] 2023/05/10 12:10:19 tcpproxy: for incoming conn 127.0.0.1:49532, error dialing "192.168.5.15:22": connect tcp 192.168.5.15:22: no route to host 
INFO[0013] [hostagent] Waiting for the essential requirement 1 of 3: "ssh" 
INFO[0013] [hostagent] 2023/05/10 12:10:29 tcpproxy: for incoming conn 127.0.0.1:49533, error dialing "192.168.5.15:22": connect tcp 192.168.5.15:22: connection was refused 
INFO[0023] [hostagent] Waiting for the essential requirement 1 of 3: "ssh" 
INFO[0023] [hostagent] 2023/05/10 12:10:39 tcpproxy: for incoming conn 127.0.0.1:49534, error dialing "192.168.5.15:22": connect tcp 192.168.5.15:22: connection was refused 
INFO[0033] [hostagent] Waiting for the essential requirement 1 of 3: "ssh" 
INFO[0033] [hostagent] 2023/05/10 12:10:49 tcpproxy: for incoming conn 127.0.0.1:49535, error dialing "192.168.5.15:22": connect tcp 192.168.5.15:22: connection was refused 
INFO[0043] [hostagent] Waiting for the essential requirement 1 of 3: "ssh" 
INFO[0043] [hostagent] 2023/05/10 12:10:59 tcpproxy: for incoming conn 127.0.0.1:49536, error dialing "192.168.5.15:22": connect tcp 192.168.5.15:22: connection was refused 
INFO[0053] [hostagent] Waiting for the essential requirement 1 of 3: "ssh"
balajiv113 commented 1 year ago

This doesn't look like a network issue, instead looks more of like disk corruption.

Unfortunately in vz we have a open issue that early boot log are not captured. Below we are changing the vmType to QEMU to identify boot failure with the same disk booted via vz.

Just for testing purpose can you try the following,

GianlucaCesari commented 1 year ago

Just for the sake of finding out if the problem is vz (qemu is not yet supported by trellis so i didn't have high hopes) i tried what you asked me, but even changing to qemu, removing mountType and 

networks:
- vzNAT: true

cause it was throwing errors, it still hangs with this message:

INFO[0000] Using the existing instance "whuis.com"
INFO[0000] [hostagent] Starting QEMU (hint: to watch the boot progress, see "/Users/gianlucacesari/.lima/whuis.com/serial.log")
INFO[0000] SSH Local Port: 50548
INFO[0000] [hostagent] Waiting for the essential requirement 1 of 5: "ssh"
INFO[0017] [hostagent] Waiting for the essential requirement 1 of 5: "ssh"
INFO[0027] [hostagent] Waiting for the essential requirement 1 of 5: "ssh"
INFO[0037] [hostagent] Waiting for the essential requirement 1 of 5: "ssh"
INFO[0047] [hostagent] Waiting for the essential requirement 1 of 5: "ssh"

This is the ha.stderr.log if it can be helpful

balajiv113 commented 1 year ago

Could you please share the serial.log file.

GianlucaCesari commented 1 year ago

It's empty, the only lines in it are these:


Ubuntu 22.04.2 LTS lima-whuis hvc0

lima-whuis login: %
balajiv113 commented 1 year ago

That's odd, after changing to qemu we should get initial boot logs in serial.log file

GianlucaCesari commented 1 year ago

serial.log Ah yes, sorry i re-run with vz, this is the qemu log

balajiv113 commented 1 year ago

Thanks. Unfortunately from serial.log it looks like successfully booted :(

terev commented 1 year ago

Experiencing the same as op after upgrading to the latest released versions of colima / lima, then creating a new vz vm.

colima version 0.5.5
git commit: 6251dc2c2c5d8197c356f0e402ad028945f0e830

runtime: docker
arch: aarch64
client: v20.10.21
server: v23.0.6

limactl version 0.16.0
balajiv113 commented 1 year ago

@terev New instance itself not getting started fully ???

terev commented 1 year ago

@balajiv113 yes thats right. though it may be slightly different:

colima start --memory 8 --cpu 2 --mount-type virtiofs --vm-type vz --vz-rosetta --dns 1.1.1.1
INFO[0000] starting colima
INFO[0000] runtime: docker
INFO[0000] creating and starting ...                     context=vm
> [hostagent] Driver stopped due to error: "usernet unable to resolve IP for SSH forwarding"
> [hostagent] Shutting down the host agent
> [hostagent] failed to exit SSH master
> [hostagent] Shutting down VZ
> [hostagent] Waiting for the essential requirement 1 of 3: "ssh"
> exiting, status={Running:false Degraded:false Exiting:true Errors:[] SSHLocalPort:0} (hint: see "/Users/trevorfoster/.lima/colima/ha.stderr.log")
FATA[0065] error starting vm: error at 'creating and starting': exit status 1
limactl start colima
INFO[0000] Using the existing instance "colima"
INFO[0000] [hostagent] Starting VZ (hint: to watch the boot progress, see "/Users/trevorfoster/.lima/colima/serial.log")
INFO[0000] [hostagent] new connection from  to
INFO[0000] [hostagent] Setting up Rosetta share
INFO[0000] SSH Local Port: 62007
INFO[0000] [hostagent] Waiting for the essential requirement 1 of 3: "ssh"
INFO[0000] [hostagent] [VZ] - vm state change: running
INFO[0010] [hostagent] Waiting for the essential requirement 1 of 3: "ssh"
INFO[0020] [hostagent] Waiting for the essential requirement 1 of 3: "ssh"
INFO[0030] [hostagent] Waiting for the essential requirement 1 of 3: "ssh"
INFO[0040] [hostagent] Waiting for the essential requirement 1 of 3: "ssh"
INFO[0050] [hostagent] Waiting for the essential requirement 1 of 3: "ssh"
INFO[0060] [hostagent] Driver stopped due to error: "usernet unable to resolve IP for SSH forwarding"
INFO[0060] [hostagent] Shutting down the host agent
WARN[0060] [hostagent] failed to exit SSH master
INFO[0060] [hostagent] Shutting down VZ
INFO[0060] [hostagent] Waiting for the essential requirement 1 of 3: "ssh"
FATA[0065] exiting, status={Running:false Degraded:false Exiting:true Errors:[] SSHLocalPort:0} (hint: see "/Users/trevorfoster/.lima/colima/ha.stderr.log")

edit: @balajiv113 fixed thanks to the suggestion to update to >= 13.3.1 here https://github.com/abiosoft/colima/issues/684#issuecomment-1568693312

AnhQKatalon commented 1 year ago

Fixed with the help from @balajiv113 . Thanks to the suggestion to update to >= 13.3.1 here https://github.com/abiosoft/colima/issues/684#issuecomment-1568693312

damienmckenna commented 1 year ago

I'm seeing this problem with the latest macOS 13.5.1 using colima 0.5.5 and lima 0.17.2 installed from Homebrew.