Argonne National Laboratory

Experimental Physics and
Industrial Control System

2002  2003  2004  2005  2006  2007  2008  2009  2010  2011  2012  2013  2014  2015  2016  2017  <20182019  2020  2021  Index 2002  2003  2004  2005  2006  2007  2008  2009  2010  2011  2012  2013  2014  2015  2016  2017  <20182019  2020  2021 
<== Date ==> <== Thread ==>

Subject: RE: Issues with latest version of base-7.0
From: Mark Rivers via Core-talk <core-talk@aps.anl.gov>
To: 'Michael Davidsaver' <mdavidsaver@gmail.com>
Cc: "'core-talk@aps.anl.gov'" <core-talk@aps.anl.gov>
Date: Fri, 21 Dec 2018 23:29:17 +0000

Hi Michael,

 

I have now reproduced the problem with a simple 6 record database (attached).  This database can be run on any IOC that is built with the busy record.  A simple one is busy/busyApp/src/testBusyAsyn.cpp.  That IOC also requires asyn, but this database does not.

 

The database works as follows:

 

bo record Acquire.  Writing 1 to this record is what will trigger the problem.

 

bi record Acquire_RBV.  This record is written to by Acquire.  It is set to 0 by Reset.  It is monitored by ClearBusy.

 

calcout record SetBusy.  This record is FLNKd by Acquire and gets its value from Acquire.  On transition to 1 it sets Busy to 1.  It FNLKs to Reset.

 

busy record Busy.  The value 1 is written to this record by SetBusy and the value 0 is written to it by ClearBusy.  The busy record is basically a clone of the bo record except that it only calls RecGblFwdLink when its value is 0.

 

seq record Reset.  This record processed when 1 is written to Busy.  It has a delay of 1 second, and after that time it writes 0 to Acquire_RBV.  It is disabled if Busy is 0 to avoid infinite loop.

 

calcout record ClearBusy.  This record monitors Acquire_RBV.  On that PV transitioning from 1 to 0 it writes 0 to the Busy record.  I believe it is this write operation that is causing the error in EPICS base.

 

This is the error from EPICS base 7.0.2 after I also added a call to epicsStaceTrace() in addition to the errlogPrintf.

 

epics> Dumping a stack trace of thread 'scanOnce':

[    0x7f49751f113b]: /usr/local/epics-devel/base-7.0.2/lib/linux-x86_64/libCom.so.3.17.2(epicsStackTrace+0x4b)

[    0x7f49756b7057]: /usr/local/epics-devel/base-7.0.2/lib/linux-x86_64/libdbCore.so.3.17.2(dbDbPutValue+0x107)

[    0x7f49756bac19]: /usr/local/epics-devel/base-7.0.2/lib/linux-x86_64/libdbCore.so.3.17.2(dbPutLink+0x29)

[    0x7f497592f8a8]: /usr/local/epics-devel/base-7.0.2/lib/linux-x86_64/libdbRecStd.so.3.17.2(execOutput+0x88)

[    0x7f497592ff29]: /usr/local/epics-devel/base-7.0.2/lib/linux-x86_64/libdbRecStd.so.3.17.2(process+0x589)

[    0x7f49756a91c8]: /usr/local/epics-devel/base-7.0.2/lib/linux-x86_64/libdbCore.so.3.17.2(dbProcess+0x1d8)

[    0x7f49756bcb37]: /usr/local/epics-devel/base-7.0.2/lib/linux-x86_64/libdbCore.so.3.17.2(onceTask+0x87)

[    0x7f49751eb7bc]: /usr/local/epics-devel/base-7.0.2/lib/linux-x86_64/libCom.so.3.17.2(start_routine+0xdc)

[    0x7f49743aae25]: /lib64/libpthread.so.0(start_thread+0xc5)

[    0x7f49746bdbad]: /lib64/libc.so.6(clone+0x6d)

Warning: 'testBusyAsyn:Busy.PUTF' found true with PACT false

 

 

Mark

 

 

 

 

 

From: Mark Rivers
Sent: Thursday, December 20, 2018 12:53 PM
To: 'Michael Davidsaver' <mdavidsaver@gmail.com>
Cc: 'core-talk@aps.anl.gov' <core-talk@aps.anl.gov>; 'Johnson, Andrew N.' <anj@anl.gov>
Subject: RE: Issues with latest version of base-7.0

 

Hi Michael,

 

I would like to pursue this issue a bit.

 

I have a test application in the synApps busy module.  It simulates the way a typical asynchronous asyn port driver works.

 

- Busy record is set to 1 to initiate an operation. Busy record sets PACT=1

- Driver get a write of the value 1 and starts a time-consuming operation in another thread.

- Busy record completes asynchronous record processing and sets PACT=0 as soon as this write operation is complete.  However, it does NOT call recGblFwdLink.

- Driver does a callback with a value 0 when the time consuming operation is done.

- Busy record processes again.  Because the value is now 0 it calls RecGblFwdLink.

 

If clients do ca_put_callback when writing 1 to the busy record, the callback will not occur until the busy record goes back to 0.

 

 

This is the medm screen for the test application.  The sleep time is the time that the driver is “busy” before it does the callback.

 

Since the sleep time is 1 second I set the timeout for a ca_put_callback to 2 seconds.  caput –c does not return until 1 second has elapsed, while caput without –c returns immediately.

 

>caput -c -w2 testBusyAsyn:Busy 1

 

camonitor shows that it is exactly 1 second after the busy record set to 1 that it goes back to 0.

 

corvette:simDetectorIOC/iocBoot/iocSimDetector>camonitor testBusyAsyn:Busy

testBusyAsyn:Busy              2018-12-20 12:26:03.111412 Zero

testBusyAsyn:Busy              2018-12-20 12:28:10.403137 One

testBusyAsyn:Busy              2018-12-20 12:28:11.403340 Zero

 

When I run this test application I do NOT get the warning messages from base 7.0.2.

 

However, when I run the real areaDetector drivers I do.  I would like to understand why that is the case, and make sure I am not doing something wrong in areaDetector.

 

These are the database records involved:

 

*****************************************

record(bo, "$(P)$(R)Acquire") {

   field(DTYP, "asynInt32")

   field(OUT, "@asyn($(PORT),$(ADDR=0),$(TIMEOUT=1))ACQUIRE")

   field(ZNAM, "Done")

   field(ONAM, "Acquire")

   field(VAL,  "0")

   field(FLNK, "$(P)$(R)SetAcquireBusy")

   info(asyn:READBACK, "1")

}

 

record(bi, "$(P)$(R)Acquire_RBV") {

   field(DTYP, "asynInt32")

   field(INP, "@asyn($(PORT),$(ADDR=0),$(TIMEOUT=1))ACQUIRE")

   field(ZNAM, "Done")

   field(ZSV,  "NO_ALARM")

   field(ONAM, "Acquiring")

   field(OSV,  "MINOR")

   field(SCAN, "I/O Intr")

}

 

record(calcout, "$(P)$(R)SetAcquireBusy")

{

    field(INPA, "$(P)$(R)Acquire NPP")

    field(CALC, "A")

    field(OOPT, "Transition To Non-zero")

    field(OUT,  "$(P)$(R)AcquireBusy PP")

}

 

record(busy, "$(P)$(R)AcquireBusy") {

   field(ZNAM, "Done")

   field(ZSV,  "NO_ALARM")

   field(ONAM, "Acquiring")

   field(OSV,  "MINOR")

   field(VAL,  "0")

}

 

record(calcout, "$(P)$(R)ClearAcquireBusy")

{

    field(INPA, "$(P)$(R)WaitForPlugins CP")

    field(INPB, "$(P)$(R)Acquire_RBV CP")

    field(INPC, "$(P)$(R)NumQueuedArrays CP")

    field(CALC, "A ? B || (C > 0) : B")

    field(OOPT, "Transition To Zero")

    field(OUT,  "$(P)$(R)AcquireBusy PP")

}

*****************************************

 

The way this database works is as follows:

-          Client writes 1 to Acquire to start acquisition

-          That forward links to SetAcquireBusy.   On transition from 0 to 1 that record writes 1 to AcquireBusy (the busy record)

-          When the driver is done it does a callback with value 0 on the Acquire_RBV record.

-          The ClearAcquireBusy record monitors Acquire_RBV with CP.  When it transitions to 0 it writes 0 to AcquireBusy, the busy record.  If WaitForPlugins is non-zero then this record also waits until NumQueuedArrays is 0 before setting AcquireBusy to 0.

 

I have modified dbDbLink.c to call epicsStackTrace just before printing the warning message.  I have also set the TPRO field of 13SIM1:cam1:AcquireBusy to 1.  This is what I see:

 

ca:epics@corvette: dbProcess of '13SIM1:cam1:AcquireBusy'

Dumping a stack trace of thread 'scanOnce':

[         0x11ae86b]: ../../bin/linux-x86_64/simDetectorApp(epicsStackTrace+0x4b)

[         0x115ed37]: ../../bin/linux-x86_64/simDetectorApp(dbDbPutValue+0x107)

[         0x112eeb9]: ../../bin/linux-x86_64/simDetectorApp(dbPutLink+0x29)

[         0x10f22b8]: ../../bin/linux-x86_64/simDetectorApp(execOutput+0x88)

[         0x10f2939]: ../../bin/linux-x86_64/simDetectorApp(process+0x589)

[         0x111e6c8]: ../../bin/linux-x86_64/simDetectorApp(dbProcess+0x1d8)

[         0x1130dd7]: ../../bin/linux-x86_64/simDetectorApp(onceTask+0x87)

[         0x11aa50c]: ../../bin/linux-x86_64/simDetectorApp(start_routine+0xdc)

[    0x7fa272973e25]: /lib64/libpthread.so.0(start_thread+0xc5)

[    0x7fa27182cbad]: /lib64/libc.so.6(clone+0x6d)

scanOnce: dbProcess of '13SIM1:cam1:AcquireBusy'

Warning: '13SIM1:cam1:AcquireBusy.PUTF' found true with PACT false

 

So I want to understand why the above database is causing the warning message to appear, when it does not appear for the simpler test in the busy module.

 

Any ideas?

 

Thanks,

Mark

 

 

 

-----Original Message-----
From: Mark Rivers
Sent: Wednesday, December 19, 2018 8:21 AM
To: 'Johnson, Andrew N.' <anj@anl.gov>; Michael Davidsaver <mdavidsaver@gmail.com>
Cc: core-talk@aps.anl.gov


Subject: RE: Issues with latest version of base-7.0

 

Unfortunately it does not look like this issue is fixed in 7.0.2.  Whenever a busy record makes a transition from 1 to 0 this message is printed on the IOC:

 

Warning: '13SIM1:cam1:AcquireBusy.PUTF' found true with PACT false

 

It is coming from this file:

./dbDbLink.c:            errlogPrintf("Warning: '%s.PUTF' found true with PACT false\n",

 

This will be annoying for everyone using the busy record, which is areaDetector and lots of synApps modules.

 

Thanks,

Mark

 

 

-----Original Message-----

From: Johnson, Andrew N. <anj@anl.gov>

Sent: Wednesday, November 14, 2018 9:18 PM

To: Michael Davidsaver <mdavidsaver@gmail.com>

Cc: Mark Rivers <rivers@cars.uchicago.edu>; core-talk@aps.anl.gov

Subject: Re: Issues with latest version of base-7.0

 

@Michael: call it experience of too many encounters with Murphy’s law...

 

I don’t think it’s worth using a debugger, this is probably because of the slightly unusual behavior of the busy record, which I didn’t really think about or test with this change. The synapps busy record explicitly allows the database to determine when processing is complete and hence when to fire put-completion; you should probably take a look at the busy::process() routine to understand it.

 

It has been suggested that we should add the busy record or something like it to base. Marty has a simple kind of busy record in the exampleCpp module.

 

I will look at Mark’s build issue when I get a chance, someone else here has also reported this, which is purely a warning message that I added but will probably disable for the final release.

 

- Andrew

 

--

Sent from my iPad

 

> On Nov 15, 2018, at 11:08 AM, Michael Davidsaver <mdavidsaver@gmail.com> wrote:

> 

>> On 11/14/18 12:59 PM, Mark Rivers wrote:

>> I am having 2 issues with the version of base-7.0 that I updated today.

>> 

>> 

>> 

>> 1)      Whenever I set a “busy” record to 0 in my drivers (e.g. areaDetector) I see this warning from modules/database/src/ioc/db/dbDbLink.c

>> 

>> 

>> 

>> Warning: '13SIM1:cam1:AcquireBusy.PUTF' found true with PACT false

> 

> Ha, now Andrew can feel smug.  I originally made this an assert().

> 

> FYI. 7.0.2 has a change to the way the PUTF, PACT, and RPRO fields interact.

> The new protocol fixes an queuing issue when chaining multiple asynchronous records (via FLNK or OUT).

> This warning is flagging a state which I didn't think should ever happen.

> Though there is not any real harm if it does.

> 

> Can you run in a debugger and set a break point on the errlogPrintf() in question?

> I'd like to know the exact stack trace (and thus DB link chain) involved.

> 

> https://code.launchpad.net/~epics-core/epics-base/+git/prop-putf/+merge/336468

> 

> 

>> 2)      When I run “make” in any App/op/ that automatically converts adl files to opi, ui, etc. I get these warnings:

>> 

>> corvette:modbus/modbusApp/op>make

>> 

>> /corvette/usr/local/epics-devel/base-7.0.1/configure/RULES_COMMON:18: warning: overriding recipe for target `show-makefile.../../configure/CONFIG'

> 

> I'll leave this one to Andrew.

Attachment: testBusyAsyn3.db
Description: testBusyAsyn3.db


Replies:
Re: Issues with latest version of base-7.0 Michael Davidsaver via Core-talk
References:
Issues with latest version of base-7.0 Mark Rivers
Re: Issues with latest version of base-7.0 Michael Davidsaver
Re: Issues with latest version of base-7.0 Johnson, Andrew N. via Core-talk
RE: Issues with latest version of base-7.0 Mark Rivers via Core-talk
RE: Issues with latest version of base-7.0 Mark Rivers via Core-talk

Navigate by Date:
Prev: RE: Issues with latest version of base-7.0 Mark Rivers via Core-talk
Next: Build failed in Jenkins: epics-base-3.15 #409 APS Jenkins via Core-talk
Index: 2002  2003  2004  2005  2006  2007  2008  2009  2010  2011  2012  2013  2014  2015  2016  2017  <20182019  2020  2021 
Navigate by Thread:
Prev: RE: Issues with latest version of base-7.0 Mark Rivers via Core-talk
Next: Re: Issues with latest version of base-7.0 Michael Davidsaver via Core-talk
Index: 2002  2003  2004  2005  2006  2007  2008  2009  2010  2011  2012  2013  2014  2015  2016  2017  <20182019  2020  2021 
ANJ, 30 Dec 2018 Valid HTML 4.01! · Home · News · About · Base · Modules · Extensions · Distributions · Download ·
· Search · EPICS V4 · IRMIS · Talk · Bugs · Documents · Links · Licensing ·