Path: csiph.com!v102.xanadu-bbs.net!xanadu-bbs.net!feeder.erje.net!eu.feeder.erje.net!newsfeed.freenet.ag!news2.euro.net!newsgate.cistron.nl!newsgate.news.xs4all.nl!post.news.xs4all.nl!not-for-mail
Return-Path: <matt@tplus1.com>
X-Original-To: python-list@python.org
Delivered-To: python-list@mail.python.org
X-Spam-Status: OK 0.000
X-Spam-Evidence: '*H*': 1.00; '*S*': 0.00; 'args': 0.04; 'configure': 0.04; 'elif': 0.04; 'handler': 0.04; 'output': 0.04; '"""': 0.05; 'debug': 0.05; 'things.': 0.05; '__name__': 0.07; 'root,': 0.07; 'python': 0.09; '###': 0.09; 'dict': 0.09; 'from:addr:matt': 0.09; 'handlers': 0.09; 'instances.': 0.09; 'logger': 0.09; 'def': 0.10; 'subject:not': 0.11; "'__main__':": 0.16; "'class':": 0.16; "'dict':": 0.16; 'argparse': 0.16; 'jumps': 0.16; 'meanwhile,': 0.16; 'skip:{ 30': 0.16; 'skip:{ 40': 0.16; 'subject:created': 0.16; '8bit%:3': 0.17; 'skip:{ 20': 0.17; 'import': 0.21; 'fine,': 0.22; 'skip:% 10': 0.22; 'seems': 0.23; 'script': 0.24; 'skip:[ 10': 0.26; 'setting': 0.26; 'wrote': 0.26; 'skip:" 20': 0.26; 'logging': 0.27; 'have,': 0.27; 'message-id:@mail.gmail.com': 0.27; 'run': 0.28; '8bit%:5': 0.29; 'skip:& 10': 0.29; "skip:' 10": 0.30; 'skip:& 30': 0.30; 'figure': 0.30; 'stuff': 0.30; 'code': 0.31; '(and': 0.32; 'problem.': 0.32; "skip:' 20": 0.32; 'print': 0.32; 'like:': 0.33; 'to:addr:python-list': 0.33; 'skip:& 20': 0.33; 'received:google.com': 0.34; 'skip:l 30': 0.35; 'created': 0.36; 'does': 0.37; 'skip:l 20': 0.38; 'nothing': 0.38; 'to:addr:python.org': 0.39; 'skip:" 10': 0.40; 'end': 0.40; 'skip:a 30': 0.60; 'different': 0.63; 'show': 0.63; 'matthew': 0.65; 'difference!': 0.84; 'different.': 0.84; 'subject:Any': 0.84; 'subject:before': 0.84; 'wilson': 0.91
X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=google.com; s=20120113; h=mime-version:x-received:date:message-id:subject:from:to :content-type:x-gm-message-state; bh=csINX3MSFvaQRpeLcXPvHgMQdwvxLO2z2jnTjYtjbWM=; b=HQXl9nV36e1DY7BK4yPoEP1scKnMQ4Q7S8vQXGCAN2aSGVfrCRsxKp62wGO8l67d+z +r4ZPTBHzj/lSWmXFvrZnpiGviNUy8e6zTpExgLVVb9dhZnNl8nMsXfK3yJlmq4RL9Nc 0BIzagnXr8ydJZrm5XKiB3sAmnoQOJXWs+xXpAZu8bDU+TjtxYn9QNPaZqENLCtvJCQi CTuM2IDiJncuibvfwSv66vykFoM+0Sg+mS7LetMLgCNrgaIfUa8kU2XNBkiRAHAf0Y/g D3mDxjUOuXYWa6bg9voJK3WN4LseUnwvbJmfn754wd72vwEKd/YV1BwKGIvEdEO7YQvj j65w==
MIME-Version: 1.0
X-Received: by 10.194.84.8 with SMTP id u8mr49069257wjy.29.1362592418603; Wed, 06 Mar 2013 09:53:38 -0800 (PST)
Date: Wed, 6 Mar 2013 12:53:38 -0500
Subject: Any logger created before calling logging.config.dictCOnfig is not configured
From: "W. Matthew Wilson" <matt@tplus1.com>
To: python-list@python.org
Content-Type: multipart/alternative; boundary=047d7bb0473a15bcd004d74545bd
X-Gm-Message-State: ALoCoQkwbRff2CqEVgDS0gomTC5f+FWGNE8qpL+l1eUBI9DYTVS+2zEqvzwqwbuiF9Jb1L98Lcua
X-BeenThere: python-list@python.org
X-Mailman-Version: 2.1.15
Precedence: list
List-Id: General discussion list for the Python programming language <python-list.python.org>
List-Unsubscribe: <http://mail.python.org/mailman/options/python-list>, <mailto:python-list-request@python.org?subject=unsubscribe>
List-Archive: <http://mail.python.org/pipermail/python-list/>
List-Post: <mailto:python-list@python.org>
List-Help: <mailto:python-list-request@python.org?subject=help>
List-Subscribe: <http://mail.python.org/mailman/listinfo/python-list>, <mailto:python-list-request@python.org?subject=subscribe>
Newsgroups: comp.lang.python
Message-ID: <mailman.2955.1362592775.2939.python-list@python.org>
Lines: 202
NNTP-Posting-Host: 2001:888:2000:d::a6
X-Trace: 1362592775 news.xs4all.nl 6909 [2001:888:2000:d::a6]:41391
X-Complaints-To: abuse@xs4all.nl
Xref: csiph.com comp.lang.python:40654

--047d7bb0473a15bcd004d74545bd
Content-Type: text/plain; charset=ISO-8859-1

It seems like that any logger I create BEFORE calling
logging.config.dictConfig does not get configured.

Meanwhile, if I configure the logger like I always have, by just setting
handlers on root, everything works fine, including the loggers that were
created BEFORE I configure logging.

I make a lot of module-level log instances.

I wrote a simple script to show my problem.  Run it like:

    $ python scratch.py code

and then

    $ python scratch.py dict

and see how the logging output is different.

### SCRIPT START

"""

import argparse
import logging
import logging.config

log1 = logging.getLogger('scratch')

def configure_logging_with_dictConfig():

    d = {
        'formatters': {
            'consolefmt': {
                'format': '%(asctime)s %(levelname)-10s %(process)-6d
%(name)-24s %(lineno)-4d %(message)s'}},

        'handlers': {
            'console': {
                'class': 'logging.StreamHandler',
                'formatter': 'consolefmt',
                'level': 'DEBUG'}},

        'root': {
            'handlers': ['console'],
            'level': 'DEBUG'},

       'version': 1}

    logging.config.dictConfig(d)

def configure_logging_with_code():

    # Set the logger to DEBUG.
    logging.root.setLevel(logging.DEBUG)

    # Now write a custom formatter, so that we get all those different
    # things.
    f = logging.Formatter(
        '%(asctime)s '
        '%(levelname)-10s '
        '%(process)-6d '
        '%(filename)-24s '
        '%(lineno)-4d '
        '%(message)s '
    )

    # Set up a stream handler for DEBUG stuff (and greater).
    sh = logging.StreamHandler()
    sh.setLevel(logging.DEBUG)
    sh.setFormatter(f)
    logging.root.addHandler(sh)

def set_up_arguments():

    ap = argparse.ArgumentParser()
    ap.add_argument('how_to_configure', choices=['code', 'dict'])
    return ap.parse_args()

if __name__ == '__main__':

    args = set_up_arguments()

    if args.how_to_configure == 'code':
        configure_logging_with_code()

    elif args.how_to_configure == 'dict':
        configure_logging_with_dictConfig()

    log1.debug('debug from log1')

    # log2 is created AFTER I configure logging.
    log2 = logging.getLogger('log2')
    log2.debug('debug from log2')

    # Try to figure out what is the difference!  Nothing jumps out at me.

    print "log.root.level: {0}".format(log1.root.level)
    print "log.root.handlers: {0}".format(log1.root.handlers)

    print "log1.parent.level: {0}".format(log1.parent.level)
    print "log1.parent.handlers: {0}".format(log1.parent.handlers)

    print "log1.level: {0}".format(log1.level)
    print "log1.handlers: {0}".format(log1.handlers)
    print "log1.propagate: {0}".format(log1.propagate)
    print "log1.getEffectiveLevel(): {0}".format(log1.getEffectiveLevel())

### SCRIPT END


-- 
W. Matthew Wilson
matt@tplus1.com
http://tplus1.com

--047d7bb0473a15bcd004d74545bd
Content-Type: text/html; charset=ISO-8859-1
Content-Transfer-Encoding: quoted-printable

<div dir=3D"ltr"><div>It seems like that any logger I create BEFORE calling=
 logging.config.dictConfig does not get configured.<br></div><div style><br=
></div><div style>Meanwhile, if I configure the logger like I always have, =
by just setting handlers on root, everything works fine, including the logg=
ers that were created BEFORE I configure logging.</div>
<div style><br></div><div style>I make a lot of module-level log instances.=
</div><div style><br></div><div style>I wrote a simple script to show my pr=
oblem. =A0Run it like:</div><div><br></div><div>=A0 =A0 $ python scratch.py=
 code</div>
<div><br></div><div>and then</div><div><br></div><div>=A0 =A0 $ python scra=
tch.py dict</div><div><br></div><div>and see how the logging output is diff=
erent.</div><div><br></div><div style>### SCRIPT START</div><div><br></div>
<div>&quot;&quot;&quot;</div><div><br></div><div>import argparse</div><div>=
import logging</div><div>import logging.config</div><div><br></div><div>log=
1 =3D logging.getLogger(&#39;scratch&#39;)</div><div><br></div><div>def con=
figure_logging_with_dictConfig():</div>
<div><br></div><div>=A0 =A0 d =3D {</div><div>=A0 =A0 =A0 =A0 &#39;formatte=
rs&#39;: {</div><div>=A0 =A0 =A0 =A0 =A0 =A0 &#39;consolefmt&#39;: {</div><=
div>=A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 &#39;format&#39;: &#39;%(asctime)s %(le=
velname)-10s %(process)-6d %(name)-24s %(lineno)-4d %(message)s&#39;}},</di=
v>
<div><br></div><div>=A0 =A0 =A0 =A0 &#39;handlers&#39;: {</div><div>=A0 =A0=
 =A0 =A0 =A0 =A0 &#39;console&#39;: {</div><div>=A0 =A0 =A0 =A0 =A0 =A0 =A0=
 =A0 &#39;class&#39;: &#39;logging.StreamHandler&#39;,</div><div>=A0 =A0 =
=A0 =A0 =A0 =A0 =A0 =A0 &#39;formatter&#39;: &#39;consolefmt&#39;,</div>
<div>=A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 &#39;level&#39;: &#39;DEBUG&#39;}},</d=
iv><div><br></div><div>=A0 =A0 =A0 =A0 &#39;root&#39;: {</div><div>=A0 =A0 =
=A0 =A0 =A0 =A0 &#39;handlers&#39;: [&#39;console&#39;],</div><div>=A0 =A0 =
=A0 =A0 =A0 =A0 &#39;level&#39;: &#39;DEBUG&#39;},</div>
<div><br></div><div>=A0 =A0 =A0 =A0&#39;version&#39;: 1}</div><div><br></di=
v><div>=A0 =A0 logging.config.dictConfig(d)</div><div><br></div><div><div>d=
ef configure_logging_with_code():</div><div><br></div><div>=A0 =A0 # Set th=
e logger to DEBUG.</div>
<div>=A0 =A0 logging.root.setLevel(logging.DEBUG)</div><div><br></div><div>=
=A0 =A0 # Now write a custom formatter, so that we get all those different<=
/div><div>=A0 =A0 # things.</div><div>=A0 =A0 f =3D logging.Formatter(</div=
><div>=A0 =A0 =A0 =A0 &#39;%(asctime)s &#39;</div>
<div>=A0 =A0 =A0 =A0 &#39;%(levelname)-10s &#39;</div><div>=A0 =A0 =A0 =A0 =
&#39;%(process)-6d &#39;</div><div>=A0 =A0 =A0 =A0 &#39;%(filename)-24s &#3=
9;</div><div>=A0 =A0 =A0 =A0 &#39;%(lineno)-4d &#39;</div><div>=A0 =A0 =A0 =
=A0 &#39;%(message)s &#39;</div><div>
=A0 =A0 )</div><div><br></div><div>=A0 =A0 # Set up a stream handler for DE=
BUG stuff (and greater).</div><div>=A0 =A0 sh =3D logging.StreamHandler()</=
div><div>=A0 =A0 sh.setLevel(logging.DEBUG)</div><div>=A0 =A0 sh.setFormatt=
er(f)</div><div>=A0 =A0 logging.root.addHandler(sh)</div>
<div><br></div><div>def set_up_arguments():</div><div><br></div><div>=A0 =
=A0 ap =3D argparse.ArgumentParser()</div><div>=A0 =A0 ap.add_argument(&#39=
;how_to_configure&#39;, choices=3D[&#39;code&#39;, &#39;dict&#39;])</div><d=
iv>=A0 =A0 return ap.parse_args()</div>
<div><br></div><div>if __name__ =3D=3D &#39;__main__&#39;:</div><div><br></=
div><div>=A0 =A0 args =3D set_up_arguments()</div><div><br></div><div>=A0 =
=A0 if args.how_to_configure =3D=3D &#39;code&#39;:</div><div>=A0 =A0 =A0 =
=A0 configure_logging_with_code()</div>
<div><br></div><div>=A0 =A0 elif args.how_to_configure =3D=3D &#39;dict&#39=
;:</div><div>=A0 =A0 =A0 =A0 configure_logging_with_dictConfig()</div><div>=
<br></div><div>=A0 =A0 log1.debug(&#39;debug from log1&#39;)</div><div><br>=
</div><div style>
=A0 =A0 # log2 is created AFTER I configure logging.</div><div>=A0 =A0 log2=
 =3D logging.getLogger(&#39;log2&#39;)</div><div>=A0 =A0 log2.debug(&#39;de=
bug from log2&#39;)</div><div><br></div><div style>=A0 =A0 # Try to figure =
out what is the difference! =A0Nothing jumps out at me.</div>
<div><br></div><div>=A0 =A0 print &quot;log.root.level: {0}&quot;.format(lo=
g1.root.level)</div><div>=A0 =A0 print &quot;log.root.handlers: {0}&quot;.f=
ormat(log1.root.handlers)</div><div><br></div><div>=A0 =A0 print &quot;log1=
.parent.level: {0}&quot;.format(log1.parent.level)</div>
<div>=A0 =A0 print &quot;log1.parent.handlers: {0}&quot;.format(log1.parent=
.handlers)</div><div><br></div><div>=A0 =A0 print &quot;log1.level: {0}&quo=
t;.format(log1.level)</div><div>=A0 =A0 print &quot;log1.handlers: {0}&quot=
;.format(log1.handlers)</div>
<div>=A0 =A0 print &quot;log1.propagate: {0}&quot;.format(log1.propagate)</=
div><div>=A0 =A0 print &quot;log1.getEffectiveLevel(): {0}&quot;.format(log=
1.getEffectiveLevel())</div></div><div><br></div><div style>### SCRIPT END<=
/div>
<div><br></div><div><br></div>-- <br>W. Matthew Wilson<br><a href=3D"mailto=
:matt@tplus1.com" target=3D"_blank">matt@tplus1.com</a><br><a href=3D"http:=
//tplus1.com" target=3D"_blank">http://tplus1.com</a><br><br>
</div>

--047d7bb0473a15bcd004d74545bd--