Back Midas Rome Roody Rootana
  Midas DAQ System  Not logged in ELOG logo
Entry  20 Jun 2012, Konstantin Olchanski, Info, midas vme benchmarks lxdaq09cpu.giflxdaq09net.gifladd02cpu.gifladd02net.gif
    Reply  20 Jun 2012, Konstantin Olchanski, Info, midas vme benchmarks 
       Reply  24 Jun 2012, Konstantin Olchanski, Info, midas vme benchmarks Scalers_(1).gif
          Reply  25 Jun 2012, Stefan Ritt, Info, midas vme benchmarks 
             Reply  25 Jun 2012, Konstantin Olchanski, Info, midas vme benchmarks 
          Reply  26 Jun 2012, Konstantin Olchanski, Info, midas vme benchmarks canvas.pdf
             Reply  26 Jun 2012, Konstantin Olchanski, Info, midas vme benchmarks Scalers.gifladd02-cpu.pngladd02-net.pngcanvas-1000-100Hz.pdf
    Reply  21 Jun 2012, Stefan Ritt, Info, midas vme benchmarks Screen_Shot_2012-06-21_at_10.14.09_.png
       Reply  21 Jun 2012, Konstantin Olchanski, Info, midas vme benchmarks 
          Reply  22 Jun 2012, Stefan Ritt, Info, midas vme benchmarks 
             Reply  24 Jun 2012, Konstantin Olchanski, Info, midas vme benchmarks 
Message ID: 816     Entry time: 26 Jun 2012     In reply to: 813     Reply to this: 817
Author: Konstantin Olchanski 
Topic: Info 
Subject: midas vme benchmarks 
> > > I am recording here the results from a test VME system using four VF48 waveform digitizers

Now we look at the detail of the event readout, or if you want, the real-time properties of the MIDAS 
multithreaded VME frontend program.

The benchmark system includes a TRIUMF-made VME-NIMIO32 VME trigger module which records the 
time of the trigger and provides a 20 MHz timestamp register. The frontend program is instrumented to 
save the trigger time and readout timing data into a special "trigger" bank ("VTR0"). The ROOTANA-based 
MIDAS analyzer is used to analyze this data and to make these plots.

Timing data is recorded like this:

NIM trigger signal ---> latched into the IO32 trigger time register (VTR0 "trigger time")
...
int read_event(pevent, etc) {
VTR0 "trigger time" = io32->latched_trigger_time();
VTR0 "readout start time" = io32->timestamp();
read the VF48 data
io32->release_busy();
VTR0 "readout end time" = io32->timestamp();
}

From the VTR0 time data, we compute these values:

1) "trigger latency" = "readout start time" - "trigger time" --- the time it takes us to "see" the trigger
2) "readout time" = "readout end time" - "readout start time" --- the time it takes to read the VF48 data
3) "busy time" = "readout end time" - "trigger time" --- time during which the "DAQ busy" trigger veto is 
active.
also computed is
4) "time between events" = "trigger time" - "time of previous trigger"

And plot them on the attached graphs:

1) "trigger latency" - we see average trigger latency is 5 usec with hardly any events taking more than 10 
usec (notice the log Y scale!). Also notice that there are 35 events that took longer that 100 usec (0.7% out 
of 5000 events).

So how "real time" is this? For "hard real time" the trigger latency should never exceed some maximum, 
which is determined by formal analysis or experimentally (in which case it will carry an experimental error 
bar - "response time is always less than X usec with probability 99.9...%" - the better system will have 
smaller X and more nines). Since I did not record the maximum latency, I can only claim that the 
"response time is always less than 1 sec, I am pretty sure of it".

For "soft real time" systems, such as subatomic particle physics DAQ systems, one is permitted to exceed 
that maximum response time, but "not too often". Such systems are characterized by the quantities 
derived from the present plot (mean response time, frequency of exceeding some deadlines, etc). The 
quality of a soft real time system is usually judged by non-DAQ criteria (i.e. if the DAQ for the T2K/ND280 
experiment does not respond within 20 msec, a neutrino beam spill an be lost and the experiment is 
required to report the number of lost spills to the weekly facility management meeting).

Can the trigger latency be improved by using interrupts instead of polling? Remember that on most 
hardware, the VME and PCI bus access time is around 1 usec and trigger latency of 5-10 usec corresponds 
to roughly 5-10 reads of a PCI or VME register. So there is not much room for speed up. Consider that an 
interrupt handler has to perform at least 2-3 PCI register reads (to determine the source of the interrupt 
and to clear the interrupt condition), it has to wake up the right process and do a rather slow CPU context 
switch, maybe do a cross-CPU interrupt (if VME interrupts are routed to the wrong CPU core). All this 
takes time. Then the Linux kernel interrupt latency comes into play. All this is overhead absent in pure-
polling implementations. (Yes, burning a CPU core to poll for data is wasteful, but is there any other use 
for this CPU core? With a dual-core CPU, the 1st core polls for data, the 2nd core runs mfe.c, the TCP/IP 
stack and the ethernet transmitter.)

2) "readout time" - between 7 and 8 msec, corresponding to the 50 Mbytes/sec VME block transfer rate. 
No events taking more than 10 msec. (Could claim hard real time performance here).

3) "busy time" - for the simple benchmark system it is a boring sum of plots (1) and (2). The mean busy 
time ("dead time") goes straight into the formula for computing cross-sections (if that is what you do).

4) "time between events" - provides an independent measurement of dead time - one can see that no 
event takes less than 7 msec to process and 27 events took longer than 10 msec (0.65% out of 4154 
events). If the trigger were cosmic rays instead of a pulser, this plot would also measure the cosmic ray 
event rate - one would see the exponential shape of the Poisson distribution (linear on Log scale, with the 
slope being the cosmic event rate).


K.O.
Attachment 1: canvas.pdf  18 kB  | Show | Show all
ELOG V3.1.4-2e1708b5