This page was generated from docs/examples/logging/logging_example.ipynb. Interactive online version: Binder badge.

Logging

TL;DR

  • There is a QCoDeS logging module: qcodes.logger

  • Call logger.start_all_logging at the start of every script/session to make sure all log messages get stored to the .qcodes/logs folder in your home directory, or set logger.start_logging_on_import to True in your qcodesrc.json configuration.

  • For debugging purposes you can log messages of an individual instrument (and see the VISA dialog).

  • You can obtain all logging messages in a pandas.DataFrame for further analysis.

Contents

Introduction

Python offers an excellent logging framework that is widely used in QCoDeS. As a user, you might be interested in reading the log messages that are generated by QCoDeS for debugging and also profiling purposes.

All log records(i.e., messages and metadata) are created using a python logging.logger object. In QCoDeS there is a logger for every module with the same name as the module itself, i.e., you can use logging.getLogger('qcodes.instrument.base') for getting the logger of the QCoDeS Instrument. From the dots in the names of the loggers a hierarchy is defined, at the top of which is the so called root logger that catches all messages. The log records created in a logger are processed by the handlers that have been attached to this specific logger. The handlers can, for example, be used to output the log messages into different locations, like the console or a log file.

Every logger, handler and log record has an associated level. The default levels are: CRITICAL, ERROR, WARNING, INFO and DEBUG. The levels determine how messages are passed: a logger passes only records that exceeds its minimal passing level to its handlers and the handlers in turn only output those messages that exceed their minimal passing level.

For a more detailed description of Python logging refer to the official manual (This is all well summed up in this chart)

Instrument communication loggers

Not all the used loggers in QCoDeS follow the previously presented rule of naming the logger after the module. For instruments there are the following loggers:

  • qcodes.instrument.base.com: This logger logs all the communication of the Instrument and its descendants with the actual physical instruments, e.g., the messages generated by the write and query calls.

  • qcodes.instrument.base.com.visa: This is a sublogger that logs all the communication related messages of the VisaInstrument and its descendants.

Set up logging in QCoDeS

At the beginning of every experiment script file you should include the following lines:

[1]:

from qcodes.logger import start_all_logging

start_all_logging()

Logging hadn't been started.
Activating auto-logging. Current session state plus future input saved.
Filename       : /home/runner/.qcodes/logs/command_history.log
Mode           : append
Output logging : True
Raw input log  : False
Timestamping   : True
State          : active
Qcodes Logfile : /home/runner/.qcodes/logs/261009-9129-qcodes.log

The call to start_all_logging does two things:

  1. Create handlers to output logging messages from the root logger to the console and to a log file.

  2. Enable logging of the IPython commands into a separate log file.

Alternatively we can configure qcodes to automatically start logging on every import of qcodes, by running the following code once. (This will persist the current configuration in ~\qcodesrc.json)

[2]:

# Code is commented out to not set this by accident. Uncomment to activate
# from qcodes import config

# config.logger.start_logging_on_import = "always"
# config.save_to_home()

QCoDeS default handlers

The effect of the console handler can be seen in the two printed lines with a red background below the previous code cell. Every line corresponds to a log record. The fields of the records are separated by ¦ and have the following meaning:

  1. time stamp

  2. logger name, here the module name

  3. record log level

  4. name of the function that created the log message

  5. line at which the message has been issued

  6. actual log message

The same format is used for the file handler. By default QCoDeS logs to the file <user directory>/.qcodes/logs/qcodes.log. To avoid endlessly long files, the files roll over at midnight and get the date appended to their name where qcodes.log without date always gives you the log messages of the same day.

To configure the levels you want to log/handle, you need to edit the qcodesrc.json file in you home directory. The default values are:

"logger":{
    "console_level": "WARNING",
    "file_level": "INFO",
    "logger_levels":{
        "pyvisa": "INFO"
    }

While console_level and file_level describe the levels of the two default handlers described previously, logger_levels is a dictionary that can be used to limit the messages passed on by module level loggers. This means with these defaults, the pyvisa module will not log messages on a DEBUG level. Therefore setting the console_level to DEBUG will not show the pyvisa debug messages (you certainly don’t want to see them as they log every single character that is passed to an instrument with an individual message). On the other hand setting the console level to warning will still suppress pyvisa info messages.

IPython command history

The output above that follows these logging messages comes from IPython. It tells us that all issued IPython commands will be logged to a file. The file lives in the same log directory as the python logs and is called command_history.log. It will not roll over.

To change the command history logging directory you will need to call start_command_history_logger with the new path as an argument.

Temporarily elevating the logging level

Sometimes you might wish to catch more than that meets to the eye. To this end, one can temporarily elevate the logging level to catch all debug messages by using a context manager. This can simply be done via:

[3]:

import logging

from qcodes import logger

log = logging.getLogger("example_logger")

log.debug("This message will not be visible as the logging level is set to `DEBUG`")

with logger.console_level(logging.DEBUG):
    log.debug(
        "This message is visible as the logging level is temporarily elevated to `DEBUG`"
    )

log.debug("The level is back to what it used to be")

2026-10-09 07:23:50,295 ¦ example_logger ¦ DEBUG ¦ 2067591600 ¦ <module> ¦ 10 ¦ This message is visible as the logging level is temporarily elevated to `DEBUG`

For other handlers than the console handler, you can do the same thing using the handler_level context manager.

Filtering log messages by instrument

A very common use case for logging in QCoDeS is to analyze the communication with a VISA instrument. For this purpose the logger module provides a context manager to filter the logging messages by instrument.

Generally one could of course simply attach a handler to the logger of qcodes.instrument_drivers.Vendor.Type but this would not show the messages that are generated by the visa communication in qcodes.instrument.visa. Additionally with the approach implemented here one can not only filter messages for a given type of instrument but also of a specific instance.

To demonstrate this consider the following mock up of the AMI430 Magnet controller that consists of individual VISA instruments for each axis, here with the names x, y and z:

[4]:

import numpy as np

from qcodes.instrument_drivers.american_magnetics import AMIModel430, AMIModel4303D

mag_x = AMIModel430(
    "x", address="GPIB::1::INSTR", pyvisa_sim_file="AMI430.yaml", terminator="\n"
)
mag_y = AMIModel430(
    "y", address="GPIB::2::INSTR", pyvisa_sim_file="AMI430.yaml", terminator="\n"
)
mag_z = AMIModel430(
    "z", address="GPIB::3::INSTR", pyvisa_sim_file="AMI430.yaml", terminator="\n"
)

field_limit = [
    lambda x, y, z: x == 0 and y == 0 and z < 3,
    lambda x, y, z: np.linalg.norm([x, y, z]) < 2,
]

driver = AMIModel4303D("AMI430_3D", mag_x, mag_y, mag_z, field_limit)

Connected to: QCoDeS AMI430_simulation (serial:1337, firmware:0.0.01) in 0.02s
Connected to: QCoDeS AMI430_simulation (serial:1337, firmware:0.0.01) in 0.00s
Connected to: QCoDeS AMI430_simulation (serial:1337, firmware:0.0.01) in 0.00s

In the above messages you can see the prefix [<instrument_name>(<instrument_type>)]. To analyze the visa communication one can use filter_instrument:

[5]:

driver.cartesian((0, 0, 0))
with logger.console_level("DEBUG"), logger.filter_instrument(mag_x):
    driver.cartesian((0, 0, 1))

2026-10-09 07:23:50,362 ¦ qcodes.instrument.instrument_base.com.visa ¦ DEBUG ¦ visa ¦ ask_raw ¦ 449 ¦ [x(AMIModel430)] Querying: STATE?
2026-10-09 07:23:50,363 ¦ qcodes.instrument.instrument_base.com.visa ¦ DEBUG ¦ visa ¦ ask_raw ¦ 451 ¦ [x(AMIModel430)] Response: 2
2026-10-09 07:23:50,364 ¦ qcodes.instrument.instrument_base.com.visa ¦ DEBUG ¦ visa ¦ ask_raw ¦ 449 ¦ [x(AMIModel430)] Querying: FIELD:MAG?
2026-10-09 07:23:50,364 ¦ qcodes.instrument.instrument_base.com.visa ¦ DEBUG ¦ visa ¦ ask_raw ¦ 451 ¦ [x(AMIModel430)] Response: 0.0
2026-10-09 07:23:50,365 ¦ qcodes.instrument.instrument_base.com.visa ¦ DEBUG ¦ visa ¦ ask_raw ¦ 449 ¦ [x(AMIModel430)] Querying: FIELD:MAG?
2026-10-09 07:23:50,365 ¦ qcodes.instrument.instrument_base.com.visa ¦ DEBUG ¦ visa ¦ ask_raw ¦ 451 ¦ [x(AMIModel430)] Response: 0.0

The output on the console shows as expected only messages from the x instrument. For multiple instruments pass a sequence of instruments to filter_instrument we write:

[6]:

driver.cartesian((0, 0, 0))
with logger.console_level("DEBUG"), logger.filter_instrument((mag_x, mag_y)):
    driver.cartesian((0, 0, 1))

2026-10-09 07:23:50,371 ¦ qcodes.instrument.instrument_base.com.visa ¦ DEBUG ¦ visa ¦ ask_raw ¦ 449 ¦ [x(AMIModel430)] Querying: STATE?
2026-10-09 07:23:50,371 ¦ qcodes.instrument.instrument_base.com.visa ¦ DEBUG ¦ visa ¦ ask_raw ¦ 451 ¦ [x(AMIModel430)] Response: 2
2026-10-09 07:23:50,372 ¦ qcodes.instrument.instrument_base.com.visa ¦ DEBUG ¦ visa ¦ ask_raw ¦ 449 ¦ [y(AMIModel430)] Querying: STATE?
2026-10-09 07:23:50,372 ¦ qcodes.instrument.instrument_base.com.visa ¦ DEBUG ¦ visa ¦ ask_raw ¦ 451 ¦ [y(AMIModel430)] Response: 2
2026-10-09 07:23:50,373 ¦ qcodes.instrument.instrument_base.com.visa ¦ DEBUG ¦ visa ¦ ask_raw ¦ 449 ¦ [x(AMIModel430)] Querying: FIELD:MAG?
2026-10-09 07:23:50,373 ¦ qcodes.instrument.instrument_base.com.visa ¦ DEBUG ¦ visa ¦ ask_raw ¦ 451 ¦ [x(AMIModel430)] Response: 0.0
2026-10-09 07:23:50,374 ¦ qcodes.instrument.instrument_base.com.visa ¦ DEBUG ¦ visa ¦ ask_raw ¦ 449 ¦ [y(AMIModel430)] Querying: FIELD:MAG?
2026-10-09 07:23:50,374 ¦ qcodes.instrument.instrument_base.com.visa ¦ DEBUG ¦ visa ¦ ask_raw ¦ 451 ¦ [y(AMIModel430)] Response: 0.0
2026-10-09 07:23:50,375 ¦ qcodes.instrument.instrument_base.com.visa ¦ DEBUG ¦ visa ¦ ask_raw ¦ 449 ¦ [x(AMIModel430)] Querying: FIELD:MAG?
2026-10-09 07:23:50,375 ¦ qcodes.instrument.instrument_base.com.visa ¦ DEBUG ¦ visa ¦ ask_raw ¦ 451 ¦ [x(AMIModel430)] Response: 0.0
2026-10-09 07:23:50,376 ¦ qcodes.instrument.instrument_base.com.visa ¦ DEBUG ¦ visa ¦ ask_raw ¦ 449 ¦ [y(AMIModel430)] Querying: FIELD:MAG?
2026-10-09 07:23:50,376 ¦ qcodes.instrument.instrument_base.com.visa ¦ DEBUG ¦ visa ¦ ask_raw ¦ 451 ¦ [y(AMIModel430)] Response: 0.0

One logger per instrument

By default all instruments share a single logger, named qcodes.instrument.instrument_base (and ...instrument_base.com.visa for the VISA communication). This means that calling setLevel, addHandler or setting propagate on instrument.log.logger affects every other instrument in the process as well.

A driver can opt in to a logger of its own by setting default_logger_scope to "instrument". This can be done on the driver class, which also works for drivers you do not control:

[7]:

class ScopedAMIModel430(AMIModel430):
    default_logger_scope = "instrument"


mag_w = ScopedAMIModel430(
    "w", address="GPIB::4::INSTR", pyvisa_sim_file="AMI430.yaml", terminator="\n"
)

print(mag_w.log.logger.name)
print(mag_w.visa_log.logger.name)
print(mag_w.switch_heater.log.logger.name)
print(mag_x.log.logger.name)

Connected to: QCoDeS AMI430_simulation (serial:1337, firmware:0.0.01) in 0.00s
__main__.ScopedAMIModel430.w
__main__.ScopedAMIModel430.w.com.visa
__main__.ScopedAMIModel430.w.switch_heater
qcodes.instrument.instrument_base

The logger name is built from the root driver’s module-qualified class followed by the name of the instrument and the keys of its submodules, so scoped loggers mirror the instrument hierarchy. For example, AMIModel430 uses the class logger qcodes.instrument_drivers.american_magnetics.AMI430_visa.AMIModel430, an instrument named mag_x uses qcodes.instrument_drivers.american_magnetics.AMI430_visa.AMIModel430.mag_x, its switch heater module uses qcodes.instrument_drivers.american_magnetics.AMI430_visa.AMIModel430.mag_x.switch_heater, and its VISA traffic uses qcodes.instrument_drivers.american_magnetics.AMI430_visa.AMIModel430.mag_x.com.visa. A submodule is named after the key it is added with in add_submodule (switch_heater), not after its own name (SwitchHeater) or class. Every logger is a child of the previous one, so a level or handler set on the logger of an instrument also covers its modules and its VISA traffic. Opted-in drivers are no longer children of qcodes.instrument.instrument_base, so levels configured there are not inherited.

The scope is looked up on the root instrument when the instrument is created, so it has to be set before instantiating the driver and applies to the whole instrument.

The level of a single instrument can now be changed without affecting any other instrument:

[8]:

mag_w.log.logger.setLevel(logging.DEBUG)

print(logging.getLevelName(mag_w.log.logger.getEffectiveLevel()))
print(logging.getLevelName(mag_w.visa_log.logger.getEffectiveLevel()))
print(logging.getLevelName(mag_x.log.logger.getEffectiveLevel()))

DEBUG
DEBUG
NOTSET

Because there is a node per module-qualified driver class, you can also raise the level for every instrument of a driver at once, which is typically what you want while developing or debugging that driver. This works for instruments that do not exist yet, so it can equally well be put in the logger_levels section of qcodesrc.json:

"logger_levels": {"qcodes.instrument_drivers.american_magnetics.AMI430_visa.AMIModel430": "DEBUG"}

[9]:

logging.getLogger(
    f"{ScopedAMIModel430.__module__}.{ScopedAMIModel430.__qualname__}"
).setLevel(logging.DEBUG)

mag_v = ScopedAMIModel430(
    "v", address="GPIB::2::INSTR", pyvisa_sim_file="AMI430.yaml", terminator="\n"
)

# both instruments of this driver are now at DEBUG, mag_x is untouched
for inst in (mag_w, mag_v):
    print(inst.name, logging.getLevelName(inst.log.logger.getEffectiveLevel()))
print(mag_x.name, logging.getLevelName(mag_x.log.logger.getEffectiveLevel()))

Connected to: QCoDeS AMI430_simulation (serial:1337, firmware:0.0.01) in 0.00s
w DEBUG
v DEBUG
x NOTSET

A few things are worth keeping in mind:

  • QCoDeS attaches its console and file handlers to the root logger and those handlers have their own levels. Lowering the level of an instrument logger to DEBUG only becomes visible if the handler level lets the record through, so combine it with console_level or handler_level as shown above.

  • Setting instrument.log.logger.propagate = False only stops records from reaching ancestor handlers, including QCoDeS’ root handlers — it is not a general mute. Handlers attached directly to that logger still run, and VISA records travel through the separate instrument.visa_log, which propagates independently. Submodule loggers are descendants, so their records are stopped at the instrument as well.

  • A level set on a logger applies to everything below it. Setting the level of ...AMIModel430.mag_x therefore also changes its modules and its VISA traffic at ...AMIModel430.mag_x.com.visa. To change only the wire traffic, set the level of that VISA logger separately.

  • There is no single logger for the VISA traffic of a whole driver class, because every instrument has its own com.visa logger below its name. To change the VISA traffic of all instruments of a driver, set the level for each of them, or set the level of the driver class to change everything.

  • A submodule added with the key com would be the parent of the VISA logger of its instrument. Avoid that key when scoped logging is enabled.

  • A submodule that is not added with add_submodule, such as a channel that only exists in a channel list, has no key and is named after its own name. The logger of a submodule is replaced when it is added, so the messages logged while it is being created, such as the debug message that announces it, go to a logger named after the module itself (...mag_x.SwitchHeater) instead.

  • The logger starts with the module where the driver class is defined. Third-party and notebook drivers may therefore start with qcodes_contrib_drivers, __main__, or another name rather than qcodes. Classes defined inside functions include <locals> in their logger name.

  • Python’s logging registry keeps every logger it creates for the lifetime of the process, and closing an instrument does not release its logger. Instruments with stable names reuse their existing logger, so a normal station is unaffected, but a workload that repeatedly creates instruments under dynamically generated names accumulates one registry entry per distinct name while this scope is enabled.

  • Module-qualified logger names can be long and are shown in the %(name)s field of QCoDeS log output.

Note also that parameters log through the logger of their root instrument, so messages from a channel parameter appear on the root instrument’s logger rather than on the channel’s own logger.

[10]:

mag_w.close()
mag_v.close()

Capturing Pandas.DataFrame

To process the logs, especially with the timestamps, the pandas module is highly suited. With logger.log_to_dataframe or logger.logfile_to_dataframe you can convert a log(file) to a pandas DataFrame. See this notebook for an example.

You can also use a context manager to capture the logs directly into a DataFrame.

[11]:

from qcodes.logger import capture_dataframe

[12]:

with logger.console_level(logging.WARNING):
    driver.cartesian((0, 0, 0))
    with capture_dataframe(level="DEBUG") as (handler, get_dataframe):
        driver.cartesian((0, 0, 1))
        df = get_dataframe()
        driver.cartesian((0, 0, 2))
        df2 = get_dataframe()  # this is the cummulative log

[13]:

df

[13]:
asctime name levelname module funcName lineno message
0 2026-10-09 07:23:50,406 qcodes.instrument.instrument_base DEBUG AMI430_visa _adjust_child_instruments 1078 [AMI430_3D(AMIModel4303D)] Checking whether fi...
1 2026-10-09 07:23:50,406 qcodes.instrument.instrument_base.com.visa DEBUG visa ask_raw 449 [x(AMIModel430)] Querying: STATE?
2 2026-10-09 07:23:50,406 qcodes.instrument.instrument_base.com.visa DEBUG visa ask_raw 451 [x(AMIModel430)] Response: 2
3 2026-10-09 07:23:50,406 qcodes.instrument.instrument_base.com.visa DEBUG visa ask_raw 449 [y(AMIModel430)] Querying: STATE?
4 2026-10-09 07:23:50,406 qcodes.instrument.instrument_base.com.visa DEBUG visa ask_raw 451 [y(AMIModel430)] Response: 2
5 2026-10-09 07:23:50,406 qcodes.instrument.instrument_base.com.visa DEBUG visa ask_raw 449 [z(AMIModel430)] Querying: STATE?
6 2026-10-09 07:23:50,406 qcodes.instrument.instrument_base.com.visa DEBUG visa ask_raw 451 [z(AMIModel430)] Response: 2
7 2026-10-09 07:23:50,406 qcodes.instrument.instrument_base DEBUG AMI430_visa _adjust_child_instruments 1097 [AMI430_3D(AMIModel4303D)] Field values OK, pr...
8 2026-10-09 07:23:50,406 qcodes.instrument.instrument_base DEBUG parameter _get_manual_parameter 311 [AMI430_3D(AMIModel4303D)] Getting raw value o...
9 2026-10-09 07:23:50,406 qcodes.instrument.instrument_base.com.visa DEBUG visa ask_raw 449 [x(AMIModel430)] Querying: FIELD:MAG?
10 2026-10-09 07:23:50,406 qcodes.instrument.instrument_base.com.visa DEBUG visa ask_raw 451 [x(AMIModel430)] Response: 0.0
11 2026-10-09 07:23:50,406 qcodes.instrument.instrument_base.com.visa DEBUG visa ask_raw 449 [y(AMIModel430)] Querying: FIELD:MAG?
12 2026-10-09 07:23:50,406 qcodes.instrument.instrument_base.com.visa DEBUG visa ask_raw 451 [y(AMIModel430)] Response: 0.0
13 2026-10-09 07:23:50,406 qcodes.instrument.instrument_base.com.visa DEBUG visa ask_raw 449 [z(AMIModel430)] Querying: FIELD:MAG?
14 2026-10-09 07:23:50,406 qcodes.instrument.instrument_base.com.visa DEBUG visa ask_raw 451 [z(AMIModel430)] Response: 0.0
15 2026-10-09 07:23:50,406 qcodes.instrument.instrument_base.com.visa DEBUG visa ask_raw 449 [x(AMIModel430)] Querying: FIELD:MAG?
16 2026-10-09 07:23:50,406 qcodes.instrument.instrument_base.com.visa DEBUG visa ask_raw 451 [x(AMIModel430)] Response: 0.0
17 2026-10-09 07:23:50,406 qcodes.instrument.instrument_base.com.visa DEBUG visa ask_raw 449 [y(AMIModel430)] Querying: FIELD:MAG?
18 2026-10-09 07:23:50,406 qcodes.instrument.instrument_base.com.visa DEBUG visa ask_raw 451 [y(AMIModel430)] Response: 0.0
19 2026-10-09 07:23:50,406 qcodes.instrument.instrument_base.com.visa DEBUG visa ask_raw 449 [z(AMIModel430)] Querying: FIELD:MAG?
20 2026-10-09 07:23:50,406 qcodes.instrument.instrument_base.com.visa DEBUG visa ask_raw 451 [z(AMIModel430)] Response: 0.0
21 2026-10-09 07:23:50,406 qcodes.instrument.instrument_base DEBUG parameter _get_manual_parameter 311 [AMI430_3D(AMIModel4303D)] Getting raw value o...
22 2026-10-09 07:23:50,406 qcodes.instrument.instrument_base.com.visa DEBUG visa ask_raw 449 [z(AMIModel430)] Querying: COIL?
23 2026-10-09 07:23:50,406 qcodes.instrument.instrument_base.com.visa DEBUG visa ask_raw 451 [z(AMIModel430)] Response: 2.0
24 2026-10-09 07:23:50,406 qcodes.instrument.instrument_base.com.visa DEBUG visa ask_raw 449 [z(AMIModel430)] Querying: CURR:LIMIT?
25 2026-10-09 07:23:50,406 qcodes.instrument.instrument_base.com.visa DEBUG visa ask_raw 451 [z(AMIModel430)] Response: 80
26 2026-10-09 07:23:50,406 qcodes.instrument.instrument_base.com.visa DEBUG visa ask_raw 449 [z(AMIModel430)] Querying: QU?
27 2026-10-09 07:23:50,406 qcodes.instrument.instrument_base.com.visa DEBUG visa ask_raw 451 [z(AMIModel430)] Response: 0
28 2026-10-09 07:23:50,406 qcodes.instrument.instrument_base.com.visa DEBUG visa ask_raw 449 [z(AMIModel430)] Querying: PERS?
29 2026-10-09 07:23:50,406 qcodes.instrument.instrument_base.com.visa DEBUG visa ask_raw 451 [z(AMIModel430)] Response: 0
30 2026-10-09 07:23:50,406 qcodes.instrument.instrument_base.com.visa DEBUG visa ask_raw 449 [z(AMIModel430)] Querying: STATE?
31 2026-10-09 07:23:50,406 qcodes.instrument.instrument_base.com.visa DEBUG visa ask_raw 451 [z(AMIModel430)] Response: 2
32 2026-10-09 07:23:50,406 qcodes.instrument.instrument_base.com.visa DEBUG visa write_raw 432 [z(AMIModel430)] Writing: PAUSE
33 2026-10-09 07:23:50,407 qcodes.instrument.instrument_base.com.visa DEBUG visa write_raw 432 [z(AMIModel430)] Writing: CONF:FIELD:TARG 1.0
34 2026-10-09 07:23:50,407 qcodes.instrument.instrument_base.com.visa DEBUG visa ask_raw 449 [z(AMIModel430)] Querying: PS:INST?
35 2026-10-09 07:23:50,407 qcodes.instrument.instrument_base.com.visa DEBUG visa ask_raw 451 [z(AMIModel430)] Response: 0
36 2026-10-09 07:23:50,407 qcodes.instrument.instrument_base.com.visa DEBUG visa write_raw 432 [z(AMIModel430)] Writing: RAMP
37 2026-10-09 07:23:50,407 qcodes.instrument.instrument_base DEBUG AMI430_visa set_field 488 [z(AMIModel430)] Starting blocking ramp of z t...
38 2026-10-09 07:23:50,407 qcodes.instrument.instrument_base.com.visa DEBUG visa ask_raw 449 [z(AMIModel430)] Querying: STATE?
39 2026-10-09 07:23:50,407 qcodes.instrument.instrument_base.com.visa DEBUG visa ask_raw 451 [z(AMIModel430)] Response: 2
40 2026-10-09 07:23:50,407 qcodes.instrument.instrument_base.com.visa DEBUG visa ask_raw 449 [z(AMIModel430)] Querying: STATE?
41 2026-10-09 07:23:50,407 qcodes.instrument.instrument_base.com.visa DEBUG visa ask_raw 451 [z(AMIModel430)] Response: 2
42 2026-10-09 07:23:50,407 qcodes.instrument.instrument_base DEBUG AMI430_visa set_field 490 [z(AMIModel430)] Finished blocking ramp 
[14]:

df2

[14]:
asctime name levelname module funcName lineno message
0 2026-10-09 07:23:50,406 qcodes.instrument.instrument_base DEBUG AMI430_visa _adjust_child_instruments 1078 [AMI430_3D(AMIModel4303D)] Checking whether fi...
1 2026-10-09 07:23:50,406 qcodes.instrument.instrument_base.com.visa DEBUG visa ask_raw 449 [x(AMIModel430)] Querying: STATE?
2 2026-10-09 07:23:50,406 qcodes.instrument.instrument_base.com.visa DEBUG visa ask_raw 451 [x(AMIModel430)] Response: 2
3 2026-10-09 07:23:50,406 qcodes.instrument.instrument_base.com.visa DEBUG visa ask_raw 449 [y(AMIModel430)] Querying: STATE?
4 2026-10-09 07:23:50,406 qcodes.instrument.instrument_base.com.visa DEBUG visa ask_raw 451 [y(AMIModel430)] Response: 2
... ... ... ... ... ... ... ...
81 2026-10-09 07:23:50,567 qcodes.instrument.instrument_base.com.visa DEBUG visa ask_raw 449 [z(AMIModel430)] Querying: STATE?
82 2026-10-09 07:23:50,567 qcodes.instrument.instrument_base.com.visa DEBUG visa ask_raw 451 [z(AMIModel430)] Response: 2
83 2026-10-09 07:23:50,567 qcodes.instrument.instrument_base.com.visa DEBUG visa ask_raw 449 [z(AMIModel430)] Querying: STATE?
84 2026-10-09 07:23:50,567 qcodes.instrument.instrument_base.com.visa DEBUG visa ask_raw 451 [z(AMIModel430)] Response: 2
85 2026-10-09 07:23:50,567 qcodes.instrument.instrument_base DEBUG AMI430_visa set_field 490 [z(AMIModel430)] Finished blocking ramp

86 rows × 7 columns

You can of course combine the context managers:

[15]:

with logger.console_level(logging.WARNING):
    driver.cartesian((0, 0, 0))
    with (
        capture_dataframe(level="DEBUG") as (handler, get_dataframe),
        logger.filter_instrument(mag_x, handler=handler),
    ):
        driver.cartesian((0, 0, 1))
        df = get_dataframe()
df

[15]:
asctime name levelname module funcName lineno message
0 2026-10-09 07:23:50,590 qcodes.instrument.instrument_base.com.visa DEBUG visa ask_raw 449 [x(AMIModel430)] Querying: STATE?
1 2026-10-09 07:23:50,590 qcodes.instrument.instrument_base.com.visa DEBUG visa ask_raw 451 [x(AMIModel430)] Response: 2
2 2026-10-09 07:23:50,590 qcodes.instrument.instrument_base.com.visa DEBUG visa ask_raw 449 [x(AMIModel430)] Querying: FIELD:MAG?
3 2026-10-09 07:23:50,590 qcodes.instrument.instrument_base.com.visa DEBUG visa ask_raw 451 [x(AMIModel430)] Response: 0.0
4 2026-10-09 07:23:50,591 qcodes.instrument.instrument_base.com.visa DEBUG visa ask_raw 449 [x(AMIModel430)] Querying: FIELD:MAG?
5 2026-10-09 07:23:50,591 qcodes.instrument.instrument_base.com.visa DEBUG visa ask_raw 451 [x(AMIModel430)] Response: 0.0

For an analysis of the timestamps please also refer to the log analysis example notebook.

Telemetry

The QCoDeS Measurement Context manager, DataSaverBuilder and DoND functions are instrumented as OpenTelemetry traces. This enables users to correlate log messages with the the measurement that they were performed within. See the (OpenTelemetry)[https://opentelemetry.io/] documentation for examples of how this can be used.

[ ]: