Logging in TG 1.5 branch

[Christopher Arndt]

Hi all, hi Ken ;)

I ran my HelloWorld benchmark app [1] for TG 1.1 with the 1.5 branch
and apart from a few config fixes, it works well, but I couldn't get
CherryPy to stop logging access and other crud to the console.

I read the CherryPy 3 docs on logging but I'm a bit confused about what
is applicable to TG 1.5 and what not.

If I understand correctly, CherryPy has the following loggers:

- cherrypy.access
- cherrypy.error
- cherrypy.access.<appid>
- cherrypy.error.<appid>

In TurboGears 1.1 requests were logged via the special '_cp_log_access'
method of the RootController class to 'turbogears.access' with level
INFO, but with CherryPy 3 this is not supported anymore, AFAICS.

Given this, how would I

1) Log 'cherrypy.access' to a file ('access.log')
2) Log turbogears.* messages with level >= WARNING to a file
('error.log')
3) Log cherrypy messages (cherrypy.error) with level >= WARNING to
stderr
4) Discard everything else?

I manage 1) and 2) but I still get request access logs to the console
and cherrypy INFO and and ENGINE messages to too.

Here's my logging config (everything in deployment config, log.cfg is
empty):

http://paste.chrisarndt.de/paste/e3ab991b685d4186bca45b402b96d838

Chris

[1] http://chrisarndt.de/projects/wf-shootout/

[Ken Kuhlman]

Yeah, logging config is something I've never looked at.   I spent a couple of hours looking at this today, but I don't have a complete patch yet.

Console logging is part cherrypy's default logging config, so you're still getting it because your [[[cp_errors]]] section isn't taking.  If you change the qualname to cherrypy.error & apply the patch below to your 1.5 install [1], you'll have better luck.

CP 3's access log uses "Combined Log Format," so I think we can just drop _cp_log_access.

I hope this helps you get going.. can you create a ticket so that we don't forget to find a more complete fix?

Thanks,
-Ken

[1] http://paste.chrisarndt.de/paste/f03f43b23eac4d8d9d30dbbd0bd02991

[Christopher Arndt]

Ken Kuhlman schrieb:

> Console logging is part cherrypy's default logging config, so you're
> still getting it because your [[[cp_errors]]] section isn't taking. If
> you change the qualname to cherrypy.error & apply the patch below to
> your 1.5 install [1], you'll have better luck.

Thanks Ken, I will try this tonight.

> CP 3's access log uses "Combined Log Format," so I think we can just
> drop _cp_log_access.

Yes, I think so.

> I hope this helps you get going.. can you create a ticket so that we
> don't forget to find a more complete fix?

Done: http://trac.turbogears.org/ticket/2391

Chris

[Christopher Arndt]

Christopher Arndt schrieb:

> Ken Kuhlman schrieb:
>> Console logging is part cherrypy's default logging config, so you're
>> still getting it because your [[[cp_errors]]] section isn't taking. If
>> you change the qualname to cherrypy.error & apply the patch below to
>> your 1.5 install [1], you'll have better luck.
>
> Thanks Ken, I will try this tonight.

This shuts up logging of CP INFO & DEBUG messages to stdout but I still
get access logs in combined log format to both the console and access.log.

Setting 'log.screen' to False in the configuration shuts this up too.

So we should make this the default and add appropriate logging config to
the quickstart templates to log 'cherrypy.access' to stdout in dev.cfg
and to 'access.log' in sample-prod.cfg.

What I don't understand is why I have to use 'cherrypy.error' as the
qualname? I thought there was a parent logger 'cherrypy', or isn't there?

Chris

[Christopher Arndt]

Another logging related (?) issue:

When I run the tests for a 1.5 project (either with "nosetests" or with
"python setup.py test"), I get the following warnings on the console
(actual paths generalized):

[...]
'.../project/pkg/config/static' (root + dir) is not an existing
filesystem path.
section: [/static]
root: None
dir: '.../project/pkg/config/static'

ok
Login with correct credentials and then logout. ... CherryPy Checker:
The config entry 'log_debug_info_hook.on' is invalid, because the
'log_debug_info_hook' config namespace is unknown.
section: [/tg_js]

CherryPy Checker:
The config entry 'log_debug_info_hook.on' is invalid, because the
'log_debug_info_hook' config namespace is unknown.
section: [/tg_static]

I don't get these warnings if I run the app normally with "python
start-pkg.py".

What's going here? Should I open a ticket for this?

Chris

[Ken Kuhlman]

Sorry for the delay.. I'm pretty swamped at my day job right now.

CP3 introduced the concept of config namespaces that I'm still trying to sort out. 

I see this issue as part of the "deprecate config keys" and "logging" blockers so a distinct ticket isn't really necessary.  Ideally, I'd like to map that key to new logging behavior & issue a deprecation warning.

-Ken

[Ken Kuhlman]

On Tue, Nov 10, 2009 at 1:08 PM, Ken Kuhlman <ksku...@gmail.com> wrote:

Sorry for the delay.. I'm pretty swamped at my day job right now.

CP3 introduced the concept of config namespaces that I'm still trying to sort out. 

I see this issue as part of the "deprecate config keys" and "logging" blockers so a distinct ticket isn't really necessary.  Ideally, I'd like to map that key to new logging behavior & issue a deprecation warning.

-Ken

I finally got a chance to research log_debug_info_filter & it wasn't very useful -- it just added log info to the rendered page when turned on.  I can see why the CP team dropped it.

Chris Z. beat me to the punch in removing the TG references to it in r6950.

-Ken