syslogging in policykit

[Matthew Miller]

I put this in Fedora's bugzilla, but clearly working upstream is the better
thing to do. <https://bugzilla.redhat.com/show_bug.cgi?id=541040>, or read
below. I really appreciate your feedback and comments; PolicyKit is a nice
architecture, and logging will help it be a powerful and useful tool in
enterprise deployments. I particularly would like to hear where I'm off-base
or otherwise thinking about things wrong, because I'm about to start actual
work on implementing this.

So:

One of the important features of sudo is its ability to log elevated-access
actions to syslog. Userhelper similarly logs actions taken as other (usually
root) users.

PolicyKit serves a similar function (in a nice, modern way), but doesn't
seem to log anything.

Additionally, since PolicyKit's LocalAuthority is already monitoring for new
pkla files, it's in a good place to log changes to policy -- something we
don't have with sudo or userhelper/PAM.

So, there's two aspects.

First, PolicyKit's LocalAuthority monitors its configuration directories for
changes. When a file is added, removed, or changed, a auth.warning message
should be logged. Details of the change should be logged as well, but at a
lower level (auth.info, probably).

Second, when PolicyKit grants authorization for a specific action, it should
log that event. The basic action should be authpriv.notice (in keeping with
sudo and userhelper). This would look something like:

  polkit-1[1111]: allowing action "org.libvirt.unix.manage" for process 222
      with identity "unix-user:mattdm"

or 

  polkit-1[1111]: DENYING action "org.libvirt.unix.manage" for process 222
      with identity "unix-user:mattdm"

(Or similar -- details, details.)

A more verbose log level (authpriv.info, maybe) should log the
authentication type requested (auth_admin, auth_self).

And a yet-more-verbose level (authpriv.debug) should log Authority-specific
configuration/diagnostic information, like the pkla or policy file from
which the authorization came.

There are four particular strengths I see to logging this information at the
PolicyKit level rather than just the client application level.

 1) Existing applications don't need to be changed, and new applications
    don't need to be counted on to do the right thing. Appropriate logging
    just starts happening. In general, having logging of security-elevation
    events in the lowest-common-denominator piece of code keeps important
    information from getting lost due to insufficient logging in a calling
    app¹.

 2) Log levels and debugging are easier to admin because there's a central
    configuration (and PolicyKit already has config files). If I need to
    turn on more authentication debugging, I don't have to hunt down   
    app-specific options.

 3) Log messages are automatically consistent between programs, making
    analysis and monitoring much easier.

 4) PolicyKit is in a position to log more about the decisions it makes
    than is (or should be) exposed to the client application. This can be
    particularly useful for debugging but may also be useful for auditing.
    If a user was allowed access for a certain reason, and that reason
    turns out to be something they shouldn't have access to but do,
    we can know to investigate.

Client applications should also be encouraged (perhaps even in the PolicyKit
documentation) to use syslog to log their elevated-privilege actions -- just
as PolicyKit knows details about the authorization that the application
can't, the application knows details about what it's doing with the
authorization that PolicyKit just doesn't care about.

Since this is a security/auditing issue, it's never wrong to error on the
side of more logging.



----
1. This bit paraphrased from a comment from Seth Vidal.  

-- 
Matthew Miller <mattdm at seas.harvard.edu>
Senior Systems Architect -- Instructional & Research Computing Services
Computing & Information Technology 
Harvard School of Engineering & Applied Sciences