push_change_event performance

# 8 years ago
christophe	Hi Tangoers, Using PyTango 8.1.6 on Windows, I have written a small test device in order to measure delays between devices chained with a push_changed_event. In my device server, I create 5 devices (evtperf_0 to evtperf_4) and subscribe each device to the previous manually with ATK : evtperf_0 send an array in the Trig command with the timestamp in the array[0] evtperf_1 receive the array, put the timestamp in array[1] etc. It appears that only the fisrt device (evtperf_1) have a significant and very variable delay with the evtperf_0. I get results from 50 ms to 900 ms if I call the Trig function with ATK. It is stable if Trig is polled … evtperf_0 –> evtperf_1 –> evtperf_2 –> evtperf_3 –> evtperf_4 0.47 0.0 0.0 0.0 Does somebody knows a way to reduce this delay ? Christophe Chappet Attachments: 3Kb

# 8 years ago

Hi Tangoers,
Using PyTango 8.1.6 on Windows, I have written a small test device in order to measure delays between devices chained with a push_changed_event.

In my device server, I create 5 devices (evtperf_0 to evtperf_4) and subscribe each device to the previous manually with ATK :
evtperf_0 send an array in the Trig command with the timestamp in the array[0]
evtperf_1 receive the array, put the timestamp in array[1]
etc.

It appears that only the fisrt device (evtperf_1) have a significant and very variable delay with the evtperf_0.
I get results from 50 ms to 900 ms if I call the Trig function with ATK.
It is stable if Trig is polled …
evtperf_0 –> evtperf_1 –> evtperf_2 –> evtperf_3 –> evtperf_4
0.47 0.0 0.0 0.0

Does somebody knows a way to reduce this delay ?

Christophe Chappet

# 8 years ago
Andy	Hi Christophe, I have run your device server on my laptop running Ubuntu and I observe the same behaviour. There is a delay between the time an event gets pushed from inside the polling of a command or attribute and the time it gets received by the client. I tried running the clients in a different process and making an attribute out of your Trig command. Always the same results. It as if there is a delay between the time an event is pushed inside a command or attribute and the time it is received. Probably related to a monitor but nonetheless this time seems very high. All chained devices receive the pushed even in much less than a few hundred microseconds. I presume there is an explanation but we need an expert to understand this. Cheers Andy

# 8 years ago

Andy

Hi Christophe,

I have run your device server on my laptop running Ubuntu and I observe the same behaviour. There is a delay between the time an event gets pushed from inside the polling of a command or attribute and the time it gets received by the client. I tried running the clients in a different process and making an attribute out of your Trig command. Always the same results. It as if there is a delay between the time an event is pushed inside a command or attribute and the time it is received. Probably related to a monitor but nonetheless this time seems very high. All chained devices receive the pushed even in much less than a few hundred microseconds.

I presume there is an explanation but we need an expert to understand this.

Cheers

Andy

# 8 years ago
Vincent M	Hi Christophe, This problem is directly related to your code and doesn't have much to do with Tango. In the init_device method, you define self.vector as numpy.arange(10000). This numpy array contains integers. When you set the first time stamp with self.vector[0] = time.time(), the float value is cast to an integer, causing the number of milliseconds to discarded. See the following example. `>>> import numpy >>> vector = numpy.arange(10) >>> vector array([0, 1, 2, 3, 4, 5, 6, 7, 8, 9]) >>> vector.dtype dtype('int64') >>> vector[0] = 10.5 >>> vector array([10, 1, 2, 3, 4, 5, 6, 7, 8, 9])` The next devices in the chain don't have this issue because Tango creates the array using the attribute definition, i.e an AttrDataFormat.SPECTRUM of float. Also I don't really see the point of using arange here, so I would define vector as numpy.zeros(10000, dtype=float). With that fix, your performance test works fine. A typical value for Delay with first on evtperf_5 is 3ms. Note that this value depends on the array size, it is about 1ms for an array of size 10. Otherwise thanks for the device, it produces very interesting results /Vincent Edited 8 years ago

# 8 years ago

Vincent M

Hi Christophe,

This problem is directly related to your code and doesn't have much to do with Tango.

In the init_device method, you define self.vector as numpy.arange(10000). This numpy array contains integers. When you set the first time stamp with self.vector[0] = time.time(), the float value is cast to an integer, causing the number of milliseconds to discarded. See the following example.

>>> import numpy
>>> vector = numpy.arange(10)
>>> vector
array([0, 1, 2, 3, 4, 5, 6, 7, 8, 9])
>>> vector.dtype
dtype('int64')
>>> vector[0] = 10.5
>>> vector
array([10,  1,  2,  3,  4,  5,  6,  7,  8,  9])

The next devices in the chain don't have this issue because Tango creates the array using the attribute definition, i.e an AttrDataFormat.SPECTRUM of float. Also I don't really see the point of using arange here, so I would define vector as numpy.zeros(10000, dtype=float).

With that fix, your performance test works fine. A typical value for Delay with first on evtperf_5 is 3ms. Note that this value depends on the array size, it is about 1ms for an array of size 10.

Otherwise thanks for the device, it produces very interesting results smile

/Vincent

Edited 8 years ago

# 8 years ago
Andy	Hi Vincent, well spotted! The problem is now explained. I agree the device is an interesting one and gives a useful output about the performance of events. I attach the results of running the devices on my laptop suing a vector of length=10. I notice there are some outliers over 1ms. This confirms that Tango events are quite fast (average delay is 200 microseconds on same laptop but not hard realtime because now and again the max time > 1 ms. delay-with-first delay-with-previous Andy Attachments:

# 8 years ago

Andy

Hi Vincent,

well spotted! The problem is now explained. I agree the device is an interesting one and gives a useful output about the performance of events. I attach the results of running the devices on my laptop suing a vector of length=10. I notice there are some outliers over 1ms. This confirms that Tango events are quite fast (average delay is 200 microseconds on same laptop but not hard realtime because now and again the max time > 1 ms.

delay-with-first

delay-with-previous

Andy

# 8 years ago
christophe	Hi Vincent, Well spotted ! and it shows again that even errors can produce interesting results Thanks Andy for the benchmark. Christophe