Experimental Physics and
Industrial Control System

Hi Andrew,
Yes, I can take a closer look at this.   As we're using TSEL more
often to timestamp values w/ pulse ID's, I think we'll be updating
most of our local record implementations soon.   I'll put together
a patch incorporating all of them.

Cheers,
- Bruce

On 11/21/2014 8:17 AM, Andrew Johnson wrote:

Hi Guys,

On 11/21/2014 06:18 AM, Dalesio, Leo wrote:

This sounds like a bug to me. What is your take on that?
IF outlinks are considered similar to flnks - getting the time stamp
prior to executing the links seems like a clean fix.
We should open the discussion on core-talk I think.

I can see the original reasoning behind the *out records getting their
time-stamp just after they send their values — it represents the time
when the value was sent to the hardware. The input record types read
their time-stamp just after getting their input values, and the calc
record after calling calcPerform().

However I am persuaded by Bruce's reasoning that a record's time-stamp
should be set before notifying an external entity. I added several calls
to recGblGetTimeStamp() to the calcout record back in March 2012 to
ensure that the time-stamp has been set before db_post_events() is
called so those monitor events would contain the current time rather
than when the record previously processed, and I see this as a similar
issue.

I think it would be worth someone doing a comprehensive review of all
the Base record types for these kinds of time-stamp issues before the
3.16 release (the code for 3.15 is now feature-frozen).

Bruce, would you be willing to take this on?

- Andrew

________________________________________
From: [email protected] [[email protected]] on behalf of Bruce Hill [[email protected]]
Sent: Friday, November 21, 2014 7:05 AM
To: Mark Rivers; [email protected]
Subject: Re: Incorrect Timestamp in aSubRecord

Hi Mark,
I see your point, as most record processing code I've seen ends w/ that
sequence of recGblGetTimeStamp, checkAlarms, monitor, and recGblFwdLink.

I setup a test using a calcout to see if it has the same issue, and the calcout record
shows the same problem.   Most likely we'll see this w/ most records with output
links.   A quick spot check shows most of the calc module records follow this
pattern, as do ao, bo, aao, longout, mbbo, mbboDirect, and stringout.
It looks like dfanout and seq get the timestamp before processing their outputs.

Of course the downside of making this change is that it affects existing timing and
users such as Hovanes have already adjusted their code to compensate for it, so
making the behavior correct from a logic standpoint could break existing applications.

That said, it really should be a bug when a TSEL link gets different timestamps depending
on the TSE setting of the record which it links to, and if you don't get the timestamp
corresponding to the data that produced a new value, TSEL isn't much use.

Regards,
- Bruce

On 11/20/2014 5:48 PM, Mark Rivers wrote:

Hi Bruce,

I just looked at the code in the aoRecord.c and calcoutRecord.c for example.  They also call recGblGetTimeStamp() after calling writeValue and execOutput respectively, i.e. after any writing to the output link.  This is the way all EPICS records are written, i.e. the following sequence:

writeOutputs()
recGblGetTimeStamp();
checkAlarms();
monitor();
recGblFwdLink();

I don't think the behavior you are seeing is unique to the aSubRecord, it is the way all records that write to outputs work.  Have you tried the same thing with a calcOut record?

Mark


-----Original Message-----
From: [email protected] [mailto:[email protected]] On Behalf Of Bruce Hill
Sent: Thursday, November 20, 2014 5:47 PM
To: [email protected]
Subject: Incorrect Timestamp in aSubRecord

I recently traced a timestamp issue on an older ioc using genSub
to when genSubRecord.c calls recGblGetTimeStamp(), and I think
the same problem exists in aSubRecord.c in 3.14.12.

In our environment, epics timestamps from our EVR's have an embedded
pulseId in the nsec field, which we use to identify which beam pulse
values are derived from.     When we use a genSub or aSub record to
do computations related to a beam pulse, that record will either get
it's timestamp via TSE -2 in the records process function or via a TSEL
link to a waveform timestamped w/ the currect pulse ID.

I found that it worked correctly for TSE -2, as the user process function
sets the timestamp.   However, when using TSEL to get the genSub or aSub
timestamp, I'd get stale timestamps on any output links which used
a TSEL back to the genSub or aSub record.

The reason this happens is that recGblGetTimeStamp() is getting called
after the output links are processed, and the TSEL based output records
thus grab the aSub timestamp before recGblGetTimeStamp is called.

Has anyone else seen this problem, or know of some reason why we
shouldn't be calling recGblGetTimeStamp before processing the output records?

Thanks!
- Bruce

P.S.  Here's my patch for this:
--- src/rec/aSubRecord.c        (revision 19727)
+++ src/rec/aSubRecord.c        (revision 19728)
@@ -266,6 +266,7 @@
            return 0;

        prec->pact = TRUE;
+    recGblGetTimeStamp(prec);

        /* Push the output link values */
        if (!status) {
@@ -276,7 +277,6 @@
                    (&prec->neva)[i]);
        }

-    recGblGetTimeStamp(prec);
        monitor(prec);
        recGblFwdLink(prec);
        prec->pact = FALSE;

References:

Re: FW: Incorrect Timestamp in aSubRecord Andrew Johnson

Navigate by Date:

Prev: Re: FW: Incorrect Timestamp in aSubRecord Andrew Johnson

Next: Re: Incorrect Timestamp in aSubRecord Till Straumann

Index: 2002  2003  2004  2005  2006  2007  2008  2009  2010  2011  2012  2013  <2014>  2015  2016  2017  2018  2019  2020  2021  2022  2023  2024 

Navigate by Thread:

Prev: Re: FW: Incorrect Timestamp in aSubRecord Andrew Johnson

Next: Re: Incorrect Timestamp in aSubRecord Till Straumann

Index: 2002  2003  2004  2005  2006  2007  2008  2009  2010  2011  2012  2013  <2014>  2015  2016  2017  2018  2019  2020  2021  2022  2023  2024