RFC: Replace print by the Python logging framework in worker. #2290
Conversation
|
I may be useful to see a comparison between old and new output? We could also take the chance to consistently change to usage of f-strings? By the way, completely unrelated: since official-stockfish/books#52 we have SRI checksums for all the books. So we can check the integrity of local books when deciding whether to download books from the repo. I think you know that part of the worker code best, in case you want to give it a try. |
It does not look particularly nice now but it can be further refined. I think for the console logger we should suppress the INFO:worker and INFO:games prompts. I would keep the WARNING: For the file logger (not implemented now) we could add time stamps. |
I guess the idea is that the books in the book repo can be updated without changing their name. Correct? |
BTW is this metadata kept up to date automatically? |
|
Yes, the metadata will be kept up to date from now on. (In the same way that the Sri data for the fishtest worker is kept up to date: manually within each PR). I think we'll still use new versions for new books. But yes, for things like adding missing move numbers (without changing the exits and their order), we can now use the Sri to trigger a book update on the worker. The main reason for the new meta data was to ensure the book data does not corrupted locally over time. We take great care to avoid duplicate book exits etc, so it would be a shame if a small edit in a local book copy invalidates that. |
For the worker it is checked by CI. I was wondering if at least something like this was in place for the books.
Ok I understand. Of course people are not supposed to edit files in the testing folder, but who knows what some people might do... |
|
It's not checked within the ci yet. But I can look into setting that up. |
I think it would be a good idea. In my experience people do not keep metadata/documentation up to date unless it is enforced in some way. |
That has now been implemented. |
Some advantages: (1) The Python logging framework is is thread safe so we do not have to worry about printing from different threads. (2) The Python logging framework is very configurable which may be useful in the future. This implementation is very rudimentary since I want to make sure that other people also agree that this is a good thing to do.
|
I am going to close this. It is currently a bit of a distraction. |
| sep="", | ||
| file=sys.stderr, | ||
| ) | ||
| logger.error(f"Failed to update the atime of {path}: " + str(e)) |
There was a problem hiding this comment.
I wrote few fishtest utils scripts using ruff check --select ALL to iron out all the warnings (eg https://github.com/official-stockfish/fishtest/blob/master/server/utils/delta_update_users.py). I learned than f-string in logging is a bad practice, because it is evaluated eagerly, even if that log level is disabled. This is CPU intensive if there are many DEBUG loggings, and it can create weird errors whit code enabled only in DEBUG mode.
logging provides %-formatting that defers string interpolation until after the level log check.
import logging
# A class that raises an error when its string representation is needed.
class Broken:
def __str__(self):
raise ValueError("Broken __str__ conversion!")
# Create an instance of the problematic class.
broken_instance = Broken()
# Configure the logger: set level to INFO so DEBUG messages are not output.
logging.basicConfig(level=logging.INFO)
logger = logging.getLogger(__name__)
# Using an f-string: the expression inside {} is evaluated immediately,
# even though DEBUG messages are disabled.
try:
logger.debug(f"F-string logging: {broken_instance}")
except Exception as e:
print("F-string raised an exception:", e)
# Using %-formatting: the logger.debug method checks the log level first.
# Since DEBUG is disabled, the string interpolation never happens and
# broken_instance.__str__() is not called.
try:
logger.debug("%%-formatting logging: %s", broken_instance)
print("%%-formatting did NOT raise an exception.")
except Exception as e:
print("%%-formatting raised an exception:", e)There was a problem hiding this comment.
Ok that makes sense. I was wondering why the logging frame work has its own string interpolation.
Nowadays it would be natural to use t-strings (lazily evaluated f-strings).
There was a problem hiding this comment.
https://peps.python.org/pep-0750/
template string will be shipped in python 3.14, so it could be used only server side (where not requiring pyramid explicit support).
PROD is running with python 3.13, but 3.13 is not officially tested by pyramid because it breaks on windows.
Pylons/pyramid#3767
3 participants
Some advantages:
(1) The Python logging framework is is thread safe so we do not have to worry about printing from different threads.
(2) The Python logging framework is very configurable which may be useful in the future.
This implementation is very rudimentary since I want to make sure that other people also agree that this is a good thing to do.
I have drafted this since it is a RFC.