Bug 632577 - stop_logging does not properly clean up the logs
Summary: stop_logging does not properly clean up the logs
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: Pulp
Classification: Retired
Component: z_other
Version: unspecified
Hardware: All
OS: Linux
low
medium
Target Milestone: ---
: ---
Assignee: Jason Connor
QA Contact: wes hayutin
URL:
Whiteboard:
Depends On:
Blocks: verified-to-close
TreeView+ depends on / blocked
 
Reported: 2010-09-10 13:37 UTC by Jay Dobies
Modified: 2014-03-31 01:38 UTC (History)
3 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2011-08-16 14:20:04 UTC
Embargoed:


Attachments (Terms of Use)
Debugger view of the log on the first test (83.48 KB, image/png)
2010-09-10 13:49 UTC, Jay Dobies
no flags Details
Debugger view of the log after multiple tests (87.13 KB, image/png)
2010-09-10 13:49 UTC, Jay Dobies
no flags Details

Description Jay Dobies 2010-09-10 13:37:33 UTC
I think there's an issue with how our logs.py sets up logging.

It has a start and stop function, using a global variable to prevent
multiple starts without a stop in between. The problem is, the stop
doesn't properly clean up the configuration that's done in the start
method. So each time it's stopped/started, we add all the handlers back
onto the loggers.

This shouldn't be a problem (currently) in the running code since it's
only started in the application bootstrap. However our unit tests are
badly broken. I noticed in the debugger that there were a ton of
duplicate handlers on loggers when running tests. The stop/start process
is tied to each time the configuration is loaded in a test, which is
done in setUp. Since that's called once for each test, it's causing our
logging configuration to blow up by the end of the test runs. As of
right now, the test_consumer_history_api tests hang for both me and John
Matthews. They run fine when I comment out the testutil.start_logging()
call.

This might also explain why Hudson is hung right now (current build has
been going for 15h). Python seems to get especially confused in the
auditing logging configuration since it's adding a bunch of
TimedRotatingFileHandlers. I'm curious if it

I'll file a high priority bug for it since it's stopping our tests and
builds from running. I'm not 100% sure of the fix, but the issue looks
to be that our stop/start logging calls are bugged.

Comment 1 Jay Dobies 2010-09-10 13:49:40 UTC
Created attachment 446517 [details]
Debugger view of the log on the first test

Comment 2 Jay Dobies 2010-09-10 13:49:59 UTC
Created attachment 446518 [details]
Debugger view of the log after multiple tests

Comment 3 Jay Dobies 2010-09-10 13:50:37 UTC
Lowered to medium since the tests can at least run again.

Comment 4 Jay Dobies 2010-09-10 13:54:17 UTC
FYI, in the two attached screenshots, look at the handlers list under logging in the bottom half. I forgot to draw a circle around the relevant part of those images.

Comment 5 Jason Connor 2010-10-28 16:42:34 UTC
added some code to clear python's logging module of existing loggers when stop_logging is called

Comment 6 Jay Dobies 2010-10-29 16:58:22 UTC
Fixed in 0.77.

Comment 7 Jay Dobies 2010-11-03 19:35:18 UTC
Fixed in build 0.78.

Comment 8 Preethi Thomas 2011-07-25 14:11:35 UTC
Looks like this has not been an issue for quite sometime.

moving to verified.

Comment 9 Preethi Thomas 2011-08-16 14:20:04 UTC
Closing with Community Release 15

pulp-0.0.223-4.


Note You need to log in before you can comment on or make changes to this bug.