openssh unix dev - Oct 2024 - sshd fails when using cryptodev-linux to compute hmac

I don't know anything about cryptodev-linux, but I assume it's an
openssl engine? If so it's possible sshd's multiprocess model and/or
file descriptor handling is confusing it.

It's not a configuration we test, so you're mostly on your own to debug
it. It's entirely possible there's a bug there; if so, I'd expect it
to be something like a fd being closed while devcrypto is still
depending on it.

I'd suggest turning on LogVerbose=* so you can see which process
(represented by it's PID) is doing what, though that probably won't
be represented in the devcrypto debug messages unless you hack something
similar in.

On Tue, 8 Oct 2024, Peter Rashleigh wrote:
> Hi All,
> 
> I'm having an issue where SSH sessions fail if I enable the cryptodev
engine for HMAC. I'd like to confirm if this is a supported configuration
and if there are any known bugs.
> 
> HMAC with the cryptodev engine works fine when using the openssl
application directly, so I suspect that something in openssh may be the cause of
the issue.
> 
> I tried this initially with sshd from openssh 9.6p1, openssl 1.1.1v, and
cryptodev-linux 1.12 on a custom buildroot Linux 6.1.53 running on ARMv8.
> My client is PuTTY on Windows using aes256-ctr/hmac-sha2-256 (but I get the
same result using openssh on Linux with the same cipher settings).
> 
> When I attempt to connect, I get the following errors from sshd, and the
client (PuTTY) reports that the server unexpectedly closed the connection. No
login prompt is displayed.
> 
> 1995-11-22T00:18:33.755757+00:00 auth.info sshd[27262]: Corrupted MAC on
input. [preauth]
> 1995-11-22T00:18:33.756013+00:00 auth.info sshd[27262]:
ssh_dispatch_run_fatal: Connection from 192.168.254.100 port 54167: message
authentication code incorrect [preauth]
> 
> Thinking that the issue might be fixed in a newer version, I then tried
upgrading to openssh 9.8p1, openssl 3.3.2, and cryptodev-linux 1.13. Now, the
session starts and I get a login prompt. After authentication, the MOTD and
LastLog are printed, but then the session is terminated. The output of
'/usr/sbin/sshd -ddd' is below. Note the "error in devcrypto"
message - this happens because of an ioctl call (CIOCCPHASH) for a non-existent
session ID (details below).
> 
> ....
> Starting session: shell on pts/0 for engadmin from 192.168.254.45 port
51222 id 0
> debug2: fd 4 setting TCP_NODELAY
> debug3: set_sock_tos: set socket 4 IP_TOS 0x48
> debug2: channel 0: rfd 11 isatty
> debug2: fd 11 setting O_NONBLOCK
> debug3: fd 9 is O_NONBLOCK
> debug1: Setting controlling tty using TIOCSCTTY.
> debug3: send packet: type 99
> channel_output_poll_input_open: channel 0: send data: error in libcrypto
> debug1: do_cleanup
> debug3: PAM: sshpam_thread_cleanup entering
> debug3: mm_request_receive: entering
> debug3: mm_request_receive: monitor fd closed
> debug1: mm_reap: preauth child exited with status 255
> debug1: do_cleanup
> debug1: PAM: cleanup
> debug1: PAM: closing session
> debug1: PAM: deleting credentials
> debug3: PAM: sshpam_thread_cleanup entering
> debug1: session_pty_cleanup2: session 0 release /dev/pts/0
> debug1: audit_event: unhandled event 12
> 
> Looking at the ioctl logging from cryptodev-linux, I can see that a session
ID is being closed (CIOCFSESSION) before an attempt is made to copy from it
(CIOCCPHASH). As you can see, crypto_destroy_session was called before a
crypto_copy_hash_state for the same SID (0x9198779A):
> 
> ....
> 2024-10-08T18:52:23.314088+00:00 debug kernel: [ 1206.105427] cryptodev:
sshd-session[2108] (cryptodev_ioctl:960): Got CIOCFSESSION
> 2024-10-08T18:52:23.314104+00:00 debug kernel: [ 1206.105473] cryptodev:
sshd-session[2109] (crypto_destroy_session:372): Removed session 0x9198779A
> 2024-10-08T18:52:23.314113+00:00 debug kernel: [ 1206.105483] cryptodev:
sshd-session[2109] (crypto_destroy_session:375): freeing space for 32 user pages
> 2024-10-08T18:52:23.314122+00:00 debug kernel: [ 1206.105500] cryptodev:
sshd-session[2109] (cryptodev_ioctl:960): Got CIOCFSESSION
> 2024-10-08T18:52:23.314152+00:00 debug kernel: [ 1206.105598] cryptodev:
sshd-session[2108] (crypto_destroy_session:372): Removed session 0xDE377830
> 2024-10-08T18:52:23.314229+00:00 debug kernel: [ 1206.105642] cryptodev:
sshd-session[2108] (crypto_destroy_session:375): freeing space for 32 user pages
> 2024-10-08T18:52:23.314241+00:00 debug kernel: [ 1206.105662] cryptodev:
sshd-session[2108] (cryptodev_ioctl:946): Got CIOCGSESSION
> 2024-10-08T18:52:23.314250+00:00 debug kernel: [ 1206.105680] cryptodev:
sshd-session[2108] (crypto_create_session:314): got alignmask 0
> 2024-10-08T18:52:23.314255+00:00 debug kernel: [ 1206.105687] cryptodev:
sshd-session[2108] (crypto_create_session:317): preallocating for 32 user pages
> 2024-10-08T18:52:23.314261+00:00 debug kernel: [ 1206.105700] cryptodev:
sshd-session[2108] (cryptodev_ioctl:977): Got CIOCCPHASH
> 2024-10-08T18:52:23.314267+00:00 debug kernel: [ 1206.105711] cryptodev:
sshd-session[2109] (crypto_destroy_session:372): Removed session 0x62D4D890
> 2024-10-08T18:52:23.314270+00:00 debug kernel: [ 1206.105718] cryptodev:
sshd-session[2109] (crypto_destroy_session:375): freeing space for 32 user pages
> 2024-10-08T18:52:23.314273+00:00 debug kernel: [ 1206.105783] cryptodev:
sshd-session[2108] (cryptodev_ioctl:960): Got CIOCFSESSION
> 2024-10-08T18:52:23.314315+00:00 debug kernel: [ 1206.105906] cryptodev:
sshd-session[2108] (crypto_destroy_session:372): Removed session 0x6FD5C855
> 2024-10-08T18:52:23.314320+00:00 debug kernel: [ 1206.105949] cryptodev:
sshd-session[2108] (crypto_destroy_session:375): freeing space for 32 user pages
> 2024-10-08T18:52:23.324801+00:00 debug kernel: [ 1206.115947] cryptodev:
sshd-session[2108] (cryptodev_ioctl:946): Got CIOCGSESSION
> 2024-10-08T18:52:23.324821+00:00 debug kernel: [ 1206.115992] cryptodev:
sshd-session[2108] (crypto_create_session:314): got alignmask 0
> 2024-10-08T18:52:23.324825+00:00 debug kernel: [ 1206.116000] cryptodev:
sshd-session[2108] (crypto_create_session:317): preallocating for 32 user pages
> 2024-10-08T18:52:23.324828+00:00 debug kernel: [ 1206.116013] cryptodev:
sshd-session[2108] (cryptodev_ioctl:977): Got CIOCCPHASH
> 2024-10-08T18:52:23.324850+00:00 err kernel: [ 1206.116019] cryptodev:
sshd-session[2108] (crypto_copy_hash_state:516): Failed to get sesssions with
sid=0x9198779A sid=f7160dd008X!
> ....
> 
> I spent some time tracing through the openssl and openssh code, and I found
that If I comment out the call to mac_clear() within kex_free_newkeys(), the
issue does not occur. Therefore, I wonder if there is some bug in openssh that
causes re-use of a cryptodev session ID, or causes the digest to be cleaned up
prematurely. I'd appreciate any feedback or suggestions. I assume that
cryptodev should be well-supported and tested, so maybe there's some problem
with my configuration. Has anyone got a setup like this working?
> 
> Thanks,
> 
> --
> Peter Rashleigh
> Embedded Developer
> Quester Tangent
> 
> 
> ________________________________
> 
> This transmission is confidential and intended solely for the addressee and
for its intended purpose. If you are not the intended recipient, please
immediately inform the sender and delete the message and any attachments from
your system. Please note that any views or opinions presented in this email are
solely those of the author and do not necessarily represent those of QTC. No
employee or agent is authorised to conclude any binding agreement on behalf of
QTC with another party by email without express written confirmation by an
officer of the company. The organization accepts no liability for any damage
arising out of transmission failures, viruses, external influence, delays and
the like.
> _______________________________________________
> openssh-unix-dev mailing list
> openssh-unix-dev at mindrot.org
> https://lists.mindrot.org/mailman/listinfo/openssh-unix-dev
>

Hi Damien,
> I don't know anything about cryptodev-linux, but I assume it's an
openssl engine?
Cryptodev-linux is a kernel module that provides access to kernel crypto
drivers, especially hardware-accelerated crypto, through the /dev/crypto device.
Openssl implements an engine which interfaces to it.
> If so it's possible sshd's multiprocess model and/or file
descriptor handling is confusing it.
This seems like a reasonable explanation based on what I've seen so far.
> It's not a configuration we test, so you're mostly on your own to
debug it. It's entirely possible there's a bug there; if so, I'd
expect it to be something like a fd being closed while devcrypto is still
depending on it.
>
> I'd suggest turning on LogVerbose=* so you can see which process
(represented by it's PID) is doing what, though that probably won't be
represented in the devcrypto debug messages unless you hack something similar
in.
Too bad, I was hoping it was a tested/supported configuration. Since that
doesn't seem to be the case, I suspect the easiest way forward for me is
going to be disabling the openssl engine entirely so that openssh works
properly. I doubt that hardware-accelerated crypto is going to have much benefit
for SSH workloads anyway.

Thanks,
Peter