EPICS Controls Argonne National Laboratory

Experimental Physics and
Industrial Control System

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  <20202021  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  <20202021  2022  2023  2024 
<== Date ==> <== Thread ==>

Subject: Re: Filtering messages print on the IOC shell console
From: "Johnson, Andrew N. via Tech-talk" <tech-talk at aps.anl.gov>
To: "Rivers, Mark L." <rivers at cars.uchicago.edu>
Cc: EPICS tech-talk <tech-talk at aps.anl.gov>
Date: Fri, 10 Apr 2020 17:24:49 +0000
On Apr 9, 2020, at 6:48 PM, Mark Rivers <rivers at cars.uchicago.edu> wrote:

As expected the taskDelay command itself is garbled but it then allows time for the rest of the error messages to appear before the next vxWorks shell command is executed.
 
dbLoadTemplate "DAC.template"
value = filename="..0/dbStatic/dbLexRout = ines.c" line numb0xer=264
S_nfsLib_NF0
#fflush(epicsGetStderr())
peninNOENT dbRead otaskDelay(120)
g file /corvette/home/epics/devel/dac128V-2-9/db/xsingleDAC.db

I color-coded the quoted text above (you will have to view this message as HTML to follow this) and discovered something interesting that I hadn’t noticed before: It’s not just that different messages are getting mixed together, we seem to have the text of a single message being scrambled and parts of it lost. The brown text all comes from the VxWorks shell and is in order. The rest is from a single call to errPrintf() which is getting scrambled. Here is one instance of that error message from later on, as it should appear:

filename="../dbStatic/dbLexRoutines.c" line number=264
S_nfsLib_NFSERR_NOENT dbRead opening file /corvette/home/epics/devel/dac128V-2-9/db/xsingleDAC.db

The red and blue text come from that message, but there are some characters completely missing – “SERR_” is nowhere to be found (that’s 5 characters) and also the first 5 characters in blue are also being output before they should.

If, as Eric Norum says, stderr should be flushing each character then why does stderr output appear in the middle of the following vxWorks commands? 

The implication is that this has nothing to do with flushing stderr. So how is it being output? Here’s the call to errPrintf() from dbLexRoutines line 264:

            errPrintf(0, __FILE__, __LINE__,
                "dbRead opening file %s",pinputFile->filename);

It’s passing in a status of 0, which tells errPrinf() to read errno for the actual error. The errPrintf() code (in modules/libcom/src/error/errlog.c checks that we aren’t inside an ISR and finds out whether it can block or not. I’m expecting isOkToBlock to be true, but actually … (see below). We ask errSymLookup() to copy a string representation of the error value into our name buffer. The next if () condition will be true when the IOC is in the process of shutting down, or when our thread is allowed to block and we haven’t been silenced by some earlier call to eltc(0). First it finds the console output stream, which should be stderr in this case, then it sends the message to that stream in several parts – filename and line-number, the error symbol, the message string, and a newline. The stream is then flushed.

We’re not done yet with errPrintf(), but I have one suggestion that Mark may want to try, just for an experiment: Before your startup script calls dbLoadTemplate(), try doing

errlogSetConsole(epicsGetStdout())

I’m not expecting that to fix the problem, but it should switch the message to come out on stdout instead or stderr, which might tell us something about the effect that line-buffering the output stream would have. If it has no effect that may hint that the messages are being queued through the errlog queue instead of being printed immediately. It’s a pity that the format strings being passed to fprintf() are identical to the ones lower down, so I can’t be 100% sure that these errors are being printed by this code; maybe Mark could also add the following calls to the script as well so we can confirm what it normally returns for the VxWorks shell task, and set it if necessary:

epicsThreadIsOkToBlock()
epicsThreadSetOkToBlock(1)

Actually looking at the code in Base, the only calls to epicsThreadSetOkToBlock(1) come from iocsh (just before it starts reading command strings) and from one of the components of iocInit(), and it looks like the default value is 0, so I’m wondering if that last call might actually fix the original problem.

Just saw Freddie’s message, which roughly agrees with my connection here. I suggest we try this before I do any more analysis of why the above messages were re-ordered.

- Andrew

-- 
Complexity comes for free, simplicity you have to work for.


Replies:
Re: Filtering messages print on the IOC shell console Johnson, Andrew N. via Tech-talk
Re: Filtering messages print on the IOC shell console Mark Rivers via Tech-talk
References:
Filtering messages print on the IOC shell console Paduan Donadio, Marcio via Tech-talk
Re: Filtering messages print on the IOC shell console Johnson, Andrew N. via Tech-talk
Re: Filtering messages print on the IOC shell console Konrad, Martin via Tech-talk
Re: Filtering messages print on the IOC shell console Konrad, Martin via Tech-talk
RE: Filtering messages print on the IOC shell console Mark Rivers via Tech-talk
Re: Filtering messages print on the IOC shell console J. Lewis Muir via Tech-talk
Re: Filtering messages print on the IOC shell console Mark Rivers via Tech-talk
Re: Filtering messages print on the IOC shell console Johnson, Andrew N. via Tech-talk
RE: Filtering messages print on the IOC shell console Mark Rivers via Tech-talk
RE: Filtering messages print on the IOC shell console Mark Rivers via Tech-talk

Navigate by Date:
Prev: RE: Filtering messages print on the IOC shell console Freddie Akeroyd - UKRI STFC via Tech-talk
Next: Re: Filtering messages print on the IOC shell console Johnson, Andrew N. 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  <20202021  2022  2023  2024 
Navigate by Thread:
Prev: RE: Filtering messages print on the IOC shell console Freddie Akeroyd - UKRI STFC via Tech-talk
Next: Re: Filtering messages print on the IOC shell console Johnson, Andrew N. 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  <20202021  2022  2023  2024 
ANJ, 10 Apr 2020 Valid HTML 4.01! · Home · News · About · Base · Modules · Extensions · Distributions · Download ·
· Search · EPICS V4 · IRMIS · Talk · Bugs · Documents · Links · Licensing ·