qiboteam / qibolab

Quantum hardware module and drivers for Qibo.
https://qibo.science
Apache License 2.0
42 stars 14 forks source link

Info messages do not appear when QM is used #1041

Open stavros11 opened 1 month ago

stavros11 commented 1 month ago

It seems that the logger from the qm library is somehow disabling all log.info messages (with from qibo.config import log), such as the one in platform.execute showing the expected execution time.

I am trying to fix this for some time without success, so I open an issue for now.

Maybe not related, but it may also be a good idea to get rid of qibo.config completely in 0.2.

alecandido commented 1 month ago

It seems that the logger from the qm library is somehow disabling all log.info messages (with from qibo.config import log), such as the one in platform.execute showing the expected execution time.

I am trying to fix this for some time without success, so I open an issue for now.

Unfortunately, the logger is somewhat global, so it gets complex if a library is affecting it in an improper way.

Maybe not related, but it may also be a good idea to get rid of qibo.config completely in 0.2.

Qibolab is also a library, so we may consider stopping logging (unless we find a strong motivation, and we make sure of doing it consistently). And if it's not very relevant, it is definitely a simplification.

(Btw, in 0.2 there is a function providing the estimate, with more or less the same input of .execute() - if needed, Qibocal can call that function, and log on its level - or postpone it even later, with an even simpler interface)

stavros11 commented 1 month ago

I played a bit with this, mainly out of curiosity, and I found the following:

import logging
import qm

log = logging.getLogger("mylogger")
handler = logging.StreamHandler()
log.addHandler(handler)
log.setLevel(logging.INFO)

log.info("test")

successfully prints test, while if the logger is defined before importing qm:

import logging

log = logging.getLogger("mylogger")

import qm

handler = logging.StreamHandler()
log.addHandler(handler)
log.setLevel(logging.INFO)

log.info("test")

the test message disappears. Clearly, importing qm is doing something that messes up existing loggers.

A clear fix it to have import qm as early as possible in the scripts, before logger definitions. This is not applicable in our case, since we don't control the order of imports in a custom script written by some other user. Also qm is an optional dependency, so moving it as early as possible is not trivial.

Another fix is to redefine a new logger with a new name (the original is destroyed by import qm) inside the QM driver, after the qm imports and use this instead of the original one in all places where logging happens in qibolab. There are various ways to do that, I even tested one and confirmed it works. However, I believe all these ways are messy since they involve manipulating a global (qibolab-wide) object. It also won't solve the issue of qm destroying loggers of other libraries (other than qibolab).

The most appropriate solution is to report to QM and hope that a later version will be more friendly to other library loggers. Since we don't know when this will happen, if this is urgent I can try the fix described above.

I believe the main issue caused by this is that we cannot see the Platform message with the expected experiment execution time. This is certainly annoying but not extremely serious.

alecandido commented 1 month ago

The most appropriate solution is to report to QM and hope that a later version will be more friendly to other library loggers. Since we don't know when this will happen, if this is urgent I can try the fix described above.

I'd say it's not urgent, as I still believe Qibolab should not log (as QM should not do it as well), and at most provide the tools for the downstream to log what needed.

Reporting is definitely appropriate (it is not difficult to find out why it's happening: despite the repo not being open, the code released is Python, and we can read it from the distributed package - but it's also a useless waste of time, at this level).

I believe the main issue caused by this is that we cannot see the Platform message with the expected experiment execution time. This is certainly annoying but not extremely serious.

Indeed, this could be an issue even when the logger will be moved to downstream (to Qibocal, and even more to the application code), but it could be easily patched by turning the log into a bare print - possibly on the standard error, but still with a different mechanism than the Python standard library logger.