EPICS Controls Argonne National Laboratory

Experimental Physics and
Industrial Control System

2002  2003  2004  2005  2006  2007  2008  2009  2010  2011  2012  2013  <20142015  2016  2017  2018  2019  2020  2021  2022  2023  2024  Index 2002  2003  2004  2005  2006  2007  2008  2009  2010  2011  2012  2013  <20142015  2016  2017  2018  2019  2020  2021  2022  2023  2024 
<== Date ==> <== Thread ==>

Subject: Re: Incorrect Timestamp in aSubRecord
From: Bruce Hill <[email protected]>
To: Till Straumann <[email protected]>, "Williams Jr., Ernest L." <[email protected]>, "Kim, Kukhee" <[email protected]>, EPICS core-talk <[email protected]>
Cc: [email protected], "Allison, Stephanie" <[email protected]>, "Zelazny, Michael Stanley" <[email protected]>, "D'Ewart, J. Mitch" <[email protected]>
Date: Wed, 26 Nov 2014 00:20:34 -0800
TSE -2 does work in the general case, as the timestamp gets done by device support
before the output links are processed.    That's a bit of a problem for calcout, as it typically
uses "Soft Channel" device support, but that was actually my first workaround for genSub.

If you set the genSub TSE field to -2, and set it's TSEL to the timestamp source, and call
recGblGetTimeStamp in your SNAM processing routine, it works. recGblGetTimeStamp gets
called again in the aSubRecord.c process function after the output links are processed, but it just fetches
the same timestamp again.  The same logic applies to aSub and other records with output links.

I wasn't happy with that solution, as it requires the EPICS developer to put a call to
recGblGetTimeStamp in their SNAM process function, or use a non-soft DTYP and call
recGblGetTimeStamp in their device process function.

As I see it there are really only two variations on this.   The scan lock set is locked during
all this processing, so there's no ambiguity about the results. If you set TSEL of a record
with output links to point to a PV that is one of it's output links, or derived thereof, you would
want the current behavior where the timestamp is fetched after the output links are processed.
I don't see why you wouldn't just look at the timestamp of the ao record in Till's example if what
you want to know is when that output was written to the hardware, but that is where we are
for historical reasons.

The other variation involves any PV which gets updated as a result of output link processing and
uses a TSEL link to the PV which wrote to that output link.   In this case after the scan lock is released,
the calcout or aSub record will have a new timestamp, but any records that use TSEL to that aSub
will have the prior timestamp.

As it stands now, I feel this is a gotcha waiting to bite new developers, requiring a detailed understanding
of record processing to detect and work around.    I realize it's a change in current behavior and would
break the use case that Till described, as well as any existing code that relies on output records w/ TSEL
getting the prior buffer's timestamp as in Hovanes' example. Thus, I propose that we provide a way
for EPICS developers to configure whether timestamps get done before or after output link processing.

Regards,
- Bruce


On 11/25/2014 5:37 PM, Till Straumann wrote:
And -- forgive my asking -- would timestamp-backpropagation,
i.e., using TSE=-2 on the last record in your chain and pointing TSEL
of upstream records to that last record, not work for you?

- T.

On 11/25/2014 04:48 PM, Bruce Hill wrote:
This is indeed a change of behavior, from post-output timestamping,
to pre-output timestamping.    Perhaps I should propose this as a new
option for the 3.16 release that would allow us to configure that behavior.

Cheers,
- Bruce

On 11/24/2014 09:55 AM, Till Straumann wrote:
I would recommend against hastily making changes.

Processing of a chain of records is a complex operation
and it is IMHO impossible to define a 'correct' point to
set timestamps if linked records obtain them from each other.

Obviously Bruce has his use case but it is easy to find another
one, e.g:

   calcout   - OUT -->     ao  (TSE = -2)
                 - TSEL -->

In this case I wish the calcout to deposit a value to an 'ao' and
fetch its own timestamp from the OUT-linked ao record. The rationale
being that I want the calcout to have the timestamp of when the
hardware really was updated (which happens in the ao record
which can set it precisely from device support).

The current behavior is what I would want for my use case
and modifying the semantics of record processing would break it.

Since it has been in place for such a long time IMHO we should
leave it the way it is.

- Till

PS: I would argue that the timestamp 'back-propagation' shown
above is 'better' in the sense that it allows me to more accurately
identify the time at which a change is 'applied'. If I take a timestamp
upstream and propagate it downstream then I have no certainty
that the timestamp is accurate, i.e., is not stale at the time the
change is 'applied'. But this use case is of course also just an example
and one could easily find other scenarios where either the proposed
or the traditional semantics seem more 'natural'.

On 11/21/2014 07:39 PM, Williams Jr., Ernest L. wrote:
Hi Guys
Would you mind conveying this tech-talk as well :)
Maybe, Andrew has consider this?
However, it won't hurt to add this view to the tech-talk thread for completeness

Till, do you agree?

Cheers
Ernest

Sent from my iPhone

On Nov 21, 2014, at 2:30 PM, Kim, Kukhee <[email protected]> wrote:

Hi Ernest,

Stephanie is right.
When we use TSEL, we make sure the timestamp source PV is complete then, the TSEL based PV grabs the timestamp.

The record processing is followed  the sequence as the followings

    Output link
    Timestamp
    Check Alarm
    Monitoring
    Forward Link

If an output record is the timestamp source, and it poke data to a TSEL based PV with PP option then we have trouble.
The output link will be processed before the timestamp update. The TSEL based PV will be processed by PP option and will grap the timestamp from timestamp source. But, it is stale one due to the timestamp in the source is not updated yet.

If we use forward link  and DOL, then it is different story.
The forward link is very end part of record processing.
So, we are sure, the TSEL based record will be processed after timestamp updating.

Bruce may need to change their database logic to use FLNK/DOL combination instead of OUT with PP.

We don't like to change on the record support layer. It is expected behavior as designed. If we changed it, there will be side effect.


Thank you.
Best regards,
Kukhee

--------------------------------------------
Kukhee Kim
SLAC National Accelerator Laboratory
2575 Sand Hill Rd, MS 64
Menlo Park, CA 94025
Email: [email protected]
Phone: (650)926-4912
Fax:   (650)926-3800


-----Original Message-----
From: Allison, Stephanie
Sent: Friday, November 21, 2014 2:11 PM
To: Williams Jr., Ernest L.; Kim, Kukhee; Straumann, Till
Subject: RE: FW: Incorrect Timestamp in aSubRecord

Hi Ernest,

AFAIK, most people on the electron-side-of-the-house use TSE=-1 or -2 for timestamping records instead of TSEL. The few places in the Mpg app and event module that use TSEL are records that are FLNKed (not OUTed) from records with the timestamp to be copied.

This problem is very interesting...

Steph

-----Original Message-----
From: Williams Jr., Ernest L.
Sent: Friday, November 21, 2014 2:01 PM
To: Allison, Stephanie; Kim, Kukhee; Straumann, Till
Cc: Williams Jr., Ernest L.
Subject: FW: FW: Incorrect Timestamp in aSubRecord

Hi,

How does this affect us?

Cheers,
Ernest
________________________________________
From: [email protected] [[email protected]] on
behalf of Bruce Hill [[email protected]]
Sent: Friday, November 21, 2014 1:25 PM
To: [email protected]
Subject: Re: FW: Incorrect Timestamp in aSubRecord

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;





--

Bruce Hill

Member Technical Staff

SLAC National Accelerator Lab

2575 Sand Hill Road M/S 10

Menlo Park, CA 94025


References:
Re: FW: Incorrect Timestamp in aSubRecord Andrew Johnson
Re: FW: Incorrect Timestamp in aSubRecord Bruce Hill
Re: Incorrect Timestamp in aSubRecord Till Straumann
Re: Incorrect Timestamp in aSubRecord Bruce Hill
Re: Incorrect Timestamp in aSubRecord Till Straumann

Navigate by Date:
Prev: Re: Incorrect Timestamp in aSubRecord Till Straumann
Next: Changing development focus for lp:epics-base Andrew Johnson
Index: 2002  2003  2004  2005  2006  2007  2008  2009  2010  2011  2012  2013  <20142015  2016  2017  2018  2019  2020  2021  2022  2023  2024 
Navigate by Thread:
Prev: Re: Incorrect Timestamp in aSubRecord Till Straumann
Next: Changing development focus for lp:epics-base Andrew Johnson
Index: 2002  2003  2004  2005  2006  2007  2008  2009  2010  2011  2012  2013  <20142015  2016  2017  2018  2019  2020  2021  2022  2023  2024 
ANJ, 02 Dec 2014 Valid HTML 4.01! · Home · News · About · Base · Modules · Extensions · Distributions · Download ·
· Search · EPICS V4 · IRMIS · Talk · Bugs · Documents · Links · Licensing ·