Acquisition rate decreases over number of scans within one Yaqc-cmds session, regardless of queue age/length

[DLafayetteII]

See title. I observe the slowdown (more time spent per data point) shown in the figure by running 40 minute scans repeatedly. There was a 4+ hour gap in labtime at the new-queue point.

If I reboot yaqc-cmds, the acquisition speed improves back to original rate. We are not stressing the computer hardware according to the task-master.

I have marked this as high priority, since this degree of extension of scan duration inversely affects the amount of averaging and signal to noise we can achieve. I have lost at least a full day of scanning over the past week due to this bug.

[DLafayetteII]

I calculate the time per point by calculating the scan duration and dividing by the number of points within each scan. I calculate the scan duration by taking the difference in labtime of the first and last index.

Relatedly, if I omit the first and last data point of the scans (trying to avoid inclusion of processing or startup time for acquisition transitions), I see the same trend but no spikes, meaning the spikes come from issues with transitions.

[DLafayetteII]

Looking at a couple select scans, all data points share ~equal weight in the extended acquisition time. Here I just plot data point index progress against real time for my first and last scan :

If I plot the slope of these lines, which is the seconds/point, for a few different scans, we see what looks to be a constant slope during scans, and a slight increase between scans. Look at the way these three plots touch on slope = 1.90, and you should see a difference between scans:

This stepped behavior suggests that the duration of acquiring a data point does not increase within a scan, but is inflated in subsequent scans due to having ran the previous scan.

[ddkohler]

somatic.acquisition.worker

https://github.com/wright-group/yaqc-cmds/blob/5d60df690d8082082d5129be3a7100666eee29cc/yaqc_cmds/somatic/acquisition.py#L91

I propose we stick in some timer logging to see which parts of the worker are slowing down as we go.

[untzag]

My two cents.

• This could be a very old bug. I'm not aware of any examples where we enqueued this many scans historically. I wouldn't weigh new changes as more suspicious here.

• If the scans speed up when you restart, I'm suspicious of a memory leak. I know you've looked at task manager, but I'm still suspicious. If you don't already, consider using system-monitor [1] as an additional sensor.

• I don't know the complexity of your experiments, but if they are very repetitive and long lasting you might consider writing a script and not using yaqc-cmds. Memory leaks can be really hard in complex multithreaded applications like yaqc-cmds, and that can make such software a poor choice for very long-lasting experiments. We could chat about the feasibility of script writing later if you wish.

[1] https://yaq.fyi/daemons/system-monitor/

[DLafayetteII]

Just to update, we do not observe the same behavior using bluesky-cmds for the acquisition software.