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:
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@xxxxxxxxxxx
>> * hmac_server: hmac-sha2-512-etm@xxxxxxxxxxx
>> * 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
