Bug 68212

Agreed.

Not following? You want that D-Bus logs what the client is that requested the bus activation? That sounds like a bug to file against dbus daemon, no? Reassigning...

I want to have a reference of what service is starting other one, in this example, what service is starting consolekit

(In reply to comment #3)
> I want to have a reference of what service is starting other one, in this
> example, what service is starting consolekit

I think it's not useful as you expected to know who is the client to request service from a well-known service, say consolekit.

Given that anyone may send request to consolekit, for example, you can do that manually with 'dbus-send'.

And the error log is quite precise, No such file or directory. That means there is no such systemd unit in corresponding systemd session, system wide or user session wide.

Related with error, I know that I don't have the unit file, but would like to know what app is still needing it (as maybe it's wrongly configured or...)

Created attachment 126943 [details] [review]
bus: Add sender name to systemd bus activation log messages

This clarifies
   Activating via systemd: service name='A' unit='B'
to
   Activating via systemd: service name='A' unit='B' sender='blah'

Comment on attachment 126943 [details] [review]
bus: Add sender name to systemd bus activation log messages

Review of attachment 126943 [details] [review]:
-----------------------------------------------------------------

> Add sender name to systemd bus activation log messages

If this was accurate, I'd complain that we should be covering the two non-systemd activation paths (fork-and-exec, and fork-and-exec the dbus-daemon-launch-helper). But in fact you already did, so please change the commit message subject instead :-)

It's OK to only mention the systemd code path in the commit message body, since the others are analogous. I'd prefer a slightly more realistic example though - perhaps service name com.example.Example resulting in systemd unit example.service, activated by :1.23 uid 1000 pid 123 comm "whatever-activat" (to demonstrate the truncation to 16 characters that is implicit in us using the /proc/$pid/comm interface).

::: bus/activation.c
@@ +1969,3 @@
>                                 service_name,
> +                               entry->systemd_service,
> +                               dbus_message_get_sender (activation_message));

"requested by" might be clearer than "sender".

I think we might be better off extracting information from the @connection rather than the @activation_message: then we could use

("... requested by '%s' (%s)",
 ...,
 bus_connection_get_name (connection),
 bus_connection_get_loginfo (connection))

If whatever-activated-it activates com.example.Example, this would give you

    Activating via systemd: service name='com.example.Example' unit='example.service' requested by ':1.23' (uid=1000 pid=123 comm="whatever-activat")

which is a better start for debugging the situation.

comm is not a security feature (any process can change its /proc/$pid/comm by issuing the PR_SET_NAME prctl in its main thread, AIUI) but it's useful for debugging non-malicious situations.

The reason I don't think the unique name is necessarily enough is that I'm thinking about this case:

    Activating via systemd: service name='com.example.Example' unit='example.service' requested by ':1.23' (uid=1000 pid=123 comm="dbus-send")

in which :1.23 will have fallen off the bus by the time you get round to looking for more information - but at least with comm quoted, you know you need to be looking for some shell script or something calling dbus-send.

If you want to add _dbus_connection_get_linux_security_label() to the loginfo (where it succeeds, i.e. where LSMs are used), as a related patch, I wouldn't say no.

@@ +1990,4 @@
>            if (!retval)
>              {
>                bus_context_log (activation->context,
> +                               DBUS_SYSTEM_LOG_INFO, "Failed to activate via systemd: service name='%s' unit='%s' sender='%s'",

I don't think we necessarily need to mention the sender here, because we already blamed them once, when activation started (and you don't seem to have mentioned them for failures on the non-systemd code path).

Created attachment 127023 [details] [review]
bus: Add sender name to bus activation log messages

Updated commit message, added loginfo, and dropped one of the changed messages.

Created attachment 127024 [details] [review]
bus: Add LSM label to connection loginfo string

If it is set (i.e. if an LSM is in use) this will make it appear in various places in log output.

With SELinux, for example, this appends something like:
   label="system_u:object_r:unlabeled_t:s0"

This commit partially rearranges the code which sets the loginfo string, so that it consistently puts a space between fields, and not one at the end.

Comment on attachment 127023 [details] [review]
bus: Add sender name to bus activation log messages

Review of attachment 127023 [details] [review]:
-----------------------------------------------------------------

Looks good

Comment on attachment 127024 [details] [review]
bus: Add LSM label to connection loginfo string

Review of attachment 127024 [details] [review]:
-----------------------------------------------------------------

Thanks, this looks ideal.

Whoops, I forgot to close this. The patches were pushed a while ago as 203a1e50940025a3e4ea675604a7db29d1fd71ae and 12a893b2ebcfe3af6d2a10c269565c105ed8f9d0, and were in the 1.11.6 release.