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

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.

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
>