Discussion:
ThreadedConnectionPool and Cherrypy
Joe Abbate
2010-06-25 01:45:50 UTC
Permalink
Hi,

I'm using psycopg2 2.0.14 and cherrypy 3.1.2. I have been using
SQLAlchemy to manage connections, but when I found out about
ThreadedConnectionPool I decided to give it a try since I don't need the
rest of SA.

I've got it working but there is an annoying side effect of using
psycopg's pool. CherryPy implements logging so it writes to stdout or
to a designated log file messages like these:

[24/Jun/2010:21:37:05] ENGINE Bus STARTING
[24/Jun/2010:21:37:05] ENGINE Serving on 127.0.0.1:8080
[24/Jun/2010:21:37:05] ENGINE Creating the SQL database engine

However, psycopg2's pool.py implements its own logger so now everything
in the log ends up duplicated:

[24/Jun/2010:21:38:58] ENGINE Bus STARTING
2010-06-24 21:38:58,900 INFO [24/Jun/2010:21:38:58] ENGINE Bus STARTING
[24/Jun/2010:21:38:59] ENGINE Serving on 127.0.0.1:8085
2010-06-24 21:38:59,105 INFO [24/Jun/2010:21:38:59] ENGINE Serving on
127.0.0.1:8085
[24/Jun/2010:21:38:59] ENGINE Creating the SQL database engine
2010-06-24 21:38:59,106 INFO [24/Jun/2010:21:38:59] ENGINE Creating the
SQL database engine

Not a big deal, but as I said it's annoying. I'm wondering if there is
some way to turn off psycopg2's logging.

TIA.

Joe
Federico Di Gregorio
2010-06-25 08:04:51 UTC
Permalink
Post by Joe Abbate
[24/Jun/2010:21:38:58] ENGINE Bus STARTING
2010-06-24 21:38:58,900 INFO [24/Jun/2010:21:38:58] ENGINE Bus STARTING
[24/Jun/2010:21:38:59] ENGINE Serving on 127.0.0.1:8085
2010-06-24 21:38:59,105 INFO [24/Jun/2010:21:38:59] ENGINE Serving on
127.0.0.1:8085
[24/Jun/2010:21:38:59] ENGINE Creating the SQL database engine
2010-06-24 21:38:59,106 INFO [24/Jun/2010:21:38:59] ENGINE Creating the
SQL database engine
Not a big deal, but as I said it's annoying. I'm wondering if there is
some way to turn off psycopg2's logging.
psycopg should not initialize the logging module if already initialized.
I supposed logging.basicConfig() would take care of that but it doesn't
seems so. Can you please comment that line in pool.py an tell us what
happens?

federico
--
Federico Di Gregorio fog-NGVKUo/i/***@public.gmane.org
A desobediência é uma virtude necessária à criatividade. -- Raul Seixas
Joe Abbate
2010-06-25 08:47:12 UTC
Permalink
Hi Federico,
Post by Federico Di Gregorio
psycopg should not initialize the logging module if already initialized.
I supposed logging.basicConfig() would take care of that but it doesn't
seems so. Can you please comment that line in pool.py an tell us what
happens?
If I comment out the logging.basicConfig() in pool.py, the duplicate
INFO-level log lines go away.

Joe
Federico Di Gregorio
2010-06-25 10:00:47 UTC
Permalink
Post by Joe Abbate
Hi Federico,
Post by Federico Di Gregorio
psycopg should not initialize the logging module if already initialized.
I supposed logging.basicConfig() would take care of that but it doesn't
seems so. Can you please comment that line in pool.py an tell us what
happens?
If I comment out the logging.basicConfig() in pool.py, the duplicate
INFO-level log lines go away.
The documentation for basicConfig says:

Does basic configuration for the logging system by creating a
StreamHandler with a default Formatter and adding it to the root logger.
The function does nothing if any handlers have been defined for
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
the root logger. The functions debug(), info(), warning(), error() and
critical() will call basicConfig() automatically if no handlers are
defined for the root logger.

So, probably, psycopg.pool is imported before other modules and the
other modules add handlers anyway. I'd say this is a psycopg bug that
being a library should not initialize the logging system. Will fix this
when I understand exactly what I library should do; in the meantime just
leave the comment in place.

federico
--
Federico Di Gregorio <mailto:fog-NGVKUo/i/***@public.gmane.org> <jid:fog-6VaHXZgVb86aHsy+***@public.gmane.org>
DISCLAIMER. If I receive a message from you, you are agreeing that:
1. I am by definition, "the intended recipient".
2. All information in the email is mine to do with as I see fit and
make such financial profit, political mileage, or good joke as it lends
itself to. In particular, I may quote it on USENET or the WWW.
3. I may take the contents as representing the views of your company.
4. This overrides any disclaimer or statement of confidentiality that
may be included on your message.
Daniele Varrazzo
2010-06-25 12:16:30 UTC
Permalink
Post by Federico Di Gregorio
So, probably, psycopg.pool is imported before other modules and the
other modules add handlers anyway. I'd say this is a psycopg bug that
being a library should not initialize the logging system. Will fix this
when I understand exactly what I library should do;
Yep, organizing the logging system between libraries is tricky. I
think the correct thing to do in libraries is just not to call
basicConfig: use the desired logger objects and leave their
configuration as a policy of the calling application. This is the
guideline I usually adopt to get rid of duplicate lines in projects
where loggings starts becoming messy.
Post by Federico Di Gregorio
in the meantime just
leave the comment in place.
If Joe wants to avoid duplicate logging in his app without changing
psycopg code (e.g. if he's using a system version) he may try to fool
the logging system by one of:

- if his application installs handlers on the root logger, he may
ensure that logging init is performed before importing psycopg
- if he's not using handlers on the root logger, he may install a
no-op handler before importing psycopg, e.g.
logging.basicConfig(stream=open(os.devnull, 'a'))
- if he thinks basicConfig is not a good idea, he may monkeypatch it
away before importing psycopg: logging.basicConfig = lambda **kwargs:
None

-- Daniele
Joe Abbate
2010-06-25 15:02:03 UTC
Permalink
Hi Daniele,
Post by Daniele Varrazzo
If Joe wants to avoid duplicate logging in his app without changing
psycopg code (e.g. if he's using a system version) he may try to fool
- if his application installs handlers on the root logger, he may
ensure that logging init is performed before importing psycopg
- if he's not using handlers on the root logger, he may install a
no-op handler before importing psycopg, e.g.
logging.basicConfig(stream=open(os.devnull, 'a'))
- if he thinks basicConfig is not a good idea, he may monkeypatch it
None
Just to clarify, my application doesn't take any explicit action with
respect to logging (except for defining log.error_file in the production
configuration). Therefore, CherryPy is the one that controls logging.
The CP code is here:

http://www.cherrypy.org/browser/tags/cherrypy-3.1.2/cherrypy/_cplogging.py

Joe
Daniele Varrazzo
2010-06-25 15:11:45 UTC
Permalink
Post by Joe Abbate
Just to clarify, my application doesn't take any explicit action with
respect to logging (except for defining log.error_file in the production
configuration).  Therefore, CherryPy is the one that controls logging.  The
I'm taking a look at an application of mine running cherrypy. It seems
the handlers are installed on the cherrypy.access and cherrypy.error
loggers and there is no handler installed on the root logger.
Therefore psycopg pool will install its own regardless of the order of
import. You may disable this using the 2nd or the 3rd of the suggested
workarounds, while we fix the library (if we decide to drop
basicConfig()).

-- Daniele
Federico Di Gregorio
2010-06-25 15:22:00 UTC
Permalink
Post by Daniele Varrazzo
import. You may disable this using the 2nd or the 3rd of the suggested
workarounds, while we fix the library (if we decide to drop
basicConfig()).
I vote for dropping it.

(How much is my vote valued? Mm.. +∞? Oh.. I love UNICODE ;)

federico
--
Federico Di Gregorio fog-NGVKUo/i/***@public.gmane.org
Those who do not study Lisp are doomed to reimplement it. Poorly.
-- from Karl M. Hegbloom .signature
Daniele Varrazzo
2010-06-25 15:28:12 UTC
Permalink
Post by Federico Di Gregorio
Post by Daniele Varrazzo
import. You may disable this using the 2nd or the 3rd of the suggested
workarounds, while we fix the library (if we decide to drop
basicConfig()).
I vote for dropping it.
(How much is my vote valued? Mm.. +∞? Oh.. I love UNICODE ;)
Somebody could vote -∞ and put the entire project in troubles...

-- Daniele
Federico Di Gregorio
2010-06-25 15:30:49 UTC
Permalink
Post by Federico Di Gregorio
Post by Daniele Varrazzo
import. You may disable this using the 2nd or the 3rd of the suggested
workarounds, while we fix the library (if we decide to drop
basicConfig()).
I vote for dropping it.
(How much is my vote valued? Mm.. +∞? Oh.. I love UNICODE ;)
Somebody could vote -∞ and put the entire project in troubles...
Argh! I don't have a font with higher-level infinites...
--
Federico Di Gregorio fog-NGVKUo/i/***@public.gmane.org
[parlando di un amica] ora mi tampina perche' vuole i miei cacciaviti.
ma ti rendi conto? -- <dani>
Karsten Hilbert
2010-06-25 15:48:02 UTC
Permalink
Post by Federico Di Gregorio
Post by Daniele Varrazzo
import. You may disable this using the 2nd or the 3rd of the suggested
workarounds, while we fix the library (if we decide to drop
basicConfig()).
I vote for dropping it.
+1

Karsten, GNUmed
--
GPG key ID E4071346 @ wwwkeys.pgp.net
E167 67FD A291 2BEA 73BD 4537 78B9 A9F9 E407 1346
Loading...