classification
Title: Change in behavior when overriding warnings.showwarning and with catch_warnings(record=True)
Type: behavior Stage: resolved
Components: Versions: Python 3.7, Python 3.6
process
Status: closed Resolution: fixed
Dependencies: Superseder:
Assigned To: vstinner Nosy List: Thomas.Robitaille, brett.cannon, martin.panter, mdk, ncoghlan, ned.deily, python-dev, serhiy.storchaka, vstinner
Priority: Keywords: patch

Created on 2016-11-30 00:29 by Thomas.Robitaille, last changed 2017-03-31 16:36 by dstufft. This issue is now closed.

Files
File name Uploaded Description Edit
warnings_fix.patch vstinner, 2016-12-05 22:28 review
warnings_fix-2.patch vstinner, 2016-12-05 22:33 review
warnings_fix-3.patch vstinner, 2016-12-05 23:06 review
showwarning-tidy.patch serhiy.storchaka, 2016-12-06 10:59 review
Pull Requests
URL Status Linked Edit
PR 552 closed dstufft, 2017-03-31 16:36
Messages (24)
msg282056 - (view) Author: Thomas Robitaille (Thomas.Robitaille) Date: 2016-11-30 00:29
In Python 3.5, the following code:

    import warnings

    def deal_with_warning(*args, **kwargs):
        print("warning emitted")

    with warnings.catch_warnings(record=True):
        warnings.showwarning = deal_with_warning
        warnings.warn("This is a warning")

results in "warning emitted" being printed to the terminal.

In Python 3.6 however (at least in 3.6b1), nothing is printed, meaning that ``deal_with_warning`` is not getting called. I bisected the CPython history and tracked it down to the changes in this issue:

https://bugs.python.org/issue26568

However it doesn't look like this was an intentional change in behavior, since it says in the description of that issue:

"For backward compatibility, warnings.showmsg() calls warnings.showwarning() if warnings.showwarning() was replaced. Same for warnings.formatmsg(): call warnings.formatwarning() if replaced."

So I believe this is a bug? (since backward-compatibility is not preserved). If not, should the change in behavior be mentioned in the changelog?
msg282184 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2016-12-01 15:19
It seems like a regression of Python 3.6, probably introduced by myself with add addition of warnings._showwarningmsg() and the source parameter.
msg282458 - (view) Author: Ned Deily (ned.deily) * (Python committer) Date: 2016-12-05 20:10
What's the status of this issue?  It's currently blocking 360rc1.  We either need a resolution now or defer it to 3.6.1.
msg282476 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2016-12-05 22:28
Ok, here is a fix.
msg282477 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2016-12-05 22:33
Oops, I made a mistake just before producing the patch: here is the right patch, test_warnings pass.
msg282480 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2016-12-05 22:40
Serhiy: Would you mind to review warnings_fix-2.patch? I tagged this bug as a release blocker, since it's a regression introduced in 3.6.
msg282483 - (view) Author: Julien Palard (mdk) * (Python committer) Date: 2016-12-05 22:57
Carefully reviewed, and tests are passing, issue is fixed: LGTM.
msg282484 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2016-12-05 23:06
Patch version 3: fix test_warnings when running the test with python3 -Werror. Reset filters in the new unit test.
msg282491 - (view) Author: Nick Coghlan (ncoghlan) * (Python committer) Date: 2016-12-06 01:56
+1 from me as well
msg282492 - (view) Author: Martin Panter (martin.panter) * (Python committer) Date: 2016-12-06 02:35
The patch looks sensible to me. The fix is basically an extension to the first fixup (9c92352324e8), where Victor split _showwarnmsg_impl() out of _showwarnmsg(). Now, _showwarnmsg() is a helper for the C module to choose between the backwards-compatible showwarning() API, and the new internal _showwarnmsg_impl() function.

I left some incidental comments on Rietveld, but they are not severe release blockers. Also, is the docstring for warnings._showwarnmsg() off? It looks like you copied it from warnings.showwarning(). Best not to suggest replacing an internal function.
msg282493 - (view) Author: Martin Panter (martin.panter) * (Python committer) Date: 2016-12-06 02:53
Actually, I found a regression. Looks like you also need to cancel any showwarning() function set by the user:

>>> import warnings
>>> warnings.showwarning = print
>>> with warnings.catch_warnings(record=True) as recording:
...     warnings.warn("hi")  # Unpatched did not call print()
... 
hi <class 'UserWarning'> __main__ 2 None None
>>> recording  # Unpatched returned the warning here
[]

Also, should the documentation of catch_warnings() be amended to say that there is no longer a custom showwarning() function? The recording mechanism is now an internal detail, and not accessible by calling showwarning().
msg282509 - (view) Author: Serhiy Storchaka (serhiy.storchaka) * (Python committer) Date: 2016-12-06 09:50
I don't understand why test_showwarnmsg_missing was added. Why deleting warnings._showwarnmsg should be supported?

I would rename _showwarning to _showwarning_orig for accenting it's purpose. It is used only for checking if showwarning was replaced by the user.
msg282512 - (view) Author: Roundup Robot (python-dev) (Python triager) Date: 2016-12-06 10:03
New changeset 150d36dbe3ba by Victor Stinner in branch '3.6':
warnings: Fix the issue number
https://hg.python.org/cpython/rev/150d36dbe3ba
msg282513 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2016-12-06 10:15
I pushed a more complete version of my patch:

New changeset 726308cfe3b5 by Victor Stinner in branch '3.6':
catch_warnings() calls showwarning() if overriden
https://hg.python.org/cpython/rev/726308cfe3b5


I dislike pushing a different change than the reviewed change, but I was in a hurry for the Python 3.6.0 release :-/ Sorry about that.

Please double-check the pushed change!

(I used the wrong issue number, fixed in the following commit.)


The final change also fixes the bug reported by Martin:

Martin: "Actually, I found a regression. Looks like you also need to cancel any showwarning() function set by the user:"

I fixed it in catch_warnings() with these lines:

            # Reset showwarning() to the default implementation to make sure
            # that _showwarnmsg() calls _showwarnmsg_impl()
            self._module.showwarning = self._module._showwarning

It also added a new unit test for this scenario.


Serhiy Storchaka: "I don't understand why test_showwarnmsg_missing was added. Why deleting warnings._showwarnmsg should be supported?"

I don't know well the warnings module. The interactions between the C _warnings module and the Python warnings module are complex. I didn't want to break the backward compatibility, and *technically*, it is possible to delete warnings.showwarning() and warnings.warn("msg") still writes the message into stderr! So I decided to support this corner case, for the backward compatibility.

Code:
---
import warnings
warnings.warn("with showwarning")
del warnings.showwarning
warnings.warn("without showwarning")
---

Output on Python 3.5 (before my showarnmsg() changes):
---
x.py:2: UserWarning: with showwarning
  warnings.warn("with showwarning")
x.py:4: UserWarning: without showwarning
  warnings.warn("without showwarning")
---

Hum, but maybe we should decorate test_showwarnmsg_missing() with @cpython_only to announce that it's a side effect of the implementation, it's not part of the "Python specification".


Serhiy Storchaka: "I would rename _showwarning to _showwarning_orig for accenting it's purpose. It is used only for checking if showwarning was replaced by the user."

Sorry, I suck at naming things :-) Feel free to rename it (after the 3.6.0 release).


By the way, I'm still interested to make showwarnmsg() public in Python 3.7. IMO it's interesting to give access to the new source parameter to custom warning loggers. And it will allow to more easily extend warnings with new parameters (it was the whole purpose of the issue #26568).


I keep the issue open so someone can still review the pushed change.
msg282515 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2016-12-06 10:38
Julien reviewed the pushed change and asked me questions on IRC:

* "nonlocal log": this change is unrelated to the fix, I should have done that in a separated change, sorry, I cannot resist to refactoring :-) The change has no effect, it's more cosmetic to help reviewers: "log is not a local variable nor a global variable, it's a "non-local" variable".

* inner function (calling log.append) renamed from "showarnmsg()" to "showarnmsg_logger()": it's to help debugging. It's a pain when two different functions completely different have the same name, especially for the warnings where many functions are overriden at runtime. Moreover, the function is now used for _showwarnmsg_impl instead of _showwarnmsg, so I also renamed the function to avoid confusion.
msg282516 - (view) Author: Serhiy Storchaka (serhiy.storchaka) * (Python committer) Date: 2016-12-06 10:59
Here is a patch that cleans up the code.
msg282563 - (view) Author: Brett Cannon (brett.cannon) * (Python committer) Date: 2016-12-06 18:24
Serhiy's patch LGTM.
msg282570 - (view) Author: Roundup Robot (python-dev) (Python triager) Date: 2016-12-06 22:15
New changeset aaee06743c61 by Ned Deily in branch '3.6':
Issue #28835: Tidy previous showwarning changes based on review comments.
https://hg.python.org/cpython/rev/aaee06743c61

New changeset 7bca3bf6401a by Ned Deily in branch 'default':
Issue #28835: merge from 3.6
https://hg.python.org/cpython/rev/7bca3bf6401a
msg282571 - (view) Author: Ned Deily (ned.deily) * (Python committer) Date: 2016-12-06 22:16
Thanks everyone for getting this resolved for 360rc1!
msg282646 - (view) Author: Brett Cannon (brett.cannon) * (Python committer) Date: 2016-12-07 18:00
There's also issue #28835 which might be related.
msg282657 - (view) Author: Ned Deily (ned.deily) * (Python committer) Date: 2016-12-07 19:56
Brett, msg282646 ?
msg282725 - (view) Author: Brett Cannon (brett.cannon) * (Python committer) Date: 2016-12-08 18:18
I just happened to look at that bug before seeing this bug and both mentioned recording issues so I thought I would mention there was a chance of a connection.
msg282734 - (view) Author: Martin Panter (martin.panter) * (Python committer) Date: 2016-12-08 20:07
Brett, what was the other bug? The bug number you posted is for this bug.
msg282758 - (view) Author: Nick Coghlan (ncoghlan) * (Python committer) Date: 2016-12-09 03:20
If the intended reference was to #28897, then yes, it was related: NumPy had introduced a workaround for the regression that existed in the beta releases (presumably thinking it was an intentional change that just hadn't been added to the porting guide yet), and this fix for the regression broke their workaround.

Reverting the workaround on the NumPy side restored compatibility :)
History
Date User Action Args
2017-03-31 16:36:16dstufftsetpull_requests: + pull_request909
2016-12-09 03:20:11ncoghlansetmessages: + msg282758
2016-12-08 20:07:57martin.pantersetmessages: + msg282734
2016-12-08 18:18:10brett.cannonsetmessages: + msg282725
2016-12-07 19:56:59ned.deilysetmessages: + msg282657
2016-12-07 18:00:23brett.cannonsetmessages: + msg282646
2016-12-06 22:16:58ned.deilysetstatus: open -> closed
priority: release blocker ->
versions: + Python 3.7
messages: + msg282571

resolution: fixed
stage: commit review -> resolved
2016-12-06 22:15:28python-devsetmessages: + msg282570
2016-12-06 18:24:01brett.cannonsetnosy: + brett.cannon
messages: + msg282563
2016-12-06 10:59:11serhiy.storchakasetfiles: + showwarning-tidy.patch

messages: + msg282516
2016-12-06 10:38:55vstinnersetmessages: + msg282515
2016-12-06 10:15:13vstinnersetmessages: + msg282513
2016-12-06 10:03:16python-devsetnosy: + python-dev
messages: + msg282512
2016-12-06 09:50:28serhiy.storchakasetmessages: + msg282509
2016-12-06 02:53:42martin.pantersetmessages: + msg282493
2016-12-06 02:35:35martin.pantersetnosy: + martin.panter
messages: + msg282492
2016-12-06 01:56:50ncoghlansetnosy: + ncoghlan
messages: + msg282491

assignee: vstinner
type: behavior
stage: commit review
2016-12-05 23:06:53vstinnersetfiles: + warnings_fix-3.patch

messages: + msg282484
2016-12-05 22:57:28mdksetnosy: + mdk
messages: + msg282483
2016-12-05 22:40:38vstinnersetnosy: + serhiy.storchaka
messages: + msg282480
2016-12-05 22:33:20vstinnersetfiles: + warnings_fix-2.patch

messages: + msg282477
2016-12-05 22:28:11vstinnersetfiles: + warnings_fix.patch
keywords: + patch
messages: + msg282476
2016-12-05 20:10:21ned.deilysetmessages: + msg282458
2016-12-01 15:19:28vstinnersetpriority: normal -> release blocker
nosy: + vstinner, ned.deily
messages: + msg282184

2016-11-30 00:29:27Thomas.Robitaillecreate