Logfile parsing

(back to overview offline,online)

read on nbviewer

Here, we provide an example concerning how to benefit from QCoDeS logs by simple analysis and visualisation.

In [1]:
%matplotlib inline
import dateutil
import os

import pandas as pd
import matplotlib.pyplot as plt

import qcodes as qc
from qcodes.logger import logfile_to_dataframe, time_difference, log_to_dataframe
from zipfile import ZipFile
Logging hadn't been started.
Activating auto-logging. Current session state plus future input saved.
Filename       : C:\Users\jenielse\.qcodes\logs\command_history.log
Mode           : append
Output logging : True
Raw input log  : False
Timestamping   : True
State          : active
Qcodes Logfile : C:\Users\jenielse\.qcodes\logs\220603-13972-qcodes.log
In [2]:
# put the 30MB into a zip file
filepath = os.path.join(os.getcwd(), 'static', 'pythonlog.zip')
with ZipFile(filepath) as z:
    with z.open('pythonlog.log', 'r') as f:
        my_log = [line.decode() for line in f]
In [3]:
os.path.exists(filepath)
Out[3]:
True
In [4]:
logdata = log_to_dataframe(my_log, separator=' - ', columns=['time', 'module', 'function', 'loglevel', 'message'])

The logdata is, now, a nice and tidy DataFrame that one can further manipulate to extract more information, if needed.

In [5]:
logdata
Out[5]:
time module function loglevel message
0 2018-05-10 16:01:50,497 qcodes.instrument_drivers.QDev.QDac_channels write DEBUG Writing to instrument qdac: wav 2 0 0 0;set 2 ...
1 2018-05-10 16:01:50,546 qcodes.instrument.visa ask_raw DEBUG Querying instrument SR860_120: OUTP? 2\r\n
2 2018-05-10 16:01:50,552 qcodes.instrument.visa ask_raw DEBUG Got response from instrument SR860_120: 8.9832...
3 2018-05-10 16:01:50,553 qcodes.instrument.visa ask_raw DEBUG Querying instrument SR860_120: SLVL?\r\n
4 2018-05-10 16:01:50,561 qcodes.instrument.visa ask_raw DEBUG Got response from instrument SR860_120: 9.9999...
... ... ... ... ... ...
255146 2018-05-10 17:12:03,208 qcodes.instrument.visa ask_raw DEBUG Querying instrument SR860_120: OUTP? 2\r\n
255147 2018-05-10 17:12:14,257 qcodes.data.data_set finalize DEBUG Finalising the DataSet. Writing.\r\n
255148 2018-05-10 17:12:14,258 qcodes.data.gnuplot_format write DEBUG Attempting to write the following group: qdac_...
255149 2018-05-10 17:12:14,259 qcodes.data.gnuplot_format write DEBUG Wrote to file from 40200 to 40201\r\n
255150 2018-05-10 17:12:14,378 qdev_wrappers.sweep_functions _do_measurement ERROR Exception in doND\r\n

255151 rows × 5 columns

In [6]:
data = logdata

Get the query time for the SR860

We know that the log file documents an experiment quering an SR860 for R and amplitude over and over. Let us analyse and visualise query response times.

In [7]:
qstr_R = 'Querying instrument SR860_120: OUTP\? 2'  # remember to escape
queries_R = data[data.message.str.contains(qstr_R)]
responses_R = data.loc[queries_R.index + 1]

qstr_lvl = 'Querying instrument SR860_120: SLVL\?'  # remember to escape
queries_lvl = data[data.message.str.contains(qstr_lvl)][:-1]
responses_lvl = data.loc[queries_lvl.index + 1]

Find the elapsed times

In [8]:
elapsed_times_R = time_difference(queries_R.time, responses_R.time)
elapsed_times_lvl =  time_difference(queries_lvl.time, responses_lvl.time)

Visualise!

In [9]:
from pandas.plotting import register_matplotlib_converters
register_matplotlib_converters()

fig, ax = plt.subplots(1,1)
ax.plot(queries_R.time.str.replace(',', '.').astype("datetime64[ns]"), elapsed_times_R, '.', label='R')
ax.plot(queries_lvl.time.str.replace(',', '.').astype("datetime64[ns]"), elapsed_times_lvl, '.', label='LVL')
fig.autofmt_xdate()
ax.set_ylabel('Response time (s)')
plt.legend()
Out[9]:
<matplotlib.legend.Legend at 0x1a32dbd2520>
In [ ]: