Added basic logging framework to handle args.quiet properly #1200

bocajnotnef · 2015-07-27T18:40:53Z

(Please see #1024 for discussions of logging frameworks.)

Four levels: info, warn, err, debug

info -> stderr, quiet
err -> stderr, loud
debug -> stdout, quiet
warn -> stdout, loud

Open to suggestions on what does what.

Ref #790 and #1024

bocajnotnef · 2015-07-27T20:15:32Z

retest this, please

ctb · 2015-07-27T20:38:01Z

Please make the functions module level, and named error, info, warning, and debug (well, ok, the names can vary).

So, you would do:

from khmer.logs import error, info, warning, debug

...

error('File does not exist; exiting.)

In particular, no objects need to be instantiated, passed around, or otherwise harmed in this utopian vision of a stupidly lightweight logging interface.

bocajnotnef · 2015-07-27T20:39:17Z

So, how would I dynamically set verbosity? Would I just have a variable in the module that's "quiet" and I set it when we fire up a script?

ctb · 2015-07-27T20:40:03Z

On Mon, Jul 27, 2015 at 01:39:17PM -0700, Jake Fenton wrote:

So, how would I dynamically set verbosity? Would I just have a variable in the module that's "quiet" and I set it when we fire up a script?

You have my permission to add a configure_logging function.

ctb · 2015-07-27T20:44:39Z

On Mon, Jul 27, 2015 at 11:40:53AM -0700, Jake Fenton wrote:

Four levels: info, warn, err, debug
Info is for status output, written to stderr, is surpressable
Warn is for warning output, written to stderr, is surpressable

Err is for critical failures, will not be surpressed when quiet is set; Err
output is written to stderr

Debug output is written to stdout and is never surpressed
Seems kind of silly to have two things that're the same (info and warn)--Open to suggestions on what does what.

Ref #790 and #1024

'warn' gets printed out with '-q', I'd say.

bocajnotnef · 2015-07-27T20:58:23Z

I ended up changing what goes where; this is current:

quiet == shushed on -q
loud == ignores -q

info -> stderr, quiet
err -> stderr, loud
debug -> stdout, quiet
warn -> stdout, loud

bocajnotnef · 2015-07-27T21:35:01Z

Is it mergeable?
Did it pass the tests?
If it introduces new functionality in scripts/ is it tested?
Check for code coverage with make clean diff-cover
Is it well formatted? Look at make pep8, make diff_pylint_report,
make cppcheck, and make doc output. Use make format and manual
fixing as needed.
Did it change the command-line interface? Only additions are allowed
without a major version increment. Changing file formats also requires a
major version number increment.
Is it documented in the ChangeLog?
http://en.wikipedia.org/wiki/Changelog#Format
Was a spellchecker run on the source code and documentation after
changes were made?
Is the Copyright year up to date?

make_diff_pylint is spewing warnings but it's all about global'd things or wrong things.

bocajnotnef · 2015-07-27T21:53:56Z

@ctb Shall I proceed with adding more scripts in, or get this merged?

ctb · 2015-07-27T22:02:00Z

get this reviewed :)

bocajnotnef · 2015-07-27T22:02:27Z

And on that note,

@ctb @luizirber @mr-c CR, please?

ctb · 2015-07-27T22:19:54Z

ChangeLog

+2015-07-27  Jacob Fenton  <bocajnotnef@gmail.com>
+
+   * scrips/normalize-by-median.py,khmer/khmer_logger.py: added logging
+   framework, prorotyped in normalize-by-median


kdm9 · 2015-07-28T00:40:00Z

@bocajnotnef I'm sure you're cognisant of this, but please make sure that whenever stdout is used to output data, logging to stdout is automagically suppressed or redirected to stderr.

bocajnotnef · 2015-07-28T00:53:57Z

@ctb pointed out that it was a bad idea to have any logging related stuff
written to stdout. I was under the impression that there was existing info
being written to stdout that we'd want verbosity control over.

On Mon, Jul 27, 2015, 17:40 Kevin Murray notifications@github.com wrote:

@bocajnotnef https://github.com/bocajnotnef I'm sure you're cognisant
of this, but please make sure that whenever stdout is used to output data,
logging to stdout is automagically suppressed or redirected to stderr.

—
Reply to this email directly or view it on GitHub
#1200 (comment).

camillescott · 2015-07-28T02:13:56Z

Hmm. Why not just use Python's built in logging module? It's very simple
and takes care of things like global configuration.

https://docs.python.org/2/howto/logging.html#logging-basic-tutorial
On Jul 27, 2015 8:53 PM, "Jake Fenton" notifications@github.com wrote:

@ctb pointed out that it was a bad idea to have any logging related stuff
written to stdout. I was under the impression that there was existing info
being written to stdout that we'd want verbosity control over.

On Mon, Jul 27, 2015, 17:40 Kevin Murray notifications@github.com wrote:

@bocajnotnef https://github.com/bocajnotnef I'm sure you're cognisant
of this, but please make sure that whenever stdout is used to output
data,
logging to stdout is automagically suppressed or redirected to stderr.

—
Reply to this email directly or view it on GitHub
#1200 (comment).

—
Reply to this email directly or view it on GitHub
#1200 (comment).

bocajnotnef · 2015-07-28T02:23:16Z

Vetoed by @ctb--the quote used the phrase "festering pile of", as I recall.

On Mon, Jul 27, 2015 at 10:14 PM Camille Scott notifications@github.com
wrote:

Hmm. Why not just use Python's built in logging module? It's very simple
and takes care of things like global configuration.

https://docs.python.org/2/howto/logging.html#logging-basic-tutorial
On Jul 27, 2015 8:53 PM, "Jake Fenton" notifications@github.com wrote:

@ctb pointed out that it was a bad idea to have any logging related stuff
written to stdout. I was under the impression that there was existing
info
being written to stdout that we'd want verbosity control over.

On Mon, Jul 27, 2015, 17:40 Kevin Murray notifications@github.com
wrote:

@bocajnotnef https://github.com/bocajnotnef I'm sure you're
cognisant
of this, but please make sure that whenever stdout is used to output
data,
logging to stdout is automagically suppressed or redirected to stderr.

—
Reply to this email directly or view it on GitHub
#1200 (comment).

—
Reply to this email directly or view it on GitHub
#1200 (comment).

—
Reply to this email directly or view it on GitHub
#1200 (comment).

ctb · 2015-07-28T13:39:16Z

@camillescott et al., please feel free to discuss logging frameworks here: #1024 . This PR is intended to fix #790 without necessarily adding a big chunk of code or a new library dependency.

ctb · 2015-07-28T13:41:51Z

@bocajnotnef looks ok to me on a first pass. Main thought - do you want to make use of the implicit formatting of the log functions (e.g. line 88 in normalize-by-median), or keep the current mix?

bocajnotnef · 2015-07-29T22:29:14Z

retest this please

bocajnotnef · 2015-07-29T23:39:47Z

Contrary to what conversation view says I did move that import.

@ctb @mr-c Merge, please?

ctb · 2015-07-30T14:16:14Z

Does normalize-by-median.py -q data/100k-filtered.fa (or any data file) work the way you expect?

ctb · 2015-07-30T14:16:53Z

scripts/normalize-by-median.py

+                    log_info('... kept {kept} of {tot} or {perc_kept:.1%} so'
+                             'far', kept=kept, tot=total,
+                             perc_kept=perc_kept)
+                    log_info('... in file ' + ifilename)


can you switch this over to {} too?

(and elsewhere)

(lots of elsewhere)

ctb · 2015-07-30T14:19:03Z

Note: per conversation with @mr-c, I am happy to try to merge this for 2.0, but we will explore adding -q to more scripts/adding logging framework stuff/etc later, after we have some experience with +/- of this particular approach.

ctb · 2015-07-30T14:20:16Z

@bocajnotnef note: #1179 (comment) - I fixed this in 24c5397, please use that language in future.

bocajnotnef · 2015-07-30T17:56:23Z

@ctb WIlco re: language

+'s removed, implicit format in use; Merge?

Conflicts: ChangeLog

ctb · 2015-07-31T14:36:27Z

I repeat: #1200 (comment)

bocajnotnef · 2015-07-31T21:24:49Z

@ctb Sorry, missed that--fixed now. Merge?

Conflicts: ChangeLog

ctb · 2015-08-01T15:17:17Z

Threw in some fixes; @mr-c @luizirber could you review, please? The logging functionality is fine, be good to get a double-check on the tst utils change.

Also, @bocajnotnef, no more adding global khmer arguments if they're not being implemented throughout the codebase - this is strike 2 (see #1179 for strike 1). I removed args.quiet because it was only used in normalize-by-median.py!

bocajnotnef · 2015-08-01T16:00:24Z

My understanding was that we were prototyping the use of --unique-kmers pre
#1179 and that the plan was to expand it to all scripts that interacted
with hash tables.

I had a similar understanding here--while Normalize-by-median is the
prototype we would later expand the functionality to all other scripts.

Additionally, the --quiet arg was in place in the hashbits args prior to my
meddling--I didn't add it.

That said, I should have pulled it down to just normalize's parser in this
PR since normalize is the only one with the framework to handle it, but it
appeared to silence some output, just not all the things.

On Sat, Aug 1, 2015, 08:17 C. Titus Brown notifications@github.com wrote:

Threw in some fixes; @mr-c https://github.com/mr-c @luizirber
https://github.com/luizirber could you review, please? The logging
functionality is fine, be good to get a double-check on the tst utils
change.

Also, @bocajnotnef https://github.com/bocajnotnef, no more adding
global khmer arguments if they're not being implemented throughout the
codebase - this is strike 2 (see #1179
#1179 for strike 1). I removed
args.quiet because it was only used in normalize-by-median.py!

—
Reply to this email directly or view it on GitHub
#1200 (comment).

ctb · 2015-08-01T16:04:20Z

On Sat, Aug 01, 2015 at 09:00:24AM -0700, Jake Fenton wrote:

My understanding was that we were prototyping the use of --unique-kmers pre
#1179 and that the plan was to expand it to all scripts that interacted
with hash tables.

I had a similar understanding here--while Normalize-by-median is the
prototype we would later expand the functionality to all other scripts.

Yep, that's the plan, but (for both this and the --unique-kmers problem)
each PR should be internally consistent. Globally adding arguments that do
nothing to most scripts is bad...

Additionally, the --quiet arg was in place in the hashbits args prior to my
meddling--I didn't add it.

Huh, ok, apologies :)

That said, I should have pulled it down to just normalize's parser in this
PR since normalize is the only one with the framework to handle it, but it
appeared to silence some output, just not all the things.

Yep.

Doesn't seem like I broke any tests so shrug.

bocajnotnef · 2015-08-01T16:06:17Z

Yeah. Herein I'll make sure to contain things a bit more. Makes sense not
to have args strewn across the code that we don't react to.

On Sat, Aug 1, 2015, 09:04 C. Titus Brown notifications@github.com wrote:

On Sat, Aug 01, 2015 at 09:00:24AM -0700, Jake Fenton wrote:

My understanding was that we were prototyping the use of --unique-kmers
pre
#1179 and that the plan was to expand it to all scripts that interacted
with hash tables.

I had a similar understanding here--while Normalize-by-median is the
prototype we would later expand the functionality to all other scripts.

Yep, that's the plan, but (for both this and the --unique-kmers problem)
each PR should be internally consistent. Globally adding arguments that do
nothing to most scripts is bad...

Additionally, the --quiet arg was in place in the hashbits args prior to
my
meddling--I didn't add it.

Huh, ok, apologies :)

That said, I should have pulled it down to just normalize's parser in
this
PR since normalize is the only one with the framework to handle it, but
it
appeared to silence some output, just not all the things.

Yep.

Doesn't seem like I broke any tests so shrug.

—
Reply to this email directly or view it on GitHub
#1200 (comment).

Conflicts: ChangeLog scripts/normalize-by-median.py

ctb · 2015-08-02T16:30:25Z

Hah, I reverted the changes I made that needed review, so I think I'll merge (#1200 (comment)).

Added basic logging framework to handle args.quiet properly

bocajnotnef · 2015-08-02T16:41:37Z

Thanks!

mr-c · 2015-08-15T01:38:39Z

khmer/khmer_logger.py

+    print(message, file=sys.stderr)
+
+
+def log_debug(message, **kwagrs):


kwargs

Please write a test that exercises this method and check for test coverage. Also, please review the pylint report for this file, your global usage is off.

Please write a test that exercises this method and check for test coverage. Also, please review the pylint report for this file, your `global` usage is off.

I think file an issue, at this point.

bocajnotnef added 2 commits July 27, 2015 14:38

added basic logging framework, prototyped in normalize-by-median

a7796bd

pep257, moar funcs

aa573ef

bocajnotnef added this to the 2.0 milestone Jul 27, 2015

made it moar lightweight

9348b44

bocajnotnef added 3 commits July 27, 2015 17:08

pointed all the things at stderr

dcb19ed

Changelog, eliminated remianing prints to stderr

00a6973

added tests

15a39a0

ctb reviewed Jul 27, 2015
View reviewed changes

cleanup

f103d29

missed extra format string

ab4c02b

ctb reviewed Jul 30, 2015
View reviewed changes

remove optimization language

24c5397

standardize on using implicit format (Sorry, zen) and removing +'s

acee523

Merge branch 'master' of github.com:dib-lab/khmer into feature/quiet

3591a3e

Conflicts: ChangeLog

modified info func to do quieting

50a66e5

ctb added 2 commits August 1, 2015 08:13

removed global args.quiet; fixed some test utils stuff

2d5fa0b

Merge branch 'master' of github.com:dib-lab/khmer into feature/quiet

23bdc24

Conflicts: ChangeLog

minor pep8 fix

c6b9bc8

ctb added 2 commits August 2, 2015 09:22

Merge branch 'master' of github.com:dib-lab/khmer into feature/quiet

055488e

Conflicts: ChangeLog scripts/normalize-by-median.py

whoops, some fixes

341a0c6

ctb added a commit that referenced this pull request Aug 2, 2015

Merge pull request #1200 from dib-lab/feature/quiet

92a2c8e

Added basic logging framework to handle args.quiet properly

ctb merged commit 92a2c8e into master Aug 2, 2015

ctb deleted the feature/quiet branch August 2, 2015 16:30

mr-c reviewed Aug 15, 2015
View reviewed changes

This was referenced Jan 3, 2017

Added progress report to console when running sourmash compute with --singleton sourmash-bio/sourmash#84

Open

Add/use logging and reporting functions sourmash-bio/sourmash#89

Closed

		print(message, file=sys.stderr)


		def log_debug(message, **kwagrs):

Added basic logging framework to handle args.quiet properly #1200

Added basic logging framework to handle args.quiet properly #1200

Conversation

bocajnotnef commented Jul 27, 2015

bocajnotnef commented Jul 27, 2015

ctb commented Jul 27, 2015

bocajnotnef commented Jul 27, 2015

ctb commented Jul 27, 2015

ctb commented Jul 27, 2015

bocajnotnef commented Jul 27, 2015

bocajnotnef commented Jul 27, 2015

bocajnotnef commented Jul 27, 2015

ctb commented Jul 27, 2015 via email

bocajnotnef commented Jul 27, 2015

ctb Jul 27, 2015

Choose a reason for hiding this comment

kdm9 commented Jul 28, 2015

bocajnotnef commented Jul 28, 2015

camillescott commented Jul 28, 2015

bocajnotnef commented Jul 28, 2015

ctb commented Jul 28, 2015

ctb commented Jul 28, 2015

bocajnotnef commented Jul 29, 2015

bocajnotnef commented Jul 29, 2015

ctb commented Jul 30, 2015

ctb Jul 30, 2015

Choose a reason for hiding this comment

ctb Jul 30, 2015

Choose a reason for hiding this comment

ctb Jul 30, 2015

Choose a reason for hiding this comment

ctb commented Jul 30, 2015

ctb commented Jul 30, 2015

bocajnotnef commented Jul 30, 2015

ctb commented Jul 31, 2015

bocajnotnef commented Jul 31, 2015

ctb commented Aug 1, 2015

bocajnotnef commented Aug 1, 2015

ctb commented Aug 1, 2015

bocajnotnef commented Aug 1, 2015

ctb commented Aug 2, 2015

bocajnotnef commented Aug 2, 2015

mr-c Aug 15, 2015

Choose a reason for hiding this comment

ctb Aug 17, 2015 via email

Choose a reason for hiding this comment