[Freeipa-devel] [PATCH 25] Improve error logging for Dogtag subsystem installation

[Petr Spacek]

On 2.12.2015 13:23, Jan Cholasta wrote:
> On 2.12.2015 12:54, Petr Spacek wrote:
>> On 2.12.2015 12:51, Christian Heimes wrote:
>>> On 2015-12-02 08:37, Petr Spacek wrote:
>>>> On 1.12.2015 18:42, Christian Heimes wrote:
>>>>>  From 33be1f56a64e53d261a1058c4606a7e48c0aac52 Mon Sep 17 00:00:00 2001
>>>>> From: Christian Heimes <cheimes at redhat.com>
>>>>> Date: Tue, 1 Dec 2015 15:49:53 +0100
>>>>> Subject: [PATCH 25] Improve error logging for Dogtag subsystem installation
>>>>>
>>>>> In the case of a failed installation or uninstallation of a Dogtag
>>>>> subsystem, the error output of pkispawn / pkidestroyed are now shown to
>>>>> the user. It makes it more obvious what went wrong and makes it easier
>>>>> to debug a problem.
>>>>>
>>>>> The error handler also attempts to get the full name of the installation
>>>>> / uninstallation log file from stdout. pkispawn and pkidestroy print the
>>>>> absolute name as 'Log file: /path/to/file.log'. The user no longer has
>>>>> to guess the right log file.
>>>>>
>>>>> Example:
>>>>>    [1/8]: configuring KRA instance
>>>>> Failed to configure KRA instance: Command ''/usr/sbin/pkispawn' '-s'
>>>>> 'KRA' '-f' '/tmp/tmp1UpbwF'' returned non-zero exit status 1
>>>>> pkispawn    : ERROR    ....... PKI subsystem 'KRA' for instance
>>>>> 'pki-tomcat' already exists!
>>>>> See the installation logs and the following files/directories for more
>>>>> information:
>>>>>    /var/log/pki/pki-tomcat
>>>>>    /var/log/pki/pki-kra-spawn.20151201151735.log
>>>>>    [error] RuntimeError: KRA configuration failed.
>>>>>
>>>>> The patch also changes a couple of modules that were using
>>>>> the CalledProcessError exception object from subprocess instead of
>>>>> ipautil.
>>>>
>>>> I'm wondering if ipautil.run() can log stdout and stderr on log level ERROR
>>>> when return code is non-zero (and log on level DEBUG as usual when return
>>>> code
>>>> is zero).
>>>>
>>>> IMHO it would be nicer, universal, and does not require any changes in places
>>>> calling ipautil.run().
>>>
>>> I think it's a bit confusing to print out stdout and stderr, because
>>> both streams are captured separately. The output is missing its
>>> chronological order. subprocess can capture stdout and stderr in the
>>> same stream, but then we can't distinguish between output and error
>>> output...
>>
>> I do not think it is a problem if these two are clearly marked as such:
>> standard output: %s (if non-empty)
>> stanrard error output: %s (if non-empty)
> 
> We do not want to log with level ERROR by default when rc != 0, because some
> commands generate a *lot* of output.

I do not agree, but whatever. Somebody needs to review the original
Christian's patch.

Petr^2 Spacek

> IMO Christian's approach is OK, because it lets the caller decide how to log
> (or not) stderr on failure.
> 
>>
>>> In case of Dogtag stderr contains the relevant error message. In order
>>> to understand the events, that lead to the particular error, a user has
>>> to read the log file anyway -- unless you run pkispawn with '-vv' for
>>> extra verbosity. But then you get pages over pages of debug output on
>>> *stderr*. It's not helpful either.
>>
>> Sure, I was not talking about that :-)