Fix acct quoting in audit_log_acct_message())

Hello,
audit_log_acct_message() is currently quoting acct differently from all other users: it adds quotes to acct if it is represented in hexadecimal, not when it is represented as-is.

The attached patch fixes it - but it also changes the format of some of the most-often used messages. It might be better to leave the message format alone, and add a special case to libauparse and other applications that parse the logs - I have no idea.
Mirek

diff -up audit-1.6.7/lib/audit_logging.c.quotes audit-1.6.7/lib/audit_logging.c
@@ -378,10 +378,10 @@ int audit_log_acct_message(int audit_fd,
 		}
 		if (enc)
 			format = 
-	 "op=%s acct=\"%s\" exe=%s (hostname=%s, addr=%s, terminal=%s res=%s)";
+	 "op=%s acct=%s exe=%s (hostname=%s, addr=%s, terminal=%s res=%s)";
 		else
 			format = 
-	     "op=%s acct=%s exe=%s (hostname=%s, addr=%s, terminal=%s res=%s)";
+	     "op=%s acct=\"%s\" exe=%s (hostname=%s, addr=%s, terminal=%s res=%s)";
 
 		snprintf(buf, sizeof(buf), format,
 			op, user, pgname,

This isn't the only audit hexadecimal parsing issue, there are many more, see my previous posts. It is a sad fact audit output is impossible to parse correctly given only the output. Correct parsing of audit data demands private knowledge about the format of audit log messages on a per kernel version basis, this is very broken IMHO.

John Dennis <[email protected]>

Following up on the discussion we had on IRC about making the audit messages easily parsable.

This proposal is just for starting the discussion.

1. Messages contain <name>=<value> pairs separated by spaces.
2. All <names> are just alphanumeric sequences.
3. Values can be either:
a) byte sequences with the following special characters encoded as %XX
where XX is hexadecimal value of the encoded byte. Special characters
are: bytes with value <= 0x20 or >= 0x7F, '%', '(', ')', and '='.
b) recursively embedded messages enclosed in '(' and ')' parentheses.

type=USER_START msg=audit(1204632061.112:32361): user pid=10902 uid=0 auid=0 subj=system_u:system_r:crond_t:s0-s0:c0.c1023 msg='op=PAM:session_open acct=root exe="/usr/sbin/crond" (hostname=?, addr=?, terminal=cron res=success)'

becomes:

type=USER_START msg=(audit=1204632061.112:3236 src=user pid=10902 uid=0 auid=0 subj=system_u:system_r:crond_t:s0-s0:c0.c1023 msg=(op=PAM:session_open acct=root exe=/usr/sbin/crond hostname=? addr=? terminal=cron res=success))

type=AVC msg=audit(1204601533.621:32307): avc: denied { read write } for pid=9822 comm="tmpwatch" path="socket:[14038]" dev=sockfs ino=14038 scontext=system_u:system_r:tmpreaper_t:s0-s0:c0.c1023 tcontext=system_u:system_r:crond_t:s0-s0:c0.c1023 tclass=tcp_socket

becomes:

type=AVC msg=(audit=1204601533.621:32307 src=avc kind=denied acts=read:write pid=9822 comm=tmpwatch path=socket:[14038] dev=sockfs ino=14038 scontext=system_u:system_r:tmpreaper_t:s0-s0:c0.c1023 tcontext=system_u:system_r:crond_t:s0-s0:c0.c1023 tclass=tcp_socket)

type=SYSCALL msg=audit(1204601533.621:32307): arch=c000003e syscall=59 success=yes exit=0 a0=2496490 a1=2493360 a2=24959a0 a3=8 items=0 ppid=9788 pid=9822 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=48 comm="tmpwatch" exe="/usr/sbin/tmpwatch" subj=system_u:system_r:tmpreaper_t:s0-s0:c0.c1023 key=(null)

becomes

type=SYSCALL msg=(audit=1204601533.621:32307 arch=c000003e syscall=59 success=yes exit=0 a0=2496490 a1=2493360 a2=24959a0 a3=8 items=0 ppid=9788 pid=9822 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=%28none%29 ses=48 comm=tmpwatch exe=/usr/sbin/tmpwatch subj=system_u:system_r:tmpreaper_t:s0-s0:c0.c1023 key=%28null%29)

Tomas Mraz
No matter how far down the wrong road you've gone, turn back.
                                              Turkish proverb

I think if a value is a string then the fact it is a string should be explicit and the boundaries of the string should be delimited.

The simplest way to achieve this is by enclosing string values in double quotes and assuring any double quote contained in the string is escaped. If a value is not enclosed in double quotes it is not a string and is not subject to unescaping (decoding).

John Dennis <[email protected]>

You also need to start looking at where messages come from before we decide we can change them any way we want. Any message generated by the audit system should be encoded according to the audit system standards. Any message generated by a CONSUMER of the audit system is wholely responsible for their own encoding decisions (although we obviously should encourage them to follow standard practice.) The audit system has no 'right' to change those messages just to make a userspace library easier. I realize you don't want to ever look at the TYPE= part of the message to make decisions, but that's just too bad.

Lets standardize syscall messages. Lets standardize audit config messages. Lets standardize every message the audit system itself generates. If the package owners so choose lets standardize each userspace audit message. But avc messages are wholely the responsibility of the selinux community and I don't want to see any patches which makes them fail to be backwards compatible.

Like it or not I will not accept any kernel patch which causes a new kernel to break SELinux usability with FC2 userspace. read that again.

-Eric

OK, I'll bite - at what point has the end-of-support for FC2 gone by *so* far that breaking it is acceptable? Hint - I suspect that you'll have to do some interesting tap-dancing to get an FC2 userspace to work with a 2.6.25+ kernel - I think we've busticated udev at least 3 or 4 times in the interim, and there's probably other stuff as well.

As soon as Andrew Morton stops running it on his test machine. I don't know how he does it, but the SELinux community is determined to stop breaking that machine. :)

-Eric

You need to ask the SE Linux folks if they would like to see their event layout change. If there's no agreement with them, should we change anything? auparse is working pretty good as is.

This is basically the parsing rules: The header was defined a long time ago, It parses in its own way, once we hit msg=, everything is name=value. We do this by repeatedly calling strtok. If the newly split string does not have a = in it, we throw it away. We trim any trailing punctuation. I'll attach the parser code at the end of this email just so you see its actually real simple. I wouldn't mind dropping some of the punctuation since that would save disk space.

What is missing perhaps is a schema file that tells the field name, its format, and maybe its meaning. Not sure meaning is really needed. If we had a schema file, then you could change things pretty easy and still parse it. But that flexibility might cost performance.

The biggest question to me is how you handle any transition from one format to another. It will take time for patches to get upstream and then back downstream. Meanwhile we could have audit logs being aggregated from a couple different releases. They all need to parse correctly. How do we handle that? I suspect the answer is to make the audit parser handle old and new formats which adds a whole lot of code and makes it more complicated.

-Steve

        buf = strdup(r->record);
        ptr = strtok_r(buf, " ", &saved);
        if (ptr == NULL)
                return -1;

        do {    // If there's an '=' sign, its a keeper
                nvnode n;
                char *val = strchr(ptr, '=');
                if (val) {
                        int len;

                        // If name is 'msg=audit' throw it away
                        if (*ptr == 'm' && strncmp(ptr, "msg=", 4) == 0) {
                                if (ptr[4] == 'a')
                                        continue;

                                // If name is 'msg='' chop off and see
                                // if there is still a = in the string.
                                else if (ptr[4] == '\'') {
                                        ptr += 5;
                                        val = strchr(ptr, '=');
                                        if (val == NULL)
                                                continue;
                                }
                        }

                        // Split the string
                        *val = 0;
                        val++;

                        // Remove beginning cruft of name
                        if (*ptr == '(')
                                ptr++;
                        n.name = strdup(ptr);
                        n.val = strdup(val);
                        // Remove trailing punctuation
                        len = strlen(n.val);
                        if (len && n.val[len-1] == ':') {
                                n.val[len-1] = 0;
                                len--;
                        }
                        if (len && n.val[len-1] == ',') {
                                n.val[len-1] = 0;
                                len--;
                        }
                        if (len && n.val[len-1] == '\'') {
                                n.val[len-1] = 0;
                                len--;
                        }
                        if (len && n.val[len-1] == ')') {
                                if (strcmp(n.val, "(none)") &&
                                        strcmp(n.val, "(null)")) {
                                        n.val[len-1] = 0;
                                        len--;
                                }
                        }
                        nvlist_append(&r->nv, &n);

Steve Grubb napsal(a):

These rules discard valuable information in currently defined audit records - so either the record format or the parsing rules need to change. That's unavoidable.

Not really. If, to handle the transition, we need to parse the old records to the new semantic format (name-value pairs or something else), that does indeed add a whole lot of code. But we need that code even if we stay with the old format simply to process the information.

Once we have the code to translate old records to a new, well-defined semantic format, modifying the code that generates the records to use a well-defined textual representation of the new semantic format requires only trivial (even if extensive) code modifications, and it is transparent to libauparse users. Applications that don't use libauparse can be best adapted by porting them to use libauparse; then we can even port the record-generating code incrementally over time, because the applications won't be able to tell the difference.
Mirek

Examples? There is going to be 2 types of problems you find, real bugs that should be fixed. And ancillary text that helps people reading the logs from vi. The ancillary text can probably be trimmed to help save disk space. Bugs I'm all for fixing.

Let's see what you find first as problems and see what we can do. We may be able to make a few adjustments in various places that helps everyone. For example, I don't mind dropping a lot of punctuation like '():,' this will help conserve disk space.

-Steve

Now this I really like.

I'd much rather have the parsing library know that key= is always followed by a string and thus there would be 2 ways to send key=(null)

key="(null)"
key=286e756c6c29

Either a real string with " to start and stop or list of hex bytes which would be easily converted back to a string. The given propsal would have

leave quotes key="(((((((("
you way key="%28%28%28%28%28%28%28%28"
my alt way key=2828282828282828

so, my choices are

leave quotes  x1.0
your way      x2.6
my alt way    x1.6

But I admit, the parser would have to know that key is a string to change it back.

-Eric

Adding two bytes to each string field (beginning and ending delimiters) is too big a burden? Instead we have to rely on difficult to manage tables to tell the parser it's a string? The 2 byte penalty might have had weight in 1970, but not in 2007.

If we're really arguing over how many bytes a record consumes then we should switch to a binary protocol instead of text. Oh and by the way, in a binary protocol you would likely prefix string data with a length field, so you're going to end up using a couple of bytes anyway.

John Dennis <[email protected]>

No it's not. The auparse approach is based on tables, tables which have been shown to be incorrect and tied to kernel versions and the patch set used to build that kernel version. Like it or not, audit data is and will be divorced from kernel versions. In fact audit data will derive from a mix of different kernel versions if the audit data is aggregated, which is the plan. In the current scheme there is no realistic way to process audit data from thousands of nodes all running different kernels in an enterprise wide auditing system.

Any scheme which requires knowing the kernel version and patch set to correctly read the data is broken. Attempts to cast this issue as pandering to userspace weenies is off the mark by a mile.

John Dennis <[email protected]>

But even if the messages were parsable into a tree regardless of kernel version, for semantic understanding of the messages you'll still have to know which kernel generated them unless the semantics is set in stone for all possible messages.

Tomas Mraz
No matter how far down the wrong road you've gone, turn back.
                                              Turkish proverb

Parsing and semantic interpretation are two distinct operations, both have merit.

A library should be able to parse the data stream without producing errors.

This is not an abstract issue for me, I had to fix bugs which threw serious exceptions because it could not determine if a value was a string or binary data (e.g. hexadecimal encoded string). When it made the wrong decision and tried to decode what it thought was hexadecimal encoding it produced a horribly malformed string which violated UTF-8, which then sent every library which was passed the string into the weeds. Which by the way would include any library which might try to interpret the semantic meaning of the string.

FWIW, I do not consider the ability to recognize a string as semantic interpretation. Semantic interpretation would be interpreting the string. Recognizing a string in a byte orientated data stream is parsing.

John Dennis <[email protected]>

Can you show some example of which kernels had one thing and which kernels another? Can you also show patch (I assume you mean a RHEL5 patch) sets on top of kernels which changed things so that 2 kernels would have conflicting output? Hopefully this will help me understand and address your concerns.

-Eric

Some of his examples was the directory auditing code that Al wrote. In the user space side of it, I hadn't gotten the interpretation of the fields working because it took a long time for it to come back downstream in Fedora and by the time we had it I forgot to go check it. It wasn't like there was a field that changed meaning, just a normal integration issue when 2 subsystems have different delivery schedules. :)

-Steve

These are the encoded audit strings in kernel 2.6.24 (Fedora):

a[0-9]+
comm
cwd
data
dir
exe
key
msg
name
new
old
path

These are the encoded audit strings in kernel 2.6.18 (RHEL-5):

comm
cwd
exe
key
name
new
ocomm
old
path

This is what audit-1.6.5 checks for:

acct
cmd
comm
cwd
exe
file
name
path
watch

This list does not include strings which are not encoded, only those known to be subject to hexadecimal decoding!

Absolutely none of the above fields should require special table driven logic in order to read their value as a string.

Just to make life interesting I believe some of these field names appear in more than one record type.

This is just two OS's. In real deployments a site might be running a much larger set of OS's all emitting audit data and probably not capturing the OS version along with the audit data. Every time we have a new release we compound the problem. Every time a new piece of audit data is added the problem is compounded. Any patch has the potential to modify the audit contents.

John Dennis <[email protected]>

Reorganized:

Field 24 18 auparse
a[0-9]+ X
acct X
cmd X
comm X X X
cwd X X X
data X
dir X X
exe X X X
file X
key X X X
msg X
name X X X
new X X
old X X
path X X X
watch X

Of these, A0-4 is probably from the execve patch. I have no idea what the status of this patch is and if its upstream. I've not seen the records so this would be something very new.

acct & cmd is a userspace thing

data, I need to go hunt this down. I don't like the name so it will probably need to change in the kernel

msg, name collision it has to change wherever it is in the kernel

new, old, these sound like bugs. They need to get fixed in the kernel

file & watch are probably legacy from RHEL4 I think. It can probably be deleted.

-Steve

you formatting didn't come through, but we both agree auparse doesn't get them all (for better or worse) and 2.6.24 only adds new stuff, it doesn't remove?

execve could always turn A0-infinity into hex. And currently upstream and RHEL5.2 kernels both can do so....

maybe audit tty stuff? I don't see it in auditsc.c or audit.c (just a guess)

not sure what this means... I only see msg used in one place, but it is a great example of non-standardization which should be cleaned up....

                        if (msg_type != AUDIT_USER_TTY)
                                audit_log_format(ab, " msg='%.1024s'",
                                                 (char *)data);
                        else {  
                                int size;

                                audit_log_format(ab, " msg=");
                                size = nlmsg_len(nlh);
                                audit_log_n_untrustedstring(ab, size,
                                                            data);
                        }

The top case will surround these with '' which the bottom will surround with ""

new and old are from audit config changes. Am i really expected to trust what came down the netlink socket from userspace was sane? nope nope nope. I don't trust userspace. Even though 10 times out of 10 these are going to be normal strings they need to remain calls to untrusted string just in case.

dont see them in my kernels

yeah I found it:

drivers/char/tty_audit.c::tty_audit_buf_push()

it needs to stay an untrusted string, but its name, well yeah, that doesn't tell us a whole lot, does it?

-Eric

Right. That should be a little more descriptive. This is new code and still undergoing testing, so its not like this is something that was forgot a long time ago. I usually don't update the interpreters until I see actual records on my system.

-Steve

It's the untrusted string code which is the primary culprit. If we fixed audit so that *all* strings written by audit are formatted by exactly one string formatting routine and that routine is sane then 99.99% of the problems would go away. That was the thrust of my original email and what I was most concerned about. Perhaps unfortunately the email included some optional suggestions which is what some folks latched onto obscuring the real issue.

John Dennis <[email protected]>

I'm including a link to the original mail for reference.

https://www.redhat.com/archives/linux-audit/2008-January/msg00082.html

The primary problem is the inconsistent use of quotes around string values with the result it's impossible to know if a string value should have hexadecimal decoding performed on it. Currently the only way to solve the problem is to have a table of every audit message and field and to have such a table for every kernel version.

Of secondary concern is the fact hexadecimal encoded strings are not human readable whereas more conventional string escapes preserve readbility (to varying degrees).

John Dennis <[email protected]>

Right.

That's with a capital A0? Lower case a0 is numeric data in the syscalls and might be a name collision.

Could be. Whatever it is, its new and need integration. The name data sounds too generic though. Its got to be something more meaningful than data.

huh? That is new and doesn't seem right.

Yes, that has got to change. msg=has only one use and its the way it used to be.

We probably need a '-' added or a couple words rearranged. I need to hunt those down to see which way they should go.

That's not the issue to me, new and old are simply non-descriptive. New and old what?

That's what I thought.

Thanks,
-Steve

hmm, no execve uses lowercase a0-inifinity. I'll look for capitalization. But it doesn't appear to be the new execve at first glance.

/me is pleased he didn't start really looking at audit until after audit tty since that appears to be 2 of the problems left on the list :)

AUDIT_MAKE_EQUIV, new names are probably a good idea....

This would be an interesting problem. If you move those to capital A0-infinity it avoids a definite name collision with syscall fields. I think under the hood the library is case sensitive, but the search fields are case insensitive. So, I think it would get the interpretation right. I don't think anything is looking at these records right now, so I think we can make the change without much worry.

Any other opinions?

-Steve

Patch applied. Thanks!

-Steve