Experimental Physics and
Industrial Control System

I also did this simDetector test with base 3.15.5 and there are no monitor callbacks after acquisition is complete.  So the issue was introduced after that release.

 

Mark

 

 

 

I did another test with the simDetector.  This is the setup screen:

 

 

The AcquireTime is 0.1 second, which means it will do 10 callbacks per second.

 

The simulation mode is linear ramp, and the Gain is 1, which means each pixel value will increase by 1 in successive images.  This makes it possible to see if the image is changing, and which image is being received.

 

The ImageMode is Multiple and NumImages=100 which means that when Acquire is set to 1 it will collect 100 images and then stop.

 

The waveform record for the NDStdArrays plugin has 20000000 elements and FTVL=SHORT.  The DataType of the simDetector is UInt16.

 

I made a new Python test program. 

-          It prints the a counter value in the callback function,  which it increments. 

-          It also prints the first value in the waveform record, so we can see how much it is changing. 

-          The program starts the acquisition, and then waits for it to complete by reading the value of the Acquire PV, which will go to 0 after 100 images have been collected.

-          It then waits another 60 seconds for any additional monitor callbacks.

 

(base) corvette:asyn/iocBoot/ioctestAsynPortDriver>more monitor_test_ad.py

from epics import PV

import numpy as np

import time

from datetime import datetime

 

def current_time():

    return datetime.now().strftime('%Y-%m-%d %H:%M:%S.%f')

 

def pv_callback(pvname=None, value=None, timestamp=None, **kw):

    global counter

    counter += 1

    print('%s: pv_callback counter=%d, pvName=%s, size=%d, value=[0]=%d' % (current_time(), counter, pvname, len(value), value[0]))

 

counter = 0

big_array = PV('13SIM1:image1:ArrayData', auto_monitor=True)

print('%s: Adding BIGARRAY callback function' % (current_time()))

big_array.add_callback(pv_callback)

 

acquire = PV('13SIM1:cam1:Acquire', auto_monitor=False)

print('%s: Starting acquisition' % (current_time()))

acquire.put(1)

 

print('%s: Waiting for acquisition to complete' % (current_time()))

while (acquire.get() == 1):

    time.sleep(0.1)

 

print('%s: Acquisition complete' % (current_time()))

print('%s: Sleeping for 60 seconds' % (current_time()))

time.sleep(60)

 

print('%s: Exiting' % (current_time()))

 

This is the output of the Python program when it is run on a remote Windows machine over a 1 Gbit link from the Linux IOC.

 

(base) J:\epics\devel\asyn\iocBoot\ioctestAsynPortDriver>python monitor_test_ad.py

2022-06-25 17:45:08.977807: Adding BIGARRAY callback function

2022-06-25 17:45:08.977807: Starting acquisition

2022-06-25 17:45:09.008815: Waiting for acquisition to complete

2022-06-25 17:45:09.501366: pv_callback counter=1, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=199

2022-06-25 17:45:09.912184: pv_callback counter=2, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=203

2022-06-25 17:45:10.326705: pv_callback counter=3, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=207

2022-06-25 17:45:10.734307: pv_callback counter=4, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=211

2022-06-25 17:45:11.144670: pv_callback counter=5, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=215

2022-06-25 17:45:11.571989: pv_callback counter=6, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=219

2022-06-25 17:45:11.987259: pv_callback counter=7, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=223

2022-06-25 17:45:12.405577: pv_callback counter=8, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=227

2022-06-25 17:45:12.823582: pv_callback counter=9, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=232

2022-06-25 17:45:13.252142: pv_callback counter=10, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=236

2022-06-25 17:45:13.668979: pv_callback counter=11, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=240

2022-06-25 17:45:14.081098: pv_callback counter=12, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=244

2022-06-25 17:45:14.497104: pv_callback counter=13, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=248

2022-06-25 17:45:14.922151: pv_callback counter=14, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=252

2022-06-25 17:45:15.341294: pv_callback counter=15, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=257

2022-06-25 17:45:15.763571: pv_callback counter=16, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=261

2022-06-25 17:45:16.187630: pv_callback counter=17, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=265

2022-06-25 17:45:16.601769: pv_callback counter=18, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=269

2022-06-25 17:45:17.018671: pv_callback counter=19, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=274

2022-06-25 17:45:17.434503: pv_callback counter=20, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=278

2022-06-25 17:45:17.856621: pv_callback counter=21, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=282

2022-06-25 17:45:18.273360: pv_callback counter=22, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=286

2022-06-25 17:45:18.687654: pv_callback counter=23, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=290

2022-06-25 17:45:19.112557: pv_callback counter=24, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=294

2022-06-25 17:45:19.527148: pv_callback counter=25, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:19.950669: pv_callback counter=26, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:19.952671: Acquisition complete

2022-06-25 17:45:19.952671: Sleeping for 60 seconds

2022-06-25 17:45:20.367371: pv_callback counter=27, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:20.782781: pv_callback counter=28, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:21.208172: pv_callback counter=29, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:21.626443: pv_callback counter=30, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:22.042891: pv_callback counter=31, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:22.457375: pv_callback counter=32, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:22.874498: pv_callback counter=33, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:23.294542: pv_callback counter=34, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:23.710515: pv_callback counter=35, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:24.129236: pv_callback counter=36, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:24.554132: pv_callback counter=37, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:24.969318: pv_callback counter=38, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:25.383840: pv_callback counter=39, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:25.815720: pv_callback counter=40, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:26.234223: pv_callback counter=41, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:26.658804: pv_callback counter=42, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:27.075088: pv_callback counter=43, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:27.701913: pv_callback counter=44, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:28.116487: pv_callback counter=45, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:28.766605: pv_callback counter=46, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:29.180284: pv_callback counter=47, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:30.773591: pv_callback counter=48, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:31.971378: pv_callback counter=49, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:32.970545: pv_callback counter=50, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:33.967158: pv_callback counter=51, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:34.783298: pv_callback counter=52, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:35.204079: pv_callback counter=53, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:35.626276: pv_callback counter=54, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:36.041266: pv_callback counter=55, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:36.453080: pv_callback counter=56, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:36.871318: pv_callback counter=57, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:37.285079: pv_callback counter=58, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:37.720734: pv_callback counter=59, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:38.366094: pv_callback counter=60, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:39.229229: pv_callback counter=61, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:39.914253: pv_callback counter=62, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:40.734391: pv_callback counter=63, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:41.148555: pv_callback counter=64, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:41.591978: pv_callback counter=65, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:42.028103: pv_callback counter=66, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:42.508956: pv_callback counter=67, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:43.030108: pv_callback counter=68, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:43.449413: pv_callback counter=69, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:43.862464: pv_callback counter=70, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:44.279789: pv_callback counter=71, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:44.703770: pv_callback counter=72, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:45.137917: pv_callback counter=73, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:45.552173: pv_callback counter=74, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:45.971023: pv_callback counter=75, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:46.388227: pv_callback counter=76, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:46.809020: pv_callback counter=77, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:47.426263: pv_callback counter=78, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:47.849754: pv_callback counter=79, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:48.463381: pv_callback counter=80, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:48.888499: pv_callback counter=81, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:49.300091: pv_callback counter=82, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:49.718147: pv_callback counter=83, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:50.141606: pv_callback counter=84, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:50.557192: pv_callback counter=85, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:50.976428: pv_callback counter=86, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:51.387190: pv_callback counter=87, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:51.802159: pv_callback counter=88, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:52.217662: pv_callback counter=89, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:52.632185: pv_callback counter=90, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:53.051046: pv_callback counter=91, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:53.668667: pv_callback counter=92, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:54.091076: pv_callback counter=93, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:54.508703: pv_callback counter=94, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:54.926338: pv_callback counter=95, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:55.335884: pv_callback counter=96, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:55.756442: pv_callback counter=97, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:56.174092: pv_callback counter=98, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:56.987064: pv_callback counter=99, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:57.603519: pv_callback counter=100, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:45:58.017257: pv_callback counter=101, pvName=13SIM1:image1:ArrayData, size=20000000, value=[0]=299

2022-06-25 17:46:19.955976: Exiting

 

Important things to note:

-          The first waveform element is usually incrementing by 4, not by 1, which means we are only getting every 4’th monitor.  This is because of the speed of the link.

-          The time between starting acquisition and detecting that it is complete is just over 10 seconds.  The acquisition should have taken 10 seconds (100 frames, 0.1 second acquisition time).

-          When acquisition was complete 26 callbacks had been received.

-          After acquisition was complete an additional 75 monitor callbacks were received.  These all have the same first pixel value, which is that of the last image collected.

-          The total number of callbacks was 101, which is 1 more than the total number of images collected.  The +1 is presumably because there is a monitor on the initial connection, before acquisition starts.

-          This behavior is exactly what Dirk observed, although I don’t know if he realized that the total number of monitors eventually received is the total number of times db_post_events was called.

 

When I increased NumImages to 150 there were 34 callbacks before acquisition completed, and a total of 141 callbacks (not 150).

When I increased NumImages to 200 there were 40 callbacks before acquisition completed, and a total of 148 callbacks (not 200).

So it does seem like something is limiting the total number of “stale” callbacks, it does not increase without bound as the number of dropped callbacks increases.

 

I made an interesting observation.  During the period when the client is receiving the stale arrays if I change conditions and start acquisition again (outside the Python program) Python immediately receives the new arrays, it does not continue to receive the stale arrays.  But then when that acquisition stops it will now receive even more stale arrays (those missing in the first acquisition and those missed in the second acquisition.

 

Mark