tooling(ux): better logging in python tests

[felix314159]

🗒️ Description

Small change, big impact: With this instead of relying of of print() + -s we now can just use logging.info("abc"). This is better for many reasons:

• No need to add -s flag
• Shows in which FILE at which LINE the log is issued (great observability)
• Coloring of log levels
• Easy to format (e.g. show current date + time in specified format)
• Never again `if verboseLogging then foo else bar', just use logging.debug() and then temporarily toggle the log level to debug in the pytest.ini

These are the supported debugging levels that have a different color in the terminal:

• logging.debug("i am not shown by default cuz we defined log level INFO for now")
• logging.info("i am GREEN")
• logging.warning("i am BROWN")
• logging.error("i am light RED")
• logging.critical("im dark RED (much danger)")

Next steps:

• Replace all calls of "print()" we have today with logging equivalents

Visualization (subset of output of fill command of a test that uses new logging):

🔗 Related Issues

✅ Checklist

• All: Set appropriate labels for the changes.
• All: Considered squashing commits to improve commit history.
• All: Added an entry to CHANGELOG.md.
• All: Considered updating the online docs in the ./docs/ directory.
• Tests: All converted JSON/YML tests from ethereum/tests have been added to converted-ethereum-tests.txt.
• Tests: A PR with removal of converted JSON/YML tests from ethereum/tests have been opened.
• Tests: Included the type and version of evm t8n tool used to locally execute test cases: e.g., ref with commit hash or geth 1.13.1-stable-3f40e65.
• Tests: Ran mkdocs serve locally and verified the auto-generated docs for new tests in the Test Case Reference are correctly formatted.

[danceratopz]

Please check:

• feat(consume): enable logging, propagate logs to hive results #1361

I tried to use pytest's built-in logging config as you are in this PR, but I couldn't fufil the requirement of getting timestamps in the captured log output from within pytest. Frustratingly, they are visible in the console output, as in your screenshot:

execution-spec-tests/src/pytest_plugins/logging/logging.py

Lines 4 to 9 in c91549c

	Note: While pytest's builtin logging is generally amazing, it does not write timestamps
	when log output is written to pytest's caplog (the captured output for a test). And having
	timestamps in this output is the main use case for adding logging to our plugins.
	This output gets shown in the `FAILURES` summary section, which is shown as the
	"simulator log" in hive simulations. For this use case, timestamps are essential to verify
	timing issues against the clients log.

I'd be happy to be wrong! I find it hard to believe right now that this was an issue, but I remember feeling that way at the time too 😆! I even tried with pytest 8 to see if the behavior had changed.

If you can get it working to show timestamps in hiveview test reports, then we should use pytest's native method and delete the unnecessary code from #1361.

[felix314159]

We can use the custom logger you wrote, but this has nothing to do with this PR as far as I am concerned: I just want a way to help me debug while I am writing a test. Let's say I want to log a value, I can do:

from pytest_plugins.logging import get_logger
logger = get_logger(__name__)

logger.info("i want this to be logged along with time and file and line")

and while this does not lead to any errors, without this PR I won't see anything in my console when filling the test that contains this code. But with this PR (changes to the pytest.ini) I now can see my logged string in the console like I want to and like it is shown in the screenshot.