Bug 1271694 - sshd has a malformed audit record
sshd has a malformed audit record
Status: CLOSED ERRATA
Product: Fedora
Classification: Fedora
Component: openssh (Show other bugs)
22
Unspecified Unspecified
unspecified Severity medium
: ---
: ---
Assigned To: Jakub Jelen
Fedora Extras Quality Assurance
:
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2015-10-14 09:48 EDT by Steve Grubb
Modified: 2015-10-31 22:29 EDT (History)
5 users (show)

See Also:
Fixed In Version: openssh-7.1p1-4.fc23
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2015-10-31 22:29:39 EDT
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)

  None (edit)
Description Steve Grubb 2015-10-14 09:48:47 EDT
Description of problem:
type=CRYPTO_SESSION msg=audit(1444829957.685:713): pid=9074 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:sshd_t:s0-s0:c0.c1023 msg='op=start direction=from-client cipher=chacha20-poly1305@openssh.com ksize=512 mac= pfs=curve25519-sha256@libssh.org spid=9076 suid=74 rport=51663 laddr=::1 lport=22  exe="/usr/sbin/sshd" hostname=? addr=::1 terminal=? res=success'

The audit records are supposed to be name=value. The 'mac' field is missing the value part of the tuple.

Version-Release number of selected component (if applicable):
openssh-6.9p1-9.fc22.x86_64
Comment 1 Jakub Jelen 2015-10-14 12:13:31 EDT
Thank you for the report. Verbose debug output says <implicit> for mac.

As wandering through the behaviour of different RHEL's I see the same happens when I am connecting from Fedora 22+ to RHEL7 (f21 -> rhel7 works fine). There is also empty value for mac. It looks like no mac is chosen (even though the lists are overlapping) and it is logged as empty sting, which is not ideal.

We do mac checking for emptiness:

  buffer_put_cstring(&m, (mac ? mac : ""));

and it is later on put into the template. What do you propose to store if we don't use MAC? 

Previous versions (rhel7) tends to fail when there is no overlap on MACs:
> no matching mac found: client hmac-md5 server umac-64@openssh.com

Current version doesn't care that it doesn't choose MAC and runs further. 
> debug2: kex_parse_kexinit: hmac-md5
> debug2: kex_parse_kexinit: umac-64@openssh.com
> debug1: kex: server->client chacha20-poly1305@openssh.com <implicit> none

This will probably require further inspection. I will have to check protocol specification if this is even possible not to use MAC.
Comment 2 Steve Grubb 2015-10-14 14:54:52 EDT
The audit system typically uses '?' to denote a NULL value. We also use 'none' in some places. I also see some other strangeness where its deleted a key but can't tell which key it was or which direction its associated with.

Try to do a login to localhost and logout. Then run:
ausearch -m 'CRYPTO_KEY_USER,CRYPTO_SESSION,USER_AUTH,LOGIN,USER_ACCT,USER_CHAUTHTOK,CRED_ACQ,USER_START,USER_LOGIN,USER_LOGOUT,USER_END,CRED_DISP' --start recent -i | less

Why is the first crypto_key_user event op=destroy? Shouldn't that be create?

Later after user_acct event, there is a crypto_key_user destroy and fp=?. Why does it not know the key being destroyed?

Grepping through the logs, I see no key creation operation. I realize this is a different issue than what was originally reported. But I was thinking that while you are looking at the audit events...there are a couple other issues. Thanks.
Comment 3 Tomas Mraz 2015-10-15 04:01:08 EDT
(In reply to Jakub Jelen from comment #1)
> Current version doesn't care that it doesn't choose MAC and runs further. 
> > debug2: kex_parse_kexinit: hmac-md5
> > debug2: kex_parse_kexinit: umac-64@openssh.com
> > debug1: kex: server->client chacha20-poly1305@openssh.com <implicit> none
> 
> This will probably require further inspection. I will have to check protocol
> specification if this is even possible not to use MAC.

It is correct because the chacha20-poly1305@openssh.com cipher is an AEAD (Authenticated Encryption with Associated Data) cipher and thus there is no separate MAC when it is used. The same holds for aes-gcm ciphers.
Comment 4 Jakub Jelen 2015-10-15 05:40:41 EDT
Tomas. Thanks for explanation. I see that this is the meaning of <implicit>. Is there some place where I can find some documentation about? I searched through RFC 4253 and google but without any success. But the understanding that chacha20 is cipher and poly1305 is authenticator makes sense.

Should we send also "<implicit>" instead of empty character to audit log or just skip this field since MAC is not used explicitly with this cipiher-set?


Second thing about the destroy: If I am right, the first destroy event is removing private host key from the forked child, since it is not required anymore. This is how it was designed 5 years ago.


But from the log I see we have there weird fingerprint hash, for example:
SHA256:f6:14:fe:75:e7:89:5b:73:73:97:30:57:bc:9d:de:2b:f9:6b:ed:06:26:c5:a6:70:78:7a:b3:3c:6d:96:01:25
which is ... mixture ... of new SHA256 hash and hexadecimal form instead of base64 as it should be default for all tools:
ssh-keygen -lf /etc/ssh/ssh_host_ecdsa_key.pub 
256 SHA256:9hT+deeJW3NzlzBXvJ3eK/lr7QYmxaZweHqzPG2WASU root@rawhide (ECDSA)

It is more readable, but too long and impossible to verify against any other ssh tool. I will check on this.


About the last remark, "op=destroy kind=session fp=?", not sure which fingerprint should be associated with destroying session key. I believe you can store there session key fingerprint, but what for? It should be unique. Also it is still the same as it was in RHEL6.
Comment 5 Steve Grubb 2015-10-15 18:18:43 EDT
You should put implicit in the field. We can't leave it empty because everything must be name=value.

The fingerprint is in the same form as the VPN fingerprints. We need to have agreement between both since they are the same field. Every application providing this record has to fill in the value the same way.

There has to be traceability from key creation to destruction. This is the purpose of the fingerprint. You should see a create and destroy record for the same fingerprint. If its filled in as '?', then you cannot correlate creation and destruction.

Did you find any creation records?
Comment 6 Jakub Jelen 2015-10-16 09:37:16 EDT
Certainly, the first report about MAC makes sense and we will probably have to clone this bug also to RHEL7 (please do so with appropriate severity), which contains the same issue (as I reproduced it in comment #1).


About fingerprints, let me go through the audit trail of one login:

We have there CRYPTO_KEY_USER three times with the same fingerprint, from different processes which destroy this one particular server key at different stages of authentication (net child, postauth child, privileged child). Creation of these keys (reading from file to memory should be also audited during daemon start? How?).

To correct my previous statement from comm, there are two events with fp=? during login. Both of them are session keys that are unique for session and the creation is audited basically by the event CRYPTO_SESSION where are the parameters and algorithms are negotiated.

Destroying session keys:
One of CRYPTO_KEY_USER is coming from the end of the user session and the other is coming from the end of preauth process, where we destroy copy in this process before terminating.

The problem with fp for session keys is that there are 6 keys derived at that point (IV and key for encryption, key for MAC; separate for both directions) and which fingerprint you want there? It is handled together as key set. If we would want to audit this, we would have to use some normalized way of fingerprinting them, but note that the creation and destroying will be the only event logged. They are used all the time for encryption of all messages and there is no point in logging this. But I don't know what is the requirement.
Comment 7 Fedora Update System 2015-10-22 12:41:03 EDT
openssh-7.1p1-4.fc23 has been submitted as an update to Fedora 23. https://bodhi.fedoraproject.org/updates/FEDORA-2015-1ff6efd876
Comment 8 Fedora Update System 2015-10-24 08:07:02 EDT
openssh-7.1p1-4.fc23 has been pushed to the Fedora 23 testing repository. If problems still persist, please make note of it in this bug report.
If you want to test the update, you can install it with
$ su -c 'dnf --enablerepo=updates-testing update openssh'
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2015-1ff6efd876
Comment 9 Fedora Update System 2015-10-31 22:29:31 EDT
openssh-7.1p1-4.fc23 has been pushed to the Fedora 23 stable repository. If problems still persist, please make note of it in this bug report.

Note You need to log in before you can comment on or make changes to this bug.