search

php / pecl-networking-ssh2

Bindings for the libssh2 library
http://pecl.php.net/package/ssh2
Other
51 stars 61 forks source link

SSH2 fails after upgrading to PHP8.2 and Debian Bookworm - ssh2_auth_pubkey_file(): Authentication failed #74

Closed clarkk closed 6 months ago

clarkk commented 9 months ago

After upgrading to Debian Bookworm and PHP 8.2 it's no longer possible to connect to remote server via PHP and SSH2

The public/private key works because it's possible to connect via command line

ssh remote-server.com

code

$user           = 'root';
$host           = 'remote-server.com';
$private_key    = '/root/.ssh/id_rsa';
$public_key     = '/root/.ssh/id_rsa.pub';

if(!is_readable($private_key) || !is_readable($public_key)){
    echo "RSA keys not found\n";
}

echo 'private key: '.file_get_contents($private_key)."\n";
echo 'public key: '.file_get_contents($public_key)."\n";
echo "host: $host\n";
echo "user: $user\n";

if(!$session = ssh2_connect($host)){
    echo "Could not connect to '$host'\n";
}

if(!ssh2_auth_pubkey_file($session, $user, $public_key, $private_key)){
    echo "Could not authenticate to '$host'\n";
}

output

# php test_ssh.php
private key: -----BEGIN OPENSSH PRIVATE KEY-----
b3BlbnNzaC1rZXktdjEAAAAABG5vbmUAAAAEbm9uZQAAAAAAAAABAAACFwAAAAdzc2gtcn
...
hoyaUZrhPmUPAAAAHHJvb3RAQVBJc2Nhbi1JbnRlbC1YZW9uLTY0Z2IBAgMEBQY=
-----END OPENSSH PRIVATE KEY-----

public key: ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAACAQC0geHl2dKCkd9UkU/2WtVBqo4NEhnprMzAV6hVhm7TAvK63GQN1xlAGlgagb7S5u1vET3BOAu+c8qPOkrvofhCKNF5a7v3uEh/u/oysd0Ckj6IA8spRdCXe3JbmXCHp85VadYjylwILC0drKetdMhXnHNnFHdvJDRIbVCqrO1j17kAJ9kf3cW/lsmqng9rPPGB8gozxcW6N5f3hNiSwDOo9ex0su37xflwxY2Hi4QYk1tdp7GO9YlaXlNS+s4Q47aU3dGsn5nMWlxUdT3yD2DJDdp7Bz24wLY3QFpKMbRqHC66YWIbe29Rr53ESUGukrNedZobanuW0f5wQ2xvFTB9BOXt0Bhf8OXVyNr1K79UEqaCSnpU3rGRA71lOxeRdZUN9EyHaji0rlq8kOCGBKgMwQ96fo2T1x8xikcWEiPVC+Bhd4pyOwq2G9Ihi3lAqV45zqm/5gx3Te7OtAAJIjb3aI7um+di6SL0DabHkkQH4ZzeeeikhV+ZmVUt8/guldpkZrPy7COqG043X27kk/meP/8mAnAS9mv7ircBvlW0IUHL7wwndJc0aGDwmrKaXk64qCS+80k+42BPuZAMk8dSrFJsu8vcYwuTVxn281T55t8N/JgGEkmNxEsP4VFM0DxQfgsktiPiBEPxe3S8P/ipPhx2Mn1JrohbIDahPDTyfQ== root@APIscan-Intel-Xeon-64gb

host: remote-server.com
user: root
PHP Warning:  ssh2_auth_pubkey_file(): Authentication failed for root using public key: Username/PublicKey combination invalid in /root/test_ssh.php on line 21

Warning: ssh2_auth_pubkey_file(): Authentication failed for root using public key: Username/PublicKey combination invalid in /root/test_ssh.php on line 21
Could not authenticate to 'worker.dynaccount.com'

PHP

# php -v
PHP 8.2.15 (cli) (built: Jan 20 2024 14:14:18) (NTS)
Copyright (c) The PHP Group
Zend Engine v4.2.15, Copyright (c) Zend Technologies
    with Zend OPcache v8.2.15, Copyright (c), by Zend Technologies

SSH client

# ssh -V
OpenSSH_9.2p1 Debian-2+deb12u2, OpenSSL 3.0.11 19 Sep 2023

SSH remote server

# ssh -V
OpenSSH_9.2p1 Debian-2+deb12u2, OpenSSL 3.0.11 19 Sep 2023

Generating public/private keys (the keys are created without passphrase)

ssh-keygen -t rsa -b 4096
clarkk commented 9 months ago

Have tried to generate the keys like this but same error

ssh-keygen -m PEM -t rsa

dcivera commented 6 months ago

I tried and it still doesn't work. I'm pretty sure I'm in the same boat here.

In my case, I'm trying to use the SSH2 feature in WordPress to install and update, but no luck.

Here are my logs in journalctl. It seems that all is well until PECL/SSH2 sends a disconnect.

May 21 10:40:48 hostname sshd[2829]: Connection from ::1 port 12345 on ::1 port 09876 rdomain ""
May 21 10:40:48 hostname sshd[2829]: debug1: Local version string SSH-2.0-OpenSSH_9.2p1 Debian-2+deb12u2
May 21 10:40:48 hostname sshd[2829]: debug1: Remote protocol version 2.0, remote software version libssh2_1.10.0 PHP
May 21 10:40:48 hostname sshd[2829]: debug1: compat_banner: no match: libssh2_1.10.0 PHP
May 21 10:40:48 hostname sshd[2829]: debug1: permanently_set_uid: 103/65534 [preauth]
May 21 10:40:48 hostname sshd[2829]: debug1: list_hostkey_types: rsa-sha2-512,rsa-sha2-256,ecdsa-sha2-nistp256,ssh-ed25519 [preauth]
May 21 10:40:48 hostname sshd[2829]: debug1: SSH2_MSG_KEXINIT sent [preauth]
May 21 10:40:48 hostname sshd[2829]: debug1: SSH2_MSG_KEXINIT received [preauth]
May 21 10:40:48 hostname sshd[2829]: debug1: kex: algorithm: curve25519-sha256 [preauth]
May 21 10:40:48 hostname sshd[2829]: debug1: kex: host key algorithm: ssh-ed25519 [preauth]
May 21 10:40:48 hostname sshd[2829]: debug1: kex: client->server cipher: aes128-ctr MAC: hmac-sha2-256 compression: none [preauth]
May 21 10:40:48 hostname sshd[2829]: debug1: kex: server->client cipher: aes128-ctr MAC: hmac-sha2-256 compression: none [preauth]
May 21 10:40:48 hostname sshd[2829]: debug1: expecting SSH2_MSG_KEX_ECDH_INIT [preauth]
May 21 10:40:48 hostname sshd[2829]: debug1: SSH2_MSG_KEX_ECDH_INIT received [preauth]
May 21 10:40:48 hostname sshd[2829]: debug1: rekey out after 4294967296 blocks [preauth]
May 21 10:40:48 hostname sshd[2829]: debug1: SSH2_MSG_NEWKEYS sent [preauth]
May 21 10:40:48 hostname sshd[2829]: debug1: expecting SSH2_MSG_NEWKEYS [preauth]
May 21 10:40:48 hostname sshd[2829]: debug1: SSH2_MSG_NEWKEYS received [preauth]
May 21 10:40:48 hostname sshd[2829]: debug1: rekey in after 4294967296 blocks [preauth]
May 21 10:40:48 hostname sshd[2829]: debug1: KEX done [preauth]
May 21 10:40:48 hostname sshd[2829]: Received disconnect from ::1 port 12345:11: PECL/ssh2 (http://pecl.php.net/packages/ssh2) [preauth]
May 21 10:40:48 hostname sshd[2829]: Disconnected from ::1 port 12345 [preauth]
dcivera commented 6 months ago

After running the application submitted by the OP, I got the same error message. However, I noticed an error message in my sshd logs saying that rsa-ssh was not in "PubkeyAcceptedAlgorithms", which is strange, because it is. But anyhow.

I decided to create keys using the following command

ssh-keygen -t ssh-ed25519

And now, the PHP script doesn't throw an error. However, it still not working. Here's what I get in my logs.

What's weird is that, for the first time, I see that that it's accepting the keys:

May 21 12:38:15 hostname sshd[3808]: Accepted key ED25519 SHA256:RW9nn7v0hzO51UWj2WaSwtY0Z+/xJC/HuEGb53MuqE8 found at /home/username/.ssh/authorized_keys:3 but it still sends a disconnect and WordPress still tells me that the keys don't work.

May 21 12:38:15 hostname sshd[3808]: Connection from remoteserverIP port 60804 on 172.26.7.64 port 09876 rdomain ""
May 21 12:38:15 hostname sshd[3808]: debug1: Local version string SSH-2.0-OpenSSH_9.2p1 Debian-2+deb12u2
May 21 12:38:15 hostname sshd[3808]: debug1: Remote protocol version 2.0, remote software version libssh2_1.10.0 PHP
May 21 12:38:15 hostname sshd[3808]: debug1: compat_banner: no match: libssh2_1.10.0 PHP
May 21 12:38:15 hostname sshd[3808]: debug1: permanently_set_uid: 103/65534 [preauth]
May 21 12:38:15 hostname sshd[3808]: debug1: list_hostkey_types: rsa-sha2-512,rsa-sha2-256,ecdsa-sha2-nistp256,ssh-ed25519 [preauth]
May 21 12:38:15 hostname sshd[3808]: debug1: SSH2_MSG_KEXINIT sent [preauth]
May 21 12:38:15 hostname sshd[3808]: debug1: SSH2_MSG_KEXINIT received [preauth]
May 21 12:38:15 hostname sshd[3808]: debug1: kex: algorithm: curve25519-sha256 [preauth]
May 21 12:38:15 hostname sshd[3808]: debug1: kex: host key algorithm: ecdsa-sha2-nistp256 [preauth]
May 21 12:38:15 hostname sshd[3808]: debug1: kex: client->server cipher: aes128-ctr MAC: hmac-sha2-256 compression: none [preauth]
May 21 12:38:15 hostname sshd[3808]: debug1: kex: server->client cipher: aes128-ctr MAC: hmac-sha2-256 compression: none [preauth]
May 21 12:38:15 hostname sshd[3808]: debug1: expecting SSH2_MSG_KEX_ECDH_INIT [preauth]
May 21 12:38:15 hostname sshd[3808]: debug1: SSH2_MSG_KEX_ECDH_INIT received [preauth]
May 21 12:38:15 hostname sshd[3808]: debug1: rekey out after 4294967296 blocks [preauth]
May 21 12:38:15 hostname sshd[3808]: debug1: SSH2_MSG_NEWKEYS sent [preauth]
May 21 12:38:15 hostname sshd[3808]: debug1: expecting SSH2_MSG_NEWKEYS [preauth]
May 21 12:38:15 hostname sshd[3808]: debug1: SSH2_MSG_NEWKEYS received [preauth]
May 21 12:38:15 hostname sshd[3808]: debug1: rekey in after 4294967296 blocks [preauth]
May 21 12:38:15 hostname sshd[3808]: debug1: KEX done [preauth]
May 21 12:38:15 hostname sshd[3808]: debug1: userauth-request for user username service ssh-connection method publickey [preauth]
May 21 12:38:15 hostname sshd[3808]: debug1: attempt 0 failures 0 [preauth]
May 21 12:38:15 hostname sshd[3808]: debug1: PAM: initializing for "username"
May 21 12:38:15 hostname sshd[3808]: debug1: PAM: setting PAM_RHOST to "remoteserverIP"
May 21 12:38:15 hostname sshd[3808]: debug1: PAM: setting PAM_TTY to "ssh"
May 21 12:38:15 hostname sshd[3808]: debug1: userauth_pubkey: publickey test pkalg ssh-ed25519 pkblob ED25519 SHA256:RW9nn7v0hzO51UWj2WaSwtY0Z+/xJC/HuEGb53MuqE8 [preauth]
May 21 12:38:15 hostname sshd[3808]: debug1: temporarily_use_uid: 1000/1000 (e=0/0)
May 21 12:38:15 hostname sshd[3808]: debug1: trying public key file /home/username/.ssh/authorized_keys
May 21 12:38:15 hostname sshd[3808]: debug1: fd 5 clearing O_NONBLOCK
May 21 12:38:15 hostname sshd[3808]: debug1: /home/username/.ssh/authorized_keys:3: matching key found: ED25519 SHA256:RW9nn7v0hzO51UWj2WaSwtY0Z+/xJC/HuEGb53MuqE8
May 21 12:38:15 hostname sshd[3808]: debug1: /home/username/.ssh/authorized_keys:3: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding
May 21 12:38:15 hostname sshd[3808]: Accepted key ED25519 SHA256:RW9nn7v0hzO51UWj2WaSwtY0Z+/xJC/HuEGb53MuqE8 found at /home/username/.ssh/authorized_keys:3
May 21 12:38:15 hostname sshd[3808]: debug1: restore_uid: 0/0
May 21 12:38:15 hostname sshd[3808]: Postponed publickey for username from remoteserverIP port 60804 ssh2 [preauth]
May 21 12:38:15 hostname sshd[3808]: debug1: userauth-request for user username service ssh-connection method publickey [preauth]
May 21 12:38:15 hostname sshd[3808]: debug1: attempt 1 failures 0 [preauth]
May 21 12:38:15 hostname sshd[3808]: debug1: temporarily_use_uid: 1000/1000 (e=0/0)
May 21 12:38:15 hostname sshd[3808]: debug1: trying public key file /home/username/.ssh/authorized_keys
May 21 12:38:15 hostname sshd[3808]: debug1: fd 5 clearing O_NONBLOCK
May 21 12:38:15 hostname sshd[3808]: debug1: /home/username/.ssh/authorized_keys:3: matching key found: ED25519 SHA256:RW9nn7v0hzO51UWj2WaSwtY0Z+/xJC/HuEGb53MuqE8
May 21 12:38:15 hostname sshd[3808]: debug1: /home/username/.ssh/authorized_keys:3: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding
May 21 12:38:15 hostname sshd[3808]: Accepted key ED25519 SHA256:RW9nn7v0hzO51UWj2WaSwtY0Z+/xJC/HuEGb53MuqE8 found at /home/username/.ssh/authorized_keys:3
May 21 12:38:15 hostname sshd[3808]: debug1: restore_uid: 0/0
May 21 12:38:15 hostname sshd[3808]: debug1: auth_activate_options: setting new authentication options
May 21 12:38:15 hostname sshd[3808]: debug1: do_pam_account: called
May 21 12:38:15 hostname sshd[3808]: Accepted publickey for username from remoteserverIP port 60804 ssh2: ED25519 SHA256:RW9nn7v0hzO51UWj2WaSwtY0Z+/xJC/HuEGb53MuqE8
May 21 12:38:15 hostname sshd[3808]: debug1: monitor_child_preauth: user username authenticated by privileged process
May 21 12:38:15 hostname sshd[3808]: debug1: auth_activate_options: setting new authentication options [preauth]
May 21 12:38:15 hostname sshd[3808]: debug1: monitor_read_log: child log fd closed
May 21 12:38:15 hostname sshd[3808]: debug1: PAM: establishing credentials
May 21 12:38:15 hostname sshd[3808]: pam_unix(sshd:session): session opened for user username(uid=1000) by (uid=0)
May 21 12:38:15 hostname systemd-logind[502]: New session 26 of user username.
May 21 12:38:15 hostname systemd[1]: Created slice user-1000.slice - User Slice of UID 1000.
May 21 12:38:15 hostname systemd[1]: Starting user-runtime-dir@1000.service - User Runtime Directory /run/user/1000...
May 21 12:38:16 hostname systemd[1]: Finished user-runtime-dir@1000.service - User Runtime Directory /run/user/1000.
May 21 12:38:16 hostname systemd[1]: Starting user@1000.service - User Manager for UID 1000...
May 21 12:38:16 hostname (systemd)[3811]: pam_unix(systemd-user:session): session opened for user username(uid=1000) by (uid=0)
May 21 12:38:16 hostname systemd[3811]: Queued start job for default target default.target.
May 21 12:38:16 hostname systemd[3811]: Created slice app.slice - User Application Slice.
May 21 12:38:16 hostname systemd[3811]: Reached target paths.target - Paths.
May 21 12:38:16 hostname systemd[3811]: Reached target timers.target - Timers.
May 21 12:38:16 hostname systemd[3811]: Listening on dirmngr.socket - GnuPG network certificate management daemon.
May 21 12:38:16 hostname systemd[3811]: Listening on gpg-agent-browser.socket - GnuPG cryptographic agent and passphrase cache (access for web browsers).
May 21 12:38:16 hostname systemd[3811]: Listening on gpg-agent-extra.socket - GnuPG cryptographic agent and passphrase cache (restricted).
May 21 12:38:16 hostname systemd[3811]: Listening on gpg-agent-ssh.socket - GnuPG cryptographic agent (ssh-agent emulation).
May 21 12:38:16 hostname systemd[3811]: Listening on gpg-agent.socket - GnuPG cryptographic agent and passphrase cache.
May 21 12:38:16 hostname systemd[3811]: Reached target sockets.target - Sockets.
May 21 12:38:16 hostname systemd[3811]: Reached target basic.target - Basic System.
May 21 12:38:16 hostname systemd[3811]: Reached target default.target - Main User Target.
May 21 12:38:16 hostname systemd[3811]: Startup finished in 73ms.
May 21 12:38:16 hostname systemd[1]: Started user@1000.service - User Manager for UID 1000.
May 21 12:38:16 hostname systemd[1]: Started session-26.scope - Session 26 of User username.
May 21 12:38:16 hostname sshd[3808]: pam_env(sshd:session): deprecated reading of user environment enabled
May 21 12:38:16 hostname sshd[3808]: User child is on pid 3832
May 21 12:38:16 hostname sshd[3832]: debug1: SELinux support disabled
May 21 12:38:16 hostname sshd[3832]: debug1: PAM: establishing credentials
May 21 12:38:16 hostname sshd[3832]: debug1: permanently_set_uid: 1000/1000
May 21 12:38:16 hostname sshd[3832]: debug1: rekey in after 4294967296 blocks
May 21 12:38:16 hostname sshd[3832]: debug1: rekey out after 4294967296 blocks
May 21 12:38:16 hostname sshd[3832]: debug1: ssh_packet_set_postauth: called
May 21 12:38:16 hostname sshd[3832]: debug1: active: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding
May 21 12:38:16 hostname sshd[3832]: debug1: Entering interactive session for SSH2.
May 21 12:38:16 hostname sshd[3832]: debug1: server_init_dispatch
May 21 12:38:16 hostname sshd[3832]: Received disconnect from remoteserverIP port 60804:11: PECL/ssh2 (http://pecl.php.net/packages/ssh2)
May 21 12:38:16 hostname sshd[3832]: Disconnected from user username remoteserverIP port 60804
May 21 12:38:16 hostname sshd[3832]: debug1: do_cleanup
May 21 12:38:16 hostname sshd[3832]: debug1: temporarily_use_uid: 1000/1000 (e=1000/1000)
May 21 12:38:16 hostname sshd[3832]: debug1: restore_uid: (unprivileged)
May 21 12:38:16 hostname sshd[3808]: debug1: do_cleanup
May 21 12:38:16 hostname sshd[3808]: debug1: PAM: cleanup
May 21 12:38:16 hostname sshd[3808]: debug1: PAM: closing session
May 21 12:38:16 hostname sshd[3808]: pam_unix(sshd:session): session closed for user username
May 21 12:38:16 hostname sshd[3808]: debug1: PAM: deleting credentials
May 21 12:38:16 hostname sshd[3808]: debug1: temporarily_use_uid: 1000/1000 (e=0/0)
May 21 12:38:16 hostname sshd[3808]: debug1: restore_uid: 0/0
May 21 12:38:16 hostname sshd[3808]: debug1: audit_event: unhandled event 12
May 21 12:38:16 hostname systemd[1]: session-26.scope: Deactivated successfully.
May 21 12:38:16 hostname systemd-logind[502]: Session 26 logged out. Waiting for processes to exit.
May 21 12:38:16 hostname systemd-logind[502]: Removed session 26.
May 21 12:38:26 hostname systemd[1]: Stopping user@1000.service - User Manager for UID 1000...
dcivera commented 6 months ago

After generating keys using the following formats:

rsa-sha2-512
rsa-sha2-256
ecdsa-sha2-nistp256
ssh-ed25519

Only ecdsa-sha2-nistp256 and ssh-ed25519 are accepted. For each, I used the following command ssh-keygen -m PEM -t $type

langemeijer commented 6 months ago

If there is an issue with supported key formats then that is all libssh2. The extension is a wrapper around this library. The php extension has no knowledge of the protocol and formats supported.

Remember that OpenSSH does not use libssh2. So although the ssh client might still work, libssh2 might not. They are not related in any way.

Also remember that the ssh protocol not only uses a key pair for authentication but also for host identification. It might well be that the newer libssh2 version compiled for your platform does not support older host key formats.

I'm closing the issue because this is not a problem in the php ssh2 extension.

dcivera commented 6 months ago

Thank you! I appreciate your quick reply and your direction. I'll move this conversation to libssh2. Hopefully, they can sort this out :)

dcivera commented 6 months ago

Ended up finding the solution. It has to do with permissions, generating the right key, and set the right configuration in WordPress. https://wordpress.org/support/topic/ssh2-not-working-wont-accept-keys/#post-17772194