Bug 240762

Summary:	[auditdistd] cannot receive trail files from servers running auditd on FreeBSD12
Product:	Base System	Reporter:	Johan S <johan.sollvander>
Component:	bin	Assignee:	freebsd-bugs (Nobody) <bugs>
Status:	New ---
Severity:	Affects Some People	CC:	dvl, emaste, gbe
Priority:	---
Version:	12.0-RELEASE
Hardware:	Any
OS:	Any
See Also:	https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=250342

Description Johan S 2019-09-23 08:50:59 UTC

After upgrading a server running auditd to FreeBSD12 (from FreeBSD 11.2) we noticed that trail files now have a dot (.) appended to the filename, which our auditdistd receiver thinks is an invalid trail name.

Logs from our receiver:
(receiver) Sender wants to open file "20190920080142.20190920080929.", which has invalid name.
(receiver) Request failed: (seq=3) OPEN(20190920080142.20190920080929.): invalid trail file name.
(receiver) Sender requested append without first opening file.
(receiver) Request failed: (seq=4) APPEND(2646): wrong operations order.
(receiver) Sender requested closing file without first opening it.
(receiver) Request failed: (seq=5) CLOSE(20190920080142.20190920080929.): wrong operations order.
(receiver) Unable to receive request header: Socket is not connected.

Logs from our sender:
(sender) Termination signal received, exiting.
(sender) Receiver returned error (invalid trail file name), disconnecting.
(sender) Disconnected from 172.22.239.16.


I've tested upgrading the receiver to FreeBSD 12 as well but that doesn't seem to fix the issue.

I also found this thread reporting the same issue:
https://forums.freebsd.org/threads/auditd-on-freebsd-12-0-release-problem.69686/

Comment 1 Gordon Bergling freebsd_committer

2020-01-07 13:56:30 UTC

I can reproduce this on a recent 12.1-STABLE.

root        audit   56 Nov 18 18:23 20191118172312.20191118172312.
root        audit   56 Jan  7 14:44 20200107134414.not_terminated.

My initial direction was the C macro getTSstr, which is defined in contrib/openbsm/bsm/auditd_lib.h:46. But after I saw that the dot is also appended after "not_terminated" that problem must be located somewhere else.

Comment 2 Gordon Bergling freebsd_committer

2020-01-07 14:00:55 UTC

I can reproduce this on a recent 12.1-STABLE.

root        audit   56 Nov 18 18:23 20191118172312.20191118172312.
root        audit   56 Jan  7 14:44 20200107134414.not_terminated.

My initial direction was the C macro getTSstr, which is defined in contrib/openbsm/bsm/auditd_lib.h:46. But after I saw that the dot is also appended after "not_terminated" that problem must be located somewhere else.

Comment 3 Gordon Bergling freebsd_committer

2020-01-08 18:05:01 UTC

On a recent -CURRENT (r356261) the problem doesn't exist. But the strange thing is that I didn't see any relevant changes within the last 18 months that could have caused this. At least not under contrib/openbsm/.

Comment 4 Dan Langille freebsd_committer

2020-01-15 16:13:06 UTC

Perhaps this PR is the cause of

Dec 18 21:19:29 dvl auditdistd[86033]: Sandbox process exited ungracefully (pid=10469, exitcode=75).


re:

https://forums.freebsd.org/threads/auditdistd-sandbox-process-exited-ungracefully.73419/

Comment 5 Gordon Bergling freebsd_committer

2020-01-22 08:39:02 UTC

This is fixed by r356962. I am not exactly sure why, because that change should only affects some parts within the hostname-part of audit-trail-files, but

Jan 22 09:17 20200116071331.20200122081723.
Jan 22 09:18 20200122081759.not_terminated
Jan 22 09:17 current -> /var/audit/20200122081759.not_terminated

Comment 6 Dan Langille freebsd_committer

2020-01-30 17:19:59 UTC

(In reply to Gordon Bergling from comment #5)

Thank you.  I will deploy a 12.2-STABLE host and test this in our environment...

Oh wait, does this affect the auditd client or the auditd server?  I think it's the server, correct?

Comment 7 Dan Langille freebsd_committer

2020-04-13 13:15:19 UTC

I updated a host to FreeBSD 12 -stable on 2020-04-08:

$ uname -a
FreeBSD fmd-12stbl-01tst.vrt.sourcefire.com 12.1-STABLE FreeBSD 12.1-STABLE r359329 GENERIC  amd64

We're still see this on that host:

Apr  9 17:10:11 example auditdistd[80387]: Sandbox process exited ungracefully (pid=20356, exitcode=75).
Apr  9 18:00:10 example auditdistd[80387]: Sandbox process exited ungracefully (pid=93827, exitcode=75).
Apr 11 04:15:28 example auditdistd[79863]: Sandbox process killed (pid=88054, signal=13).

Comment 8 Ed Maste freebsd_committer

2020-05-19 17:15:12 UTC

(In reply to Gordon Bergling from comment #5)
To confirm that I understand correctly, you believe the original issue is fixed in -CURRENT and in stable/12, so that 12.2 will be fixed?

And dvl's issue is perhaps something else?

Comment 9 Dan Langille freebsd_committer

2020-05-19 17:24:05 UTC

The reason I am testing stable is to ensure this issue does not persist for us on 12.2

Comment 10 Ed Maste freebsd_committer

2020-05-19 17:26:33 UTC

(In reply to Dan Langille from comment #9)
Indeed - I'm trying to figure out if the original issue here is fixed for 12.2 and there's something else that needs investigation.

Comment 11 Dan Langille freebsd_committer

2020-10-12 15:05:55 UTC

What's up?

Comment 12 Ed Maste freebsd_committer

2020-10-12 21:12:38 UTC

In comment #5 gbe reports that the issue is fixed by r356962, a MFC of r342873. This change is in 12.2.

So the problem in comment #7 is presumably something else, and needs its own PR with full details.

Comment 13 Dan Langille freebsd_committer

2020-10-14 14:15:02 UTC

(In reply to Ed Maste from comment #12)
I have created https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=250342