Standardize logging

[TomAugspurger]

1. Provide a contextmanager for "timed" log statements.
2. Consistent naming
3. Consistency in what is logged

[jakirkham]

Would it be worth considering capturing and forwarding logging information from things like scikit-learn wrapped algorithms? Just thinking of our recent experience watching this information getting dropped. 😉

[mrocklin]

I'm inclined to use the logging module and let downstream users decide what logging streams they want to capture.

…

On Tue, Jun 5, 2018 at 10:19 PM, jakirkham ***@***.***> wrote: Would it be worth considering capturing and forwarding logging information from things like scikit-learn wrapped algorithms? Just thinking of our recent experience watching this information getting dropped. 😉 — You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub <#193 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AASszG6qqLtftsV57yvO8LUmNc5lA6yUks5t5zwegaJpZM4UY9jn> .

[TomAugspurger]

The issue in that case was that scikit-learn just prints to stdout. There's a stalled PR moving things to logging: scikit-learn/scikit-learn#6930. In the meantime, users can do something like https://www.electricmonk.nl/log/2011/08/14/redirect-stdout-and-stderr-to-a-logger-in-python/ to redirect the print statements, but we shouldn't do that as a library. On Tue, Jun 5, 2018 at 10:29 PM, Matthew Rocklin <notifications@github.com> wrote:

…

I'm inclined to use the logging module and let downstream users decide what logging streams they want to capture. On Tue, Jun 5, 2018 at 10:19 PM, jakirkham ***@***.***> wrote: > Would it be worth considering capturing and forwarding logging information > from things like scikit-learn wrapped algorithms? Just thinking of our > recent experience watching this information getting dropped. 😉 > > — > You are receiving this because you are subscribed to this thread. > Reply to this email directly, view it on GitHub > <#193 (comment)>, or mute > the thread > <https://github.com/notifications/unsubscribe-auth/ AASszG6qqLtftsV57yvO8LUmNc5lA6yUks5t5zwegaJpZM4UY9jn> > . > — You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub <#193 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/ABQHIt9NU280J4P8F-KlVprY7IeSKlNzks5t50yhgaJpZM4UY9jn> .

[jakirkham]

Interesting, thanks for the reference. Gave that PR a nudge.

On a different point, it's probably worthwhile for Distributed to start capturing printed info on workers and start logging it. Currently that info is just lost, which seems worse. Opened issue ( dask/distributed#2033 ) on this point.

[TomAugspurger]

As an example of the kind of changes I had in mind, see https://github.com/dask/dask-ml/pull/228/files#diff-86d9909fd7ff2d87b6a68dba02a52da5R217

and their use in https://github.com/dask/dask-ml/pull/228/files#diff-b551222a46da15072e0a51ca86cdae11R166

For timing things, I think a context manager like

import contextlib
from timeit import default_timer

@contextlib.contextmanager
def _timed(name, *args, **kwargs):
    start = default_timer()
    logger.info("Starting %s", name)
    yield
    stop = defult_timer()
    logger.info("Finished %s in %s, name, stop - start)  # nicer formatting for time.

would be useful

[gglanzani]

@TomAugspurger Were you thinking about something like this?