[systemd-devel] [PATCH] Log failing start conditions

[Harald Hoyer]

On 07/05/2013 07:46 AM, Zbigniew Jędrzejewski-Szmek wrote:
> On Wed, Jul 03, 2013 at 06:35:53AM +0200, Zbigniew Jędrzejewski-Szmek wrote:
>> On Wed, Jun 26, 2013 at 03:06:38PM +0200, harald at redhat.com wrote:
>>> From: Harald Hoyer <harald at redhat.com>
>>>
>>> $ systemctl status dracut-initqueue.service
>>> dracut-initqueue.service - dracut initqueue hook
>>>    Loaded: loaded (/usr/lib/systemd/system/dracut-initqueue.service;
>>> static)
>>>    Active: inactive (dead)
>>>           start condition failed at Wed 2013-06-26 13:01:05 UTC; 22s ago
>>>      Docs: man:dracut-initqueue.service(8)
>>>
>>> Jun 26 13:01:05 lenovo systemd[1]: Starting of dracut-initqueue.service
>>> skipped because the following start conditions were not met:
>>>    ConditionKernelCommandLine:|rd.break=initqueue
>>>    ConditionPathExistsGlob: |/lib/dracut/hooks/initqueue/timeout/*.sh
>>>    ConditionPathExistsGlob: |/lib/dracut/hooks/initqueue/online/*.sh
>>>    ConditionPathExistsGlob: |/lib/dracut/hooks/initqueue/finished/*.sh
>>>    ConditionPathExistsGlob: |/lib/dracut/hooks/initqueue/settled/*.sh
>>>    ConditionPathExistsGlob: |/lib/dracut/hooks/initqueue/*.sh
>>>    ConditionPathExists: |/lib/dracut/need-initqueue
>> Hi Harald,
>>
>> your patch seems to is better than mine, I somehow missed
>> the question of muliple conditions. I think you should go ahead
>> and appy this.
> Hm, I missed one big problem with your patch: at levels >= INFO, the
> messages about failing conditions are logged to the console. This is
> definitly not OK. But with level == DEBUG, the messages are not
> logged by default at all.
> 
> Maybe we don't need to take a bit more relaxed approach, and when
> the triggering conditions are not met, simply log the fact in one
> line: "Starting of service.service skipped because none of the trigger conditions were met." This might be good enough for the user, and remove the need for
> patching the logging routines. (Changes done in patch 1/2 also have
> the disadvantage that they slow down a very common path, for a
> relatively minor goal.)

Well, the problem is, that in retrospect debugging, you cannot get the
information from the journal, which of the conditions were not met.

We could make the MESSAGE a one liner. But I really would like to add the
CONDITION_RESULTS. This of course requires the log_struct_internal() patch.

The slow down are two memchr(). I think that's worth the multiple lines capability.

log_struct_unit(LOG_NOTICE,
                u->id,
                MESSAGE_ID(SD_MESSAGE_UNIT_CONDITIONS),
                "MESSAGE=Starting of %s skipped because none of the start
conditions were met.", u->id,
                "CONDITION_RESULTS=%s", buf,
                NULL);


maybe rename CONDITION_RESULTS to CONDITIONS_FAILED