Experimental Physics and Industrial Control System
What version of asyn are you running?
If the CPU usage is that low then something else is causing the problem.
Mark
________________________________________
From: Paweł Plewiński [[email protected]]
Sent: Wednesday, April 12, 2017 3:29 AM
To: Mark Rivers
Cc: [email protected]
Subject: Re: [AsynPortDriver] "Multiple interrupt callbacks between processing" warning with multiple arrays
This is an x86-64 PC based on Core 2 Duo L7400 (2x 1,5 Ghz) running in a
MTCA chassis, it's running Ubuntu Linux with kernel 4.4.0. Epics is
supplied from debian packages. The overall CPU consumption is under 15%
(usually about 5%), with about 2% for the IOC (split in several
processes).
I haven't set this variable myself so I assume it defaults to 16384.
Kind regards,
Paweł
W dniu 2017-04-11 22:01, Mark Rivers napisał(a):
> That is strange. I run many waveform records at 10Hz or greater on
> VME system which are not fast CPUs at all. What kind of CPU and what
> operating system is this? What does your OS report for the CPU usage
> when you are running the IOC and the driver is sleeping for 0.5
> seconds?
>
> Are your waveform records forward linked to any other records which
> could be slowing things down?
>
> What value are you using for EPICS_CA_MAX_ARRAY_BYTES?
>
> Mark
>
>
>
> -----Original Message-----
> From: Paweł Plewiński [mailto:[email protected]]
> Sent: Tuesday, April 11, 2017 2:55 PM
> To: Mark Rivers
> Cc: [email protected]
> Subject: Re: [AsynPortDriver] "Multiple interrupt callbacks between
> processing" warning with multiple arrays
>
>> When you say "lower than 1 second" do you mean the time between
>> callbacks in your driver is less than 1 second, i.e. the usleep()
>> value is less than 1000000?
> Exactly, value below 1000000 (well, actually I can get down to 600000
> without warnings) in usleep results in warnings. Maybe it's a matter of
> speed, the machine that runs the IOC (and only the IOC, CSS is running
> on a separate computer) is not the fastest one, but our Qt application
> for this device is able to achieve update rate of ~100 ms at the same
> time drawing plot, so I think period in the range of 100-150 ms should
> be achievable here.
>
> Now when I added asynSetTraceMask for the "missing" channels 1-3 now it
> reports this warning for all variables.
>
> Kind regards,
> Paweł
>
> W dniu 2017-04-11 21:18, Mark Rivers napisał(a):
>> The record definition and dbpr output looks OK to me.
>>
>> In your original post you said:
>>
>>> The driver works, however if the update rate is lower than 1 second,
>>> strange warning appears in the console at the time of every refresh
>>
>> When you say "lower than 1 second" do you mean the time between
>> callbacks in your driver is less than 1 second, i.e. the usleep()
>> value is less than 1000000?
>>
>>> (and that's only for one of 4 channels), namely:
>>> 2017/04/11 15:42:08.682 PIEZO:OSC-CH0-WAVEFORM
>>> devAsynFloat64Array::interruptCallbackInput
>>> \000\000\000\000\000@\205?\000\000\000\000\000\300\202?\000\000\000\000\000\000\204?\000\000\000\000\000\000\204?\000\000\000\000\000\300\202?\000\000\000\000\000\000\204?\000\000\000\000\000@\205?\000\000\000\000\000\000\204?\000\000\000\000\000\300\202?\000\000\000\000\000\000\204?
>>
>> Is the output coming because you have enabled some asynTrace?
>>
>>> 2017/04/11 15:42:08.682 PIEZO:OSC-CH0-WAVEFORM
>>> devAsynFloat64Array::processCommon, warning, multiple interrupt
>>> callbacks between processing
>>
>> Are you saying that this warning message only happens on the first
>> waveform record, not on all of them? That message is printed with
>> this code in devAsynXXXArray.h:
>>
>> if (pPvt->gotValue) {
>> \
>> asynPrint(pPvt->pasynUser, ASYN_TRACE_WARNING,
>> \
>> "%s %s::processCommon, "
>> \
>> "warning: multiple interrupt callbacks between
>> processing\n", \
>> pr->name, driverName);
>> \
>> }
>> \
>>
>> Note that it is printed with the ASYN_TRACE_WARNING mask. How have
>> you called asynSetTraceMask in your startup script? Is it possible
>> you set it like this?
>>
>> asynSetTraceMask(testAPD, 0, 255)
>>
>> If so that would explain why you are only seeing the messages for the
>> first waveform record. The asynTrace is specific to the asyn address,
>> and this only enables asynTrace on address 0. To see the messages
>> from all 4 waveform records you can do this:
>>
>> asynSetTraceMask(testAPD, -1, 255)
>>
>> or this
>>
>> asynSetTraceMask(testAPD, 0, 255)
>> asynSetTraceMask(testAPD, 1, 255)
>> asynSetTraceMask(testAPD, 2, 255)
>> asynSetTraceMask(testAPD, 3, 255)
>>
>> This would not explain why you are getting the messages in the first
>> place, but it would explain why you are only seeing them for the first
>> waveform record.
>>
>> Mark
>>
>> -----Original Message-----
>> From: Paweł Plewiński [mailto:[email protected]]
>> Sent: Tuesday, April 11, 2017 1:55 PM
>> To: Mark Rivers
>> Cc: [email protected]
>> Subject: Re: [AsynPortDriver] "Multiple interrupt callbacks between
>> processing" warning with multiple arrays
>>
>> Hi Mark,
>>
>> thanks for quick answer. Actually I forgot to post the record, but it
>> had SCAN set to I/O INTR, similarly to the example project. Here's the
>> record definition:
>>
>> record(waveform, "PIEZO:OSC-CH$(CHANNEL)-WAVEFORM")
>> {
>> field(DTYP, "asynFloat64ArrayIn")
>> field(INP, "@asyn($(PORT),$(ADDR),$(TIMEOUT))OSC_WAVEFORM")
>> field(FTVL, "DOUBLE")
>> field(NELM, "$(NPOINTS)")
>> field(LOPR, "0")
>> field(HOPR, "10")
>> field(SCAN, "I/O Intr")
>> }
>>
>> As for the commands you asked for, the results are, respectively:
>>
>> ACKS: NO_ALARM ACKT: YES APST: Always ASG:
>> ASP: (nil) BKPT: 00 BPTR: 0xbcb3e0 BUSY: 0
>> DESC: DISA: 0 DISP: 0 DISS:
>> NO_ALARM
>> DISV: 1 DPVT: 0xc05690 DSET: 0x7f2dbdcea9a0
>> DTYP: asynFloat64ArrayIn EGU: EVNT: 0
>> FLNK:CONSTANT 0 FTVL: DOUBLE HASH: 0 HOPR: 10
>> INP:INST_IO @asyn(testAPD,0,1)OSC_WAVEFORM LCNT: 0
>> LOPR: 0 LSET: 0xc07f40
>> MLIS: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
>> MLOK: b0 b3 bc 00 00 00 00 00 MPST: Always
>> NAME: PIEZO:OSC-CH0-WAVEFORM NELM: 1000 NORD: 1000
>> NSEV: NO_ALARM NSTA: NO_ALARM PACT: 0 PHAS: 0
>> PINI: NO PPN: (nil) PPNR: (nil) PREC: 0
>> PRIO: LOW PROC: 0 PUTF: 0 RARM: 0
>> RDES: 0xb86470 RPRO: 0 RSET: 0x7f2dbda73340
>> SCAN: I/O Intr SDIS:CONSTANT SEVR: NO_ALARM
>> SIML:CONSTANT
>> SIMM: NO SIMS: NO_ALARM SIOL:CONSTANT SPVT:
>> 0xc135e0
>> STAT: NO_ALARM TIME: 2017-04-11 20:53:12.153366126 TPRO: 0
>> TSE: 0 TSEL:CONSTANT UDF: 0 VAL: (nil)
>>
>>
>> ACKS: NO_ALARM ACKT: YES APST: Always ASG:
>> ASP: (nil) BKPT: 00 BPTR: 0xbcd3a0 BUSY: 0
>> DESC: DISA: 0 DISP: 0 DISS:
>> NO_ALARM
>> DISV: 1 DPVT: 0xc05be0 DSET: 0x7f2dbdcea9a0
>> DTYP: asynFloat64ArrayIn EGU: EVNT: 0
>> FLNK:CONSTANT 0 FTVL: DOUBLE HASH: 0 HOPR: 10
>> INP:INST_IO @asyn(testAPD,1,1)OSC_WAVEFORM LCNT: 0
>> LOPR: 0 LSET: 0xc07f60
>> MLIS: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
>> MLOK: 70 d3 bc 00 00 00 00 00 MPST: Always
>> NAME: PIEZO:OSC-CH1-WAVEFORM NELM: 1000 NORD: 1000
>> NSEV: NO_ALARM NSTA: NO_ALARM PACT: 0 PHAS: 0
>> PINI: NO PPN: (nil) PPNR: (nil) PREC: 0
>> PRIO: LOW PROC: 0 PUTF: 0 RARM: 0
>> RDES: 0xb86470 RPRO: 0 RSET: 0x7f2dbda73340
>> SCAN: I/O Intr SDIS:CONSTANT SEVR: NO_ALARM
>> SIML:CONSTANT
>> SIMM: NO SIMS: NO_ALARM SIOL:CONSTANT SPVT:
>> 0xc138f0
>> STAT: NO_ALARM TIME: 2017-04-11 20:53:29.910249080 TPRO: 0
>> TSE: 0 TSEL:CONSTANT UDF: 0 VAL: (nil)
>>
>>
>> ACKS: NO_ALARM ACKT: YES APST: Always ASG:
>> ASP: (nil) BKPT: 00 BPTR: 0xbcf360 BUSY: 0
>> DESC: DISA: 0 DISP: 0 DISS:
>> NO_ALARM
>> DISV: 1 DPVT: 0xc060e0 DSET: 0x7f2dbdcea9a0
>> DTYP: asynFloat64ArrayIn EGU: EVNT: 0
>> FLNK:CONSTANT 0 FTVL: DOUBLE HASH: 0 HOPR: 10
>> INP:INST_IO @asyn(testAPD,2,1)OSC_WAVEFORM LCNT: 0
>> LOPR: 0 LSET: 0xc07f80
>> MLIS: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
>> MLOK: 30 f3 bc 00 00 00 00 00 MPST: Always
>> NAME: PIEZO:OSC-CH2-WAVEFORM NELM: 1000 NORD: 1000
>> NSEV: NO_ALARM NSTA: NO_ALARM PACT: 0 PHAS: 0
>> PINI: NO PPN: (nil) PPNR: (nil) PREC: 0
>> PRIO: LOW PROC: 0 PUTF: 0 RARM: 0
>> RDES: 0xb86470 RPRO: 0 RSET: 0x7f2dbda73340
>> SCAN: I/O Intr SDIS:CONSTANT SEVR: NO_ALARM
>> SIML:CONSTANT
>> SIMM: NO SIMS: NO_ALARM SIOL:CONSTANT SPVT:
>> 0xc13c00
>> STAT: NO_ALARM TIME: 2017-04-11 20:54:17.907769453 TPRO: 0
>> TSE: 0 TSEL:CONSTANT UDF: 0 VAL: (nil)
>>
>>
>> ACKS: NO_ALARM ACKT: YES APST: Always ASG:
>> ASP: (nil) BKPT: 00 BPTR: 0xa7b540 BUSY: 0
>> DESC: DISA: 0 DISP: 0 DISS:
>> NO_ALARM
>> DISV: 1 DPVT: 0xab0810 DSET: 0x7efec944b9a0
>> DTYP: asynFloat64ArrayIn EGU: EVNT: 0
>> FLNK:CONSTANT 0 FTVL: DOUBLE HASH: 0 HOPR: 10
>> INP:INST_IO @asyn(testAPD,3,1)OSC_WAVEFORM LCNT: 0
>> LOPR: 0 LSET: 0xab21d0
>> MLIS: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
>> MLOK: 10 b5 a7 00 00 00 00 00 MPST: Always
>> NAME: PIEZO:OSC-CH3-WAVEFORM NELM: 1000 NORD: 1000
>> NSEV: NO_ALARM NSTA: NO_ALARM PACT: 0 PHAS: 0
>> PINI: NO PPN: (nil) PPNR: (nil) PREC: 0
>> PRIO: LOW PROC: 0 PUTF: 0 RARM: 0
>> RDES: 0xa30650 RPRO: 0 RSET: 0x7efec91d4340
>> SCAN: I/O Intr SDIS:CONSTANT SEVR: NO_ALARM
>> SIML:CONSTANT
>> SIMM: NO SIMS: NO_ALARM SIOL:CONSTANT SPVT:
>> 0xabe140
>> STAT: NO_ALARM TIME: 2017-04-11 20:52:33.970326348 TPRO: 0
>> TSE: 0 TSEL:CONSTANT UDF: 0 VAL: (nil)
>>
>>
>> Best regards,
>> Paweł
>>
>>
>>
>> W dniu 2017-04-11 18:24, Mark Rivers napisał(a):
>>> Hi Pawel,
>>>
>>> What is the SCAN field of your waveform record? I suspect it is
>>> probably periodic ("1 second", etc.). For this application you
>>> should
>>> set it to SCAN="I/O Intr". Then the waveform record will process
>>> each
>>> time your driver does a callback to device support. If the record is
>>> periodically processing at 1 second and your driver is doing
>>> callbacks
>>> faster than 1 Hz then you will see the error you report.
>>>
>>> Mark
>>>
>>>
>>> -----Original Message-----
>>> From: [email protected]
>>> [mailto:[email protected]] On Behalf Of Pawel Plewinski
>>> Sent: Tuesday, April 11, 2017 8:49 AM
>>> To: [email protected]
>>> Subject: [AsynPortDriver] "Multiple interrupt callbacks between
>>> processing" warning with multiple arrays
>>>
>>> Hi,
>>>
>>> I've recently written asyn-based device support for a custom device
>>> communicating over PCIe. One of its functions is to periodically
>>> retrieve 4 waveforms from 4 channels, which is done in a separate
>>> thread, from which the callback function is called to notify asyn
>>> about
>>> change. I heavily based the code on the AsynPortDriver example.
>>> The driver works, however if the update rate is lower than 1 second,
>>> strange warning appears in the console at the time of every refresh
>>> (and
>>> that's only for one of 4 channels), namely:
>>>
>>> 2017/04/11 15:42:08.682 PIEZO:OSC-CH0-WAVEFORM
>>> devAsynFloat64Array::interruptCallbackInput
>>> \000\000\000\000\000@\205?\000\000\000\000\000\300\202?\000\000\000\000\000\000\204?\000\000\000\000\000\000\204?\000\000\000\000\000\300\202?\000\000\000\000\000\000\204?\000\000\000\000\000@\205?\000\000\000\000\000\000\204?\000\000\000\000\000\300\202?\000\000\000\000\000\000\204?
>>> 2017/04/11 15:42:08.682 PIEZO:OSC-CH0-WAVEFORM
>>> devAsynFloat64Array::processCommon, warning, multiple interrupt
>>> callbacks between processing
>>>
>>> The parameters passed to the top level constructor are
>>> : asynPortDriver(portName,
>>> 4, /* maxAddr */
>>> (int)NUM_SCOPE_PARAMS,
>>> asynInt32Mask | asynFloat64Mask |
>>> asynFloat64ArrayMask | asynEnumMask | asynDrvUserMask, /* Interface
>>> mask
>>> */
>>> asynInt32Mask | asynFloat64Mask |
>>> asynFloat64ArrayMask | asynEnumMask, /* Interrupt mask */
>>> ASYN_MULTIDEVICE, /* asynFlags. This driver
>>> does
>>> not block and it is not multi-device, so flag is 0 */
>>> 1, /* Autoconnect */
>>> 0, /* Default priority */
>>> 0) /* Default stack size*/
>>>
>>> The readback thread code:
>>>
>>> void piezoPortDriver::readbackTask(void)
>>> {
>>> while (1) {
>>> bool stopped = false;
>>>
>>> lock();
>>> auto new_data = osc->fetch_data(vtim, vdat);
>>> unlock();
>>>
>>> if (!stopped)
>>> {
>>> lock();
>>> this->osc_update_trigger();
>>> unlock();
>>> }
>>> callParamCallbacks();
>>>
>>> for (int i = 0; i < 4; i++){
>>> doCallbacksFloat64Array(vdat[i].data(), vdat[i].size(),
>>> P_OscWaveform, i);
>>> }
>>> usleep(100000);
>>> }
>>> }
>>>
>>> The fetch_data method reads four 1000-element double vectors from
>>> PCIe.
>>>
>>> Could you give me some suggestions what may be wrong?
>>>
>>> Regards,
>>> Paweł Plewiński
>>> Department of Microelectronics and Computer Science
>>> Lodz University of Technology
- References:
- [AsynPortDriver] "Multiple interrupt callbacks between processing" warning with multiple arrays Paweł Plewiński
- RE: [AsynPortDriver] "Multiple interrupt callbacks between processing" warning with multiple arrays Mark Rivers
- Re: [AsynPortDriver] "Multiple interrupt callbacks between processing" warning with multiple arrays Paweł Plewiński
- RE: [AsynPortDriver] "Multiple interrupt callbacks between processing" warning with multiple arrays Mark Rivers
- Re: [AsynPortDriver] "Multiple interrupt callbacks between processing" warning with multiple arrays Paweł Plewiński
- RE: [AsynPortDriver] "Multiple interrupt callbacks between processing" warning with multiple arrays Mark Rivers
- Re: [AsynPortDriver] "Multiple interrupt callbacks between processing" warning with multiple arrays Paweł Plewiński
- Navigate by Date:
- Prev:
Re: CA client within Asyn Benoit RAT
- Next:
RE: Writing Area Detector Monitor Iain Marcuson
- 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: [AsynPortDriver] "Multiple interrupt callbacks between processing" warning with multiple arrays Paweł Plewiński
- Next:
Writing Area Detector Monitor Iain Marcuson
- 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