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

[Jan Cholasta]

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.

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 :-)
>


-- 
Jan Cholasta