Experimental Physics and
Industrial Control System

Andrew Johnson <[email protected]> · Mon, 3 Nov 2008 14:40:34 -0600

Hi Lewis,

On Saturday 01 November 2008 15:56:52 J. Lewis Muir wrote:
>
> I'm having a problem with errlogVprintf.  When I use it, messages are
> not written to the console; they only get written into the errlog
> facility.  I would expect the messages to be written to the console like
> they are for errlogPrintf.

Ooh, code archaeological research <grin>...

There is a note in the latest AppDevGuide in section 10.2.1 that says

> If epicsThreadIsOkToBlock is true, which is true during iocInit,
> errlogVprintf does NOT send output to the errlog task.

That matches the behavior you're seeing.  Also, section 10.5 says:

> The errlog system can also display messages on the ioc console. It calls
> epicsThreadIsOkToBlock to decide when to display the message. If it is OK
> to block, the message is displayed by the same thread that calls one of the
> errlog print routines. If it is not OK to block, errlogThread displays the
> messages.

The last sentence is obviously not true, and was added for the R3.14.7 
AppDevGuide whereas the contradiction in 10.2.1 was added later for the 
R3.14.8 version.

The middle sentence "by the same thread" is important in understanding why the 
existing code is like it is.  Developers don't particularly like it if their 
errlogPrintf() output doesn't come out immediately; they expect the sequence 
of calls
	printf("A\n");
	errlogPrintf("B\n");
	printf("C\n");
to generate "A" "B" and "C" in order, which is why the "by the same thread" 
part was added.  Now if epicsThreadIsOkToBlock() returns false we must avoid 
blocking the thread (any kind of printf() to a file descriptor is potentially 
blocking) so we have no choice but to punt the printf() to the errlogThread, 
but where blocking isn't a problem it's nicer to do the printf() directly in 
the calling thread.

One other piece of evidence is relevent at this point: The macro va_copy() was 
only standardized in C99, and is not yet available on all of the platforms we 
have to support.  Unfortunately without va_copy() it's not possible for 
errlogVprintf() to call vfprintf(stderr, pFormat, pvar) followed by 
tvsnPrint(pbuffer, ..., pvar) because we have no way to reset pvar back to 
point to the first item in the va_list.

So why doesn't it just convert the text into the buffer and then fprintf() 
that?  I think that is probably because we have a strict length limit on the 
output message (normally 256 bytes, but can be made longer at init time).  
The current implementation of errlogPrintf() ensures that the whole message 
will always get printed to the console, although the logged version will get 
truncated.

Looking through CVS, back in R3.14.7 the 'direct output to console' 
functionality was implemented in errlogVprintf(), but it didn't work on all 
platforms because it passed pvar first to vfprintf() and then to tvsnPrint() 
without resetting it in between (that works on some architectures, but not on 
PowerPC or x86_64 CPUs).  In R3.14.8.2 it was moved to errlogPrintf() and the 
note about errlogVprintf() added to the AppDevGuide.

I hope that explains how we got to where we are, the question is now what to 
do about it?  I agree that there should be no difference in the visible 
behavior between the two errlog(P|Vp)rintf routines, so what we have now 
needs at least some reworking.

The question I have for any core-talk readers still paying attention is:

    How important is it that errlogPrintf() and friends directly call
    fprintf(stderr) when called in a thread that is allowed to block?

    My inclination would be to do what Lewis proposes and do all the
    console output from the errlogThread, but that would often cause
    the example above to output "A", "C" and then later "B".

Comments please, if you care...

- Andrew
-- 
Talk is cheap. Show me the code. -- Linus Torvalds

Experimental Physics and Industrial Control System

Experimental Physics and
Industrial Control System