RE: Filtering messages print on the IOC shell console

[Freddie Akeroyd - UKRI STFC via Tech-talk <tech-talk at aps.anl.gov>]

Hi Mark,

Your non-error output has the lines 

# firstChan   = first channel to be digitized.  This must be in the range:
#               0 to 31 (single-ended)
#               0 to 15 (differential)
# lastChan    = last channel to be digitized
# intVec        Interrupt vector

In the error output  "# lastChan" looks to be missing - is output being lost as well as garbled?

The "stdout" output appears to print all together, I think it is by default line buffered so gets flushed either when there is a \n or the buffer fills up.

The "stderr" output is unbuffered, but looks a bit more garbed than I might have expected. I wonder if you could improve the output ordering by making "stderr" line buffered with a call setvbuf() early in the ioc startup ( maybe in main() )

Regards,

Freddie

-----Original Message-----
From: Tech-talk <tech-talk-bounces at aps.anl.gov> On Behalf Of Mark Rivers via Tech-talk
Sent: 27 March 2020 14:27
To: 'Konrad, Martin' <konrad at frib.msu.edu>; J. Lewis Muir <jlmuir at imca-cat.org>; Johnson, Andrew N. <anj at anl.gov>
Cc: EPICS Tech-Talk <tech-talk at aps.anl.gov>
Subject: RE: Filtering messages print on the IOC shell console

Hi Martin,

> dbLoadTemplate.y is printing messages using fprintf(stderr,...); My 
> recommendation would be to print all messages to the same stream.

Unfortunately this is out of my control.  The problem I am seeing is the garbling of output from dbLoadTemplate (EPICS base) and the echoing of subsequent vxWorks shell commands (Wind River).

But this suggests that the vxWorks shell is proceeding to execute the next command before the previous one has displayed all of its output on the console?  This does not seem correct.

Note that in my previous post I was using procServ for the telnet connection to this IOC through a terminal server, so perhaps procServ was the problem.  I took procServ out of the loop and I see the same thing:

*************************************
# Initialize Systran DAC
# initDAC128V(char *portName, int carrier, int slot) # portName  = name to give this asyn port
# carrier     = IPAC carrier number (0, 1, etc.)
# slot        = IPAC slot (0,1,2,3, etc.)
initDAC128V("DAC1", 0, 3)
value = 0 = 0x0
dbLoadTemplate "DAC.template"
filename="../dbStatic/dbLevalue = xRoutines.c"0 line number=264 S_ = nfsLib_NFSERR_NOE0xNT dbRead opening 0

file /corvet Acromag IP-330 ADC
/dac128/epics/devel# initIp330(
db2-9/db/singleDAC.#   const char *portName, int carrier, int slot,

filename="../d *typeString, const char *rangeString,
es.c" l/dbLexRoutin#   int firstChan, int lastChan,
ine number=264
sLib#   int intVec)
d opening file /Rea# portName    = name to give this asyn port
/devel/dac1me/epics# carrier     = IPAC carrier number (0, 1, etc.)
C.db2-9/db/singleDA# slot        = IPAC slot (0,1,2,3, etc.)

filename="..  = "D" or "S" for differential or single-ended ines.c"ic/dbLexRout# rangeString = "-5to5","-10to10","0to5", or "0to10"
 line number=264
nfsLib_NFSERR_NO  This value must match hardware setting selected
file bRead opening # firstChan   = first channel to be digitized.  This must be in the range:
scorvette/home/epic#               0 to 31 (single-ended)
ddevel/dac128V-2-9/#               0 to 15 (differential)
b/singleDAC.db
filename="../dbStatt channel to be digitized
 line nxRoutines.c"# intVec        Interrupt vector
umber=264
NFSERR_NOENT dp330("Ip330_1",0,2,"D","-5to5",0,15,120)
value = 0 = 0x0
*************************************

Note that if I fix the problem with the missing singleDAC.db file then the output is fine:

*************************************
# Initialize Systran DAC
# initDAC128V(char *portName, int carrier, int slot) # portName  = name to give this asyn port
# carrier     = IPAC carrier number (0, 1, etc.)
# slot        = IPAC slot (0,1,2,3, etc.)
initDAC128V("DAC1", 0, 3)
value = 0 = 0x0
dbLoadTemplate "DAC.template"
value = 0 = 0x0

# Initialize Acromag IP-330 ADC
# initIp330(
#   const char *portName, int carrier, int slot,
#   const char *typeString, const char *rangeString,
#   int firstChan, int lastChan,
#   int intVec)
# portName    = name to give this asyn port
# carrier     = IPAC carrier number (0, 1, etc.)
# slot        = IPAC slot (0,1,2,3, etc.)
# typeString  = "D" or "S" for differential or single-ended # rangeString = "-5to5","-10to10","0to5", or "0to10"
#               This value must match hardware setting selected
# firstChan   = first channel to be digitized.  This must be in the range:
#               0 to 31 (single-ended)
#               0 to 15 (differential)
# lastChan    = last channel to be digitized
# intVec        Interrupt vector
initIp330("Ip330_1",0,2,"D","-5to5",0,15,120)
value = 0 = 0x0
*************************************

So the problem is that dbLoadTemplate error messages are still coming out when the vxWorks shell has proceeded to process the next comments and commands in the file.

Is this how it should work?

Mark

-----Original Message-----
From: Konrad, Martin <konrad at frib.msu.edu>
Sent: Friday, March 27, 2020 9:09 AM
To: Mark Rivers <rivers at cars.uchicago.edu>; J. Lewis Muir <jlmuir at imca-cat.org>; Johnson, Andrew N. <anj at anl.gov>
Cc: EPICS Tech-Talk <tech-talk at aps.anl.gov>
Subject: Re: Filtering messages print on the IOC shell console

Hi Mark,
> Here is an example of garbled output coming simply from the 
> dbLoadTemplate command.
> [...]
> Is this because dbLoadTemplate is actually loading the database file 
> in another thread?  If not why is it garbled?
dbLoadTemplate.y is printing messages using

fprintf(stderr,...);

Other parts of the code are probably printing to stdout. AFAIK POSIX doesn't give any guarantees regarding the ordering of messages printed to stdout vs. stderr. The following example demonstrates the problem:

#include <stdio.h>

int main() {

printf("AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA");
  fprintf(stderr,
"BBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBB");
}

On my Linux machine I get the following output:

AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAABBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBAAAAA

This suggests that my OS is using a 1024 byte buffer. Other operating systems might use different buffer sizes. I'm not sure if the behavior is specified when the messages are terminated with a linebreak.

My recommendation would be to print all messages to the same stream.

-Martin

--
Martin Konrad
Facility for Rare Isotope Beams
Michigan State University
640 South Shaw Lane
East Lansing, MI 48824-1321, USA
Tel. 517-908-7253
Email: konrad at frib.msu.edu