Re: svn commit: r1297676 - /subversion/trunk/subversion/tests/cmdline/svntest/main.py

2012-03-06 Thread Hyrum K Wright
On Tue, Mar 6, 2012 at 3:02 PM, Greg Stein  wrote:
> On Tue, Mar 6, 2012 at 15:58, Hyrum K Wright  
> wrote:
>> On Tue, Mar 6, 2012 at 2:42 PM, Greg Stein  wrote:
>>...
>>> You may as well use the default logger. That way, every module can
>>> just: import logging ; logging.info('whatever: %s %s', foo, bar)
>>
>> I thought about that, but figured using the custom logger would give
>> us more flexibility.  Separate test suites could use separate loggers
>> when run in parallel, for instance, and they wouldn't interleave each.
>>  By establishing the habit of using a named logger, rather than the
>> default one, it means we can just change the logger reference, instead
>> of go back and rewrite everything to use a custom logger later.
>>
>> This first pass is to just get as much as possible using the logging
>> framework, and then we can go back and worry about such things.  I
>> just don't want us to prematurely optimize. :)
>
> Euh... that's not premature optimization. That is keeping things
> *simple* unless and until circumstances dictate that we need more
> complexity. You haven't demonstrated that at all yet.
>
> And as long as you keep doing a per-module logger, then each and every
> one of those loggers will need to be configured. Add a stream handler.
> Add a formatter. Adjust their loglevel based on the verbose flag.
> etc-f'in-etc.
>
> By sticking to the root logger, the main.py can get it configured
> properly and all modules can use it without concern. As it stands,
> per-module loggers absolutely increases complexity with zero benefit.

I understand your eloquently-put point.  I've no objection to using the root
logger, but I'd like to refer to it through a named variable, rather
than using the global variable implicit in the "logging.debug()"
construction.

>
>>...
>>> You may want to change most of the calls to logging.FOO rather than
>>> logger.FOO for consistency with other modules that will use the
>>> logging framework.
>>>
>>> I would also recommend creating a Formatter and attaching it to that
>>> StreamHandler:
>>>
>>>    formatter = logging.Formatter('%(asctime)s [%(levelname)s] %(message)s',
>>>                                  '%Y-%m-%d %H:%M:%S')
>>>    handler.setFormatter(formatter)
>>>
>>> that will give us a timestamp for each line.
>>
>> Future Work.  A valuable suggestion, but right now I'm focused on
>> getting the logging infrastructure in place, so we can make this kind
>> of changes on a system-wide basis.
>
> It can only be done (easily) on a system-wide basis if you use the
> root logger :-)

Or have a logger constructor/fetcher method. :)

-Hyrum



-- 

uberSVN: Apache Subversion Made Easy
http://www.uberSVN.com/


Re: svn commit: r1297676 - /subversion/trunk/subversion/tests/cmdline/svntest/main.py

2012-03-06 Thread Greg Stein
On Tue, Mar 6, 2012 at 15:58, Hyrum K Wright  wrote:
> On Tue, Mar 6, 2012 at 2:42 PM, Greg Stein  wrote:
>...
>> You may as well use the default logger. That way, every module can
>> just: import logging ; logging.info('whatever: %s %s', foo, bar)
>
> I thought about that, but figured using the custom logger would give
> us more flexibility.  Separate test suites could use separate loggers
> when run in parallel, for instance, and they wouldn't interleave each.
>  By establishing the habit of using a named logger, rather than the
> default one, it means we can just change the logger reference, instead
> of go back and rewrite everything to use a custom logger later.
>
> This first pass is to just get as much as possible using the logging
> framework, and then we can go back and worry about such things.  I
> just don't want us to prematurely optimize. :)

Euh... that's not premature optimization. That is keeping things
*simple* unless and until circumstances dictate that we need more
complexity. You haven't demonstrated that at all yet.

And as long as you keep doing a per-module logger, then each and every
one of those loggers will need to be configured. Add a stream handler.
Add a formatter. Adjust their loglevel based on the verbose flag.
etc-f'in-etc.

By sticking to the root logger, the main.py can get it configured
properly and all modules can use it without concern. As it stands,
per-module loggers absolutely increases complexity with zero benefit.

>...
>> You may want to change most of the calls to logging.FOO rather than
>> logger.FOO for consistency with other modules that will use the
>> logging framework.
>>
>> I would also recommend creating a Formatter and attaching it to that
>> StreamHandler:
>>
>>    formatter = logging.Formatter('%(asctime)s [%(levelname)s] %(message)s',
>>                                  '%Y-%m-%d %H:%M:%S')
>>    handler.setFormatter(formatter)
>>
>> that will give us a timestamp for each line.
>
> Future Work.  A valuable suggestion, but right now I'm focused on
> getting the logging infrastructure in place, so we can make this kind
> of changes on a system-wide basis.

It can only be done (easily) on a system-wide basis if you use the
root logger :-)

Cheers,
-g


Re: svn commit: r1297676 - /subversion/trunk/subversion/tests/cmdline/svntest/main.py

2012-03-06 Thread Hyrum K Wright
On Tue, Mar 6, 2012 at 2:42 PM, Greg Stein  wrote:
> On Tue, Mar 6, 2012 at 15:18,   wrote:
>>...
>> +++ subversion/trunk/subversion/tests/cmdline/svntest/main.py Tue Mar  6 
>> 20:18:16 2012
>>...
>> @@ -78,6 +79,10 @@ SVN_VER_MINOR = 8
>>
>>  default_num_threads = 5
>>
>> +# Set up logging
>> +logger = logging.getLogger(__name__)
>
> You may as well use the default logger. That way, every module can
> just: import logging ; logging.info('whatever: %s %s', foo, bar)

I thought about that, but figured using the custom logger would give
us more flexibility.  Separate test suites could use separate loggers
when run in parallel, for instance, and they wouldn't interleave each.
 By establishing the habit of using a named logger, rather than the
default one, it means we can just change the logger reference, instead
of go back and rewrite everything to use a custom logger later.

This first pass is to just get as much as possible using the logging
framework, and then we can go back and worry about such things.  I
just don't want us to prematurely optimize. :)

>>...
>> @@ -1473,6 +1469,9 @@ def create_default_options():
>>
>>  def _create_parser():
>>   """Return a parser for our test suite."""
>> +  def set_log_debug(option, opt, value, parser):
>> +    logger.setLevel(logging.DEBUG)
>
> axe this, see below:
>
>> +
>>   # set up the parser
>>   _default_http_library = 'serf'
>>   usage = 'usage: %prog [options] [ ...]'
>> @@ -1481,7 +1480,8 @@ def _create_parser():
>>                     help='Print test doc strings instead of running them')
>>   parser.add_option('--milestone-filter', action='store', 
>> dest='milestone_filter',
>>                     help='Limit --list to those with target milestone 
>> specified')
>> -  parser.add_option('-v', '--verbose', action='store_true', dest='verbose',
>> +  parser.add_option('-v', '--verbose', action='callback',
>> +                    callback=set_log_debug,
>>                     help='Print binary command-lines (not with --quiet)')
>
> callback=logger.setLevel, callback_args=(logging.DEBUG,)

Mentioned this on IRC, but:
TypeError: setLevel() takes exactly 2 arguments (6 given)

Essentially, the optparser provides a number of extra arguments that
setLevel() doesn't expect (or use).

>>...
>
> You may want to change most of the calls to logging.FOO rather than
> logger.FOO for consistency with other modules that will use the
> logging framework.
>
> I would also recommend creating a Formatter and attaching it to that
> StreamHandler:
>
>    formatter = logging.Formatter('%(asctime)s [%(levelname)s] %(message)s',
>                                  '%Y-%m-%d %H:%M:%S')
>    handler.setFormatter(formatter)
>
> that will give us a timestamp for each line.

Future Work.  A valuable suggestion, but right now I'm focused on
getting the logging infrastructure in place, so we can make this kind
of changes on a system-wide basis.

-Hyrum


-- 

uberSVN: Apache Subversion Made Easy
http://www.uberSVN.com/


Re: svn commit: r1297676 - /subversion/trunk/subversion/tests/cmdline/svntest/main.py

2012-03-06 Thread Greg Stein
On Tue, Mar 6, 2012 at 15:18,   wrote:
>...
> +++ subversion/trunk/subversion/tests/cmdline/svntest/main.py Tue Mar  6 
> 20:18:16 2012
>...
> @@ -78,6 +79,10 @@ SVN_VER_MINOR = 8
>
>  default_num_threads = 5
>
> +# Set up logging
> +logger = logging.getLogger(__name__)

You may as well use the default logger. That way, every module can
just: import logging ; logging.info('whatever: %s %s', foo, bar)

>...
> @@ -1473,6 +1469,9 @@ def create_default_options():
>
>  def _create_parser():
>   """Return a parser for our test suite."""
> +  def set_log_debug(option, opt, value, parser):
> +    logger.setLevel(logging.DEBUG)

axe this, see below:

> +
>   # set up the parser
>   _default_http_library = 'serf'
>   usage = 'usage: %prog [options] [ ...]'
> @@ -1481,7 +1480,8 @@ def _create_parser():
>                     help='Print test doc strings instead of running them')
>   parser.add_option('--milestone-filter', action='store', 
> dest='milestone_filter',
>                     help='Limit --list to those with target milestone 
> specified')
> -  parser.add_option('-v', '--verbose', action='store_true', dest='verbose',
> +  parser.add_option('-v', '--verbose', action='callback',
> +                    callback=set_log_debug,
>                     help='Print binary command-lines (not with --quiet)')

callback=logger.setLevel, callback_args=(logging.DEBUG,)

>...

You may want to change most of the calls to logging.FOO rather than
logger.FOO for consistency with other modules that will use the
logging framework.

I would also recommend creating a Formatter and attaching it to that
StreamHandler:

formatter = logging.Formatter('%(asctime)s [%(levelname)s] %(message)s',
  '%Y-%m-%d %H:%M:%S')
handler.setFormatter(formatter)

that will give us a timestamp for each line.

Cheers,
-g