Bug 35358

Summary: should syslog when we drop messages on the floor due to quotas
Product: dbus Reporter: Simon McVittie <smcv>
Component: coreAssignee: Simon McVittie <smcv>
Status: RESOLVED FIXED QA Contact: John (J5) Palmieri <johnp>
Severity: normal    
Priority: medium CC: hp, walters
Version: 1.4.xKeywords: patch
Hardware: Other   
OS: All   
URL: http://git.collabora.co.uk/?p=user/smcv/dbus-smcv.git;a=shortlog;h=refs/heads/log-dropped-messages
Whiteboard: nearly r+
i915 platform: i915 features:
Bug Depends on:    
Bug Blocks: 33606, 36074    
Attachments: bus_context_check_security_policy: factor out complain_about_message
bus_context_check_security_policy: syslog SELinux rejections if enabled
bus_context_check_security_policy: syslog if we hit the outgoing quota
_dbus_init_system_log: remove FIXME on Windows
process_config_first_time_only: initialize syslog as intended.
bus_context_log: divert messages to stderr if we're not using syslog
complain_about_message: don't return early if syslog is disabled
bus_context_check_security_policy: don't syslog SELinux denials, just share the code

Description Simon McVittie 2011-03-16 08:18:38 UTC
As noted on Bug #33606, hitting the outgoing quota can cause messages to be dropped on the floor. If they're signals, no error is sent back to the sender.

There's no way for an application to detect this, and even if there was, not all D-Bus APIs are sufficiently state-recoverable that they could do anything about it, so we should at least syslog it so users/sysadmins/developers can see why everything's breaking.

Related issues found while fixing this, which I've also fixed:

- SELinux rejections are logged with less information than policy rejections

- _dbus_init_system_log() is never actually called, although the SELinux code
  does reimplement it (!)

- a spurious FIXME on Windows

- whether we're syslogging or not, messages that are syslogged should
  probably also go to stderr

Not yet fixed:

- perhaps we should be recommending to distributions that they
  run the session dbus-daemon with options/environment variables that will
  cause its complaints to be logged to stderr (i.e. ~/.xsession-errors when
  using gdm/xdm/... on Debian, or startx's stderr if using that) or to
  syslog, too; running dbus-launch with DBUS_DEBUG_OUTPUT=1 might be
  sufficient?
Comment 1 Simon McVittie 2011-03-16 08:20:18 UTC
Created attachment 44504 [details] [review]
bus_context_check_security_policy: factor out complain_about_message
Comment 2 Simon McVittie 2011-03-16 08:20:49 UTC
Created attachment 44505 [details] [review]
bus_context_check_security_policy: syslog SELinux rejections if enabled

This also reduces duplication a bit.
Comment 3 Simon McVittie 2011-03-16 08:21:10 UTC
Created attachment 44506 [details] [review]
bus_context_check_security_policy: syslog if we hit the outgoing quota

In practice, nothing copes with missing broadcast signals, so the least
we can do is make the failure mode visible.
Comment 4 Simon McVittie 2011-03-16 08:21:36 UTC
Created attachment 44507 [details] [review]
_dbus_init_system_log: remove FIXME on Windows

We don't need any initialization here, so there's nothing to fix.
Comment 5 Simon McVittie 2011-03-16 08:22:02 UTC
Created attachment 44508 [details] [review]
process_config_first_time_only: initialize syslog as intended.

On Linux, we previously called openlog() (with different options!) while
initializing SELinux; leave SELinux messages as LOG_USER|LOG_INFO in case
anyone was relying on that, but let the rest of our log messages come
out as LOG_DAEMON.

Also enable LOG_PERROR (copy syslog messages to stderr) unconditionally;
we can make this an autoconf check if anyone's pet Unix doesn't have
LOG_PERROR.
Comment 6 Simon McVittie 2011-03-16 08:22:21 UTC
Created attachment 44509 [details] [review]
bus_context_log: divert messages to stderr if we're not using syslog
Comment 7 Simon McVittie 2011-03-16 08:24:08 UTC
The patches are relative to my branches from Bug #34570 and Bug #34393, but should hopefully apply cleanly to either 1.4 or master. (Any thoughts on whether this should be fixed in 1.4 or just master?)
Comment 8 Colin Walters 2011-03-26 11:42:04 UTC
(In reply to comment #1)
> Created an attachment (id=44504) [details]
> bus_context_check_security_policy: factor out complain_about_message

"log_rejection_and_set_error" maybe?  But not a big deal.  Looks good otherwise.
Comment 9 Colin Walters 2011-03-26 11:53:06 UTC
(In reply to comment #2)
> Created an attachment (id=44505) [details]
> bus_context_check_security_policy: syslog SELinux rejections if enabled
> 
> This also reduces duplication a bit.

I don't think we should syslog SELinux rejections here; isn't that handled selinux.c?  avc_has_perm will syslog.
Comment 10 Colin Walters 2011-03-26 11:57:26 UTC
Comment on attachment 44506 [details] [review]
bus_context_check_security_policy: syslog if we hit the outgoing quota

Looks fine.
Comment 11 Colin Walters 2011-03-26 11:57:52 UTC
Comment on attachment 44507 [details] [review]
_dbus_init_system_log: remove FIXME on Windows

I can't comment on windows, but if you checked, sounds good!
Comment 12 Colin Walters 2011-03-26 12:02:47 UTC
Comment on attachment 44508 [details] [review]
process_config_first_time_only: initialize syslog as intended.


>index fe04063..e94d8a8 100644
>--- a/bus/selinux.c
>+++ b/bus/selinux.c
>@@ -164,7 +164,7 @@ log_callback (const char *fmt, ...)
>   }
> #endif /* HAVE_LIBAUDIT */
>   
>-  vsyslog (LOG_INFO, fmt, ap);
>+  vsyslog (LOG_USER | LOG_INFO, fmt, ap);
>   va_end(ap);
> }

This is fine, but do note that practically speaking, I don't know of anyone who ships --enable-selinux --disable-libaudit, and if we have perms to write to the audit system, the "return;" prevented us from ever hitting this code path.

Otherwise looks good.
Comment 13 Colin Walters 2011-03-26 12:06:09 UTC
Comment on attachment 44509 [details] [review]
bus_context_log: divert messages to stderr if we're not using syslog

Looks good.
Comment 14 Colin Walters 2011-03-26 12:06:34 UTC
(In reply to comment #7)
> The patches are relative to my branches from Bug #34570 and Bug #34393, but
> should hopefully apply cleanly to either 1.4 or master. (Any thoughts on
> whether this should be fixed in 1.4 or just master?)

This all seem OK for 1.4 to me.
Comment 15 Simon McVittie 2011-03-28 05:54:02 UTC
(In reply to comment #9)
> (In reply to comment #2)
> > Created an attachment (id=44505) [details] [details]
> > bus_context_check_security_policy: syslog SELinux rejections if enabled
> > 
> > This also reduces duplication a bit.
> 
> I don't think we should syslog SELinux rejections here; isn't that handled
> selinux.c?  avc_has_perm will syslog.

Only if it doesn't have permission to write the audit log, if I'm reading the code correctly? But I can change this to set @error without syslogging if you'd prefer: the change is just to change "(addressed_recipient == proposed_recipient)" to "FALSE" in the call to complain_about_message.

(I do think it's valuable to put all of the complaints about messages through one code path, so that if we decide to put an extra bit of information in, we'll get it consistently, for all complaints.)

(In reply to comment #11)
> (From update of attachment 44507 [details] [review])
> I can't comment on windows, but if you checked, sounds good!

I don't do Windows either, but MSDN doesn't mention any special initialization for OutputDebugString, and presumably someone would have noticed if the current code crashed or something...

(In reply to comment #12)
> This is fine, but do note that practically speaking, I don't know of
> anyone who ships --enable-selinux --disable-libaudit

Debian (and probably our derivatives like Ubuntu, although I haven't inspected their build logs to confirm this).
Comment 16 Simon McVittie 2011-03-28 06:12:12 UTC
Created attachment 44933 [details] [review]
complain_about_message: don't return early if syslog is disabled

This defeats output of messages to stderr when not syslogging.

---

This could be squashed into Attachment #44509 [details] if you're into that sort of thing.
Comment 17 Simon McVittie 2011-03-28 06:13:19 UTC
Created attachment 44934 [details] [review]
bus_context_check_security_policy: don't syslog SELinux denials, just share the code

This partially reverts the effect of commit 8930ff209. Colin pointed out
that selinux.c logs denials itself.

---

Commit 8930ff209 is Attachment #44505 [details]. They could be squashed if you insist. Colin, it's up to you whether you want to insist on this one or not.
Comment 18 Colin Walters 2011-04-12 11:20:10 UTC
(In reply to comment #15)
> (In reply to comment #9)
> > (In reply to comment #2)
> > > Created an attachment (id=44505) [details] [details] [details]
> > > bus_context_check_security_policy: syslog SELinux rejections if enabled
> > > 
> > > This also reduces duplication a bit.
> > 
> > I don't think we should syslog SELinux rejections here; isn't that handled
> > selinux.c?  avc_has_perm will syslog.
> 
> Only if it doesn't have permission to write the audit log, if I'm reading the
> code correctly? But I can change this to set @error without syslogging if you'd

Yeah, and we know we'll have permissions to audit.  But regardless we don't want *both* an audit record and a syslog, so libselinux is doing the right thing.

> (I do think it's valuable to put all of the complaints about messages through
> one code path, so that if we decide to put an extra bit of information in,
> we'll get it consistently, for all complaints.)

Would be nice, but SELinux is special here in that the check is happening in an external library, so we should just comment to that effect and not duplicate it.
 
> Debian (and probably our derivatives like Ubuntu, although I haven't inspected
> their build logs to confirm this).

Oh...weird (why not libaudit?).  But okay.
Comment 19 Simon McVittie 2011-05-25 07:10:38 UTC
(In reply to comment #16)
> Attachment #44933 [details]
> complain_about_message: don't return early if syslog is disabled
> 
> This defeats output of messages to stderr when not syslogging.

I think this is the only unreviewed patch here - I spotted this breakage when testing other changes.

(In reply to comment #17)
> Attachment #44934 [details]
> bus_context_check_security_policy: don't syslog SELinux denials, just share the
> code
> 
> This partially reverts the effect of commit 8930ff209. Colin pointed out
> that selinux.c logs denials itself.

I think this addresses Comment #9 and Comment #18. Colin, is this OK?
Comment 20 Colin Walters 2011-05-25 09:29:06 UTC
Both patches look good, thanks!
Comment 21 Simon McVittie 2011-05-25 10:19:33 UTC
Fixed in git for 1.4.10/1.5.2, thanks

Use of freedesktop.org services, including Bugzilla, is subject to our Code of Conduct. How we collect and use information is described in our Privacy Policy.