[Freeipa-devel] [PATCH] 0014 Add final debug message in installers

Tue Apr 17 13:30:54 UTC 2012

On 04/17/2012 12:12 AM, Rob Crittenden wrote:
> John Dennis wrote:
>> On 04/16/2012 04:15 PM, Rob Crittenden wrote:
>>> John Dennis wrote:
>>>> On 04/16/2012 01:31 PM, Rob Crittenden wrote:
>>>>> John Dennis wrote:
>>>>>> On 04/13/2012 06:25 AM, Petr Viktorin wrote:
>>>>>>>> When the utility sets logging to console, the extra log message
>>>>>>>> gets
>>>>>>>> printed out there. I agree this isn't optimal.
>>>>>>>> Attached patch removes the console log handler before logging the
>>>>>>>> result.
>>>>>>>>
>>>>>>>
>>>>>>> I read through log_manager, and found that I can do this more
>>>>>>> cleanly
>>>>>>> with remove_handler.
>>>>>>>
>>>>>>> John, is this a good use of the API?
>>>>>>
>>>>>> The problem you're trying to correct is that under some
>>>>>> circumstances a
>>>>>> log message is emitted twice to the console, right?
>>>>>>
>>>>>> Removing the console handler fees like the wrong solution, it's a
>>>>>> pretty
>>>>>> big hammer, you have to know when to remove it and once removed any
>>>>>> expectation that messages will appear on the console will be untrue.
>>>>>>
>>>>>> Can you give me a brief explanation as to why you're getting
>>>>>> duplicate
>>>>>> messages on the console. I wonder if there isn't a better way to
>>>>>> handle
>>>>>> the problem which isn't so invasive and potentially hidden.

The patch adds a final log message that says if the command ultimately 
succeeded or not (https://fedorahosted.org/freeipa/ticket/2071).
Some of the commands print an error message to the console 
independently. When they've configured logging to console, the added 
message appears as well.

The right thing to do is to modify the utility just log once. But this 
patch treats the utilities as black boxes, otherwise it's too invasive.

>>>>>> Or is the issue you don't want a console handler at all? If that's
>>>>>> the
>>>>>> case then maybe we should provide a configuration that does not
>>>>>> create
>>>>>> one, that way it will be explicit and obvious there is no console
>>>>>> handler.

This would mean changing how the commands set up logging. I plan to do 
that, but it's too invasive to do now.

>>>>>> FWIW, the current configuration of logging is historical dating
>>>>>> back to
>>>>>> the beginning of the project. When I added the log manager the intent
>>>>>> was to fix deficiencies in logging, not to modify the existing
>>>>>> behavior.
>>>>>> I wasn't clear to me the existing configuration was ideal. If you're
>>>>>> hitting problems because of the existing configuration perhaps we
>>>>>> should
>>>>>> look at the historical configuration and ask if it needs to be
>>>>>> modified.
>>>>>
>>>>> This patch is standardizing logging the final disposition of a
>>>>> number of
>>>>> commands. Currently is must be inferred.
>>>>>
>>>>> The problem is that some commands have had this disposition added but
>>>>> open no log files so some error messages are being displayed twice and
>>>>> in log format.
>>>>>
>>>>> I think the easiest solution would simply be to scale this back to
>>>>> only
>>>>> those commands that open a log file at all.
>>>>
>>>> You say "command" but command is a loaded word :-) I presume you mean
>>>> command line utility and not an IPA Command object. The reason I'm
>>>> drawing this distinction is because the environment Commands execute in
>>>> are not supposed to change once api.bootstrap() has completed.
>>>>
>>>> Who or what is aggregating the final disposition of a number of
>>>> commands? The reason I ask is because the log_mgr object is global and
>>>> deleting a handler from a global resource to satisfy a local need may
>>>> have unintentional global side effects. How is the aggregation
>>>> accomplished?

This is a wrapper around scripts. The final log message is the last 
thing done before exiting Python.

>>> This patch is in the context of the command-line utilities like
>>> ipa-server-install, ipa-client-install, etc. and not the ipa tool. Some
>>> of them initialize the api, some do not.

Also there's ipa-ldap-updater, which sometimes opens a log file and 
sometimes not.

>> This is exactly the type of problem I'm concerned about, a conflict over
>> who owns the logging configuration.
>>
>> These multiple potential "owners" of a global configuration is what lead
>> me to introduce the "configure_state" attribute of the log manager, to
>> disambiguate who is in control and who initialized the configuration. In
>> fact bootstrap() in plugable.py explicitly examines the configure_state
>> attribute of the log_manager and if it's been previously configured (for
>> example because the api was loaded by a command line utility that has
>> configured it's own logging) it then defers to the logging configuration
>> established by the environment it's being run in (in other words if a
>> command line utility calls standard_logging_setup() before loading the
>> api it wins and the logging configuration belongs to the utility, not
>> the api).
>>
>> All of this is to say that isolated code that reaches into a global
>> configuration and takes an axe to it and chops out a significant part of
>> the configuration that someone else may have established without them
>> knowing about it feels wrong.
>>
>> I suspect there is some deeper problem afoot and unilaterally chopping
>> out the console handler is not addressing the fundamental problem and
>> likely introduces a new one. But I really need to look at the specific
>> instances of the problem, maybe if I dig through the history of this
>> patch review more carefully I'll discover it, but if someone wants to
>> chime in an point me at the exact issue that would be great :-)
>
> Like I've said, this is a non-issue in this case. Those utilities that
> do not open a log simply don't need to call this log_on_exit function.
>
> Any remaining logging issues should be logged as a ticket.
>
> I think you're overstating the logging problem in general though.
> Basically we just want a way to override the default log that the API
> chooses. So the API bootstrap() call defers to the user if logging has
> already been configured. It is the responsibility of the developer to
> know when to do what but since there is less than a half dozen
> exceptions I don't think this is worth a significant time investment.
>
> At some point we may rewrite all of these utilities to use the API
> itself at which time this problem will simply go away.
>
> rob

Attaching a patch that only adds the final log for commands that do 
standard_logging_setup. It still includes the removing of the console 
handler, though.

-- 
Petr³
-------------- next part --------------
A non-text attachment was scrubbed...
Name: freeipa-pviktori-0014-10-Add-final-debug-message-in-installers.patch
Type: text/x-patch
Size: 23765 bytes
Desc: not available
URL: <http://listman.redhat.com/archives/freeipa-devel/attachments/20120417/0e824774/attachment.bin>