[arch-general][OT] vagrant + ubuntu 20.04 based docker image
Hello ! At work I need to use an ubuntu 20.04 based docker image built by our org, and we use vagrant to easy the way to load and start the image. I'm not able to do "vagrant up", since it seems the host can't connect to the container (guest):
INFO global: Vagrant version: 2.4.1 INFO global: Ruby version: 3.0.6 INFO global: RubyGems version: 3.3.25 INFO global: VAGRANT_INSTALLER_EMBEDDED_DIR="/opt/vagrant/embedded" INFO global: VAGRANT_EXECUTABLE="/opt/vagrant/embedded/gems/gems/vagrant-2.4.1/bin/vagrant" INFO global: VAGRANT_INSTALLER_ENV="1" INFO global: VAGRANT_INSTALLER_VERSION="2" INFO global: VAGRANT_LOG="debug" ... DEBUG ssh: Checking key permissions: /home/vasqueja/.vagrant.d/insecure_private_keys/vagrant.key.ed25519 DEBUG ssh: Checking key permissions: /home/vasqueja/.vagrant.d/insecure_private_keys/vagrant.key.rsa INFO ssh: Attempting SSH connection... INFO ssh: Attempting to connect to SSH... INFO ssh: - Host: 127.0.0.1 INFO ssh: - Port: 2222 INFO ssh: - Username: a2sdk INFO ssh: - Password? false INFO ssh: - Key Path: ["/home/vasqueja/.vagrant.d/insecure_private_keys/vagrant.key.ed25519", "/home/vasqueja/.vagrant.d/insecure_private_keys/vagrant.key.rsa"] DEBUG ssh: - connect_opts: {:auth_methods=>["none", "hostbased", "publickey"], :config=>false, :forward_agent=>true, :send_env=>false, :keys_only=>true, :verify_host_key=>:never, :password=>nil, :port=>"2222", :timeout=>15, :user_known_hosts_file=>[], :verbose=>:debug, :logger=>#<Logger:0x000070e2913f9dc0 @level=0, @progname=nil, @default_formatter=#<Logger::Formatter:0x000070e2913f9d20 @datetime_format=nil>, @formatter=nil, @logdev=#<Logger::LogDevice:0x000070e2913f9c80 @shift_period_suffix=nil, @shift_size=nil, @shift_age=nil, @filename=nil, @dev=#<StringIO:0x000070e2913f9e38>, @binmode=false, @mon_data=#<Monitor:0x000070e2913f9c30>, @mon_data_owner_object_id=14600>>, :keys=>["/home/vasqueja/.vagrant.d/insecure_private_keys/vagrant.key.ed25519", "/home/vasqueja/.vagrant.d/insecure_private_keys/vagrant.key.rsa"], :remote_user=>"a2sdk", :keepalive=>true, :keepalive_interval=>5} DEBUG ssh: == Net-SSH connection debug-level log START == DEBUG ssh: D, [2024-01-26T23:11:19.799621 #24466] DEBUG -- net.ssh.transport.session[391c]: establishing connection to 127.0.0.1:2222 D, [2024-01-26T23:11:19.799907 #24466] DEBUG -- net.ssh.transport.session[391c]: connection established I, [2024-01-26T23:11:19.799980 #24466] INFO -- net.ssh.transport.server_version[3930]: negotiating protocol version D, [2024-01-26T23:11:19.800002 #24466] DEBUG -- net.ssh.transport.server_version[3930]: local is `SSH-2.0-Ruby/Net::SSH_7.2.1 x86_64-linux' D, [2024-01-26T23:11:19.810429 #24466] DEBUG -- net.ssh.transport.server_version[3930]: remote is `SSH-2.0-OpenSSH_8.2p1 Ubuntu-4ubuntu0.9' I, [2024-01-26T23:11:19.810692 #24466] INFO -- net.ssh.transport.algorithms[3944]: sending KEXINIT D, [2024-01-26T23:11:19.810886 #24466] DEBUG -- socket[3958]: queueing packet nr 0 type 20 len 852 D, [2024-01-26T23:11:19.810953 #24466] DEBUG -- socket[3958]: sent 856 bytes D, [2024-01-26T23:11:19.811421 #24466] DEBUG -- socket[3958]: read 1056 bytes D, [2024-01-26T23:11:19.811496 #24466] DEBUG -- socket[3958]: received packet nr 0 type 20 len 1052 I, [2024-01-26T23:11:19.811532 #24466] INFO -- net.ssh.transport.algorithms[3944]: got KEXINIT from server I, [2024-01-26T23:11:19.811623 #24466] INFO -- net.ssh.transport.algorithms[3944]: negotiating algorithms D, [2024-01-26T23:11:19.811712 #24466] DEBUG -- net.ssh.transport.algorithms[3944]: negotiated: ... * kex: ecdh-sha2-nistp521 * host_key: ssh-ed25519 * encryption_server: aes256-ctr * encryption_client: aes256-ctr * hmac_client: hmac-sha2-512-etm@openssh.com * hmac_server: hmac-sha2-512-etm@openssh.com * compression_client: none * compression_server: none * language_client: * language_server: D, [2024-01-26T23:11:19.811733 #24466] DEBUG -- net.ssh.transport.algorithms[3944]: exchanging keys D, [2024-01-26T23:11:19.812318 #24466] DEBUG -- socket[3958]: queueing packet nr 1 type 30 len 148 D, [2024-01-26T23:11:19.812375 #24466] DEBUG -- socket[3958]: sent 152 bytes D, [2024-01-26T23:11:19.816223 #24466] DEBUG -- socket[3958]: read 312 bytes D, [2024-01-26T23:11:19.816293 #24466] DEBUG -- socket[3958]: received packet nr 1 type 31 len 292 D, [2024-01-26T23:11:19.818291 #24466] DEBUG -- socket[3958]: queueing packet nr 2 type 21 len 20 D, [2024-01-26T23:11:19.818346 #24466] DEBUG -- socket[3958]: sent 24 bytes D, [2024-01-26T23:11:19.818401 #24466] DEBUG -- socket[3958]: received packet nr 2 type 21 len 12 D, [2024-01-26T23:11:19.818751 #24466] DEBUG -- net.ssh.authentication.session[396c]: beginning authentication of `a2sdk' D, [2024-01-26T23:11:19.818817 #24466] DEBUG -- socket[3958]: using encrypt-then-mac D, [2024-01-26T23:11:19.820166 #24466] DEBUG -- socket[3958]: queueing packet nr 3 type 5 len 32 D, [2024-01-26T23:11:19.820205 #24466] DEBUG -- socket[3958]: sent 100 bytes D, [2024-01-26T23:11:19.859904 #24466] DEBUG -- socket[3958]: read 100 bytes D, [2024-01-26T23:11:19.860311 #24466] DEBUG -- socket[3958]: received packet nr 3 type 6 len 32 D, [2024-01-26T23:11:19.860522 #24466] DEBUG -- net.ssh.authentication.session[396c]: trying none D, [2024-01-26T23:11:19.860731 #24466] DEBUG -- socket[3958]: using encrypt-then-mac D, [2024-01-26T23:11:19.860969 #24466] DEBUG -- socket[3958]: queueing packet nr 4 type 50 len 48 D, [2024-01-26T23:11:19.861076 #24466] DEBUG -- socket[3958]: sent 116 bytes D, [2024-01-26T23:11:19.866706 #24466] DEBUG -- socket[3958]: read 100 bytes D, [2024-01-26T23:11:19.867057 #24466] DEBUG -- socket[3958]: received packet nr 4 type 51 len 32 D, [2024-01-26T23:11:19.867183 #24466] DEBUG -- net.ssh.authentication.session[396c]: allowed methods: publickey,password D, [2024-01-26T23:11:19.867282 #24466] DEBUG -- net.ssh.authentication.methods.none[3980]: none failed D, [2024-01-26T23:11:19.867369 #24466] DEBUG -- net.ssh.authentication.session[396c]: trying publickey D, [2024-01-26T23:11:19.868848 #24466] DEBUG -- net.ssh.authentication.agent[3994]: connecting to ssh-agent D, [2024-01-26T23:11:19.869065 #24466] DEBUG -- net.ssh.authentication.agent[3994]: sending agent request 1 len 44 D, [2024-01-26T23:11:19.869366 #24466] DEBUG -- net.ssh.authentication.agent[3994]: received agent packet 5 len 1 D, [2024-01-26T23:11:19.869434 #24466] DEBUG -- net.ssh.authentication.agent[3994]: sending agent request 11 len 0 D, [2024-01-26T23:11:19.869678 #24466] DEBUG -- net.ssh.authentication.agent[3994]: received agent packet 12 len 498 D, [2024-01-26T23:11:19.870704 #24466] DEBUG -- net.ssh.authentication.methods.publickey[39bc]: trying publickey (dd:3b:b8:2e:85:04:06:e9:ab:ff:a8:0a:c0:04:6e:d6) alg rsa-sha2-256 D, [2024-01-26T23:11:19.870908 #24466] DEBUG -- socket[3958]: using encrypt-then-mac D, [2024-01-26T23:11:19.871129 #24466] DEBUG -- socket[3958]: queueing packet nr 5 type 50 len 352 D, [2024-01-26T23:11:19.871241 #24466] DEBUG -- socket[3958]: sent 420 bytes D, [2024-01-26T23:11:19.876890 #24466] DEBUG -- socket[3958]: read 100 bytes D, [2024-01-26T23:11:19.877237 #24466] DEBUG -- socket[3958]: received packet nr 5 type 51 len 32 D, [2024-01-26T23:11:19.877359 #24466] DEBUG -- net.ssh.authentication.session[396c]: allowed methods: publickey,password D, [2024-01-26T23:11:19.877425 #24466] DEBUG -- net.ssh.authentication.methods.publickey[39bc]: trying publickey (dd:3b:b8:2e:85:04:06:e9:ab:ff:a8:0a:c0:04:6e:d6) alg ssh-rsa D, [2024-01-26T23:11:19.877582 #24466] DEBUG -- socket[3958]: using encrypt-then-mac D, [2024-01-26T23:11:19.877778 #24466] DEBUG -- socket[3958]: queueing packet nr 6 type 50 len 352 D, [2024-01-26T23:11:19.877885 #24466] DEBUG -- socket[3958]: sent 420 bytes D, [2024-01-26T23:11:19.883542 #24466] DEBUG -- socket[3958]: read 100 bytes D, [2024-01-26T23:11:19.883942 #24466] DEBUG -- socket[3958]: received packet nr 6 type 51 len 32 D, [2024-01-26T23:11:19.884065 #24466] DEBUG -- net.ssh.authentication.session[396c]: allowed methods: publickey,password D, [2024-01-26T23:11:19.884282 #24466] DEBUG -- net.ssh.authentication.methods.publickey[39bc]: trying publickey (c8:ac:1c:f8:c5:f9:7f:fc:86:97:a4:96:a3:a1:2e:d8) alg ssh-ed25519 D, [2024-01-26T23:11:19.884463 #24466] DEBUG -- socket[3958]: using encrypt-then-mac D, [2024-01-26T23:11:19.884677 #24466] DEBUG -- socket[3958]: queueing packet nr 7 type 50 len 128 D, [2024-01-26T23:11:19.884800 #24466] DEBUG -- socket[3958]: sent 196 bytes D, [2024-01-26T23:11:19.890441 #24466] DEBUG -- socket[3958]: read 100 bytes D, [2024-01-26T23:11:19.890795 #24466] DEBUG -- socket[3958]: received packet nr 7 type 51 len 32 D, [2024-01-26T23:11:19.890918 #24466] DEBUG -- net.ssh.authentication.session[396c]: allowed methods: publickey,password E, [2024-01-26T23:11:19.891081 #24466] ERROR -- net.ssh.authentication.session[396c]: all authorization methods failed (tried none, publickey)
DEBUG ssh: == Net-SSH connection debug-level log END == INFO ssh: SSH not up: #<Vagrant::Errors::SSHAuthenticationFailed: SSH authentication failed! This is typically caused by the public/private keypair for the SSH user not being properly set on the guest VM. Please verify that the guest VM is setup with the proper public key, and that the private key path for Vagrant is setup properly as well.> ERROR warden: Error occurred: Guest-specific operations were attempted on a machine that is not ready for guest communication. This should not happen and a bug should be reported. INFO warden: Beginning recovery process... INFO warden: Recovery complete. INFO warden: Beginning recovery process... INFO warden: Recovery complete. INFO warden: Beginning recovery process... INFO warden: Recovery complete. ERROR warden: Error occurred: Guest-specific operations were attempted on a machine that is not ready for guest communication. This should not happen and a bug should be reported. INFO warden: Beginning recovery process... INFO warden: Recovery complete. ERROR warden: Error occurred: Guest-specific operations were attempted on a machine that is not ready for guest communication. This should not happen and a bug should be reported.
... INFO interface: error: Guest-specific operations were attempted on a machine that is not ready for guest communication. This should not happen and a bug should be reported. Guest-specific operations were attempted on a machine that is not ready for guest communication. This should not happen and a bug should be reported. INFO interface: Machine: error-exit ["Vagrant::Errors::MachineGuestNotReady", "Guest-specific operations were attempted on a machine that is not\nready for guest communication. This should not happen and a bug\nshould be reported."]
After the SSH authentication error, apparently because none of the attempted key authentication methods worked. Weird thing, on ubuntu 22.04 there's no problem. On arch is that I see the error. BTW, I tried "config.ssh.disable_deprecated_algorithms" [1] set to true on the Vagrantfile, and it doesn't help. I see nothing particularly curious on the Vagrantfile. For SSH:
# SSH options sdk.ssh.username = "<container_username>" sdk.ssh.forward_agent = true sdk.ssh.pty = true sdk.ssh.forward_x11 = true sdk.ssh.insert_key = false
Disabling deprecated algorithms since Arch has obviously a newer openssh, but again, that didn't help. It's weird that on arch the SSH authentication fails... I've created other docker containers based on ubuntu, pretty similar on this SSH Vagrantfile config, and no issues. On the other hand, I've also used other docker containers. Actually there are 2 from the org I work, that I would like to use on my arch box, but I just cant, currently relying on remote VMs... Thanks for any hints... -- Javier [1] https://developer.hashicorp.com/vagrant/docs/vagrantfile/ssh_settings
On 1/31/24 00:00, Javier wrote:
Hello !
At work I need to use an ubuntu 20.04 based docker image built by our org, and we use vagrant to easy the way to load and start the image.
I'm not able to do "vagrant up", since it seems the host can't connect to the container (guest):
INFO global: Vagrant version: 2.4.1 INFO global: Ruby version: 3.0.6 INFO global: RubyGems version: 3.3.25 INFO global: VAGRANT_INSTALLER_EMBEDDED_DIR="/opt/vagrant/embedded" INFO global: VAGRANT_EXECUTABLE="/opt/vagrant/embedded/gems/gems/vagrant-2.4.1/bin/vagrant" INFO global: VAGRANT_INSTALLER_ENV="1" INFO global: VAGRANT_INSTALLER_VERSION="2" INFO global: VAGRANT_LOG="debug" ... DEBUG ssh: Checking key permissions: /home/vasqueja/.vagrant.d/insecure_private_keys/vagrant.key.ed25519 DEBUG ssh: Checking key permissions: /home/vasqueja/.vagrant.d/insecure_private_keys/vagrant.key.rsa INFO ssh: Attempting SSH connection... INFO ssh: Attempting to connect to SSH... INFO ssh: - Host: 127.0.0.1 INFO ssh: - Port: 2222 INFO ssh: - Username: a2sdk INFO ssh: - Password? false INFO ssh: - Key Path: ["/home/vasqueja/.vagrant.d/insecure_private_keys/vagrant.key.ed25519", "/home/vasqueja/.vagrant.d/insecure_private_keys/vagrant.key.rsa"] DEBUG ssh: - connect_opts: {:auth_methods=>["none", "hostbased", "publickey"], :config=>false, :forward_agent=>true, :send_env=>false, :keys_only=>true, :verify_host_key=>:never, :password=>nil, :port=>"2222", :timeout=>15, :user_known_hosts_file=>[], :verbose=>:debug, :logger=>#<Logger:0x000070e2913f9dc0 @level=0, @progname=nil, @default_formatter=#<Logger::Formatter:0x000070e2913f9d20 @datetime_format=nil>, @formatter=nil, @logdev=#<Logger::LogDevice:0x000070e2913f9c80 @shift_period_suffix=nil, @shift_size=nil, @shift_age=nil, @filename=nil, @dev=#<StringIO:0x000070e2913f9e38>, @binmode=false, @mon_data=#<Monitor:0x000070e2913f9c30>, @mon_data_owner_object_id=14600>>, :keys=>["/home/vasqueja/.vagrant.d/insecure_private_keys/vagrant.key.ed25519", "/home/vasqueja/.vagrant.d/insecure_private_keys/vagrant.key.rsa"], :remote_user=>"a2sdk", :keepalive=>true, :keepalive_interval=>5} DEBUG ssh: == Net-SSH connection debug-level log START == DEBUG ssh: D, [2024-01-26T23:11:19.799621 #24466] DEBUG -- net.ssh.transport.session[391c]: establishing connection to 127.0.0.1:2222 D, [2024-01-26T23:11:19.799907 #24466] DEBUG -- net.ssh.transport.session[391c]: connection established I, [2024-01-26T23:11:19.799980 #24466] INFO -- net.ssh.transport.server_version[3930]: negotiating protocol version D, [2024-01-26T23:11:19.800002 #24466] DEBUG -- net.ssh.transport.server_version[3930]: local is `SSH-2.0-Ruby/Net::SSH_7.2.1 x86_64-linux' D, [2024-01-26T23:11:19.810429 #24466] DEBUG -- net.ssh.transport.server_version[3930]: remote is `SSH-2.0-OpenSSH_8.2p1 Ubuntu-4ubuntu0.9' I, [2024-01-26T23:11:19.810692 #24466] INFO -- net.ssh.transport.algorithms[3944]: sending KEXINIT D, [2024-01-26T23:11:19.810886 #24466] DEBUG -- socket[3958]: queueing packet nr 0 type 20 len 852 D, [2024-01-26T23:11:19.810953 #24466] DEBUG -- socket[3958]: sent 856 bytes D, [2024-01-26T23:11:19.811421 #24466] DEBUG -- socket[3958]: read 1056 bytes D, [2024-01-26T23:11:19.811496 #24466] DEBUG -- socket[3958]: received packet nr 0 type 20 len 1052 I, [2024-01-26T23:11:19.811532 #24466] INFO -- net.ssh.transport.algorithms[3944]: got KEXINIT from server I, [2024-01-26T23:11:19.811623 #24466] INFO -- net.ssh.transport.algorithms[3944]: negotiating algorithms D, [2024-01-26T23:11:19.811712 #24466] DEBUG -- net.ssh.transport.algorithms[3944]: negotiated: ... * kex: ecdh-sha2-nistp521 * host_key: ssh-ed25519 * encryption_server: aes256-ctr * encryption_client: aes256-ctr * hmac_client: hmac-sha2-512-etm@openssh.com * hmac_server: hmac-sha2-512-etm@openssh.com * compression_client: none * compression_server: none * language_client: * language_server: D, [2024-01-26T23:11:19.811733 #24466] DEBUG -- net.ssh.transport.algorithms[3944]: exchanging keys D, [2024-01-26T23:11:19.812318 #24466] DEBUG -- socket[3958]: queueing packet nr 1 type 30 len 148 D, [2024-01-26T23:11:19.812375 #24466] DEBUG -- socket[3958]: sent 152 bytes D, [2024-01-26T23:11:19.816223 #24466] DEBUG -- socket[3958]: read 312 bytes D, [2024-01-26T23:11:19.816293 #24466] DEBUG -- socket[3958]: received packet nr 1 type 31 len 292 D, [2024-01-26T23:11:19.818291 #24466] DEBUG -- socket[3958]: queueing packet nr 2 type 21 len 20 D, [2024-01-26T23:11:19.818346 #24466] DEBUG -- socket[3958]: sent 24 bytes D, [2024-01-26T23:11:19.818401 #24466] DEBUG -- socket[3958]: received packet nr 2 type 21 len 12 D, [2024-01-26T23:11:19.818751 #24466] DEBUG -- net.ssh.authentication.session[396c]: beginning authentication of `a2sdk' D, [2024-01-26T23:11:19.818817 #24466] DEBUG -- socket[3958]: using encrypt-then-mac D, [2024-01-26T23:11:19.820166 #24466] DEBUG -- socket[3958]: queueing packet nr 3 type 5 len 32 D, [2024-01-26T23:11:19.820205 #24466] DEBUG -- socket[3958]: sent 100 bytes D, [2024-01-26T23:11:19.859904 #24466] DEBUG -- socket[3958]: read 100 bytes D, [2024-01-26T23:11:19.860311 #24466] DEBUG -- socket[3958]: received packet nr 3 type 6 len 32 D, [2024-01-26T23:11:19.860522 #24466] DEBUG -- net.ssh.authentication.session[396c]: trying none D, [2024-01-26T23:11:19.860731 #24466] DEBUG -- socket[3958]: using encrypt-then-mac D, [2024-01-26T23:11:19.860969 #24466] DEBUG -- socket[3958]: queueing packet nr 4 type 50 len 48 D, [2024-01-26T23:11:19.861076 #24466] DEBUG -- socket[3958]: sent 116 bytes D, [2024-01-26T23:11:19.866706 #24466] DEBUG -- socket[3958]: read 100 bytes D, [2024-01-26T23:11:19.867057 #24466] DEBUG -- socket[3958]: received packet nr 4 type 51 len 32 D, [2024-01-26T23:11:19.867183 #24466] DEBUG -- net.ssh.authentication.session[396c]: allowed methods: publickey,password D, [2024-01-26T23:11:19.867282 #24466] DEBUG -- net.ssh.authentication.methods.none[3980]: none failed D, [2024-01-26T23:11:19.867369 #24466] DEBUG -- net.ssh.authentication.session[396c]: trying publickey D, [2024-01-26T23:11:19.868848 #24466] DEBUG -- net.ssh.authentication.agent[3994]: connecting to ssh-agent D, [2024-01-26T23:11:19.869065 #24466] DEBUG -- net.ssh.authentication.agent[3994]: sending agent request 1 len 44 D, [2024-01-26T23:11:19.869366 #24466] DEBUG -- net.ssh.authentication.agent[3994]: received agent packet 5 len 1 D, [2024-01-26T23:11:19.869434 #24466] DEBUG -- net.ssh.authentication.agent[3994]: sending agent request 11 len 0 D, [2024-01-26T23:11:19.869678 #24466] DEBUG -- net.ssh.authentication.agent[3994]: received agent packet 12 len 498 D, [2024-01-26T23:11:19.870704 #24466] DEBUG -- net.ssh.authentication.methods.publickey[39bc]: trying publickey (dd:3b:b8:2e:85:04:06:e9:ab:ff:a8:0a:c0:04:6e:d6) alg rsa-sha2-256 D, [2024-01-26T23:11:19.870908 #24466] DEBUG -- socket[3958]: using encrypt-then-mac D, [2024-01-26T23:11:19.871129 #24466] DEBUG -- socket[3958]: queueing packet nr 5 type 50 len 352 D, [2024-01-26T23:11:19.871241 #24466] DEBUG -- socket[3958]: sent 420 bytes D, [2024-01-26T23:11:19.876890 #24466] DEBUG -- socket[3958]: read 100 bytes D, [2024-01-26T23:11:19.877237 #24466] DEBUG -- socket[3958]: received packet nr 5 type 51 len 32 D, [2024-01-26T23:11:19.877359 #24466] DEBUG -- net.ssh.authentication.session[396c]: allowed methods: publickey,password D, [2024-01-26T23:11:19.877425 #24466] DEBUG -- net.ssh.authentication.methods.publickey[39bc]: trying publickey (dd:3b:b8:2e:85:04:06:e9:ab:ff:a8:0a:c0:04:6e:d6) alg ssh-rsa D, [2024-01-26T23:11:19.877582 #24466] DEBUG -- socket[3958]: using encrypt-then-mac D, [2024-01-26T23:11:19.877778 #24466] DEBUG -- socket[3958]: queueing packet nr 6 type 50 len 352 D, [2024-01-26T23:11:19.877885 #24466] DEBUG -- socket[3958]: sent 420 bytes D, [2024-01-26T23:11:19.883542 #24466] DEBUG -- socket[3958]: read 100 bytes D, [2024-01-26T23:11:19.883942 #24466] DEBUG -- socket[3958]: received packet nr 6 type 51 len 32 D, [2024-01-26T23:11:19.884065 #24466] DEBUG -- net.ssh.authentication.session[396c]: allowed methods: publickey,password D, [2024-01-26T23:11:19.884282 #24466] DEBUG -- net.ssh.authentication.methods.publickey[39bc]: trying publickey (c8:ac:1c:f8:c5:f9:7f:fc:86:97:a4:96:a3:a1:2e:d8) alg ssh-ed25519 D, [2024-01-26T23:11:19.884463 #24466] DEBUG -- socket[3958]: using encrypt-then-mac D, [2024-01-26T23:11:19.884677 #24466] DEBUG -- socket[3958]: queueing packet nr 7 type 50 len 128 D, [2024-01-26T23:11:19.884800 #24466] DEBUG -- socket[3958]: sent 196 bytes D, [2024-01-26T23:11:19.890441 #24466] DEBUG -- socket[3958]: read 100 bytes D, [2024-01-26T23:11:19.890795 #24466] DEBUG -- socket[3958]: received packet nr 7 type 51 len 32 D, [2024-01-26T23:11:19.890918 #24466] DEBUG -- net.ssh.authentication.session[396c]: allowed methods: publickey,password E, [2024-01-26T23:11:19.891081 #24466] ERROR -- net.ssh.authentication.session[396c]: all authorization methods failed (tried none, publickey)
DEBUG ssh: == Net-SSH connection debug-level log END == INFO ssh: SSH not up: #<Vagrant::Errors::SSHAuthenticationFailed: SSH authentication failed! This is typically caused by the public/private keypair for the SSH user not being properly set on the guest VM. Please verify that the guest VM is setup with the proper public key, and that the private key path for Vagrant is setup properly as well.> ERROR warden: Error occurred: Guest-specific operations were attempted on a machine that is not ready for guest communication. This should not happen and a bug should be reported. INFO warden: Beginning recovery process... INFO warden: Recovery complete. INFO warden: Beginning recovery process... INFO warden: Recovery complete. INFO warden: Beginning recovery process... INFO warden: Recovery complete. ERROR warden: Error occurred: Guest-specific operations were attempted on a machine that is not ready for guest communication. This should not happen and a bug should be reported. INFO warden: Beginning recovery process... INFO warden: Recovery complete. ERROR warden: Error occurred: Guest-specific operations were attempted on a machine that is not ready for guest communication. This should not happen and a bug should be reported.
... INFO interface: error: Guest-specific operations were attempted on a machine that is not ready for guest communication. This should not happen and a bug should be reported. Guest-specific operations were attempted on a machine that is not ready for guest communication. This should not happen and a bug should be reported. INFO interface: Machine: error-exit ["Vagrant::Errors::MachineGuestNotReady", "Guest-specific operations were attempted on a machine that is not\nready for guest communication. This should not happen and a bug\nshould be reported."]
After the SSH authentication error, apparently because none of the attempted key authentication methods worked. Weird thing, on ubuntu 22.04 there's no problem. On arch is that I see the error.
BTW, I tried "config.ssh.disable_deprecated_algorithms" [1] set to true on the Vagrantfile, and it doesn't help. I see nothing particularly curious on the Vagrantfile. For SSH:
# SSH options sdk.ssh.username = "<container_username>" sdk.ssh.forward_agent = true sdk.ssh.pty = true sdk.ssh.forward_x11 = true sdk.ssh.insert_key = false
Disabling deprecated algorithms since Arch has obviously a newer openssh, but again, that didn't help.
It's weird that on arch the SSH authentication fails... I've created other docker containers based on ubuntu, pretty similar on this SSH Vagrantfile config, and no issues. On the other hand, I've also used other docker containers. Actually there are 2 from the org I work, that I would like to use on my arch box, but I just cant, currently relying on remote VMs...
Thanks for any hints...
BTW, if enable logging with DEBUG3 on both the SSH client and server on the host, there are no additional logs from the client neither from the server, so that doesn't help. -- Javier
I'm not familiar with vagrant, but did you verify that the server listening on 2222 indeed has the two keys you're trying to use in authorized_keys for a2sdk? I'd put that server in debug mode and see that instead, as it seems your client simply tries the keys and server denies them. Martin On Fri, Feb 2, 2024, 05:13 Javier <je-vv@e.email> wrote:
Hello !
At work I need to use an ubuntu 20.04 based docker image built by our org, and we use vagrant to easy the way to load and start the image.
I'm not able to do "vagrant up", since it seems the host can't connect to the container (guest):
INFO global: Vagrant version: 2.4.1 INFO global: Ruby version: 3.0.6 INFO global: RubyGems version: 3.3.25 INFO global: VAGRANT_INSTALLER_EMBEDDED_DIR="/opt/vagrant/embedded" INFO global: VAGRANT_EXECUTABLE="/opt/vagrant/embedded/gems/gems/vagrant-2.4.1/bin/vagrant" INFO global: VAGRANT_INSTALLER_ENV="1" INFO global: VAGRANT_INSTALLER_VERSION="2" INFO global: VAGRANT_LOG="debug" ... DEBUG ssh: Checking key permissions: /home/vasqueja/.vagrant.d/insecure_private_keys/vagrant.key.ed25519 DEBUG ssh: Checking key permissions: /home/vasqueja/.vagrant.d/insecure_private_keys/vagrant.key.rsa INFO ssh: Attempting SSH connection... INFO ssh: Attempting to connect to SSH... INFO ssh: - Host: 127.0.0.1 INFO ssh: - Port: 2222 INFO ssh: - Username: a2sdk INFO ssh: - Password? false INFO ssh: - Key Path: ["/home/vasqueja/.vagrant.d/insecure_private_keys/vagrant.key.ed25519", "/home/vasqueja/.vagrant.d/insecure_private_keys/vagrant.key.rsa"] DEBUG ssh: - connect_opts: {:auth_methods=>["none", "hostbased", "publickey"], :config=>false, :forward_agent=>true, :send_env=>false, :keys_only=>true, :verify_host_key=>:never, :password=>nil, :port=>"2222", :timeout=>15, :user_known_hosts_file=>[], :verbose=>:debug, :logger=>#<Logger:0x000070e2913f9dc0 @level=0, @progname=nil, @default_formatter=#<Logger::Formatter:0x000070e2913f9d20 @datetime_format=nil>, @formatter=nil, @logdev=#<Logger::LogDevice:0x000070e2913f9c80 @shift_period_suffix=nil, @shift_size=nil, @shift_age=nil, @filename=nil, @dev=#<StringIO:0x000070e2913f9e38>, @binmode=false, @mon_data=#<Monitor:0x000070e2913f9c30>, @mon_data_owner_object_id=14600>>, :keys=>["/home/vasqueja/.vagrant.d/insecure_private_keys/vagrant.key.ed25519", "/home/vasqueja/.vagrant.d/insecure_private_keys/vagrant.key.rsa"], :remote_user=>"a2sdk", :keepalive=>true, :keepalive_interval=>5} DEBUG ssh: == Net-SSH connection debug-level log START == DEBUG ssh: D, [2024-01-26T23:11:19.799621 #24466] DEBUG -- net.ssh.transport.session[391c]: establishing connection to 127.0.0.1:2222 D, [2024-01-26T23:11:19.799907 #24466] DEBUG -- net.ssh.transport.session[391c]: connection established I, [2024-01-26T23:11:19.799980 #24466] INFO -- net.ssh.transport.server_version[3930]: negotiating protocol version D, [2024-01-26T23:11:19.800002 #24466] DEBUG -- net.ssh.transport.server_version[3930]: local is `SSH-2.0-Ruby/Net::SSH_7.2.1 x86_64-linux' D, [2024-01-26T23:11:19.810429 #24466] DEBUG -- net.ssh.transport.server_version[3930]: remote is `SSH-2.0-OpenSSH_8.2p1 Ubuntu-4ubuntu0.9' I, [2024-01-26T23:11:19.810692 #24466] INFO -- net.ssh.transport.algorithms[3944]: sending KEXINIT D, [2024-01-26T23:11:19.810886 #24466] DEBUG -- socket[3958]: queueing
D, [2024-01-26T23:11:19.810953 #24466] DEBUG -- socket[3958]: sent 856 bytes D, [2024-01-26T23:11:19.811421 #24466] DEBUG -- socket[3958]: read 1056 bytes D, [2024-01-26T23:11:19.811496 #24466] DEBUG -- socket[3958]: received
I, [2024-01-26T23:11:19.811532 #24466] INFO -- net.ssh.transport.algorithms[3944]: got KEXINIT from server I, [2024-01-26T23:11:19.811623 #24466] INFO -- net.ssh.transport.algorithms[3944]: negotiating algorithms D, [2024-01-26T23:11:19.811712 #24466] DEBUG -- net.ssh.transport.algorithms[3944]: negotiated: ... * kex: ecdh-sha2-nistp521 * host_key: ssh-ed25519 * encryption_server: aes256-ctr * encryption_client: aes256-ctr * hmac_client: hmac-sha2-512-etm@openssh.com * hmac_server: hmac-sha2-512-etm@openssh.com * compression_client: none * compression_server: none * language_client: * language_server: D, [2024-01-26T23:11:19.811733 #24466] DEBUG -- net.ssh.transport.algorithms[3944]: exchanging keys D, [2024-01-26T23:11:19.812318 #24466] DEBUG -- socket[3958]: queueing
D, [2024-01-26T23:11:19.812375 #24466] DEBUG -- socket[3958]: sent 152 bytes D, [2024-01-26T23:11:19.816223 #24466] DEBUG -- socket[3958]: read 312 bytes D, [2024-01-26T23:11:19.816293 #24466] DEBUG -- socket[3958]: received
D, [2024-01-26T23:11:19.818291 #24466] DEBUG -- socket[3958]: queueing
D, [2024-01-26T23:11:19.818346 #24466] DEBUG -- socket[3958]: sent 24 bytes D, [2024-01-26T23:11:19.818401 #24466] DEBUG -- socket[3958]: received
D, [2024-01-26T23:11:19.818751 #24466] DEBUG -- net.ssh.authentication.session[396c]: beginning authentication of `a2sdk' D, [2024-01-26T23:11:19.818817 #24466] DEBUG -- socket[3958]: using encrypt-then-mac D, [2024-01-26T23:11:19.820166 #24466] DEBUG -- socket[3958]: queueing
D, [2024-01-26T23:11:19.820205 #24466] DEBUG -- socket[3958]: sent 100 bytes D, [2024-01-26T23:11:19.859904 #24466] DEBUG -- socket[3958]: read 100 bytes D, [2024-01-26T23:11:19.860311 #24466] DEBUG -- socket[3958]: received
D, [2024-01-26T23:11:19.860522 #24466] DEBUG -- net.ssh.authentication.session[396c]: trying none D, [2024-01-26T23:11:19.860731 #24466] DEBUG -- socket[3958]: using encrypt-then-mac D, [2024-01-26T23:11:19.860969 #24466] DEBUG -- socket[3958]: queueing
D, [2024-01-26T23:11:19.861076 #24466] DEBUG -- socket[3958]: sent 116 bytes D, [2024-01-26T23:11:19.866706 #24466] DEBUG -- socket[3958]: read 100 bytes D, [2024-01-26T23:11:19.867057 #24466] DEBUG -- socket[3958]: received
D, [2024-01-26T23:11:19.867183 #24466] DEBUG -- net.ssh.authentication.session[396c]: allowed methods: publickey,password D, [2024-01-26T23:11:19.867282 #24466] DEBUG -- net.ssh.authentication.methods.none[3980]: none failed D, [2024-01-26T23:11:19.867369 #24466] DEBUG -- net.ssh.authentication.session[396c]: trying publickey D, [2024-01-26T23:11:19.868848 #24466] DEBUG -- net.ssh.authentication.agent[3994]: connecting to ssh-agent D, [2024-01-26T23:11:19.869065 #24466] DEBUG -- net.ssh.authentication.agent[3994]: sending agent request 1 len 44 D, [2024-01-26T23:11:19.869366 #24466] DEBUG -- net.ssh.authentication.agent[3994]: received agent packet 5 len 1 D, [2024-01-26T23:11:19.869434 #24466] DEBUG -- net.ssh.authentication.agent[3994]: sending agent request 11 len 0 D, [2024-01-26T23:11:19.869678 #24466] DEBUG -- net.ssh.authentication.agent[3994]: received agent packet 12 len 498 D, [2024-01-26T23:11:19.870704 #24466] DEBUG -- net.ssh.authentication.methods.publickey[39bc]: trying publickey (dd:3b:b8:2e:85:04:06:e9:ab:ff:a8:0a:c0:04:6e:d6) alg rsa-sha2-256 D, [2024-01-26T23:11:19.870908 #24466] DEBUG -- socket[3958]: using encrypt-then-mac D, [2024-01-26T23:11:19.871129 #24466] DEBUG -- socket[3958]: queueing
D, [2024-01-26T23:11:19.871241 #24466] DEBUG -- socket[3958]: sent 420 bytes D, [2024-01-26T23:11:19.876890 #24466] DEBUG -- socket[3958]: read 100 bytes D, [2024-01-26T23:11:19.877237 #24466] DEBUG -- socket[3958]: received
D, [2024-01-26T23:11:19.877359 #24466] DEBUG -- net.ssh.authentication.session[396c]: allowed methods: publickey,password D, [2024-01-26T23:11:19.877425 #24466] DEBUG -- net.ssh.authentication.methods.publickey[39bc]: trying publickey (dd:3b:b8:2e:85:04:06:e9:ab:ff:a8:0a:c0:04:6e:d6) alg ssh-rsa D, [2024-01-26T23:11:19.877582 #24466] DEBUG -- socket[3958]: using encrypt-then-mac D, [2024-01-26T23:11:19.877778 #24466] DEBUG -- socket[3958]: queueing
D, [2024-01-26T23:11:19.877885 #24466] DEBUG -- socket[3958]: sent 420 bytes D, [2024-01-26T23:11:19.883542 #24466] DEBUG -- socket[3958]: read 100 bytes D, [2024-01-26T23:11:19.883942 #24466] DEBUG -- socket[3958]: received
D, [2024-01-26T23:11:19.884065 #24466] DEBUG -- net.ssh.authentication.session[396c]: allowed methods: publickey,password D, [2024-01-26T23:11:19.884282 #24466] DEBUG -- net.ssh.authentication.methods.publickey[39bc]: trying publickey (c8:ac:1c:f8:c5:f9:7f:fc:86:97:a4:96:a3:a1:2e:d8) alg ssh-ed25519 D, [2024-01-26T23:11:19.884463 #24466] DEBUG -- socket[3958]: using encrypt-then-mac D, [2024-01-26T23:11:19.884677 #24466] DEBUG -- socket[3958]: queueing
D, [2024-01-26T23:11:19.884800 #24466] DEBUG -- socket[3958]: sent 196 bytes D, [2024-01-26T23:11:19.890441 #24466] DEBUG -- socket[3958]: read 100 bytes D, [2024-01-26T23:11:19.890795 #24466] DEBUG -- socket[3958]: received
D, [2024-01-26T23:11:19.890918 #24466] DEBUG -- net.ssh.authentication.session[396c]: allowed methods: publickey,password E, [2024-01-26T23:11:19.891081 #24466] ERROR -- net.ssh.authentication.session[396c]: all authorization methods failed (tried none, publickey)
DEBUG ssh: == Net-SSH connection debug-level log END == INFO ssh: SSH not up: #<Vagrant::Errors::SSHAuthenticationFailed: SSH authentication failed! This is typically caused by the public/private keypair for the SSH user not being properly set on the guest VM. Please verify that the guest VM is setup with the proper public key, and that the private key path for Vagrant is setup properly as well.> ERROR warden: Error occurred: Guest-specific operations were attempted on a machine that is not ready for guest communication. This should not happen and a bug should be reported. INFO warden: Beginning recovery process... INFO warden: Recovery complete. INFO warden: Beginning recovery process... INFO warden: Recovery complete. INFO warden: Beginning recovery process... INFO warden: Recovery complete. ERROR warden: Error occurred: Guest-specific operations were attempted on a machine that is not ready for guest communication. This should not happen and a bug should be reported. INFO warden: Beginning recovery process... INFO warden: Recovery complete. ERROR warden: Error occurred: Guest-specific operations were attempted on a machine that is not ready for guest communication. This should not happen and a bug should be reported.
... INFO interface: error: Guest-specific operations were attempted on a machine that is not ready for guest communication. This should not happen and a bug should be reported. Guest-specific operations were attempted on a machine that is not ready for guest communication. This should not happen and a bug should be reported. INFO interface: Machine: error-exit ["Vagrant::Errors::MachineGuestNotReady", "Guest-specific operations were attempted on a machine that is not\nready for guest communication. This should not happen and a bug\nshould be reported."]
After the SSH authentication error, apparently because none of the attempted key authentication methods worked. Weird thing, on ubuntu 22.04
On 1/31/24 00:00, Javier wrote: packet nr 0 type 20 len 852 packet nr 0 type 20 len 1052 packet nr 1 type 30 len 148 packet nr 1 type 31 len 292 packet nr 2 type 21 len 20 packet nr 2 type 21 len 12 packet nr 3 type 5 len 32 packet nr 3 type 6 len 32 packet nr 4 type 50 len 48 packet nr 4 type 51 len 32 packet nr 5 type 50 len 352 packet nr 5 type 51 len 32 packet nr 6 type 50 len 352 packet nr 6 type 51 len 32 packet nr 7 type 50 len 128 packet nr 7 type 51 len 32 there's no problem. On arch is that I see the error.
BTW, I tried "config.ssh.disable_deprecated_algorithms" [1] set to true
on the Vagrantfile, and it doesn't help. I see nothing particularly curious on the Vagrantfile. For SSH:
# SSH options sdk.ssh.username = "<container_username>" sdk.ssh.forward_agent = true sdk.ssh.pty = true sdk.ssh.forward_x11 = true sdk.ssh.insert_key = false
Disabling deprecated algorithms since Arch has obviously a newer
openssh, but again, that didn't help.
It's weird that on arch the SSH authentication fails... I've created
other docker containers based on ubuntu, pretty similar on this SSH Vagrantfile config, and no issues. On the other hand, I've also used other docker containers. Actually there are 2 from the org I work, that I would like to use on my arch box, but I just cant, currently relying on remote VMs...
Thanks for any hints...
BTW, if enable logging with DEBUG3 on both the SSH client and server on the host, there are no additional logs from the client neither from the server, so that doesn't help.
-- Javier
participants (2)
-
Javier
-
Martin Rys