RE: Problem with TSE="-2" records

[Mark Rivers via Tech-talk <tech-talk@aps.anl.gov>]

If you look at the timestamp .nsec field as an integer can you tell if the difference is always in specific bits (low order 8-bits or 16-bits for example)?

 

 

From: William Norum <wenorum@lbl.gov>
Sent: Thursday, February 7, 2019 2:56 PM
To: Mark Rivers <rivers@cars.uchicago.edu>; Andrew Johnson <anj@aps.anl.gov>; Joao Afonso via Tech-talk <tech-talk@aps.anl.gov>
Subject: Problem with TSE="-2" records

 

EPICS Base 3.15.4.  ASYN R4-30.

 

I’m seeing odd behaviour of some record time stamps.  I have a number of FPGA-based beam position monitors each with an embedded MRF-compatible event receiver used to synchronize data acquisition and to provide acquisition time stamps.  Each BPM publishes a ’slow acquisition’ packet at about 10Hz.  The packets contain the MRF-supplied seconds and ticks at the time of acquisition.  The seconds and ticks from all BPMs are the same since all BPMs are synchronized to a ‘heartbeat’ event.

The IOC reads the packets in asynchronous ‘reader’ threads (one per BPM) and uses the ASYN int32Interrupt->callback() method to push values into records.  The time stamp for the callback is based on the value in the received packet (with POSIX seconds converted to EPICS seconds and with MRF ’ticks’ converted to nanoseconds).

 

Here’s an example of one of the records that’s causing problems.  The record is configured with SCAN=“I/O Intr” and TSE=“-2” to allow the callback to push the value and time stamp into the records:

record(ai, "$(P)$(R)SA:X") {

    field(DESC, "Beam X position")

    field(DTYP, "asynInt32")

    field(INP,  "@asyn($(PORT) 0xB30 0)")

    field(SCAN, "I/O Intr")

    field(TSE,  "-2")

    field(PREC, "5")

    field(LINR, "SLOPE")

    field(EGU,  "mm")

    field(ESLO, "1e-6")

    field(EOFF, "0")

    field(LOPR, "-10")

    field(HOPR, "10")

}

Something appears to be mangling the time stamps though.

I wrote a small python client (pyEpics 3.3.2) with monitor callbacks from a handful of these records.  If the time stamps for a given acquisition cycle aren’t the same I print a message. When I run this, every now and then I see a record with an unexpected time stamp.  So things are good most of the time, but not always. The same problem shows up with MATLAB clients too.

Here’s an example output.  Columns are:

1. Offending PV name
2. Offending PV timestamp (POSIX)
3. Name of PV whose callback started this acquisition cycle
4. Timestamp of PV whose callback started this acquisition cycle (all PVs in the cycle should have exactly this timestamp)
5. Difference between the two timestamps in seconds
6. Difference between the two timestamps converted back to MRF ticks

 

SR03C:BPM6:SA:X 1549571900.11028504  SR11S:IDBPM4:SA:X 1549571900.11025190  3.3140182e-05 4139.557

SR11S:IDBPM1:SA:X 1549571901.90631294  SR09C:BPM1:SA:X 1549571901.90634608  -3.3140182e-05 -4139.557

SR01C:BPM6:SA:X 1549571906.39541507  SR08C:BPM6:SA:X 1549571906.39656091  -0.0011458397 -143127.409

SR09C:BPM1:SA:X 1549571907.39428902  SR05C:BPM1:SA:X 1549571907.39438796  -9.894371e-05 -12359.108

 

So it appears that once in a while the fractional part of the timestamp gets mangled.  And only the fractional part — the integer part seems fine.  Note also  that the tick differences are not integers.  This implies that the problem is occurring after the IOC callback since if the problem were between the FPGA and the IOC the differences would have to be an integral number of MRF ticks.  

 

One other oddity is that in addition to the scalar records like the one shown above the IOC also pushes the complete raw packet received from the FPGA into a waveform record.  When my test client monitors these waveform records it never sees any problems.  It’s only the scalar records (both ai and longin) that show the bad time stamps.  I had a look at the ASYN devEpics ai and longin record support code but nothing there seems obviously out of the ordinary.  Perhaps I’m just not looking close enough, or perhaps the problem is somewhere completely different.

Suggestions welcomed.

 -- 
Eric Norum
wenorum@lbl.gov