BUG: Strange behavior at testing test_ts_plot_with_tz

[StefRe]

I came across a rather strange and annoying behavior when running the plotting tests that leaves me completely clueless.

TestTSPlot.test_ts_plot_with_tz['UTC'] fails when running the whole test suite but passes when run in isolation. In particular it fails when run after all TestRegistration tests and passes when run on its own or after any of the six test functions in TestRegistration:

FAILURE:

(pandas-dev) C:\Daten\Python\pandas>pytest pandas\tests\plotting\ -k "TestRegistration | test_ts_plot_with_tz"
====================================================================== test session starts ======================================================================
platform win32 -- Python 3.8.2, pytest-5.4.3, py-1.9.0, pluggy-0.13.1
rootdir: C:\Daten\Python\pandas, inifile: setup.cfg
plugins: hypothesis-5.19.0, asyncio-0.14.0, cov-2.10.0, forked-1.2.0, xdist-1.32.0
collected 479 items / 460 deselected / 19 selected

pandas\tests\plotting\test_converter.py ......                                                                                                             [ 31%]
pandas\tests\plotting\test_datetimelike.py F............                                                                                                   [100%]

=========================================================================== FAILURES ============================================================================
____________________________________________________________ TestTSPlot.test_ts_plot_with_tz['UTC'] _____________________________________________________________

self = <pandas.tests.plotting.test_datetimelike.TestTSPlot object at 0x000002965C714E20>, tz_aware_fixture = 'UTC'

    @pytest.mark.slow
    def test_ts_plot_with_tz(self, tz_aware_fixture):
        # GH2877, GH17173, GH31205, GH31580
        tz = tz_aware_fixture
        index = date_range("1/1/2011", periods=2, freq="H", tz=tz)
        ts = Series([188.5, 328.25], index=index)
        with tm.assert_produces_warning(None):
            _check_plot_works(ts.plot)
            ax = ts.plot()
            xdata = list(ax.get_lines())[0].get_xdata()
            # Check first and last points' labels are correct
>           assert (xdata[0].hour, xdata[0].minute) == (0, 0)
E           AttributeError: 'numpy.datetime64' object has no attribute 'hour'

pandas\tests\plotting\test_datetimelike.py:57: AttributeError
==================================================================== short test summary info ====================================================================
FAILED pandas/tests/plotting/test_datetimelike.py::TestTSPlot::test_ts_plot_with_tz['UTC'] - AttributeError: 'numpy.datetime64' object has no attribute 'hour'
========================================================= 1 failed, 18 passed, 460 deselected in 2.98s ==========================================================

SUCCESS:

(pandas-dev) C:\Daten\Python\pandas>pytest pandas\tests\plotting\ -k test_ts_plot_with_tz
====================================================================== test session starts ======================================================================
platform win32 -- Python 3.8.2, pytest-5.4.3, py-1.9.0, pluggy-0.13.1
rootdir: C:\Daten\Python\pandas, inifile: setup.cfg
plugins: hypothesis-5.19.0, asyncio-0.14.0, cov-2.10.0, forked-1.2.0, xdist-1.32.0
collected 479 items / 466 deselected / 13 selected

pandas\tests\plotting\test_datetimelike.py .............                                                                                                   [100%]

============================================================== 13 passed, 466 deselected in 2.43s ===============================================================

As I said it passes when run after any of the individual functions in TestRegistration, i.e. with -k "test_register_by_default | test_ts_plot_with_tz", "test_registering_no_warning | test_ts_plot_with_tz" etc.

Tests are run in an environment set up as described here. Pytest and plugin versions see above. Pandas fresh snapshot as of yesterday 1.1.0.dev0+1977.g1706d830d.

I'm pretty sure it's a question of my setup, so sorry for bothering you with it, but maybe someone has any idea or pointers of where to look for the reason of this behavior.

[TomAugspurger]

Not intentional. Most likely there's some state leaking between tests, but I haven't confirmed that. Any investigation here would be welcome.

[StefRe]

Seems to be related to/duplicate of #32331 (Saw it just now when browsing the other 'unreliable tests' issues).

[StefRe]

more specifically it boils down to running both test_pandas_plots_register and test_option_no_warning before test_ts_plot_with_tz (note also the different error now):

(pandas-dev) C:\Daten\Python\pandas>pytest pandas\tests\plotting\ -k "test_pandas_plots_register | test_option_no_warning | test_ts_plot_with_tz & UTC"
====================================================================== test session starts ======================================================================
platform win32 -- Python 3.8.2, pytest-5.4.3, py-1.9.0, pluggy-0.13.1
rootdir: C:\Daten\Python\pandas, inifile: setup.cfg
plugins: hypothesis-5.19.0, asyncio-0.14.0, cov-2.10.0, forked-1.2.0, xdist-1.32.0
collected 479 items / 473 deselected / 6 selected

pandas\tests\plotting\test_converter.py ..                                                                                                                 [ 33%]
pandas\tests\plotting\test_datetimelike.py F...                                                                                                            [100%]

=========================================================================== FAILURES ============================================================================
____________________________________________________________ TestTSPlot.test_ts_plot_with_tz['UTC'] _____________________________________________________________

self = <pandas.tests.plotting.test_datetimelike.TestTSPlot object at 0x000001D2FDEAC550>, tz_aware_fixture = 'UTC'

    @pytest.mark.slow
    def test_ts_plot_with_tz(self, tz_aware_fixture):
        # GH2877, GH17173, GH31205, GH31580
        tz = tz_aware_fixture
        index = date_range("1/1/2011", periods=2, freq="H", tz=tz)
        ts = Series([188.5, 328.25], index=index)
        with tm.assert_produces_warning(None):
            _check_plot_works(ts.plot)
            ax = ts.plot()
            xdata = list(ax.get_lines())[0].get_xdata()
            # Check first and last points' labels are correct
            assert (xdata[0].hour, xdata[0].minute) == (0, 0)
>           assert (xdata[-1].hour, xdata[-1].minute) == (1, 0)
E           assert (0, 0) == (1, 0)
E             At index 0 diff: 0 != 1
E             Use -v to get the full diff

pandas\tests\plotting\test_datetimelike.py:58: AssertionError
==================================================================== short test summary info ====================================================================
FAILED pandas/tests/plotting/test_datetimelike.py::TestTSPlot::test_ts_plot_with_tz['UTC'] - assert (0, 0) == (1, 0)
========================================================== 1 failed, 5 passed, 473 deselected in 1.59s ==========================================================

[StefRe]

if we add print(xdata) after

pandas/pandas/tests/plotting/test_datetimelike.py

Line 55 in bf12604

xdata = list(ax.get_lines())[0].get_xdata()

we see that we get the data from a different plot (xdata should be [Period('2011-01-01 00:00', 'H') Period('2011-01-01 01:00', 'H')]):

in the case of the attribute error:

[Period('2017-01-01 00:00', 'H') Period('2017-01-02 00:00', 'H')
 Period('2017-01-03 00:00', 'H') Period('2017-01-04 00:00', 'H')
 Period('2017-01-05 00:00', 'H') Period('2017-01-06 00:00', 'H')
 Period('2017-01-07 00:00', 'H') Period('2017-01-08 00:00', 'H')
 Period('2017-01-09 00:00', 'H') Period('2017-01-10 00:00', 'H')
 Period('2017-01-11 00:00', 'H') Period('2017-01-12 00:00', 'H')]

in the case of the assertion error:

['2017-01-01T00:00:00.000000000' '2017-01-02T00:00:00.000000000'
 '2017-01-03T00:00:00.000000000' '2017-01-04T00:00:00.000000000'
 '2017-01-05T00:00:00.000000000' '2017-01-06T00:00:00.000000000'
 '2017-01-07T00:00:00.000000000' '2017-01-08T00:00:00.000000000'
 '2017-01-09T00:00:00.000000000' '2017-01-10T00:00:00.000000000'
 '2017-01-11T00:00:00.000000000' '2017-01-12T00:00:00.000000000']

[StefRe]

I tried to wrap my head around it but can't find the root cause.

The immediate failure cause is that the axes object still holds the previous line plot (as first Lines2D object ax.get_lines())[0]). The new test data get into ax.get_lines())[1]. Just adding clf in a class teardown method of TestRegistration doesn't help as after _check_plot_works(ts.plot) the plt state gets restored somehow (if you comment it out and do clf in the previous teardown then everything is OK).

Inside _check_plot_works(ts.plot) we get the correct values. I don't understand, however, how the plt state gets restored: self.plt.clf() before _check_plot_works(ts.plot) doesn't help but if you add it after _check_plot_works(ts.plot) then everything is OK.

So a makeshift workaround is to add self.plt.clf() between these two lines:

pandas/pandas/tests/plotting/test_datetimelike.py

Lines 53 to 54 in 8d10bfb

	_check_plot_works(ts.plot)
	ax = ts.plot()

This doen't however address the root cause. To properly resolve the issue the plt state must be cleared/reset after the TestRegistration tests. I can't figure out, howver, how to do this. Maybe someone more knowledgable of the pandas internals can use these findings and resolve this issue completely.

[StefRe]

Another possibility is to add plt.clf() at the end of test_registering_no_warning, test_pandas_plots_register and test_option_no_warning. This seems cleaner to me as it's close to the origin of the problem, although I'm not completely convinced if this indeed addresses the root cause of the issue.

@mroeschke / @TomAugspurger If you feel that this is sufficient to address this issue I can prepare a PR.

[TomAugspurger]

Cleaning up at the end of the test makes sense.

…

On Thu, Jul 2, 2020 at 7:54 AM Steffen Rehberg ***@***.***> wrote: Another possibility is to add plt.clf() at the end of test_registering_no_warning, test_pandas_plots_register and test_option_no_warning. This seems cleaner to me as it's close to the origin of the problem, although I'm not completely convinced if this indeed addresses the root cause of the issue. @mroeschke <https://github.com/mroeschke> / @TomAugspurger <https://github.com/TomAugspurger> If you feel that this is sufficient to address this issue I can prepare a PR. — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub <#35080 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AAKAOIVV2PCC2E42SPVHIRLRZR7P3ANCNFSM4ONDCRLA> .