Argonne National Laboratory

Experimental Physics and
Industrial Control System

1994  1995  1996  1997  1998  1999  2000  2001  2002  2003  2004  2005  2006  2007  2008  2009  2010  2011  2012  2013  2014  2015  2016  2017  2018  <20192020  Index 1994  1995  1996  1997  1998  1999  2000  2001  2002  2003  2004  2005  2006  2007  2008  2009  2010  2011  2012  2013  2014  2015  2016  2017  2018  <20192020 
<== Date ==> <== Thread ==>

Subject: Problem with TSE="-2" records
From: William Norum via Tech-talk <tech-talk@aps.anl.gov>
To: Mark Rivers <rivers@cars.uchicago.edu>, Andrew Johnson <anj@aps.anl.gov>, Joao Afonso via Tech-talk <tech-talk@aps.anl.gov>
Date: Thu, 7 Feb 2019 12:55:55 -0800
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




Replies:
RE: Problem with TSE="-2" records Mark Rivers via Tech-talk

Navigate by Date:
Prev: RE: Point Grey GigE Blackfly conflict Mark Rivers via Tech-talk
Next: RE: Problem with TSE="-2" records Mark Rivers via Tech-talk
Index: 1994  1995  1996  1997  1998  1999  2000  2001  2002  2003  2004  2005  2006  2007  2008  2009  2010  2011  2012  2013  2014  2015  2016  2017  2018  <20192020 
Navigate by Thread:
Prev: Re: How to read and Write PVs in C# Alain Bertrand via Tech-talk
Next: RE: Problem with TSE="-2" records Mark Rivers via Tech-talk
Index: 1994  1995  1996  1997  1998  1999  2000  2001  2002  2003  2004  2005  2006  2007  2008  2009  2010  2011  2012  2013  2014  2015  2016  2017  2018  <20192020 
ANJ, 10 Feb 2019 Valid HTML 4.01! · Home · News · About · Base · Modules · Extensions · Distributions · Download ·
· Search · EPICS V4 · IRMIS · Talk · Bugs · Documents · Links · Licensing ·