EPICS Home EPICS Controls Argonne National Laboratory

Experimental Physics and
Industrial Control System

Format page
for printing


Search Tech-talk
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  <2019>  2020  2021  2022  2023  2024  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  <2019>  2020  2021  2022  2023  2024 
<== Date ==> <== Thread ==>
Subject: RE: Asyn 4-35 IOC upgrade misbehavior
From: Mark Rivers via Tech-talk <[email protected]>
To: 'Lucas Russo' <[email protected]>
Cc: "[email protected]" <[email protected]>
Date: Thu, 13 Jun 2019 21:50:34 +0000

Ø  I was able to make some more tests and it worked with asyn up until release 4-31 and then it broke with 4-32. Any idea why it was working before?

 

R4-32 added a timeout callback function which is called when a queue request to lock the port for synchronous I/O times out.  That timeout function will also be called if the port/address is not connected.  The bug in your driver made it appear that the port/address was not connected, so the synchronous I/O generated an error.

 

Mark

 

 

 

From: Lucas Russo <[email protected]>
Sent: Thursday, June 13, 2019 2:33 PM
To: Mark Rivers <[email protected]>
Cc: [email protected]
Subject: Re: Asyn 4-35 IOC upgrade misbehavior

 

Hi Mark,

 

That's great news! I will make the changes and see if everything works.

 

I was able to make some more tests and it worked with asyn up until release 4-31 and then it broke with 4-32. Any idea why it was working before?

 

Thanks a lot for the help!

 

Cheers!

 

Lucas Russo

 

On Thu, Jun 13, 2019 at 4:20 PM Mark Rivers <[email protected]> wrote:

Hi Lucas,

 

I found the problem.  It is in your drvBPM::connect() function.

 

asynStatus drvBPM::connect(asynUser* pasynUser)

{

    return bpmClientConnect();

}

 

asynStatus drvBPM::bpmClientConnect(void)

{

…

    pasynManager->exceptionConnect(this->pasynUserSelf);

 

    return status;

…

}

 

The problem is that you are calling pasynManager->exceptionConnect with this->pasynUserSelf.  this->pasynUserSelf is connected to addr=0, rather than the actual addr encoded in the pasynUser passed to drvBPM::connect().

 

You need to change this code to:

 

asynStatus drvBPM::connect(asynUser* pasynUser)

{

    return bpmClientConnect(pasynUser);

}

 

asynStatus drvBPM::bpmClientConnect(asynUser *pasynUser)

{

…

    pasynManager->exceptionConnect(pasynUser);

 

    return status;

…

}

 

I was able to reproduce the behavior that the initial read worked with addr=0, but failed for addr=1.  Once I made the fix above the initial read worked for both addr=0 and addr=0.

 

Mark

 

 

 

From: Mark Rivers <[email protected]>
Sent: Thursday, June 13, 2019 9:55 AM
To: Lucas Russo <[email protected]>
Cc: [email protected]
Subject: Re: Asyn 4-35 IOC upgrade misbehavior

 

Thanks for the hint!  When I enable ASYN_TRACE_WARNING before iocInit I indeed see this:

 

asynSetTraceMask("BPM",0,ASYN_TRACE_ERROR+ASYN_TRACE_WARNING)

iocInit()

Starting iocInit

############################################################################

## EPICS R7.0.2.2

## EPICS Base built May 10 2019

############################################################################

2019/06/13 09:52:25.099 BPM asynManager::queueLockPortTimeoutCallback WARNING: queueLockPort timeout

2019/06/13 09:52:25.099 BPM asynManager::queueLockPortTimeoutCallback WARNING: queueLockPort timeout

2019/06/13 09:52:25.099 BPM asynManager::queueLockPortTimeoutCallback WARNING: queueLockPort timeout

2019/06/13 09:52:25.099 BPM asynManager::queueLockPortTimeoutCallback WARNING: queueLockPort timeout

2019/06/13 09:52:25.099 BPM asynManager::queueLockPortTimeoutCallback WARNING: queueLockPort timeout

2019/06/13 09:52:25.099 BPM asynManager::queueLockPortTimeoutCallback WARNING: queueLockPort timeout

2019/06/13 09:52:25.099 BPM asynManager::queueLockPortTimeoutCallback WARNING: queueLockPort timeout

2019/06/13 09:52:25.100 BPM asynManager::queueLockPortTimeoutCallback WARNING: queueLockPort timeout

2019/06/13 09:52:25.100 BPMTest:BPM1:asyn: special queueRequest timeout

2019/06/13 09:52:25.100 BPM asynManager::queueLockPortTimeoutCallback WARNING: queueLockPort timeout

2019/06/13 09:52:25.100 BPM asynManager::queueLockPortTimeoutCallback WARNING: queueLockPort timeout

2019/06/13 09:52:25.100 BPM asynManager::queueLockPortTimeoutCallback WARNING: queueLockPort timeout

2019/06/13 09:52:25.100 BPM asynManager::queueLockPortTimeoutCallback WARNING: queueLockPort timeout

2019/06/13 09:52:25.100 BPM asynManager::queueLockPortTimeoutCallback WARNING: queueLockPort timeout

2019/06/13 09:52:25.100 BPM asynManager::queueLockPortTimeoutCallback WARNING: queueLockPort timeout

2019/06/13 09:52:25.100 BPM asynManager::queueLockPortTimeoutCallback WARNING: queueLockPort timeout

 

So that is the problem.  I will track it down.

 

Mark

 

 

 

From: Lucas Russo <[email protected]>
Sent: Thursday, June 13, 2019 9:43 AM
To: Mark Rivers
Cc: [email protected]
Subject: Re: Asyn 4-35 IOC upgrade misbehavior

 

Hi Mark,

 

Oh nice! I've been trying to run different versions of asyn to try to track the exact commit where the issue appeared. Not a fast track for me since I have to change some other modules for compatibility.

 

Bruno Martins has been helping me on that as well and he suggested this commit https://github.com/epics-modules/asyn/commit/d24760b0e34ea738805f65646fec79340e55d3c6

could have something to do with the issue. Maybe it's worth taking a look at.

 

Thanks a lot for your help!

 

If I find anything promising I will report back.

 

Regards,

 

Lucas Russo

 

On Thu, Jun 13, 2019 at 11:34 AM Mark Rivers <[email protected]> wrote:

Lucas,

 

I have stripped down your application so it does not talk to any hardware.  I have it running, and just loading 2 copies of the Acq database with addr=0 and 1,

 

dbLoadRecords("${TOP}/db/BPMAcq.template", "P=${P}, R=${R}, ACQ_NAME=ACQ, PORT=$(PORT), ADDR=0, TIMEOUT=1")

dbLoadRecords("${TOP}/db/BPMAcq.template", "P=${P}, R=${R}, ACQ_NAME=ACQ_PM, PORT=$(PORT), ADDR=1, TIMEOUT=1")

 

I think I have reproduced your problem, only for me it is even worse, it does not call readUInt32Digital in iocInit even for addr=0.  It does call it if I force an mbbi record to process, so I know the basic setup is OK.

 

I will work on tracking this down, no need for you to also spend time on it.

 

Mark

 

 

From: Mark Rivers <[email protected]>
Sent: Wednesday, June 12, 2019 10:26 PM
To: Lucas Russo <[email protected]>
Cc: [email protected]
Subject: Re: Asyn 4-35 IOC upgrade misbehavior

 

Hi Lucas,

 

The asynReport looks fine to me.  It is multidevice, the parameter is defined for both addr=0 and addr=1, etc.

 

The is the important finding is that the call to read the initial value with pasynUInt32DigitalSyncIO->read() is failing with error 3.

 

initLo: portName = BPM, addr = 1, userParam = TRIGGER_RCV_CNT_RST
initLo ERROR: portName = BPM, addr = 1, userParam = TRIGGER_RCV_CNT_RST, error = 3

 

That read should be resulting in a call to your driver's readUInt32Digital function, but it seems that is not, and it is returning an error instead.  status=3 is just ASYN_ERROR, so not very informative.  It looks like deeper debugging is needed.

 

Mark

 

 

From: Lucas Russo <[email protected]>
Sent: Wednesday, June 12, 2019 9:05 PM
To: Mark Rivers
Cc: [email protected]
Subject: Re: Asyn 4-35 IOC upgrade misbehavior

 

Hi Mark,

 

File attached.

 

Thanks,

 

Lucas

 

On Wed, Jun 12, 2019 at 10:32 PM Mark Rivers <[email protected]> wrote:


Hi Lucas,

Please send the output of the following command at the IOC shell:

asynReport 10 BPM_NAME

where BPM_NAME is the name of the asyn port.

Mark


________________________________
From: Lucas Russo <[email protected]>
Sent: Wednesday, June 12, 2019 8:03 PM
To: Mark Rivers
Cc: [email protected]
Subject: Re: Asyn 4-35 IOC upgrade misbehavior

Hi Mark,

Thanks for your tips. Sorry for the long email...

> When I look up those parameters in your template file I see that those are mbbo/mbbi records.  You said that other parameters are called correctly for both addr=0 and addr=1.  Can you see if the mbbo/mbbi records all fail to be called with addr=1 and all other record types are called OK with addr=1?

So, I commented most of my st.cmd file and it look like this now:

< envPaths

# Override default TOP variable
epicsEnvSet("TOP","../..")
epicsEnvSet("EPICS_DB_INCLUDE_PATH", "$(ADCORE)/db")
epicsEnvSet("BPM_TYPE","FMC250M_4CH")

< BPM.config

## Register all support components
dbLoadDatabase("${TOP}/dbd/BPM.dbd")
BPM_registerRecordDeviceDriver (pdbbase)

drvBPMConfigure("$(BPM_NAME)", "$(BPM_ENDPOINT)", "$(BPM_NUMBER)", "$(BPM_TYPE)", "$(BPM_VERBOSE)", "$(BPM_TIMEOUT)", "$(WAVEFORM_MAX_POINTS)", "$(MAXBUFFERS)", "$(MAXMEMORY)")


## Load record instances
dbLoadRecords("${TOP}/db/BPMAcq.template", "P=${P}, R=${R}, ACQ_NAME=ACQ, PORT=$(PORT), ADDR=0, TIMEOUT=1")
dbLoadRecords("${TOP}/db/BPMAcq.template", "P=${P}, R=${R}, ACQ_NAME=ACQ_PM, PORT=$(PORT), ADDR=1, TIMEOUT=1")
#dbLoadRecords("${TOP}/db/BPMSwitching.template", "P=${P}, R=${R}, PORT=$(PORT), ADDR=0, TIMEOUT=1")
#dbLoadRecords("${TOP}/db/BPMActiveClk.template", "P=${P}, R=${R}, PORT=$(PORT), ADDR=0, TIMEOUT=1")
#dbLoadRecords("${TOP}/db/BPMAdcCommon.template", "P=${P}, R=${R}, PORT=$(PORT), ADDR=0, TIMEOUT=1")
#dbLoadRecords("${TOP}/db/MonitDspCtl.template", "P=${P}, R=${R}, PORT=$(PORT), ADDR=0, TIMEOUT=1")
#dbLoadRecords("${TOP}/db/BPMInfo.template", "P=${P}, R=${R}, PORT=$(PORT), ADDR=0, TIMEOUT=1")
#dbLoadRecords("${TOP}/db/BPMSP.template", "P=${P}, R=${R}, PORT=$(PORT), ADDR=0, TIMEOUT=1")
dbLoadRecords("$(ASYN)/db/asynRecord.db","P=${P}, R=${R}asyn,PORT=$(PORT),ADDR=0,OMAX=80,IMAX=80")
dbLoadRecords("${TOP}/db/BPMTrigger.template", "P=${P}, R=${R}, PORT=$(PORT), TRIGGER_NAME=TRIGGER, TRIGGER_CHAN=0, ADDR=0, TIMEOUT=1")
dbLoadRecords("${TOP}/db/BPMTrigger.template", "P=${P}, R=${R}, PORT=$(PORT), TRIGGER_NAME=TRIGGER, TRIGGER_CHAN=1, ADDR=1, TIMEOUT=1")

#< triggerBPM.cmd
#< fmc250m_4ch.cmd
#< waveformPlugins.cmd
#< waveformFilePlugins.cmd
#< waveformFFTRecords.cmd
#< statsPlugins.cmd
#< save_restore.cmd

# Turn on asynTraceFlow and asynTraceError for global trace, i.e. no connected asynUser.
asynSetTraceIOMask("$(BPM_NAME)",0,0x2)
#asynSetTraceMask("", 0, 17)
#asynSetTraceMask("$(BPM_NAME)",0,0xff)

iocInit()

#< initBPMCommands

# save things every thirty seconds
#create_monitor_set("auto_settings.req", 30,"P=${P}, R=${R}")
#set_savefile_name("auto_settings.req", "auto_settings_${P}${R}.sav")

Only the BPMAcq.template and the BPMTrigger.template files are loaded. Plus, I added right at the end of my readUInt32Digital (), readInt32 () and readFloat64 () functions the following snippet (example showing for int32):

    asynPrint(pasynUserSelf, ASYN_TRACE_ERROR,
            "%s:%s: readInt32 parameter addr = %d, value = %u, functionId = %d, paramName = %s\n",
            driverName, functionName, addr, *value, function, paramName);

So, it should print the print everytime a read is executed.

The IOC log is as follows:

@@@ Welcome to procServ (procServ Process Server 2.7.0)
@@@ Use ^X to kill the child, auto restart is ON, use ^T to toggle auto restart
@@@ procServ server PID: 24581
@@@ Server startup directory: /opt/epics/startup/ioc/bpm-epics-ioc/iocBoot/iocBPM
@@@ Child startup directory: /opt/epics/startup/ioc/bpm-epics-ioc/iocBoot/iocBPM
@@@ Child "halcs-be-ioc21" started as: ./runBPM.sh
@@@ Child "halcs-be-ioc21" is SHUT DOWN
@@@ procServ server started at: Wed Jun 12 21:11:09 2019
@@@ 0 user(s) and 0 logger(s) connected (plus you)
@@@ ^R or ^X restarts the child, ^Q quits the server
@@@ Restarting child "halcs-be-ioc21"
@@@    (as ./runBPM.sh)
@@@ The PID of new child "halcs-be-ioc21" is: 24608
@@@ @@@ @@@ @@@ @@@
/var/log/halcs/halcsd11_be0_info.log found. Parsing it to find which FMC board we have.
Synthesis name: bpm-gw-bo-siriu+
FMC 0 name: LNLS_FMC250M_REGS
FMC 1 name: LNLS_FMC250M_REGS
Using st.cmd file: stBPM250M.cmd
< envPaths
epicsEnvSet("IOC","iocBPM")
epicsEnvSet("TOP","/root/postinstall/apps/bpm-app/bpm-epics-ioc")
epicsEnvSet("SUPPORT","/opt/epics/synApps-lnls-R1-2-1/support")
epicsEnvSet("EPICS_BASE","/opt/epics/base")
epicsEnvSet("ASYN","/opt/epics/synApps-lnls-R1-2-1/support/asyn-R4-35")
epicsEnvSet("SSCAN","/opt/epics/synApps-lnls-R1-2-1/support/sscan-R2-11-2")
epicsEnvSet("CALC","/opt/epics/synApps-lnls-R1-2-1/support/calc-R3-7-2")
epicsEnvSet("AUTOSAVE","/opt/epics/synApps-lnls-R1-2-1/support/autosave-R5-9")
epicsEnvSet("BUSY","/opt/epics/synApps-lnls-R1-2-1/support/busy-R1-7-1")
epicsEnvSet("AREA_DETECTOR","/opt/epics/synApps-lnls-R1-2-1/support/areaDetector-R3-6")
epicsEnvSet("ADCORE","/opt/epics/synApps-lnls-R1-2-1/support/areaDetector-R3-6/ADCore")
epicsEnvSet("AREA_DETECTOR_COMPAT","/opt/epics/synApps-lnls-R1-2-1/support/areaDetector-R3-6/ADCore")
# Override default TOP variable
epicsEnvSet("TOP","../..")
epicsEnvSet("EPICS_DB_INCLUDE_PATH", "/opt/epics/synApps-lnls-R1-2-1/support/areaDetector-R3-6/ADCore/db")
epicsEnvSet("BPM_TYPE","FMC250M_4CH")
< BPM.config
# Set externally
#epicsEnvSet("BPM_ENDPOINT","tcp://10.2.117.47:9999<http://10.2.117.47:9999>")
#epicsEnvSet("BPM_NUMBER","17")
epicsEnvSet("BPM_VERBOSE","0")
epicsEnvSet("BPM_TIMEOUT","2000")
epicsEnvSet("WAVEFORM_MAX_POINTS", "100000")
epicsEnvSet("QSIZE", "20")
# Must be greater than asyn MAX_ADDR when using NDStats plugin
epicsEnvSet("MAX_SIGNALS", "30")
epicsEnvSet("NCHANS", "10")
epicsEnvSet("RING_SIZE", "10000")
epicsEnvSet("MAXBUFFERS", "0")
# 50MB limit for NDArrays
epicsEnvSet("MAXMEMORY", "50000000")
epicsEnvSet("COEFF_ARRAY_SIZE", "20")
# PV prefixes
epicsEnvSet("P", "BO-28U:")
epicsEnvSet("R", "DI-BPM:")
epicsEnvSet("PORT", "BPM")
epicsEnvSet("BPM_NAME","BPM")
## Register all support components
dbLoadDatabase("../../dbd/BPM.dbd")
BPM_registerRecordDeviceDriver (pdbbase)
Warning: IOC is booting with TOP = "../.."
          but was built with TOP = "/root/postinstall/apps/bpm-app/bpm-epics-ioc"
drvBPMConfigure("BPM", "ipc:///tmp/malamute", "21", "FMC250M_4CH", "0", "2000", "100000", "0", "50000000")
## Load record instances
dbLoadRecords("../../db/BPMAcq.template", "P=BO-28U:, R=DI-BPM:, ACQ_NAME=ACQ, PORT=BPM, ADDR=0, TIMEOUT=1")
dbLoadRecords("../../db/BPMAcq.template", "P=BO-28U:, R=DI-BPM:, ACQ_NAME=ACQ_PM, PORT=BPM, ADDR=1, TIMEOUT=1")
#dbLoadRecords("${TOP}/db/BPMSwitching.template", "P=${P}, R=${R}, PORT=$(PORT), ADDR=0, TIMEOUT=1")
#dbLoadRecords("${TOP}/db/BPMActiveClk.template", "P=${P}, R=${R}, PORT=$(PORT), ADDR=0, TIMEOUT=1")
#dbLoadRecords("${TOP}/db/BPMAdcCommon.template", "P=${P}, R=${R}, PORT=$(PORT), ADDR=0, TIMEOUT=1")
#dbLoadRecords("${TOP}/db/MonitDspCtl.template", "P=${P}, R=${R}, PORT=$(PORT), ADDR=0, TIMEOUT=1")
#dbLoadRecords("${TOP}/db/BPMInfo.template", "P=${P}, R=${R}, PORT=$(PORT), ADDR=0, TIMEOUT=1")
#dbLoadRecords("${TOP}/db/BPMSP.template", "P=${P}, R=${R}, PORT=$(PORT), ADDR=0, TIMEOUT=1")
dbLoadRecords("/opt/epics/synApps-lnls-R1-2-1/support/asyn-R4-35/db/asynRecord.db","P=BO-28U:, R=DI-BPM:asyn,PORT=BPM,ADDR=0,OMAX=80,IMAX=80")
dbLoadRecords("../../db/BPMTrigger.template", "P=BO-28U:, R=DI-BPM:, PORT=BPM, TRIGGER_NAME=TRIGGER, TRIGGER_CHAN=0,  ADDR=0,  TIMEOUT=1")
dbLoadRecords("../../db/BPMTrigger.template", "P=BO-28U:, R=DI-BPM:, PORT=BPM, TRIGGER_NAME=TRIGGER, TRIGGER_CHAN=1,  ADDR=1,  TIMEOUT=1")
#< triggerBPM.cmd
#< fmc250m_4ch.cmd
#< waveformPlugins.cmd
#< waveformFilePlugins.cmd
#< waveformFFTRecords.cmd
#< statsPlugins.cmd
#< save_restore.cmd
# Turn on asynTraceFlow and asynTraceError for global trace, i.e. no connected asynUser.
asynSetTraceIOMask("BPM",0,0x2)
#asynSetTraceMask("", 0, 17)
#asynSetTraceMask("$(BPM_NAME)",0,0xff)
iocInit()
Starting iocInit
############################################################################
## EPICS R3.15.6
## EPICS Base built Jun  7 2019
############################################################################
2019/06/12 21:11:10.995 drvBPM:readInt32: readInt32 parameter addr = 0, value = 0, functionId = 52, paramName = BPM_MODE
2019/06/12 21:11:10.996 drvBPM:readInt32: readInt32 parameter addr = 0, value = 0, functionId = 123, paramName = ACQ_CHANNEL
2019/06/12 21:11:10.996 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 0, functionId = 125, paramName = ACQ_TRIGGER
2019/06/12 21:11:10.996 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 1, functionId = 126, paramName = ACQ_TRIGGER_EVENT
2019/06/12 21:11:10.997 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 0, functionId = 127, paramName = ACQ_TRIGGER_REP
2019/06/12 21:11:10.998 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 0, functionId = 129, paramName = ACQ_TRIGGER_POL
2019/06/12 21:11:10.999 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 0, functionId = 133, paramName = ACQ_DATA_TRIG_CHAN
2019/06/12 21:11:11.001 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 1, functionId = 158, paramName = TRIGGER_DIR
2019/06/12 21:11:11.002 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 1, functionId = 159, paramName = TRIGGER_DIR_POL
2019/06/12 21:11:11.003 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 0, functionId = 166, paramName = TRIGGER_RCV_SRC
2019/06/12 21:11:11.004 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 0, functionId = 167, paramName = TRIGGER_TRN_SRC
2019/06/12 21:11:11.005 drvBPM:readFloat64: readFloat64 parameter addr = 0, value = 1.000000, functionId = 124, paramName = ACQ_UPDATE_TIME
2019/06/12 21:11:11.006 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 1000, functionId = 120, paramName = ACQ_SAMPLES_PRE
2019/06/12 21:11:11.006 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 0, functionId = 121, paramName = ACQ_SAMPLES_POST
2019/06/12 21:11:11.006 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 1, functionId = 122, paramName = ACQ_NUM_SHOTS
2019/06/12 21:11:11.007 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 0, functionId = 128, paramName = ACQ_TRIGGER_THRES
2019/06/12 21:11:11.008 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 0, functionId = 130, paramName = ACQ_TRIGGER_SEL
2019/06/12 21:11:11.009 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 0, functionId = 131, paramName = ACQ_TRIGGER_FILT
2019/06/12 21:11:11.010 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 0, functionId = 132, paramName = ACQ_TRIGGER_HWDLY
2019/06/12 21:11:11.010 drvBPM:readInt32: readInt32 parameter addr = 0, value = 0, functionId = 157, paramName = TRIGGER_CHAN
2019/06/12 21:11:11.011 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 0, functionId = 160, paramName = TRIGGER_RCV_CNT_RST
2019/06/12 21:11:11.013 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 0, functionId = 161, paramName = TRIGGER_TRN_CNT_RST
2019/06/12 21:11:11.014 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 1, functionId = 162, paramName = TRIGGER_RCV_LEN
2019/06/12 21:11:11.015 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 1, functionId = 163, paramName = TRIGGER_TRN_LEN
2019/06/12 21:11:11.016 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 0, functionId = 168, paramName = TRIGGER_RCV_IN_SEL
2019/06/12 21:11:11.017 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 0, functionId = 169, paramName = TRIGGER_TRN_OUT_SEL
cas warning: Configured TCP port was unavailable.
cas warning: Using dynamically assigned TCP port 44921,
cas warning: but now two or more servers share the same UDP port.
cas warning: Depending on your IP kernel this server may not be
cas warning: reachable with UDP unicast (a host's IP in EPICS_CA_ADDR_LIST)
2019/06/12 21:11:11.529 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 7, functionId = 164, paramName = TRIGGER_CNT_RCV
2019/06/12 21:11:11.529 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 0, functionId = 165, paramName = TRIGGER_CNT_TRN
2019/06/12 21:11:11.530 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 1, value = 0, functionId = 164, paramName = TRIGGER_CNT_RCV
2019/06/12 21:11:11.530 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 1, value = 0, functionId = 165, paramName = TRIGGER_CNT_TRN
iocRun: All initialization complete
#< initBPMCommands
# save things every thirty seconds
#create_monitor_set("auto_settings.req", 30,"P=${P}, R=${R}")
#set_savefile_name("auto_settings.req", "auto_settings_${P}${R}.sav")
epics>

So, loading the BPMAcq.template (which has longout/longin, mbbo/mbbi, ao/ai records) with addr = 0 and addr = 1 showed that only read functions for addr = 0. The longin records were also called (last 4 readUInt32Read messages) (BPMTrigger.template has 2 records that are longin), but I guess that's because PINI = "yes" for those *in records. Does that make sense?

> I also notice that some of your mbbo records use asynInt32, e.g. BPM_MODE, and some use asynUInt32Digital, e.g. ACQ_TRIGGER.  Does one of the interfaces fail and one work for mbbo records?  Why are you using different interfaces for different records?

It seems that they all fail for addr = 1 (different from what I had previously said), except the case for longin records (but I think this is another this, because for longin values are not read on devce init, right?). I was using differente interfaces because BPM_MODE is just an IOC parameter to select between two operation modes and ACQ_TRIGGER is a hardware value that are mapped to a register inside an FPGA. I guess I could have used the same interface for both, but I though it made sense to distinguish those two.

> That code is called for every mbbo record unless init_common returns an error.  If init_common returns an error it always prints an error message. Did you check carefully that there are no error messages right after iocInit?

> If you still think your driver is not being called for addr=1 with those parameters you could add a debugging printf just before the above call that prints pPvt->portName, pPvt->addr, and pPvt->userParam.  That will show you if it is calling the port for addr=1 and that parameter string.

So, I added the following to devAsynUInt32Digital.c:

    printf("initLo: portName = %s, addr = %d, userParam = %s\n",
        pPvt->portName, pPvt->addr, pPvt->userParam);
    /* Read the current value from the device */
    status = pasynUInt32DigitalSyncIO->read(pPvt->pasynUserSync,
                      &value, pPvt->mask,pPvt->pasynUser->timeout);
...
    printf("initMbbo: portName = %s, addr = %d, userParam = %s\n",
        pPvt->portName, pPvt->addr, pPvt->userParam);
    /* Read the current value from the device */
    status = pasynUInt32DigitalSyncIO->read(pPvt->pasynUserSync,
                      &value, pPvt->mask, pPvt->pasynUser->timeout);

I also added the following just at the top of my readUInt32Digital ():

asynStatus drvBPM::readUInt32Digital(asynUser *pasynUser, epicsUInt32 *value,
        epicsUInt32 mask)
{
    int function = pasynUser->reason;
    asynStatus status = asynSuccess;
    int addr = 0;
    const char *functionName = "readUInt32Digital";
    const char *paramName;

    asynPrint(pasynUserSelf, ASYN_TRACE_ERROR,
            "%s:%s: ENTERING readUInt32Read value = %u, functionId = %d\n",
            driverName, functionName, *value, function);

And here is the output:

@@@ Welcome to procServ (procServ Process Server 2.7.0)
@@@ Use ^X to kill the child, auto restart is ON, use ^T to toggle auto restart
@@@ procServ server PID: 4670
@@@ Server startup directory: /opt/epics/startup/ioc/bpm-epics-ioc/iocBoot/iocBPM
@@@ Child startup directory: /opt/epics/startup/ioc/bpm-epics-ioc/iocBoot/iocBPM
@@@ Child "halcs-be-ioc21" started as: ./runBPM.sh
@@@ Child "halcs-be-ioc21" is SHUT DOWN
@@@ procServ server started at: Wed Jun 12 21:34:17 2019
@@@ 0 user(s) and 0 logger(s) connected (plus you)
@@@ ^R or ^X restarts the child, ^Q quits the server
@@@ Restarting child "halcs-be-ioc21"
@@@    (as ./runBPM.sh)
@@@ The PID of new child "halcs-be-ioc21" is: 4685
@@@ @@@ @@@ @@@ @@@
/var/log/halcs/halcsd11_be0_info.log found. Parsing it to find which FMC board we have.
Synthesis name: bpm-gw-bo-siriu+
FMC 0 name: LNLS_FMC250M_REGS
FMC 1 name: LNLS_FMC250M_REGS
Using st.cmd file: stBPM250M.cmd
< envPaths
epicsEnvSet("IOC","iocBPM")
epicsEnvSet("TOP","/root/postinstall/apps/bpm-app/bpm-epics-ioc")
epicsEnvSet("SUPPORT","/opt/epics/synApps-lnls-R1-2-1/support")
epicsEnvSet("EPICS_BASE","/opt/epics/base")
epicsEnvSet("ASYN","/opt/epics/synApps-lnls-R1-2-1/support/asyn-R4-35")
epicsEnvSet("SSCAN","/opt/epics/synApps-lnls-R1-2-1/support/sscan-R2-11-2")
epicsEnvSet("CALC","/opt/epics/synApps-lnls-R1-2-1/support/calc-R3-7-2")
epicsEnvSet("AUTOSAVE","/opt/epics/synApps-lnls-R1-2-1/support/autosave-R5-9")
epicsEnvSet("BUSY","/opt/epics/synApps-lnls-R1-2-1/support/busy-R1-7-1")
epicsEnvSet("AREA_DETECTOR","/opt/epics/synApps-lnls-R1-2-1/support/areaDetector-R3-6")
epicsEnvSet("ADCORE","/opt/epics/synApps-lnls-R1-2-1/support/areaDetector-R3-6/ADCore")
epicsEnvSet("AREA_DETECTOR_COMPAT","/opt/epics/synApps-lnls-R1-2-1/support/areaDetector-R3-6/ADCore")
# Override default TOP variable
epicsEnvSet("TOP","../..")
epicsEnvSet("EPICS_DB_INCLUDE_PATH", "/opt/epics/synApps-lnls-R1-2-1/support/areaDetector-R3-6/ADCore/db")
epicsEnvSet("BPM_TYPE","FMC250M_4CH")
< BPM.config
# Set externally
#epicsEnvSet("BPM_ENDPOINT","tcp://10.2.117.47:9999<http://10.2.117.47:9999>")
#epicsEnvSet("BPM_NUMBER","17")
epicsEnvSet("BPM_VERBOSE","0")
epicsEnvSet("BPM_TIMEOUT","2000")
epicsEnvSet("WAVEFORM_MAX_POINTS", "100000")
epicsEnvSet("QSIZE", "20")
# Must be greater than asyn MAX_ADDR when using NDStats plugin
epicsEnvSet("MAX_SIGNALS", "30")
epicsEnvSet("NCHANS", "10")
epicsEnvSet("RING_SIZE", "10000")
epicsEnvSet("MAXBUFFERS", "0")
# 50MB limit for NDArrays
epicsEnvSet("MAXMEMORY", "50000000")
epicsEnvSet("COEFF_ARRAY_SIZE", "20")
# PV prefixes
epicsEnvSet("P", "BO-28U:")
epicsEnvSet("R", "DI-BPM:")
epicsEnvSet("PORT", "BPM")
epicsEnvSet("BPM_NAME","BPM")
## Register all support components
dbLoadDatabase("../../dbd/BPM.dbd")
BPM_registerRecordDeviceDriver (pdbbase)
Warning: IOC is booting with TOP = "../.."
          but was built with TOP = "/root/postinstall/apps/bpm-app/bpm-epics-ioc"
drvBPMConfigure("BPM", "ipc:///tmp/malamute", "21", "FMC250M_4CH", "0", "2000", "100000", "0", "50000000")
## Load record instances
dbLoadRecords("../../db/BPMAcq.template", "P=BO-28U:, R=DI-BPM:, ACQ_NAME=ACQ, PORT=BPM, ADDR=0, TIMEOUT=1")
dbLoadRecords("../../db/BPMAcq.template", "P=BO-28U:, R=DI-BPM:, ACQ_NAME=ACQ_PM, PORT=BPM, ADDR=1, TIMEOUT=1")
#dbLoadRecords("${TOP}/db/BPMSwitching.template", "P=${P}, R=${R}, PORT=$(PORT), ADDR=0, TIMEOUT=1")
#dbLoadRecords("${TOP}/db/BPMActiveClk.template", "P=${P}, R=${R}, PORT=$(PORT), ADDR=0, TIMEOUT=1")
#dbLoadRecords("${TOP}/db/BPMAdcCommon.template", "P=${P}, R=${R}, PORT=$(PORT), ADDR=0, TIMEOUT=1")
#dbLoadRecords("${TOP}/db/MonitDspCtl.template", "P=${P}, R=${R}, PORT=$(PORT), ADDR=0, TIMEOUT=1")
#dbLoadRecords("${TOP}/db/BPMInfo.template", "P=${P}, R=${R}, PORT=$(PORT), ADDR=0, TIMEOUT=1")
#dbLoadRecords("${TOP}/db/BPMSP.template", "P=${P}, R=${R}, PORT=$(PORT), ADDR=0, TIMEOUT=1")
dbLoadRecords("/opt/epics/synApps-lnls-R1-2-1/support/asyn-R4-35/db/asynRecord.db","P=BO-28U:, R=DI-BPM:asyn,PORT=BPM,ADDR=0,OMAX=80,IMAX=80")
dbLoadRecords("../../db/BPMTrigger.template", "P=BO-28U:, R=DI-BPM:, PORT=BPM, TRIGGER_NAME=TRIGGER, TRIGGER_CHAN=0,  ADDR=0,  TIMEOUT=1")
dbLoadRecords("../../db/BPMTrigger.template", "P=BO-28U:, R=DI-BPM:, PORT=BPM, TRIGGER_NAME=TRIGGER, TRIGGER_CHAN=1,  ADDR=1,  TIMEOUT=1")
#< triggerBPM.cmd
#< fmc250m_4ch.cmd
#< waveformPlugins.cmd
#< waveformFilePlugins.cmd
#< waveformFFTRecords.cmd
#< statsPlugins.cmd
#< save_restore.cmd
# Turn on asynTraceFlow and asynTraceError for global trace, i.e. no connected asynUser.
asynSetTraceIOMask("BPM",0,0x2)
#asynSetTraceMask("", 0, 17)
#asynSetTraceMask("$(BPM_NAME)",0,0xff)
iocInit()
Starting iocInit
############################################################################
## EPICS R3.15.6
## EPICS Base built Jun  7 2019
############################################################################
2019/06/12 21:34:19.859 drvBPM:readInt32: readInt32 parameter addr = 0, value = 0, functionId = 52, paramName = BPM_MODE
2019/06/12 21:34:19.859 drvBPM:readInt32: readInt32 parameter addr = 0, value = 0, functionId = 123, paramName = ACQ_CHANNEL
initMbbo: portName = BPM, addr = 0, userParam = ACQ_TRIGGER
2019/06/12 21:34:19.859 drvBPM:readUInt32Digital: ENTERING readUInt32Read value = 10200264, functionId = 125
2019/06/12 21:34:19.859 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 0, functionId = 125, paramName = ACQ_TRIGGER
initMbbo: portName = BPM, addr = 0, userParam = ACQ_TRIGGER_EVENT
2019/06/12 21:34:19.860 drvBPM:readUInt32Digital: ENTERING readUInt32Read value = 0, functionId = 126
2019/06/12 21:34:19.860 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 1, functionId = 126, paramName = ACQ_TRIGGER_EVENT
initMbbo: portName = BPM, addr = 0, userParam = ACQ_TRIGGER_REP
2019/06/12 21:34:19.860 drvBPM:readUInt32Digital: ENTERING readUInt32Read value = 1, functionId = 127
2019/06/12 21:34:19.860 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 0, functionId = 127, paramName = ACQ_TRIGGER_REP
initMbbo: portName = BPM, addr = 0, userParam = ACQ_TRIGGER_POL
2019/06/12 21:34:19.860 drvBPM:readUInt32Digital: ENTERING readUInt32Read value = 0, functionId = 129
2019/06/12 21:34:19.861 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 0, functionId = 129, paramName = ACQ_TRIGGER_POL
initMbbo: portName = BPM, addr = 0, userParam = ACQ_DATA_TRIG_CHAN
2019/06/12 21:34:19.861 drvBPM:readUInt32Digital: ENTERING readUInt32Read value = 0, functionId = 133
2019/06/12 21:34:19.862 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 0, functionId = 133, paramName = ACQ_DATA_TRIG_CHAN
initMbbo: portName = BPM, addr = 1, userParam = ACQ_TRIGGER
initMbbo: portName = BPM, addr = 1, userParam = ACQ_TRIGGER_EVENT
initMbbo: portName = BPM, addr = 1, userParam = ACQ_TRIGGER_REP
initMbbo: portName = BPM, addr = 1, userParam = ACQ_TRIGGER_POL
initMbbo: portName = BPM, addr = 1, userParam = ACQ_DATA_TRIG_CHAN
initMbbo: portName = BPM, addr = 0, userParam = TRIGGER_DIR
2019/06/12 21:34:19.863 drvBPM:readUInt32Digital: ENTERING readUInt32Read value = 10249048, functionId = 158
2019/06/12 21:34:19.864 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 1, functionId = 158, paramName = TRIGGER_DIR
initMbbo: portName = BPM, addr = 0, userParam = TRIGGER_DIR_POL
2019/06/12 21:34:19.864 drvBPM:readUInt32Digital: ENTERING readUInt32Read value = 1, functionId = 159
2019/06/12 21:34:19.865 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 1, functionId = 159, paramName = TRIGGER_DIR_POL
initMbbo: portName = BPM, addr = 0, userParam = TRIGGER_RCV_SRC
2019/06/12 21:34:19.866 drvBPM:readUInt32Digital: ENTERING readUInt32Read value = 1, functionId = 166
2019/06/12 21:34:19.867 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 0, functionId = 166, paramName = TRIGGER_RCV_SRC
initMbbo: portName = BPM, addr = 0, userParam = TRIGGER_TRN_SRC
2019/06/12 21:34:19.867 drvBPM:readUInt32Digital: ENTERING readUInt32Read value = 0, functionId = 167
2019/06/12 21:34:19.868 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 0, functionId = 167, paramName = TRIGGER_TRN_SRC
initMbbo: portName = BPM, addr = 1, userParam = TRIGGER_DIR
initMbbo: portName = BPM, addr = 1, userParam = TRIGGER_DIR_POL
initMbbo: portName = BPM, addr = 1, userParam = TRIGGER_RCV_SRC
initMbbo: portName = BPM, addr = 1, userParam = TRIGGER_TRN_SRC
2019/06/12 21:34:19.869 drvBPM:readFloat64: readFloat64 parameter addr = 0, value = 1.000000, functionId = 124, paramName = ACQ_UPDATE_TIME
initLo: portName = BPM, addr = 0, userParam = ACQ_SAMPLES_PRE
2019/06/12 21:34:19.870 drvBPM:readUInt32Digital: ENTERING readUInt32Read value = 0, functionId = 120
2019/06/12 21:34:19.870 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 1000, functionId = 120, paramName = ACQ_SAMPLES_PRE
initLo: portName = BPM, addr = 0, userParam = ACQ_SAMPLES_POST
2019/06/12 21:34:19.870 drvBPM:readUInt32Digital: ENTERING readUInt32Read value = 1000, functionId = 121
2019/06/12 21:34:19.870 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 0, functionId = 121, paramName = ACQ_SAMPLES_POST
initLo: portName = BPM, addr = 0, userParam = ACQ_NUM_SHOTS
2019/06/12 21:34:19.870 drvBPM:readUInt32Digital: ENTERING readUInt32Read value = 0, functionId = 122
2019/06/12 21:34:19.870 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 1, functionId = 122, paramName = ACQ_NUM_SHOTS
initLo: portName = BPM, addr = 0, userParam = ACQ_TRIGGER_THRES
2019/06/12 21:34:19.870 drvBPM:readUInt32Digital: ENTERING readUInt32Read value = 1, functionId = 128
2019/06/12 21:34:19.871 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 0, functionId = 128, paramName = ACQ_TRIGGER_THRES
initLo: portName = BPM, addr = 0, userParam = ACQ_TRIGGER_SEL
2019/06/12 21:34:19.872 drvBPM:readUInt32Digital: ENTERING readUInt32Read value = 0, functionId = 130
2019/06/12 21:34:19.873 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 0, functionId = 130, paramName = ACQ_TRIGGER_SEL
initLo: portName = BPM, addr = 0, userParam = ACQ_TRIGGER_FILT
2019/06/12 21:34:19.873 drvBPM:readUInt32Digital: ENTERING readUInt32Read value = 0, functionId = 131
2019/06/12 21:34:19.874 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 0, functionId = 131, paramName = ACQ_TRIGGER_FILT
initLo: portName = BPM, addr = 0, userParam = ACQ_TRIGGER_HWDLY
2019/06/12 21:34:19.874 drvBPM:readUInt32Digital: ENTERING readUInt32Read value = 0, functionId = 132
2019/06/12 21:34:19.875 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 0, functionId = 132, paramName = ACQ_TRIGGER_HWDLY
initLo: portName = BPM, addr = 1, userParam = ACQ_SAMPLES_PRE
initLo: portName = BPM, addr = 1, userParam = ACQ_SAMPLES_POST
initLo: portName = BPM, addr = 1, userParam = ACQ_NUM_SHOTS
initLo: portName = BPM, addr = 1, userParam = ACQ_TRIGGER_THRES
initLo: portName = BPM, addr = 1, userParam = ACQ_TRIGGER_SEL
initLo: portName = BPM, addr = 1, userParam = ACQ_TRIGGER_FILT
initLo: portName = BPM, addr = 1, userParam = ACQ_TRIGGER_HWDLY
2019/06/12 21:34:19.876 drvBPM:readInt32: readInt32 parameter addr = 0, value = 0, functionId = 157, paramName = TRIGGER_CHAN
initLo: portName = BPM, addr = 0, userParam = TRIGGER_RCV_CNT_RST
2019/06/12 21:34:19.876 drvBPM:readUInt32Digital: ENTERING readUInt32Read value = 1594275040, functionId = 160
2019/06/12 21:34:19.877 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 0, functionId = 160, paramName = TRIGGER_RCV_CNT_RST
initLo: portName = BPM, addr = 0, userParam = TRIGGER_TRN_CNT_RST
2019/06/12 21:34:19.877 drvBPM:readUInt32Digital: ENTERING readUInt32Read value = 0, functionId = 161
2019/06/12 21:34:19.878 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 0, functionId = 161, paramName = TRIGGER_TRN_CNT_RST
initLo: portName = BPM, addr = 0, userParam = TRIGGER_RCV_LEN
2019/06/12 21:34:19.879 drvBPM:readUInt32Digital: ENTERING readUInt32Read value = 0, functionId = 162
2019/06/12 21:34:19.880 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 1, functionId = 162, paramName = TRIGGER_RCV_LEN
initLo: portName = BPM, addr = 0, userParam = TRIGGER_TRN_LEN
2019/06/12 21:34:19.880 drvBPM:readUInt32Digital: ENTERING readUInt32Read value = 1, functionId = 163
2019/06/12 21:34:19.881 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 1, functionId = 163, paramName = TRIGGER_TRN_LEN
initLo: portName = BPM, addr = 0, userParam = TRIGGER_RCV_IN_SEL
2019/06/12 21:34:19.881 drvBPM:readUInt32Digital: ENTERING readUInt32Read value = 1, functionId = 168
2019/06/12 21:34:19.882 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 0, functionId = 168, paramName = TRIGGER_RCV_IN_SEL
initLo: portName = BPM, addr = 0, userParam = TRIGGER_TRN_OUT_SEL
2019/06/12 21:34:19.882 drvBPM:readUInt32Digital: ENTERING readUInt32Read value = 0, functionId = 169
2019/06/12 21:34:19.883 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 0, functionId = 169, paramName = TRIGGER_TRN_OUT_SEL
initLo: portName = BPM, addr = 1, userParam = TRIGGER_RCV_CNT_RST
initLo: portName = BPM, addr = 1, userParam = TRIGGER_TRN_CNT_RST
initLo: portName = BPM, addr = 1, userParam = TRIGGER_RCV_LEN
initLo: portName = BPM, addr = 1, userParam = TRIGGER_TRN_LEN
initLo: portName = BPM, addr = 1, userParam = TRIGGER_RCV_IN_SEL
initLo: portName = BPM, addr = 1, userParam = TRIGGER_TRN_OUT_SEL
cas warning: Configured TCP port was unavailable.
cas warning: Using dynamically assigned TCP port 42271,
cas warning: but now two or more servers share the same UDP port.
cas warning: Depending on your IP kernel this server may not be
cas warning: reachable with UDP unicast (a host's IP in EPICS_CA_ADDR_LIST)
2019/06/12 21:34:20.394 drvBPM:readUInt32Digital: ENTERING readUInt32Read value = 0, functionId = 164
2019/06/12 21:34:20.394 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 7, functionId = 164, paramName = TRIGGER_CNT_RCV
2019/06/12 21:34:20.394 drvBPM:readUInt32Digital: ENTERING readUInt32Read value = 0, functionId = 165
2019/06/12 21:34:20.394 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 0, functionId = 165, paramName = TRIGGER_CNT_TRN
2019/06/12 21:34:20.394 drvBPM:readUInt32Digital: ENTERING readUInt32Read value = 0, functionId = 164
2019/06/12 21:34:20.395 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 1, value = 0, functionId = 164, paramName = TRIGGER_CNT_RCV
2019/06/12 21:34:20.395 drvBPM:readUInt32Digital: ENTERING readUInt32Read value = 0, functionId = 165
2019/06/12 21:34:20.395 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 1, value = 0, functionId = 165, paramName = TRIGGER_CNT_TRN
iocRun: All initialization complete
#< initBPMCommands
# save things every thirty seconds
#create_monitor_set("auto_settings.req", 30,"P=${P}, R=${R}")
#set_savefile_name("auto_settings.req", "auto_settings_${P}${R}.sav")

You could see that, for instance, ACQ_SAMPLES_PRE is called for addr = 0:

initLo: portName = BPM, addr = 0, userParam = ACQ_SAMPLES_PRE
2019/06/12 21:34:19.870 drvBPM:readUInt32Digital: ENTERING readUInt32Read value = 0, functionId = 120
2019/06/12 21:34:19.870 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 1000, functionId = 120, paramName = ACQ_SAMPLES_PRE

But not for addr = 1:

initLo: portName = BPM, addr = 1, userParam = ACQ_SAMPLES_PRE
initLo: portName = BPM, addr = 1, userParam = ACQ_SAMPLES_POST
initLo: portName = BPM, addr = 1, userParam = ACQ_NUM_SHOTS
initLo: portName = BPM, addr = 1, userParam = ACQ_TRIGGER_THRES
initLo: portName = BPM, addr = 1, userParam = ACQ_TRIGGER_SEL
initLo: portName = BPM, addr = 1, userParam = ACQ_TRIGGER_FILT
initLo: portName = BPM, addr = 1, userParam = ACQ_TRIGGER_HWDLY

Finally, after all this I printed the status after calling pasynUInt32DigitalSyncIO->read () in initLo:

    status = pasynUInt32DigitalSyncIO->read(pPvt->pasynUserSync,
                      &value, pPvt->mask,pPvt->pasynUser->timeout);
    if (status == asynSuccess) {
        pr->val = value;
        pr->udf = 0;
    }
    else {
        printf("initLo ERROR: portName = %s, addr = %d, userParam = %s, error = %d\n",
            pPvt->portName, pPvt->addr, pPvt->userParam, status);
    }

And I got this for all addr = 1:

initLo: portName = BPM, addr = 1, userParam = TRIGGER_RCV_CNT_RST
initLo ERROR: portName = BPM, addr = 1, userParam = TRIGGER_RCV_CNT_RST, error = 3

Any suggestions on how I should proceed?

Thanks!

Lucas

On Wed, Jun 12, 2019 at 7:57 PM Mark Rivers <[email protected]<mailto:[email protected]>> wrote:
Hi Lucas,


You listed these parameters 4 parameters as having problems:

 ACQ_TRIGGER
ACQ_TRIGGER_EVENT

ACQ_TRIGGER_REP

ACQ_TRIGGER_POL


You said the readUInt32Digital function only seems to be called for those with addr=0, not with addr=1.


When I look up those parameters in your template file I see that those are mbbo/mbbi records.  You said that other parameters are called correctly for both addr=0 and addr=1.  Can you see if the mbbo/mbbi records all fail to be called with addr=1 and all other record types are called OK with addr=1?


I also notice that some of your mbbo records use asynInt32, e.g. BPM_MODE, and some use asynUInt32Digital, e.g. ACQ_TRIGGER.  Does one of the interfaces fail and one work for mbbo records?  Why are you using different interfaces for different records?


The code that does the initial call to asynPortDriver::readUInt32Digital is in devAsynUInt32Digital::initMbbo.


    status = pasynUInt32DigitalSyncIO->read(pPvt->pasynUserSync,
                      &value, pPvt->mask, pPvt->pasynUser->timeout);

That code is called for every mbbo record unless init_common returns an error.  If init_common returns an error it always prints an error message. Did you check carefully that there are no error messages right after iocInit?

If you still think your driver is not being called for addr=1 with those parameters you could add a debugging printf just before the above call that prints pPvt->portName, pPvt->addr, and pPvt->userParam.  That will show you if it is calling the port for addr=1 and that parameter string.

Mark



________________________________
From: [email protected]<mailto:[email protected]> <[email protected]<mailto:[email protected]>> on behalf of Lucas Russo via Tech-talk <[email protected]<mailto:[email protected]>>
Sent: Wednesday, June 12, 2019 11:50 AM
To: Hinko Kocevar
Cc: [email protected]<mailto:[email protected]>
Subject: Re: Asyn 4-35 IOC upgrade misbehavior

Hi Hinko,

I forgot to point out the correct branch of that repository. I'm using the following https://github.com/lnls-dig/bpm-epics-ioc/blob/base-3.15-synapps-lnls-R1-2-1/BPMApp/src/drvBPM.cpp, which includes the asynNDArrayDriver modification already.

I had taken a look at the ADCore release notes, but couldn't find anything else that might explain the issue I'm having. Maybe I missed something?

Thanks for taking a look!

Lucas Russo

On Wed, Jun 12, 2019 at 1:48 PM Hinko Kocevar via Tech-talk <[email protected]<mailto:[email protected]><mailto:[email protected]<mailto:[email protected]>>> wrote:
Forgot tech-talk ..
________________________________________
From: Hinko Kocevar
Sent: Wednesday, June 12, 2019 6:43 PM
To: Lucas Russo
Subject: Re: Asyn 4-35 IOC upgrade misbehavior

Hi Lucas,

I'm going out on a limb here, and Mark will probably correct me if I'm wrong.

I believe that the asynNDArrayDriver class signature has changed between the ADCore R2-0 and R3-6 (as have other things) and you might be passing parameters to the constructor that end up in wrong place:

Compare

https://github.com/lnls-dig/bpm-epics-ioc/blob/95d26f9ccccb4aebcb5814ec6c9648dab13b031a/BPMApp/src/drvBPM.cpp#L717

with

https://github.com/areaDetector/ADCore/blob/035fdf2d0768cce582646b96831b5fff03d1ae0d/ADApp/ADSrc/asynNDArrayDriver.h#L121

Especially "(int)NUM_PARAMS," part is the one I noticed to be out of sync.

Hope this helps,
//hinko
________________________________________
From: [email protected]<mailto:[email protected]><mailto:[email protected]<mailto:[email protected]>> <[email protected]<mailto:[email protected]><mailto:[email protected]<mailto:[email protected]>>> on behalf of Lucas Russo via Tech-talk <[email protected]<mailto:[email protected]><mailto:[email protected]<mailto:[email protected]>>>
Sent: Wednesday, June 12, 2019 3:07:42 PM
To: [email protected]<mailto:[email protected]><mailto:[email protected]<mailto:[email protected]>>
Subject: Asyn 4-35 IOC upgrade misbehavior

Hello everyone,

I've been using the following module versions for a BPM IOC (complete code here: https://github.com/lnls-dig/bpm-epics-ioc) for some time:

EPICS base: 3.14.12.6
asyn: 4-26
areaDetector: R2-0
autosave: 5-9

Now, I'm upgrading this IOC to the following versions:

EPICS base: 3.15.6
asyn: 4-35
areaDetector: R3-6
autosave: 5-9

But I'm experiencing some unexpected behavior when upgrading it. I could track down the issue to the asyn upgrade from 4-26 to 4-35, as I kept everything else the same and changed just the asyn version.

The issue is as follows.

With asyn 4-26, device support devAsynUInt32Digital correctly read the hardware values and updated the corresponding my out records for all addresses. So, specifically, records that control acquisitions for two addresses are correct initialized. I instantiate my Db as follows in my st.cmd:

"
dbLoadRecords("${TOP}/db/BPMAcq.template", "P=${P}, R=${R}, ACQ_NAME=ACQ, PORT=$(PORT), ADDR=0, TIMEOUT=1")
dbLoadRecords("${TOP}/db/BPMAcq.template", "P=${P}, R=${R}, ACQ_NAME=ACQ_PM, PORT=$(PORT), ADDR=1, TIMEOUT=1")
"

And I can see that asyn devAsynUInt32Digital called my read function with some simple debug messages on IOC initialization:

"
2019/06/11 16:11:05.914 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 0, functionId = 118, paramName = ACQ_TRIGGER
2019/06/11 16:11:05.915 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 1, functionId = 119, paramName = ACQ_TRIGGER_EVENT
2019/06/11 16:11:05.915 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 0, functionId = 120, paramName = ACQ_TRIGGER_REP
2019/06/11 16:11:05.916 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 0, functionId = 122, paramName = ACQ_TRIGGER_POL
2019/06/11 16:11:05.918 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 1, value = 1, functionId = 118, paramName = ACQ_TRIGGER
2019/06/11 16:11:05.918 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 1, value = 0, functionId = 119, paramName = ACQ_TRIGGER_EVENT
2019/06/11 16:11:05.918 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 1, value = 1, functionId = 120, paramName = ACQ_TRIGGER_REP
2019/06/11 16:11:05.920 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 1, value = 0, functionId = 122, paramName = ACQ_TRIGGER_POL
2019/06/11 16:11:05.921 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 1000, functionId = 113, paramName = ACQ_SAMPLES_PRE
2019/06/11 16:11:05.922 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 0, functionId = 114, paramName = ACQ_SAMPLES_POST
2019/06/11 16:11:05.922 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 1, functionId = 115, paramName = ACQ_NUM_SHOTS
2019/06/11 16:11:05.923 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 0, functionId = 121, paramName = ACQ_TRIGGER_THRES
2019/06/11 16:11:05.924 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 0, functionId = 123, paramName = ACQ_TRIGGER_SEL
"

I can see that parameters from both addr = 0 and addr = 1 are called.

Now, when I changed to asyn 4-35 I get the following on IOC initialization:

"
2019/06/11 16:13:57.703 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 0, functionId = 125, paramName = ACQ_TRIGGER
2019/06/11 16:13:57.703 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 1, functionId = 126, paramName = ACQ_TRIGGER_EVENT
2019/06/11 16:13:57.704 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 0, functionId = 127, paramName = ACQ_TRIGGER_REP
2019/06/11 16:13:57.705 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 0, functionId = 129, paramName = ACQ_TRIGGER_POL
2019/06/11 16:13:57.709 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 1000, functionId = 120, paramName = ACQ_SAMPLES_PRE
2019/06/11 16:13:57.709 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 0, functionId = 121, paramName = ACQ_SAMPLES_POST
2019/06/11 16:13:57.709 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 1, functionId = 122, paramName = ACQ_NUM_SHOTS
2019/06/11 16:13:57.710 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 0, functionId = 128, paramName = ACQ_TRIGGER_THRES
2019/06/11 16:13:57.712 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 0, functionId = 130, paramName = ACQ_TRIGGER_SEL
2019/06/11 16:13:57.713 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 0, functionId = 131, paramName = ACQ_TRIGGER_FILT
2019/06/11 16:13:57.714 drvBPM:readUInt32Digital: readUInt32Read parameter addr = 0, value = 0, functionId = 132, paramName = ACQ_TRIGGER_HWDLY
"

In this case, only addr = 0 was called and the records associated with addr = 1 are not initialized with the hardware values.

I can see that other parameters with addr != 0 (1, 2, 3, 4...) are called during IOC initialization (not shown here for brevity), but this set of acquisition parameters are not called at all.
So, this is not a problem that affected all address != 0, but only this set.

Could this be related to the "READBACK tag" issue fixed in asyn 4-33 that somehow affected records not using the tag?

"
Fixed a problem with output records that have the asyn:READBACK info tag, i.e. output records that update on callbacks from the driver. Previously it did not correctly distinguish between record processing due to a driver callback (in which case it should not call the driver) and normal record processing (in which case the driver should be called). A new test application, testOutputCallbackApp, was added to test this. It allows testing all combinations of the following 6 settings for all 4 of these device support files:
"

Cheers!

Lucas Russo

Replies:
Re: Asyn 4-35 IOC upgrade misbehavior Lucas Russo via Tech-talk
References:
Asyn 4-35 IOC upgrade misbehavior Lucas Russo via Tech-talk
Re: Asyn 4-35 IOC upgrade misbehavior Hinko Kocevar via Tech-talk
Re: Asyn 4-35 IOC upgrade misbehavior Lucas Russo via Tech-talk
Re: Asyn 4-35 IOC upgrade misbehavior Mark Rivers via Tech-talk
Re: Asyn 4-35 IOC upgrade misbehavior Lucas Russo via Tech-talk
Re: Asyn 4-35 IOC upgrade misbehavior Mark Rivers via Tech-talk
Re: Asyn 4-35 IOC upgrade misbehavior Mark Rivers via Tech-talk
RE: Asyn 4-35 IOC upgrade misbehavior Mark Rivers via Tech-talk
Re: Asyn 4-35 IOC upgrade misbehavior Lucas Russo via Tech-talk
Re: Asyn 4-35 IOC upgrade misbehavior Mark Rivers via Tech-talk
RE: Asyn 4-35 IOC upgrade misbehavior Mark Rivers via Tech-talk
Re: Asyn 4-35 IOC upgrade misbehavior Lucas Russo via Tech-talk
Navigate by Date:
Prev: Re: Asyn 4-35 IOC upgrade misbehavior Lucas Russo via Tech-talk
Next: Re: Asyn 4-35 IOC upgrade misbehavior Lucas Russo 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  <2019>  2020  2021  2022  2023  2024 
Navigate by Thread:
Prev: Re: Asyn 4-35 IOC upgrade misbehavior Lucas Russo via Tech-talk
Next: Re: Asyn 4-35 IOC upgrade misbehavior Lucas Russo 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  <2019>  2020  2021  2022  2023  2024 
ANJ, 13 Jun 2019 Valid HTML 4.01! · Home · News · About · Base · Modules · Extensions · Distributions · Download ·
· Search · EPICS V4 · IRMIS · Talk · Bugs · Documents · Links · Licensing ·