bpo-35726:QueueHandler formatting affects other handlers #11537

Zheaoli · 2019-01-12T17:37:12Z

https://bugs.python.org/issue35726

remilapeyre

Hi @Zheaoli, thanks for your contribution !

Tests for the logging module do not pass anymore, can you look into it?

Zheaoli · 2019-01-13T00:57:06Z

@remilapeyre
sorry about the fail.

I have already fixed the test error! This PR could be reviewed and merged right now.

Zheaoli · 2019-01-13T01:04:06Z

this PR needs backport to 3.0-3.7 and 2.7

Lib/logging/handlers.py

Misc/NEWS.d/next/Library/2019-01-13-01-33-00.bpo-35726.dasdas.rst

bedevere-bot · 2019-01-13T09:26:21Z

A Python core developer has requested some changes be made to your pull request before we can consider merging it. If you could please address their requests along with any other requests in other reviews from core developers that would be appreciated.

Once you have made the requested changes, please leave a comment on this pull request containing the phrase I have made the requested changes; please review again. I will then notify any core developers who have left a review that you're ready for them to take another look at this pull request.

And if you don't make the requested changes, you will be poked with soft cushions!

Zheaoli · 2019-01-13T10:49:13Z

I have made the requested changes; please review again

bedevere-bot · 2019-01-13T10:49:15Z

Thanks for making the requested changes!

@vsajip: please review the changes made to this pull request.

QueueHandler.prepare() now makes a copy of the record before modifying and enqueueing it, to avoid affecting other handlers in the chain.

Zheaoli · 2019-01-14T03:16:20Z

I have made the requested changes; please review again

bedevere-bot · 2019-01-14T03:16:22Z

Thanks for making the requested changes!

@vsajip: please review the changes made to this pull request.

Zheaoli · 2019-01-23T07:31:14Z

@vsajip this PR need be back to Python 3.5/3.6/3.7

tirkarthi · 2019-01-23T07:45:29Z

3.5 and 3.6 are in security fixes only mode so this can be backported only to 3.7.

Zheaoli · 2019-01-23T07:49:11Z

@tirkarthi Got it, thx

tirkarthi · 2019-01-23T09:22:18Z

@Zheaoli @vsajip I am just curious if there is a test for this in test_logging or as a separate PR? I hope below script illustrates the issue.

import queue
import logging
from logging import handlers

queue = queue.Queue(-1)

que_hdlr = handlers.QueueHandler(queue)
stream_hdlr = logging.StreamHandler()

logger = logging.getLogger(__name__)
queue_log_format = "Queue %(name)s -> %(levelname)s: %(message)s"
queue_formatter = logging.Formatter(queue_log_format)
stream_log_format = "Stream %(name)s -> %(levelname)s: %(message)s"
stream_formatter = logging.Formatter(stream_log_format)

stream_hdlr.setFormatter(stream_formatter)
que_hdlr.setFormatter(queue_formatter)

listener = handlers.QueueListener(queue, que_hdlr)
listener.start()

logger.setLevel(logging.WARNING)
logger.addHandler(que_hdlr)
logger.addHandler(stream_hdlr)

logger.exception("hello")

➜  cpython git:(master) ✗ python3.7 /tmp/foo.py
Stream __main__ -> ERROR: Queue __main__ -> ERROR: hello
NoneType: None
➜  cpython git:(master) ✗ ./python.exe /tmp/foo.py # patched master
Stream __main__ -> ERROR: hello
NoneType: None

tirkarthi · 2019-01-23T10:14:45Z

I can raise a PR something along the lines of below if there is a confirmation that there are no tests for the current PR.

@unittest.skipUnless(hasattr(logging.handlers, 'QueueListener'),
                     'logging.handlers.QueueListener required for this test')
def test_queue_listener_with_multiple_handlers(self):
    # Test that queue handler format doesn't affect other handler formats ([bpo-35726](https://bugs.python.org/issue35726)).
    self.que_hdlr.setFormatter(self.root_formatter)
    self.que_logger.addHandler(self.root_hdlr)

    listener = logging.handlers.QueueListener(self.queue, self.que_hdlr)
    listener.start()
    self.que_logger.error("error")
    listener.stop()
    self.assertEqual(self.stream.getvalue().strip(), "que -> ERROR: error")

Without patch

./python.exe -m unittest -v test.test_logging.QueueHandlerTest.test_queue_listener_with_multiple_handlers
test_queue_listener_with_multiple_handlers (test.test_logging.QueueHandlerTest) ... FAIL

======================================================================
FAIL: test_queue_listener_with_multiple_handlers (test.test_logging.QueueHandlerTest)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/Users/karthikeyansingaravelan/stuff/python/cpython/Lib/test/test_logging.py", line 3519, in test_queue_listener_with_multiple_handlers
    self.assertEqual(self.stream.getvalue().strip(), "que -> ERROR: error")
AssertionError: 'que -> ERROR: que -> ERROR: error' != 'que -> ERROR: error'
- que -> ERROR: que -> ERROR: error
+ que -> ERROR: error


----------------------------------------------------------------------
Ran 1 test in 0.009s

FAILED (failures=1)

With patch

./python.exe -m unittest -v test.test_logging.QueueHandlerTest.test_queue_listener_with_multiple_handlers
test_queue_listener_with_multiple_handlers (test.test_logging.QueueHandlerTest) ... ok

----------------------------------------------------------------------
Ran 1 test in 0.005s

OK

vsajip · 2019-01-23T12:23:54Z

A PR with a test would be good, thanks. I don't believe there was a test for this specific case.

miss-islington · 2019-04-07T11:57:04Z

Thanks @Zheaoli for the PR, and @vsajip for merging it 🌮🎉.. I'm working now to backport this PR to: 3.7.
🐍🍒⛏🤖

…er handlers (pythonGH-11537) QueueHandler.prepare() now makes a copy of the record before modifying and enqueueing it, to avoid affecting other handlers in the chain. (cherry picked from commit da6424e) Co-authored-by: Manjusaka <[email protected]>

bedevere-bot · 2019-04-07T15:23:49Z

GH-12716 is a backport of this pull request to the 3.7 branch.

…er handlers (GH-11537) (GH-12716) QueueHandler.prepare() now makes a copy of the record before modifying and enqueueing it, to avoid affecting other handlers in the chain. (cherry picked from commit da6424e) Co-authored-by: Manjusaka <[email protected]>

the-knights-who-say-ni added the CLA signed label Jan 12, 2019

bedevere-bot added the awaiting review label Jan 12, 2019

remilapeyre suggested changes Jan 12, 2019

View reviewed changes

bedevere-bot added awaiting core review and removed awaiting review labels Jan 12, 2019

Zheaoli force-pushed the bpo-35726 branch from de1f5f1 to 0effdfa Compare January 13, 2019 00:37

vsajip changed the title ~~bpo-35726:QueueHandler formating affects other handlers~~ bpo-35726:QueueHandler formatting affects other handlers Jan 13, 2019

vsajip requested changes Jan 13, 2019

View reviewed changes

Lib/logging/handlers.py Show resolved Hide resolved

Misc/NEWS.d/next/Library/2019-01-13-01-33-00.bpo-35726.dasdas.rst Outdated Show resolved Hide resolved

Misc/NEWS.d/next/Library/2019-01-13-01-33-00.bpo-35726.dasdas.rst Outdated Show resolved Hide resolved

bedevere-bot added awaiting changes and removed awaiting core review labels Jan 13, 2019

Zheaoli force-pushed the bpo-35726 branch from 0effdfa to 467e6f0 Compare January 13, 2019 10:30

bedevere-bot removed the awaiting changes label Jan 13, 2019

bedevere-bot added the awaiting change review label Jan 13, 2019

bpo-35726:

528aa52

QueueHandler.prepare() now makes a copy of the record before modifying and enqueueing it, to avoid affecting other handlers in the chain.

Zheaoli force-pushed the bpo-35726 branch from e6b1049 to 528aa52 Compare January 14, 2019 02:31

vsajip merged commit da6424e into python:master Jan 23, 2019

bedevere-bot removed the awaiting change review label Jan 23, 2019

Zheaoli deleted the bpo-35726 branch January 23, 2019 14:04

Zheaoli restored the bpo-35726 branch January 23, 2019 14:04

tirkarthi mentioned this pull request Jan 23, 2019

bpo-35726: Add test for QueueHandler with multiple handlers #11659

Merged

Zheaoli deleted the bpo-35726 branch January 25, 2019 16:37

tirkarthi mentioned this pull request Apr 7, 2019

[3.7] bpo-35726: Add test for QueueHandler with multiple handlers (GH-11659) #12714

Closed

vsajip added the needs backport to 3.7 label Apr 7, 2019

bedevere-bot removed the needs backport to 3.7 label Apr 7, 2019

Uh oh!

bpo-35726:QueueHandler formatting affects other handlers #11537

bpo-35726:QueueHandler formatting affects other handlers #11537

Uh oh!

Conversation

Zheaoli commented Jan 12, 2019 • edited by bedevere-bot Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

remilapeyre left a comment

Choose a reason for hiding this comment

Uh oh!

Zheaoli commented Jan 13, 2019

Uh oh!

Zheaoli commented Jan 13, 2019 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

bedevere-bot commented Jan 13, 2019

Uh oh!

Zheaoli commented Jan 13, 2019

Uh oh!

bedevere-bot commented Jan 13, 2019

Uh oh!

Zheaoli commented Jan 14, 2019

Uh oh!

bedevere-bot commented Jan 14, 2019

Uh oh!

Zheaoli commented Jan 23, 2019

Uh oh!

tirkarthi commented Jan 23, 2019

Uh oh!

Zheaoli commented Jan 23, 2019

Uh oh!

tirkarthi commented Jan 23, 2019

Uh oh!

tirkarthi commented Jan 23, 2019 • edited by bedevere-bot Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

vsajip commented Jan 23, 2019 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

miss-islington commented Apr 7, 2019

Uh oh!

bedevere-bot commented Apr 7, 2019

Uh oh!

Uh oh!

Zheaoli commented Jan 12, 2019 •

edited by bedevere-bot

Loading

Zheaoli commented Jan 13, 2019 •

edited

Loading

tirkarthi commented Jan 23, 2019 •

edited by bedevere-bot

Loading

vsajip commented Jan 23, 2019 •

edited

Loading