[Bug 3864] "Confirm user presence for key" shown twice when using a security key

[bugzilla-daemon at mindrot.org]

https://bugzilla.mindrot.org/show_bug.cgi?id=3864

--- Comment #2 from visco at riseup.net ---
Here is the log:

------------------
ssh -vvv user at host     
OpenSSH_9.6p1 Ubuntu-3ubuntu13.14, OpenSSL 3.0.13 30 Jan 2024
debug1: Reading configuration data /home/user/.ssh/config
debug1: /home/user/.ssh/config line 1: Applying options for *
debug1: /home/user/.ssh/config line 11: Applying options for user at host
debug1: Reading configuration data /etc/ssh/ssh_config
debug1: /etc/ssh/ssh_config line 19: include
/etc/ssh/ssh_config.d/*.conf matched no files
debug1: /etc/ssh/ssh_config line 21: Applying options for *
debug2: resolve_canonicalize: hostname <IP address> is address
debug3: expanded UserKnownHostsFile '~/.ssh/known_hosts' ->
'/home/user/.ssh/known_hosts'
debug3: expanded UserKnownHostsFile '~/.ssh/known_hosts2' ->
'/home/user/.ssh/known_hosts2'
debug1: auto-mux: Trying existing master at
'/home/user/.ssh/control/user@<IP address>:<port>'
debug1: Control socket "/home/user/.ssh/control/user@<IP
address>:<port>" does not exist
debug3: channel_clear_timeouts: clearing
debug3: ssh_connect_direct: entering
debug1: Connecting to <IP address> [<IP address>] port <port>.
debug3: set_sock_tos: set socket 3 IP_TOS 0x10
debug1: Connection established.
debug1: identity file /home/user/.ssh/<key name>.key type 12
debug1: identity file /home/user/.ssh/<key name>.key-cert type -1
debug1: Local version string SSH-2.0-OpenSSH_9.6p1 Ubuntu-3ubuntu13.14
debug1: Remote protocol version 2.0, remote software version
OpenSSH_8.9p1 Ubuntu-3ubuntu0.13
debug1: compat_banner: match: OpenSSH_8.9p1 Ubuntu-3ubuntu0.13 pat
OpenSSH* compat 0x04000000
debug2: fd 3 setting O_NONBLOCK
debug1: Authenticating to <IP address>:<port> as 'user'
debug3: put_host_port: [<IP address>]:<port>
debug3: record_hostkey: found key type ED25519 in file
/home/user/.ssh/known_hosts:13
debug3: load_hostkeys_file: loaded 1 keys from [<IP address>]:<port>
debug1: load_hostkeys: fopen /home/user/.ssh/known_hosts2: No such file
or directory
debug1: load_hostkeys: fopen /etc/ssh/ssh_known_hosts: No such file or
directory
debug1: load_hostkeys: fopen /etc/ssh/ssh_known_hosts2: No such file or
directory
debug3: order_hostkeyalgs: have matching best-preference key type
ssh-ed25519-cert-v01 at openssh.com, using HostkeyAlgorithms verbatim
debug3: send packet: type 20
debug1: SSH2_MSG_KEXINIT sent
debug3: receive packet: type 20
debug1: SSH2_MSG_KEXINIT received
debug2: local client KEXINIT proposal
debug2: KEX algorithms:
sntrup761x25519-sha512 at openssh.com,curve25519-sha256,curve25519-sha256 at libssh.org,diffie-hellman-group-exchange-sha256,diffie-hellman-group16-sha512,diffie-hellman-group18-sha512,ext-info-c,kex-strict-c-v00 at openssh.com
debug2: host key algorithms:
ssh-ed25519-cert-v01 at openssh.com,sk-ssh-ed25519-cert-v01 at openssh.com,rsa-sha2-512-cert-v01 at openssh.com,rsa-sha2-256-cert-v01 at openssh.com,ssh-ed25519,sk-ssh-ed25519 at openssh.com,rsa-sha2-512,rsa-sha2-256
debug2: ciphers ctos:
chacha20-poly1305 at openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm at openssh.com,aes256-gcm at openssh.com
debug2: ciphers stoc:
chacha20-poly1305 at openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm at openssh.com,aes256-gcm at openssh.com
debug2: MACs ctos:
umac-128-etm at openssh.com,hmac-sha2-256-etm at openssh.com,hmac-sha2-512-etm at openssh.com
debug2: MACs stoc:
umac-128-etm at openssh.com,hmac-sha2-256-etm at openssh.com,hmac-sha2-512-etm at openssh.com
debug2: compression ctos: none,zlib at openssh.com,zlib
debug2: compression stoc: none,zlib at openssh.com,zlib
debug2: languages ctos: 
debug2: languages stoc: 
debug2: first_kex_follows 0 
debug2: reserved 0 
debug2: peer server KEXINIT proposal
debug2: KEX algorithms:
curve25519-sha256,curve25519-sha256 at libssh.org,sntrup761x25519-sha512 at openssh.com,diffie-hellman-group16-sha512,diffie-hellman-group18-sha512,kex-strict-s-v00 at openssh.com
debug2: host key algorithms: rsa-sha2-512,rsa-sha2-256,ssh-ed25519
debug2: ciphers ctos:
chacha20-poly1305 at openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm at openssh.com,aes256-gcm at openssh.com
debug2: ciphers stoc:
chacha20-poly1305 at openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm at openssh.com,aes256-gcm at openssh.com
debug2: MACs ctos:
umac-128-etm at openssh.com,hmac-sha2-256-etm at openssh.com,hmac-sha2-512-etm at openssh.com
debug2: MACs stoc:
umac-128-etm at openssh.com,hmac-sha2-256-etm at openssh.com,hmac-sha2-512-etm at openssh.com
debug2: compression ctos: none,zlib at openssh.com
debug2: compression stoc: none,zlib at openssh.com
debug2: languages ctos: 
debug2: languages stoc: 
debug2: first_kex_follows 0 
debug2: reserved 0 
debug3: kex_choose_conf: will use strict KEX ordering
debug1: kex: algorithm: sntrup761x25519-sha512 at openssh.com
debug1: kex: host key algorithm: ssh-ed25519
debug1: kex: server->client cipher: chacha20-poly1305 at openssh.com MAC:
<implicit> compression: none
debug1: kex: client->server cipher: chacha20-poly1305 at openssh.com MAC:
<implicit> compression: none
debug3: send packet: type 30
debug1: expecting SSH2_MSG_KEX_ECDH_REPLY
debug3: receive packet: type 31
debug1: SSH2_MSG_KEX_ECDH_REPLY received
debug1: Server host key: ssh-ed25519 SHA256:<hash>
debug3: put_host_port: [<IP address>]:<port>
debug3: put_host_port: [<IP address>]:<port>
debug3: record_hostkey: found key type ED25519 in file
/home/user/.ssh/known_hosts:13
debug3: load_hostkeys_file: loaded 1 keys from [<IP address>]:<port>
debug1: load_hostkeys: fopen /home/user/.ssh/known_hosts2: No such file
or directory
debug1: load_hostkeys: fopen /etc/ssh/ssh_known_hosts: No such file or
directory
debug1: load_hostkeys: fopen /etc/ssh/ssh_known_hosts2: No such file or
directory
debug1: Host '[<IP address>]:<port>' is known and matches the ED25519
host key.
debug1: Found key in /home/user/.ssh/known_hosts:13
debug3: send packet: type 21
debug1: ssh_packet_send2_wrapped: resetting send seqnr 3
debug2: ssh_set_newkeys: mode 1
debug1: rekey out after 134217728 blocks
debug1: SSH2_MSG_NEWKEYS sent
debug1: expecting SSH2_MSG_NEWKEYS
debug3: receive packet: type 21
debug1: ssh_packet_read_poll2: resetting read seqnr 3
debug1: SSH2_MSG_NEWKEYS received
debug2: ssh_set_newkeys: mode 0
debug1: rekey in after 134217728 blocks
debug3: send packet: type 5
debug3: receive packet: type 7
debug1: SSH2_MSG_EXT_INFO received
debug3: kex_input_ext_info: extension server-sig-algs
debug1: kex_ext_info_client_parse:
server-sig-algs=<ssh-ed25519,sk-ssh-ed25519 at openssh.com,ssh-rsa,rsa-sha2-256,rsa-sha2-512,ssh-dss,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,sk-ecdsa-sha2-nistp256 at openssh.com,webauthn-sk-ecdsa-sha2-nistp256 at openssh.com>
debug3: kex_input_ext_info: extension publickey-hostbound at openssh.com
debug1: kex_ext_info_check_ver: publickey-hostbound at openssh.com=<0>
debug3: receive packet: type 6
debug2: service_accept: ssh-userauth
debug1: SSH2_MSG_SERVICE_ACCEPT received
debug3: send packet: type 50
debug3: receive packet: type 51
debug1: Authentications that can continue: publickey
debug3: start over, passed a different list publickey
debug3: preferred
gssapi-with-mic,publickey,keyboard-interactive,password
debug3: authmethod_lookup publickey
debug3: remaining preferred: keyboard-interactive,password
debug3: authmethod_is_enabled publickey
debug1: Next authentication method: publickey
debug3: ssh_get_authentication_socket_path: path
'/run/user/1000/keyring/ssh'
debug1: get_agent_identities: bound agent to hostkey
debug1: get_agent_identities: ssh_fetch_identitylist: agent contains no
identities
debug1: Will attempt key: /home/user/.ssh/<key name>.key ED25519-SK
SHA256:<hash> explicit authenticator
debug2: pubkey_prepare: done
debug1: Offering public key: /home/user/.ssh/<key name>.key ED25519-SK
SHA256:<hash> explicit authenticator
debug3: send packet: type 50
debug2: we sent a publickey packet, wait for reply
debug3: receive packet: type 60
debug1: Server accepts key: /home/user/.ssh/<key name>.key ED25519-SK
SHA256:<hash> explicit authenticator
debug3: sign_and_send_pubkey: using publickey-hostbound-v00 at openssh.com
with ED25519-SK SHA256:<hash>
debug3: sign_and_send_pubkey: signing using sk-ssh-ed25519 at openssh.com
SHA256:<hash>
Enter passphrase for key '/home/user/.ssh/<key name>.key': 
Confirm user presence for key ED25519-SK SHA256:<hash>
debug3: start_helper: started pid=7676
debug3: ssh_msg_send: type 5
debug3: ssh_msg_recv entering
debug1: start_helper: starting /usr/lib/openssh/ssh-sk-helper 
debug1: process_sign: ready to sign with key ED25519-SK, provider
internal: msg len 298, compat 0x4000000
debug1: sshsk_sign: provider "internal", key ED25519-SK, flags 0x25
debug1: sk_probe: 1 device(s) detected
debug1: sk_probe: selecting sk by touch
debug1: check_sk_options: option uv is unknown
debug1: ssh_sk_sign: check_sk_options uv
debug1: sshsk_sign: sk_sign failed with code -3
debug1: ssh-sk-helper: Signing failed: incorrect passphrase supplied to
decrypt private key
debug1: main: reply len 8
debug3: ssh_msg_send: type 5
debug1: client_converse: helper returned error -43
debug3: reap_helper: pid=7676
debug1: identity_sign: sshkey_sign: incorrect passphrase supplied to
decrypt private key
Enter PIN for ED25519-SK key /home/user/.ssh/<key name>.key: 
Confirm user presence for key ED25519-SK SHA256:<hash>
debug3: start_helper: started pid=7677
debug3: ssh_msg_send: type 5
debug3: ssh_msg_recv entering
debug1: start_helper: starting /usr/lib/openssh/ssh-sk-helper 
debug1: process_sign: ready to sign with key ED25519-SK, provider
internal: msg len 298, compat 0x4000000
debug1: sshsk_sign: provider "internal", key ED25519-SK, flags 0x25
with-pin
debug1: sk_probe: 1 device(s) detected
debug1: sk_probe: selecting sk by touch
debug1: main: reply len 111
debug3: ssh_msg_send: type 5
debug3: reap_helper: pid=7677
User presence confirmed
debug3: send packet: type 50
debug3: receive packet: type 52
Authenticated to <IP address> ([<IP address>]:<port>) using
"publickey".
debug1: setting up multiplex master socket
debug3: muxserver_listen: temporary control path
/home/user/.ssh/control/user@<IP address>:<port>.***
debug2: fd 4 setting O_NONBLOCK
debug3: fd 4 is O_NONBLOCK
debug3: fd 4 is O_NONBLOCK
debug1: channel 0: new mux listener [/home/user/.ssh/control/user@<IP
address>:<port>] (inactive timeout: 0)
debug3: muxserver_listen: mux listener channel 0 fd 4
debug1: channel 1: new session [client-session] (inactive timeout: 0)
debug3: ssh_session2_open: channel_new: 1
debug2: channel 1: send open
debug3: send packet: type 90
debug1: Entering interactive session.
debug1: pledge: id
debug3: client_repledge: enter
debug3: receive packet: type 80
debug1: client_input_global_request: rtype hostkeys-00 at openssh.com
want_reply 0
debug3: client_input_hostkeys: received RSA key SHA256:<hash>
debug3: client_input_hostkeys: received ECDSA key SHA256:<hash>
debug3: client_input_hostkeys: ecdsa-sha2-nistp256 key not permitted by
HostkeyAlgorithms
debug3: client_input_hostkeys: received ED25519 key SHA256:<hash>
debug3: put_host_port: [<IP address>]:<port>
debug1: client_input_hostkeys: searching /home/user/.ssh/known_hosts
for [<IP address>]:<port> / (none)
debug3: hostkeys_foreach: reading file "/home/user/.ssh/known_hosts"
debug3: hostkeys_find: found ssh-ed25519 key under different name/addr
at /home/user/.ssh/known_hosts:2
debug3: hostkeys_find: found ssh-rsa key under different name/addr at
/home/user/.ssh/known_hosts:3
debug3: hostkeys_find: found ssh-ed25519 key at
/home/user/.ssh/known_hosts:13
debug1: client_input_hostkeys: searching /home/user/.ssh/known_hosts2
for [<IP address>]:<port> / (none)
debug1: client_input_hostkeys: hostkeys file
/home/user/.ssh/known_hosts2 does not exist
debug3: client_input_hostkeys: 2 server keys: 1 new, 0 retained, 1
incomplete match. 0 to remove
debug1: client_input_hostkeys: host key found matching a different
name/address, skipping UserKnownHostsFile update
debug3: client_repledge: enter
debug3: receive packet: type 4
debug1: Remote: /home/user/.ssh/authorized_keys:1: key options:
agent-forwarding port-forwarding pty user-rc x11-forwarding
debug3: receive packet: type 4
debug1: Remote: /home/user/.ssh/authorized_keys:1: key options:
agent-forwarding port-forwarding pty user-rc x11-forwarding
debug3: receive packet: type 91
debug2: channel_input_open_confirmation: channel 1: callback start
debug2: fd 3 setting TCP_NODELAY
debug3: set_sock_tos: set socket 3 IP_TOS 0x10
debug2: client_session2_setup: id 1
debug2: channel 1: request pty-req confirm 1
debug3: send packet: type 98
debug1: Sending environment.
debug3: Ignored env SYSTEMD_EXEC_PID
debug3: Ignored env CLUTTER_DISABLE_MIPMAPPED_TEXT
debug3: Ignored env SESSION_MANAGER
debug3: Ignored env PAPERSIZE
debug3: Ignored env SSH_AUTH_SOCK
debug3: Ignored env XDG_CURRENT_DESKTOP
debug1: channel 1: setting env LANG = "en_US.UTF-8"
debug2: channel 1: request env confirm 0
debug3: send packet: type 98
debug3: Ignored env ANDROID_HOME
debug1: channel 1: setting env LC_IDENTIFICATION = "ru_RU.UTF-8"
debug2: channel 1: request env confirm 0
debug3: send packet: type 98
debug3: Ignored env GNOME_TERMINAL_SCREEN
debug3: Ignored env WAYLAND_DISPLAY
debug3: Ignored env PWD
debug3: Ignored env QT_IM_MODULE
debug1: channel 1: setting env LC_TELEPHONE = "ru_RU.UTF-8"
debug2: channel 1: request env confirm 0
debug3: send packet: type 98
debug3: Ignored env USER
debug3: Ignored env DESKTOP_SESSION
debug3: Ignored env XDG_MENU_PREFIX
debug3: Ignored env OLDPWD
debug1: channel 1: setting env LC_MEASUREMENT = "ru_RU.UTF-8"
debug2: channel 1: request env confirm 0
debug3: send packet: type 98
debug3: Ignored env NDK
debug3: Ignored env DBUS_SESSION_BUS_ADDRESS
debug3: Ignored env GOPATH
debug3: Ignored env JAVA_HOME
debug1: channel 1: setting env LC_NUMERIC = "ru_RU.UTF-8"
debug2: channel 1: request env confirm 0
debug3: send packet: type 98
debug3: Ignored env _
debug3: Ignored env GTK_MODULES
debug3: Ignored env VTE_VERSION
debug3: Ignored env XDG_SESSION_DESKTOP
debug3: Ignored env GSM_SKIP_SSH_AGENT_WORKAROUND
debug3: Ignored env QT_ACCESSIBILITY
debug3: Ignored env XDG_DATA_DIRS
debug3: Ignored env GNOME_SETUP_DISPLAY
debug3: Ignored env QSYS_ROOTDIR
debug3: Ignored env GNOME_DESKTOP_SESSION_ID
debug3: Ignored env LOGNAME
debug1: channel 1: setting env LC_TIME = "ru_RU.UTF-8"
debug2: channel 1: request env confirm 0
debug3: send packet: type 98
debug3: Ignored env GNOME_TERMINAL_SERVICE
debug3: Ignored env HOME
debug3: Ignored env MEMORY_PRESSURE_WRITE
debug1: channel 1: setting env LC_PAPER = "ru_RU.UTF-8"
debug2: channel 1: request env confirm 0
debug3: send packet: type 98
debug3: Ignored env GNOME_SHELL_SESSION_MODE
debug3: Ignored env XDG_RUNTIME_DIR
debug3: Ignored env XMODIFIERS
debug3: Ignored env SHELL
debug3: Ignored env XDG_SESSION_TYPE
debug1: channel 1: setting env LC_MONETARY = "ru_RU.UTF-8"
debug2: channel 1: request env confirm 0
debug3: send packet: type 98
debug3: Ignored env USERNAME
debug3: Ignored env PATH
debug3: Ignored env MEMORY_PRESSURE_WATCH
debug3: Ignored env COLORTERM
debug3: Ignored env LD_LIBRARY_PATH
debug3: Ignored env XAUTHORITY
debug1: channel 1: setting env LC_NAME = "ru_RU.UTF-8"
debug2: channel 1: request env confirm 0
debug3: send packet: type 98
debug3: Ignored env XDG_SESSION_CLASS
debug3: Ignored env TERM
debug3: Ignored env GDMSESSION
debug3: Ignored env DISPLAY
debug1: channel 1: setting env LC_ADDRESS = "ru_RU.UTF-8"
debug2: channel 1: request env confirm 0
debug3: send packet: type 98
debug3: Ignored env SHLVL
debug3: Ignored env ZSH
debug3: Ignored env PAGER
debug3: Ignored env LESS
debug3: Ignored env LSCOLORS
debug3: Ignored env LS_COLORS
debug3: Ignored env NVM_DIR
debug3: Ignored env NVM_CD_FLAGS
debug3: Ignored env NVM_BIN
debug3: Ignored env NVM_INC
debug2: channel 1: request shell confirm 1
debug3: send packet: type 98
debug3: client_repledge: enter
debug2: channel_input_open_confirmation: channel 1: callback done
debug2: channel 1: open confirm rwindow 0 rmax 32768
debug3: receive packet: type 99
debug2: channel_input_status_confirm: type 99 id 1
debug2: PTY allocation request accepted on channel 1
debug2: channel 1: rcvd adjust 2097152
debug3: receive packet: type 99
debug2: channel_input_status_confirm: type 99 id 1
debug2: shell request accepted on channel 1
Welcome to Ubuntu 22.04.5 LTS (GNU/Linux 5.15.0-153-generic x86_64)
-------------------------------------------------------------------

The key's passphrase is entered correctly. Should I enter it wrong, the
message would be "bad passphrase given, try again..."

-- 
You are receiving this mail because:
You are watching the assignee of the bug.
You are watching someone on the CC list of the bug.