mdmintz / pynose

pynose fixes nose to extend unittest and make testing easier
https://pypi.org/project/pynose/
GNU Lesser General Public License v2.1
14 stars 6 forks source link

Enable logcapture plugin by default #22

Closed millerdev closed 8 months ago

millerdev commented 8 months ago

Previously it was impossible to enable the plugin. This change was copied from the original nose source code.

mdmintz commented 8 months ago

Nope. See https://github.com/mdmintz/pynose/pull/12 for details.

millerdev commented 8 months ago

This is for log capture, not stdout. I see no reference to the logcapture plugin on #12.

mdmintz commented 8 months ago

It's set as needed. See: https://github.com/mdmintz/pynose/blob/12eda1043b7d118d0e3a6d2c3e805615d8151838/nose/plugins/logcapture.py#L102

mdmintz commented 8 months ago

And those logs were very noisy. Definitely don't want that enabled by default.

millerdev commented 8 months ago

Yes, it is noisy. However, when I'm running tests with pynose I'm seeing log output where previously I was not with nose 1.3.7. That's because the logcapture plugin is disabled by default in pynose, where it was not in nose.

Also, the documentation says it's enabled by default:

https://github.com/mdmintz/pynose/blob/12eda1043b7d118d0e3a6d2c3e805615d8151838/nose/plugins/logcapture.py#L5-L6

However, that was changed in the Add "pynose" files commit way back at the beginning of pynose:

https://github.com/mdmintz/pynose/blob/5b7314a0a7c1ad61a98fb506dca54a095aa9ad30/nose/plugins/logcapture.py#L113

which differs from the same line in nose 1.3.7

            default=not env.get(self.env_opt), dest="logcapture",

It's set as needed.

env_opt = 'NOSE_NOLOGCAPTURE'

The logcapture plugin disables itself based on the value of self.logcapture, which was defaulting to 0 in pynose, which means that contrary to its own documentation, it is disabled by default.

https://github.com/mdmintz/pynose/blob/12eda1043b7d118d0e3a6d2c3e805615d8151838/nose/plugins/logcapture.py#L158-L159

mdmintz commented 8 months ago

Show me an example test where you see more logs in pynose than regular nose. pynose hides default logs, but shows the output of print() statements. That was the goal.

millerdev commented 8 months ago

Here is output from a test in https://github.com/dimagi/commcare-hq, where we're attempting to replace nose with pynose.

Test command

./manage.py test -x corehq.motech.repeaters.tests.test_repeater:DataSourceRepeaterTest

nose output

..
----------------------------------------------------------------------
Ran 2 tests in 4.685s

OK

pynose output (after running pip uninstall nose; pip install pynose)

.WARNING:kafka.consumer.group:use auto_offset_reset=earliest (smallest is deprecated)
INFO:pillowtop:(case-pillow-test_cases-20230524-test_case-search-20230524-messaging-sync) setting checkpoint: {"case-sql,0": 3672}
.
----------------------------------------------------------------------
Ran 2 tests in 5.000s

OK

Applying this PR to pynose makes the output of both identical.

millerdev commented 8 months ago

--nologcapture does nothing meaningful in pynose because that option is configured with store_false.

https://github.com/mdmintz/pynose/blob/5b7314a0a7c1ad61a98fb506dca54a095aa9ad30/nose/plugins/logcapture.py#L112-L113

--nologcapture effectively changes the value of options.logcapture from the deafult 0 (false) to False when the it is used on the command line.

The env_opt = 'NOSE_NOLOGCAPTURE' in the logcapture plugin also does nothing. It is not referenced.

mdmintz commented 8 months ago

Try with https://github.com/seleniumbase/SeleniumBase/tree/master/examples (I'm not seeing any warnings)

mdmintz commented 8 months ago

You'll have to show me either a basic example script I can run for the warnings, or an example of it in SeleniumBase so that I can verify the before & after part.

mdmintz commented 8 months ago

OK, I verified. logcapture is set the way I want it. (Where you can see the output of print() statements.)

millerdev commented 8 months ago

logcapture does not affect print() statements, it affects logging output. I will make a simpler example tomorrow.

mdmintz commented 8 months ago

I tested with the following when running pynose:

from seleniumbase import BaseCase

class MyTestClass(BaseCase):
    def test_base(self):
        print("hi!")

Using default=1, dest="logcapture", I don't see the print().

Using default=0, dest="logcapture", I do see the print(), which is what I want, and what it's currently set to.

millerdev commented 8 months ago
$ cat > test.py << EOF
import logging

def test_print():
    print("print")

def test_logging():
    log = logging.getLogger()
    log.error("log")
EOF

$ sed -i 's/default=.,/default=0,/g' nose/plugins/logcapture.py 
$ pynose test.py
print
.log
.
----------------------------------------------------------------------
Ran 2 tests in 0.001s

OK

$ sed -i 's/default=.,/default=1,/g' nose/plugins/logcapture.py 
$ pynose test.py
print
..
----------------------------------------------------------------------
Ran 2 tests in 0.000s

OK

Similarly with SeleniumBase

hi! is printed with both default=1 and default=0.

$ python -m venv sb
$ . sb/bin/activate
(sb) $ pip install -e .  # install pynose in cwd
(sb) $ pip install seleniumbase

(sb) $ cat > sbtest.py << EOF
from seleniumbase import BaseCase

class MyTestClass(BaseCase):
    def test_base(self):
        print("hi!")
EOF

(sb) $ sed -i 's/default=.,/default=1,/g' nose/plugins/logcapture.py
(sb) $ pynose sbtest.py --headless
hi!
.
----------------------------------------------------------------------
Ran 1 test in 0.300s

OK

(sb) $ sed -i 's/default=.,/default=0,/g' nose/plugins/logcapture.py
(sb) $ pynose sbtest.py --headless
hi!
.
----------------------------------------------------------------------
Ran 1 test in 0.312s

OK
mdmintz commented 8 months ago

Good morning. Today I had some time to review all the details for this and provide better feedback. (A maintainer's life is busy, especially with full-time paid work on top of that.)

Have you seen pynose/nose/plugins/capture.py?

It provides an option to undo the defaults that were set in pynose in regards to log capture.

If you use: --capture-output:

pynose --capture-output

... then you will no longer see the output of the print() statements that you are trying to capture.

You can also set that in your environment: os.environ["NOSE_CAPTURE"] = "1" Then you won't need to add --capture-output every time you run pynose.

millerdev commented 8 months ago

Have you seen pynose/nose/plugins/capture.py?

Yes. That captures output to stdout. I am not concerned with that at this time.

... then you will no longer see the output of the print() statements that you are trying to capture.

I am trying to fix capturing of logging output, NOT print() statements.

Depending on how logging is configured, it will send its output to stderr, which is not affected by --capture-output. Currently pynose has no way to enable capturing only logging output because pynose/nose/plugins/logcapture.py is broken.

Did you see and try the simple examples I provided?

mdmintz commented 8 months ago

OK, here's what I'll do: I'll create a --capture-logs option so that all logs can be captured too. (I'll also create an os.environ option for it: "NOSE_CAPTURELOGS")

Changes will arrive in the next release (soon). I've already created a local branch for it. The default levels that are currently set won't be changed.

millerdev commented 8 months ago

I do not understand. Why are you opposed to the tiny change in this PR? There is already a plugin that does what you are proposing, and this is simply fixing a bug in it.

mdmintz commented 8 months ago

I'll be adding command-line options to the existing plugin. Not adding a new plugin.

You're proposing a change that breaks the default behavior of showing logging level warnings and errors. Some people want to see those by default. The better solution is to add an option that changes default behavior, rather than having the default behavior change. You're treating the default settings as a bug because you don't like the default settings. However, the current default settings are intended behavior. You need to take the considerations of other developers into account, and not just make changes for your own personal needs.

millerdev commented 8 months ago

The change I have proposed restores the default behavior of nose as it has been for many years. I think you are the one changing the defaults to match your own personal preferences. But go ahead and make the changes to add those new options. I can live with setting an extra environment variable to restore the behavior that nose has always had.

mdmintz commented 8 months ago

The default logging level for the original nose was DEBUG, which was quite noisy.

pynose was created to fix the bugs with the original nose.

See https://github.com/mdmintz/pynose/releases/tag/v1.5.1 for the changes made to update logging output.