On 5/21/25 15:53, Jakub Jelen wrote:
On Wed, May 21, 2025 at 1:43 PM <g4-l...@tonarchiv.ch> wrote:
Hi
On 5/21/25 09:44, Jakub Jelen wrote:
Hi,
the strace does not show much what libssh does.
It just confirms the check is failing locally, without sending
the public key to server. But the signature algorithm depends on
the extensions negotiated during key exchange, which should be
logged in verbose log.
I meant setting the log level using something like this:
int verbosity = SSH_LOG_TRACE;
ssh_options_set(session, SSH_OPTIONS_LOG_VERBOSITY, &verbosity);
Ah sure, but you don't need strace to read the log ;) I disabled
it on purpose so you see the essential filehandling...
Here you go again (attached).
I think this was still log level 3, while to get all of the tracing
information and packet numbers, log level 4 is required.
I'm confused about how ssh_options_set(session,
SSH_OPTIONS_LOG_VERBOSITY, ...) and ssh_set_log_level() is connected.
I used ssh_set_log_level(SSH_LOG_PACKET) - this is not equal to
ssh_options_set() with SSH_LOG_TRACE?
Ah wait I see the issue: I called ssh_set_log_level() after ssh_new(). I
guess that makes the difference.
New log attached.
I am still trying to figure out if the extensions are negotiated and
sent correctly to see if it is server or client issue. This is still
not visible from this log. I think the code to handle this is already
in 0.9.7, but it might be also affected by some configuration/options
on the server side.
It is also possible that the global configuration from
cryptographic policies overrides the
`SSH_OPTIONS_PUBLICKEY_ACCEPTED_TYPES`. The strace log shows that
the OpenSSH configuration is read before connecting:
openat(AT_FDCWD, "/etc/crypto-policies/back-ends/openssh.config",
O_RDONLY) = 5
This file does not have the ssh-rsa (SHA1) mechanisms in accepted
types:
$ cat /etc/crypto-policies/back-ends/openssh.config | grep ssh-rsa
If this is the case, is there a option to keep libssh from reading
systemwide configs? In my case that would be neater than enabling
SHA for the whole system...
There is SSH_OPTIONS_PROCESS_CONFIG in ssh_options_set(), which if set
to false, will not process any system configuration.
https://api.libssh.org/master/group__libssh__session.html#ga7a801b85800baa3f4e16f5b47db0a73d
Yes! That did the trick:
[2025/05/21 16:16:49.030307, 3] ssh_packet_need_rekey: rekey:
[data_rekey_needed=0, out_blocks=61, in_blocks=45]
[2025/05/21 16:16:49.030405, 2] ssh_userauth_publickey_auto:
Successfully authenticated using /home/useruser/id_rsa
Connected and authenticated with key!
Cheers
Till
[2025/05/21 16:12:17.046966, 3] ssh_config_parse_file: Reading configuration data from /etc/ssh/ssh_config
[2025/05/21 16:12:17.047203, 3] local_parse_file: Reading additional configuration data from /etc/ssh/ssh_config.d/50-redhat.conf
[2025/05/21 16:12:17.047253, 4] ssh_config_parse_line: line 3: Processing Match keyword 'final'
[2025/05/21 16:12:17.047272, 2] ssh_config_parse_line: line 3: Unsupported Match keyword 'final', skipping
[2025/05/21 16:12:17.047287, 4] ssh_config_parse_line: line 3: Processing Match keyword 'all'
[2025/05/21 16:12:17.047326, 3] local_parse_file: Reading additional configuration data from /etc/crypto-policies/back-ends/openssh.config
[2025/05/21 16:12:17.047389, 2] ssh_config_parse_line: Unknown option: GSSAPIKexAlgorithms, line: 3
[2025/05/21 16:12:17.047457, 2] ssh_config_parse_line: Unknown option: CASignatureAlgorithms, line: 6
[2025/05/21 16:12:17.047477, 2] ssh_config_parse_line: Unknown option: RequiredRSASize, line: 7
[2025/05/21 16:12:17.047512, 2] ssh_config_parse_line: Unapplicable option: ForwardX11Trusted, line: 12
[2025/05/21 16:12:17.047693, 2] ssh_connect: libssh 0.10.4 (c) 2003-2022 Aris Adamantiadis, Andreas Schneider and libssh contributors. Distributed under the LGPL, please refer to COPYING file for information about your rights, using threading threads_pthread
[2025/05/21 16:12:17.047736, 3] getai: host 10.10.10.108 matches an IP address
[2025/05/21 16:12:17.048093, 2] ssh_socket_connect: Nonblocking connection socket: 3
[2025/05/21 16:12:17.048146, 2] ssh_connect: Socket connecting, now waiting for the callbacks to work
[2025/05/21 16:12:17.048165, 3] ssh_connect: Actual timeout : 10000
[2025/05/21 16:12:17.048736, 4] ssh_socket_pollcallback: Poll callback on socket 3 (POLLOUT ), out buffer 0
[2025/05/21 16:12:17.048781, 3] ssh_socket_pollcallback: Received POLLOUT in connecting state
[2025/05/21 16:12:17.048800, 1] socket_callback_connected: Socket connection callback: 1 (0)
[2025/05/21 16:12:17.048976, 3] ssh_socket_unbuffered_write: Enabling POLLOUT for socket
[2025/05/21 16:12:17.049021, 4] ssh_socket_pollcallback: Poll callback on socket 3 (POLLOUT ), out buffer 0
[2025/05/21 16:12:17.050317, 4] ssh_socket_pollcallback: Poll callback on socket 3 (POLLIN ), out buffer 0
[2025/05/21 16:12:17.050369, 3] callback_receive_banner: Received banner: SSH-2.0-libssh_0.9.7
[2025/05/21 16:12:17.050381, 2] ssh_client_connection_callback: SSH server banner: SSH-2.0-libssh_0.9.7
[2025/05/21 16:12:17.050390, 2] ssh_analyze_banner: Analyzing banner: SSH-2.0-libssh_0.9.7
[2025/05/21 16:12:17.052005, 3] ssh_client_select_hostkeys: Order of wanted host keys: "ssh-ed25519,ecdsa-sha2-nistp521,ecdsa-sha2-nistp384,ecdsa-sha2-nistp256,rsa-sha2-512,rsa-sha2-256"
[2025/05/21 16:12:17.052094, 1] ssh_known_hosts_read_entries: Failed to open the known_hosts file '/etc/ssh/ssh_known_hosts': No such file or directory
[2025/05/21 16:12:17.052118, 3] ssh_client_select_hostkeys: No key found in known_hosts; changing host key method to "ssh-ed25519,ecdsa-sha2-nistp521,ecdsa-sha2-nistp384,ecdsa-sha2-nistp256,rsa-sha2-512,rsa-sha2-256"
[2025/05/21 16:12:17.052133, 4] ssh_list_kex: kex algos: curve25519-sha256,curve25519-sha...@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group14-sha256,diffie-hellman-group16-sha512,diffie-hellman-group18-sha512,ext-info-c
[2025/05/21 16:12:17.052142, 4] ssh_list_kex: server host key algo: ssh-ed25519,ecdsa-sha2-nistp521,ecdsa-sha2-nistp384,ecdsa-sha2-nistp256,rsa-sha2-512,rsa-sha2-256
[2025/05/21 16:12:17.052149, 4] ssh_list_kex: encryption client->server: aes256-...@openssh.com,chacha20-poly1...@openssh.com,aes256-ctr,aes128-...@openssh.com,aes128-ctr
[2025/05/21 16:12:17.052156, 4] ssh_list_kex: encryption server->client: aes256-...@openssh.com,chacha20-poly1...@openssh.com,aes256-ctr,aes128-...@openssh.com,aes128-ctr
[2025/05/21 16:12:17.052163, 4] ssh_list_kex: mac algo client->server: hmac-sha2-256-...@openssh.com,hmac-sha1-...@openssh.com,hmac-sha2-512-...@openssh.com,hmac-sha2-256,hmac-sha1,hmac-sha2-512
[2025/05/21 16:12:17.052183, 4] ssh_list_kex: mac algo server->client: hmac-sha2-256-...@openssh.com,hmac-sha1-...@openssh.com,hmac-sha2-512-...@openssh.com,hmac-sha2-256,hmac-sha1,hmac-sha2-512
[2025/05/21 16:12:17.052192, 4] ssh_list_kex: compression algo client->server: none,z...@openssh.com,zlib
[2025/05/21 16:12:17.052199, 4] ssh_list_kex: compression algo server->client: none,z...@openssh.com,zlib
[2025/05/21 16:12:17.052206, 4] ssh_list_kex: languages client->server:
[2025/05/21 16:12:17.052213, 4] ssh_list_kex: languages server->client:
[2025/05/21 16:12:17.052349, 3] ssh_socket_unbuffered_write: Enabling POLLOUT for socket
[2025/05/21 16:12:17.052383, 3] packet_send2: packet: wrote [type=20, len=900, padding_size=7, comp=892, payload=892]
[2025/05/21 16:12:17.052394, 3] ssh_send_kex: SSH_MSG_KEXINIT sent
[2025/05/21 16:12:17.052408, 4] ssh_socket_pollcallback: Poll callback on socket 3 (POLLIN POLLOUT ), out buffer 0
[2025/05/21 16:12:17.052433, 3] ssh_packet_socket_callback: packet: read type 20 [len=884,padding=9,comp=874,payload=874]
[2025/05/21 16:12:17.052444, 3] ssh_packet_process: Dispatching handler for packet type 20
[2025/05/21 16:12:17.052459, 4] ssh_list_kex: kex algos: curve25519-sha256,curve25519-sha...@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group18-sha512,diffie-hellman-group16-sha512,diffie-hellman-group-exchange-sha256,diffie-hellman-group14-sha256,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1
[2025/05/21 16:12:17.052467, 4] ssh_list_kex: server host key algo: rsa-sha2-512,rsa-sha2-256,ssh-rsa
[2025/05/21 16:12:17.052475, 4] ssh_list_kex: encryption client->server: aes256-...@openssh.com,aes128-...@openssh.com,aes256-ctr,aes192-ctr,aes128-ctr,aes256-cbc,aes192-cbc,aes128-cbc,3des-cbc
[2025/05/21 16:12:17.052482, 4] ssh_list_kex: encryption server->client: aes256-...@openssh.com,aes128-...@openssh.com,aes256-ctr,aes192-ctr,aes128-ctr,aes256-cbc,aes192-cbc,aes128-cbc,3des-cbc
[2025/05/21 16:12:17.052489, 4] ssh_list_kex: mac algo client->server: hmac-sha2-256-...@openssh.com,hmac-sha2-512-...@openssh.com,hmac-sha1-...@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1
[2025/05/21 16:12:17.052496, 4] ssh_list_kex: mac algo server->client: hmac-sha2-256-...@openssh.com,hmac-sha2-512-...@openssh.com,hmac-sha1-...@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1
[2025/05/21 16:12:17.052503, 4] ssh_list_kex: compression algo client->server: none
[2025/05/21 16:12:17.052510, 4] ssh_list_kex: compression algo server->client: none
[2025/05/21 16:12:17.052517, 4] ssh_list_kex: languages client->server:
[2025/05/21 16:12:17.052524, 4] ssh_list_kex: languages server->client:
[2025/05/21 16:12:17.052551, 2] ssh_kex_select_methods: Negotiated curve25519-sha256,rsa-sha2-512,aes256-...@openssh.com,aes256-...@openssh.com,aead-gcm,aead-gcm,none,none,,
[2025/05/21 16:12:17.052774, 3] packet_send2: packet: wrote [type=30, len=44, padding_size=6, comp=37, payload=37]
[2025/05/21 16:12:17.052800, 3] ssh_socket_unbuffered_write: Enabling POLLOUT for socket
[2025/05/21 16:12:17.052814, 4] ssh_socket_pollcallback: Poll callback on socket 3 (POLLOUT ), out buffer 0
[2025/05/21 16:12:17.052822, 4] ssh_socket_pollcallback: sending control flow event
[2025/05/21 16:12:17.052829, 4] ssh_packet_socket_controlflow_callback: sending channel_write_wontblock callback
[2025/05/21 16:12:17.113139, 4] ssh_socket_pollcallback: Poll callback on socket 3 (POLLIN ), out buffer 0
[2025/05/21 16:12:17.113219, 3] ssh_packet_socket_callback: packet: read type 31 [len=612,padding=11,comp=600,payload=600]
[2025/05/21 16:12:17.113241, 3] ssh_packet_process: Dispatching handler for packet type 31
[2025/05/21 16:12:17.113889, 3] ssh_socket_unbuffered_write: Enabling POLLOUT for socket
[2025/05/21 16:12:17.113934, 3] packet_send2: packet: wrote [type=21, len=12, padding_size=10, comp=1, payload=1]
[2025/05/21 16:12:17.113952, 4] ssh_packet_set_newkeys: called, direction = OUT
[2025/05/21 16:12:17.114628, 3] crypt_set_algorithms2: Set output algorithm to aes256-...@openssh.com
[2025/05/21 16:12:17.114696, 3] crypt_set_algorithms2: Set HMAC output algorithm to aead-gcm
[2025/05/21 16:12:17.114716, 3] crypt_set_algorithms2: Set input algorithm to aes256-...@openssh.com
[2025/05/21 16:12:17.114731, 3] crypt_set_algorithms2: Set HMAC input algorithm to aead-gcm
[2025/05/21 16:12:17.114901, 2] ssh_init_rekey_state: Set rekey after 4294967296 blocks
[2025/05/21 16:12:17.114926, 2] ssh_init_rekey_state: Set rekey after 4294967296 blocks
[2025/05/21 16:12:17.114984, 2] ssh_packet_client_curve25519_reply: SSH_MSG_NEWKEYS sent
[2025/05/21 16:12:17.115015, 4] ssh_socket_pollcallback: Poll callback on socket 3 (POLLIN POLLOUT ), out buffer 0
[2025/05/21 16:12:17.115112, 3] ssh_packet_socket_callback: packet: read type 21 [len=12,padding=10,comp=1,payload=1]
[2025/05/21 16:12:17.115134, 3] ssh_packet_process: Dispatching handler for packet type 21
[2025/05/21 16:12:17.115149, 2] ssh_packet_newkeys: Received SSH_MSG_NEWKEYS
[2025/05/21 16:12:17.115181, 4] ssh_pki_signature_verify: Going to verify a rsa-sha2-512 type signature
[2025/05/21 16:12:17.115491, 4] pki_verify_data_signature: Signature valid
[2025/05/21 16:12:17.115527, 2] ssh_packet_newkeys: Signature verified and valid
[2025/05/21 16:12:17.115543, 4] ssh_packet_set_newkeys: called, direction = IN
[2025/05/21 16:12:17.115609, 4] ssh_socket_pollcallback: sending control flow event
[2025/05/21 16:12:17.115632, 4] ssh_packet_socket_controlflow_callback: sending channel_write_wontblock callback
[2025/05/21 16:12:17.115649, 3] ssh_connect: current state : 7
[2025/05/21 16:12:17.115673, 3] ssh_userauth_publickey_auto: Trying to authenticate with /home/useruser/id_rsa
[2025/05/21 16:12:17.115849, 3] ssh_key_algorithm_allowed: Checking rsa-sha2-512 with list <ecdsa-sha2-nistp256,ecdsa-sha2-nistp256-cert-...@openssh.com,ecdsa-sha2-nistp384,ecdsa-sha2-nistp384-cert-...@openssh.com,ecdsa-sha2-nistp521,ecdsa-sha2-nistp521-cert-...@openssh.com,ssh-ed25519,ssh-ed25519-cert-...@openssh.com,rsa-sha2-256,rsa-sha2-256-cert-...@openssh.com,rsa-sha2-512,rsa-sha2-512-cert-...@openssh.com>
[2025/05/21 16:12:17.115884, 3] ssh_key_algorithm_allowed: Checking rsa-sha2-256 with list <ecdsa-sha2-nistp256,ecdsa-sha2-nistp256-cert-...@openssh.com,ecdsa-sha2-nistp384,ecdsa-sha2-nistp384-cert-...@openssh.com,ecdsa-sha2-nistp521,ecdsa-sha2-nistp521-cert-...@openssh.com,ssh-ed25519,ssh-ed25519-cert-...@openssh.com,rsa-sha2-256,rsa-sha2-256-cert-...@openssh.com,rsa-sha2-512,rsa-sha2-512-cert-...@openssh.com>
[2025/05/21 16:12:17.115901, 3] ssh_key_algorithm_allowed: Checking ssh-rsa with list <ecdsa-sha2-nistp256,ecdsa-sha2-nistp256-cert-...@openssh.com,ecdsa-sha2-nistp384,ecdsa-sha2-nistp384-cert-...@openssh.com,ecdsa-sha2-nistp521,ecdsa-sha2-nistp521-cert-...@openssh.com,ssh-ed25519,ssh-ed25519-cert-...@openssh.com,rsa-sha2-256,rsa-sha2-256-cert-...@openssh.com,rsa-sha2-512,rsa-sha2-512-cert-...@openssh.com>
[2025/05/21 16:12:17.115917, 1] ssh_userauth_try_publickey: The key algorithm 'ssh-rsa' is not allowed to be used by PUBLICKEY_ACCEPTED_TYPES configuration option
[2025/05/21 16:12:17.115933, 3] ssh_userauth_publickey_auto: Public key for /home/useruser/id_rsa refused by server
[2025/05/21 16:12:17.115966, 3] ssh_userauth_publickey_auto: Trying to authenticate with /home/useruser/.ssh/id_ed25519
[2025/05/21 16:12:17.116000, 1] ssh_pki_import_pubkey_file: Error opening /home/useruser/.ssh/id_ed25519.pub: No such file or directory
[2025/05/21 16:12:17.116026, 1] ssh_pki_import_privkey_file: Error opening /home/useruser/.ssh/id_ed25519: No such file or directory
[2025/05/21 16:12:17.116042, 3] ssh_userauth_publickey_auto: Private key /home/useruser/.ssh/id_ed25519 doesn't exist.
[2025/05/21 16:12:17.116057, 3] ssh_userauth_publickey_auto: Trying to authenticate with /home/useruser/.ssh/id_ecdsa
[2025/05/21 16:12:17.116078, 1] ssh_pki_import_pubkey_file: Error opening /home/useruser/.ssh/id_ecdsa.pub: No such file or directory
[2025/05/21 16:12:17.116099, 1] ssh_pki_import_privkey_file: Error opening /home/useruser/.ssh/id_ecdsa: No such file or directory
[2025/05/21 16:12:17.116128, 3] ssh_userauth_publickey_auto: Private key /home/useruser/.ssh/id_ecdsa doesn't exist.
[2025/05/21 16:12:17.116144, 3] ssh_userauth_publickey_auto: Trying to authenticate with /home/useruser/.ssh/id_rsa
[2025/05/21 16:12:17.116166, 1] ssh_pki_import_pubkey_file: Error opening /home/useruser/.ssh/id_rsa.pub: No such file or directory
[2025/05/21 16:12:17.116187, 1] ssh_pki_import_privkey_file: Error opening /home/useruser/.ssh/id_rsa: No such file or directory
[2025/05/21 16:12:17.116202, 3] ssh_userauth_publickey_auto: Private key /home/useruser/.ssh/id_rsa doesn't exist.
[2025/05/21 16:12:17.116217, 2] ssh_userauth_publickey_auto: Tried every public key, none matched
Authentication failed: The key algorithm 'ssh-rsa' is not allowed to be used by PUBLICKEY_ACCEPTED_TYPES configuration option
[2025/05/21 16:12:17.116398, 3] ssh_socket_unbuffered_write: Enabling POLLOUT for socket
[2025/05/21 16:12:17.116435, 3] packet_send2: packet: wrote [type=1, len=32, padding_size=11, comp=20, payload=20]
