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  <20102011  2012  2013  2014  2015  2016  2017  2018  2019  Index 1994  1995  1996  1997  1998  1999  2000  2001  2002  2003  2004  2005  2006  2007  2008  2009  <20102011  2012  2013  2014  2015  2016  2017  2018  2019 
<== Date ==> <== Thread ==>

Subject: Re: Tektronic Scope DPO7254 over VXI-11 crashes IOC
From: Benjamin Franksen <benjamin.franksen@bessy.de>
To: tech-talk@aps.anl.gov
Date: Wed, 17 Mar 2010 13:09:33 +0100
On Wednesday 17 March 2010, Benjamin Franksen wrote:
> I'm trying to talk to the mentioned scope via asyn/stream and get
>  mysterious crashes the first time the IOC tries to communicate over the
>  link. Below is a trace of the IOC shell up to the crash. I am using the
>  latest and greatest versions of everything except EPICS base:
>  base-3.14.8.2, asyn-4.11a (supposedly the last version that works with
>  base-3.14.8), StreamDevice-2- snapshot20081007. The crash happens on the
>  latest ubuntu version as well as on a debian stable system. I should
>  point out that with the exact same setup I can talk fine with e.g. a
>  GPIB controller.

Ok I did dome more research. GÃtz suggested valgrind and indeed I got 
interesting results:

(1) When I run the IOC under valgrind it doesn't crash, it even talks to the 
device. Nice.

(2) Valgrind complains about StreamDevice doing "Mismatched free() / delete 
/ delete []". See below for a transcript.

My current theory is that these mismatched calls cause the memory free list 
to become corrupted. Note that VXI-11 is based on RPC which heavily uses 
malloc/free internally during runtime, so there is some probability that a 
corrupted free list will lead to a crash inside the RPC library.

Dirk, could you look into this?

Cheers
Ben

PS: this is a log of the IOC shell run under valgrind:

> valgrind ../../bin/linux-x86/SIOC3CP ./st.cmd
==31115== Memcheck, a memory error detector
==31115== Copyright (C) 2002-2009, and GNU GPL'd, by Julian Seward et al.
==31115== Using Valgrind-3.5.0-Debian and LibVEX; rerun with -h for 
copyright info
==31115== Command: ../../bin/linux-x86/SIOC3CP ./st.cmd
==31115== 
#!../../bin/linux-x86/SIOC3CP
# Change to top directory
cd ../..
########################################################### Set up 
Environment
epicsEnvSet IOC SIOC3CP
#epicsEnvSet LOG_DIR /opt/IOC/log
epicsEnvSet LOG_DIR /projects/ctl/franksen/epics/ioc/MLS-Controls/work-
scopes/log
#epicsEnvSet EPICS_CA_PUT_LOG_INET 192.168.48.97
epicsEnvSet EPICS_CA_PUT_LOG_INET 193.149.12.189
epicsEnvSet VXI11_IO_TIMEOUT 1
epicsEnvSet VXI11_RPC_TIMEOUT 10
#VXI11_RECOVER_W_IFC 0 : no
#                    1 : yes
epicsEnvSet VXI11_RECOVER_W_IFC 1
epicsEnvSet GPIB_ADDR 1
epicsEnvSet GPIB_LINK L1
epicsEnvSet GPIB_VXI11_NAME gpib0
epicsEnvSet GPIB_GATEWAY gpibc3cp.mlscs.bessy.de
epicsEnvSet SCOPEC2S1GP_INET 192.168.101.116
epicsEnvSet SCOPEC2S1GP_LINK L2
epicsEnvSet SCOPEC2S1GP_ADDR -1
epicsEnvSet SCOPEC2S1GP_VXI11_NAME inst0
epicsEnvSet STREAM_PROTOCOL_PATH db
############################################## Register all support 
components
dbLoadDatabase dbd/SIOC3CP.dbd 0 0
SIOC3CP_registerRecordDeviceDriver pdbbase
############################################################ Configure 
drivers
# Configure asyn vxi-11 driver
#vxi11Configure ${GPIB_LINK} ${GPIB_GATEWAY} ${VXI11_RECOVER_W_IFC} 
${VXI11_IO_TIMEOUT} ${GPIB_VXI11_NAME}
vxi11Configure L2 192.168.101.116 0 1 inst0 0 1
#asynSetTraceMask ${GPIB_LINK} ${GPIB_ADDR} 0x0010
#asynSetTraceIOMask ${GPIB_LINK} ${GPIB_ADDR} 0x0003
#asynSetOption ${GPIB_LINK} -1 rpctimeout ${VXI11_RPC_TIMEOUT}
#asynSetTraceMask ${SCOPEC2S1GP_LINK} ${SCOPEC2S1GP_ADDR} 0x001F
#asynSetTraceIOMask ${SCOPEC2S1GP_LINK} ${SCOPEC2S1GP_ADDR} 0x0003
#asynSetOption ${SCOPEC2S1GP_LINK} -1 rpctimeout ${VXI11_RPC_TIMEOUT}
####################################################### Autosave 
configuration
set_savefile_path /projects/ctl/franksen/epics/ioc/MLS-Controls/work-
scopes/log/autoSaveRestore
save_restoreSet_DatedBackupFiles 1
save_restoreSet_UseStatusPVs 0
######################################################## Load record 
instances
dbLoadRecords db/SIOC-stats.db IOC=SIOC3CP
#dbLoadRecords db/ScopeMeas.db  
"DEVN=SCOPE1ZCP,ADDR=${GPIB_ADDR},LINK=${GPIB_LINK}"
#
dbLoadRecords db/ScopeMeas.db  "DEVN=SCOPEC2S1GP,ADDR=-1,LINK=L2"
######################################################## Restore record 
values
#set_pass0_restoreFile ScopeMeas.sav
########################################################### Configure IOC 
Core
# IOC Log Server Connection  0=enabled 1=disabled
setIocLogDisable 1
# Configure Access Security
#asSetFilename db/no_security.acf
#################################################################### Start 
IOC
iocInit
Starting iocInit
############################################################################
###  EPICS IOC CORE built on Mar  3 2010
###  EPICS R3.14.8.2 $R3-14-8-2$ $2006/01/06 15:55:13$
############################################################################
initHooks: set_pass[0,1]_restoreFile() were never called.
initHooks: Specifying 'auto_settings.sav' and 'auto_positions.sav'
initHooks: for backward compatibility with old autosave/restore.
save_restore: Can't figure out which seq file is most recent,
save_restore: so I'm just going to start with 
'/projects/ctl/franksen/epics/ioc/MLS-Controls/work-
scopes/log/autoSaveRestore/auto_positions.sav0'.
save_restore: Can't find a file to restore from...save_restore: ...last 
tried '/projects/ctl/franksen/epics/ioc/MLS-Controls/work-
scopes/log/autoSaveRestore/auto_positions.sav2'. I give up.
save_restore: Can't figure out which seq file is most recent,
save_restore: so I'm just going to start with 
'/projects/ctl/franksen/epics/ioc/MLS-Controls/work-
scopes/log/autoSaveRestore/auto_settings.sav0'.
save_restore: Can't find a file to restore from...save_restore: ...last 
tried '/projects/ctl/franksen/epics/ioc/MLS-Controls/work-
scopes/log/autoSaveRestore/auto_settings.sav2'. I give up.
==31115== Mismatched free() / delete / delete []
==31115==    at 0x402554D: operator delete(void*) (vg_replace_malloc.c:346)
==31115==    by 0x80598F3: StreamBuffer::grow(long) (StreamBuffer.cc:105)
==31115==    by 0x805DCEC: StreamProtocolParser::readToken(StreamBuffer&, 
char const*, bool) (StreamBuffer.h:42)
==31115==    by 0x805F16C: StreamProtocolParser::parseValue(StreamBuffer&, 
bool) (StreamProtocol.cc:602)
==31115==    by 0x805FA62: 
StreamProtocolParser::parseProtocol(StreamProtocolParser::Protocol&, 
StreamBuffer*) (StreamProtocol.cc:406)
==31115==    by 0x805FBEE: 
StreamProtocolParser::parseProtocol(StreamProtocolParser::Protocol&, 
StreamBuffer*) (StreamProtocol.cc:370)
==31115==    by 0x806001C: 
StreamProtocolParser::StreamProtocolParser(_IO_FILE*, char const*) 
(StreamProtocol.cc:73)
==31115==    by 0x80602B3: StreamProtocolParser::readFile(char const*) 
(StreamProtocol.cc:201)
==31115==    by 0x80603B7: StreamProtocolParser::getProtocol(char const*, 
StreamBuffer const&) (StreamProtocol.cc:135)
==31115==    by 0x8064818: StreamCore::parse(char const*, char const*) 
(StreamCore.cc:216)
==31115==    by 0x80588E7: Stream::initRecord() (StreamEpics.cc:620)
==31115==    by 0x8058C3E: streamInitRecord (StreamEpics.cc:426)
==31115==  Address 0x44540d0 is 0 bytes inside a block of size 128 alloc'd
==31115==    at 0x4026024: operator new[](unsigned int) 
(vg_replace_malloc.c:258)
==31115==    by 0x80598A7: StreamBuffer::grow(long) (StreamBuffer.cc:99)
==31115==    by 0x805DE99: StreamProtocolParser::readToken(StreamBuffer&, 
char const*, bool) (StreamBuffer.h:42)
==31115==    by 0x805F16C: StreamProtocolParser::parseValue(StreamBuffer&, 
bool) (StreamProtocol.cc:602)
==31115==    by 0x805FA62: 
StreamProtocolParser::parseProtocol(StreamProtocolParser::Protocol&, 
StreamBuffer*) (StreamProtocol.cc:406)
==31115==    by 0x805FBEE: 
StreamProtocolParser::parseProtocol(StreamProtocolParser::Protocol&, 
StreamBuffer*) (StreamProtocol.cc:370)
==31115==    by 0x806001C: 
StreamProtocolParser::StreamProtocolParser(_IO_FILE*, char const*) 
(StreamProtocol.cc:73)
==31115==    by 0x80602B3: StreamProtocolParser::readFile(char const*) 
(StreamProtocol.cc:201)
==31115==    by 0x80603B7: StreamProtocolParser::getProtocol(char const*, 
StreamBuffer const&) (StreamProtocol.cc:135)
==31115==    by 0x8064818: StreamCore::parse(char const*, char const*) 
(StreamCore.cc:216)
==31115==    by 0x80588E7: Stream::initRecord() (StreamEpics.cc:620)
==31115==    by 0x8058C3E: streamInitRecord (StreamEpics.cc:426)
==31115== 
==31115== Mismatched free() / delete / delete []
==31115==    at 0x402554D: operator delete(void*) (vg_replace_malloc.c:346)
==31115==    by 0x805BDF7: 
StreamProtocolParser::Protocol::Variable::~Variable() (StreamBuffer.h:67)
==31115==    by 0x805BE6B: StreamProtocolParser::Protocol::~Protocol() 
(StreamProtocol.cc:767)
==31115==    by 0x8064877: StreamCore::parse(char const*, char const*) 
(StreamCore.cc:228)
==31115==    by 0x80588E7: Stream::initRecord() (StreamEpics.cc:620)
==31115==    by 0x8058C3E: streamInitRecord (StreamEpics.cc:426)
==31115==    by 0x8053D9A: initRecord (devaiStream.c:80)
==31115==    by 0x80A64AA: init_record (aiRecord.c:143)
==31115==    by 0x80C38F4: iocInit (iocInit.c:351)
==31115==    by 0x80C3286: iocInitCallFunc (dbAccessRegister.c:69)
==31115==    by 0x80C09BD: iocshBody (iocsh.cpp:743)
==31115==    by 0x8053B1C: main (SoftIocMain.cpp:24)
==31115==  Address 0x4455ae8 is 0 bytes inside a block of size 128 alloc'd
==31115==    at 0x4026024: operator new[](unsigned int) 
(vg_replace_malloc.c:258)
==31115==    by 0x80598A7: StreamBuffer::grow(long) (StreamBuffer.cc:99)
==31115==    by 0x8059B5B: StreamBuffer::init(void const*, long) 
(StreamBuffer.cc:44)
==31115==    by 0x805A7D6: 
StreamProtocolParser::Protocol::Variable::Variable(StreamProtocolParser::Protocol::Variable 
const&) (StreamBuffer.h:61)
==31115==    by 0x805A99C: 
StreamProtocolParser::Protocol::Protocol(StreamProtocolParser::Protocol 
const&, StreamBuffer&, int) (StreamProtocol.cc:744)
==31115==    by 0x805BCE4: StreamProtocolParser::getProtocol(StreamBuffer 
const&) (StreamProtocol.cc:239)
==31115==    by 0x8060353: StreamProtocolParser::getProtocol(char const*, 
StreamBuffer const&) (StreamProtocol.cc:142)
==31115==    by 0x8064818: StreamCore::parse(char const*, char const*) 
(StreamCore.cc:216)
==31115==    by 0x80588E7: Stream::initRecord() (StreamEpics.cc:620)
==31115==    by 0x8058C3E: streamInitRecord (StreamEpics.cc:426)
==31115==    by 0x8053D9A: initRecord (devaiStream.c:80)
==31115==    by 0x80A64AA: init_record (aiRecord.c:143)
==31115== 
==31115== Mismatched free() / delete / delete []
==31115==    at 0x402554D: operator delete(void*) (vg_replace_malloc.c:346)
==31115==    by 0x80596BC: StreamBuffer::replace(long, long, void const*, 
long) (StreamBuffer.cc:215)
==31115==    by 0x80606CB: 
StreamProtocolParser::Protocol::compileString(StreamBuffer&, char const*&, 
FormatType, StreamProtocolParser::Client*, int) (StreamBuffer.h:145)
==31115==    by 0x80666C5: 
StreamCore::compileCommand(StreamProtocolParser::Protocol*, StreamBuffer&, 
char const*, char const*&) (StreamCore.cc:306)
==31115==    by 0x805C9B8: 
StreamProtocolParser::Protocol::compileCommands(StreamBuffer&, char const*&, 
StreamProtocolParser::Client*) (StreamProtocol.cc:1646)
==31115==    by 0x805CB72: StreamProtocolParser::Protocol::getCommands(char 
const*, StreamBuffer&, StreamProtocolParser::Client*) 
(StreamProtocol.cc:924)
==31115==    by 0x8064586: 
StreamCore::compile(StreamProtocolParser::Protocol*) (StreamCore.cc:274)
==31115==    by 0x806482A: StreamCore::parse(char const*, char const*) 
(StreamCore.cc:222)
==31115==    by 0x80588E7: Stream::initRecord() (StreamEpics.cc:620)
==31115==    by 0x8058C3E: streamInitRecord (StreamEpics.cc:426)
==31115==    by 0x8053D9A: initRecord (devaiStream.c:80)
==31115==    by 0x80A64AA: init_record (aiRecord.c:143)
==31115==  Address 0x445fbb0 is 0 bytes inside a block of size 128 alloc'd
==31115==    at 0x4026024: operator new[](unsigned int) 
(vg_replace_malloc.c:258)
==31115==    by 0x8059625: StreamBuffer::replace(long, long, void const*, 
long) (StreamBuffer.cc:208)
==31115==    by 0x80606CB: 
StreamProtocolParser::Protocol::compileString(StreamBuffer&, char const*&, 
FormatType, StreamProtocolParser::Client*, int) (StreamBuffer.h:145)
==31115==    by 0x80666C5: 
StreamCore::compileCommand(StreamProtocolParser::Protocol*, StreamBuffer&, 
char const*, char const*&) (StreamCore.cc:306)
==31115==    by 0x805C9B8: 
StreamProtocolParser::Protocol::compileCommands(StreamBuffer&, char const*&, 
StreamProtocolParser::Client*) (StreamProtocol.cc:1646)
==31115==    by 0x805CB72: StreamProtocolParser::Protocol::getCommands(char 
const*, StreamBuffer&, StreamProtocolParser::Client*) 
(StreamProtocol.cc:924)
==31115==    by 0x8064586: 
StreamCore::compile(StreamProtocolParser::Protocol*) (StreamCore.cc:274)
==31115==    by 0x806482A: StreamCore::parse(char const*, char const*) 
(StreamCore.cc:222)
==31115==    by 0x80588E7: Stream::initRecord() (StreamEpics.cc:620)
==31115==    by 0x8058C3E: streamInitRecord (StreamEpics.cc:426)
==31115==    by 0x8053D9A: initRecord (devaiStream.c:80)
==31115==    by 0x80A64AA: init_record (aiRecord.c:143)
==31115== 
==31115== Mismatched free() / delete / delete []
==31115==    at 0x402554D: operator delete(void*) (vg_replace_malloc.c:346)
==31115==    by 0x8060A6E: 
StreamProtocolParser::Protocol::compileString(StreamBuffer&, char const*&, 
FormatType, StreamProtocolParser::Client*, int) (StreamBuffer.h:67)
==31115==    by 0x80666C5: 
StreamCore::compileCommand(StreamProtocolParser::Protocol*, StreamBuffer&, 
char const*, char const*&) (StreamCore.cc:306)
==31115==    by 0x805C9B8: 
StreamProtocolParser::Protocol::compileCommands(StreamBuffer&, char const*&, 
StreamProtocolParser::Client*) (StreamProtocol.cc:1646)
==31115==    by 0x805CB72: StreamProtocolParser::Protocol::getCommands(char 
const*, StreamBuffer&, StreamProtocolParser::Client*) 
(StreamProtocol.cc:924)
==31115==    by 0x8064586: 
StreamCore::compile(StreamProtocolParser::Protocol*) (StreamCore.cc:274)
==31115==    by 0x806482A: StreamCore::parse(char const*, char const*) 
(StreamCore.cc:222)
==31115==    by 0x80588E7: Stream::initRecord() (StreamEpics.cc:620)
==31115==    by 0x8058C3E: streamInitRecord (StreamEpics.cc:426)
==31115==    by 0x8053D9A: initRecord (devaiStream.c:80)
==31115==    by 0x80A64AA: init_record (aiRecord.c:143)
==31115==    by 0x80C38F4: iocInit (iocInit.c:351)
==31115==  Address 0x445fd90 is 0 bytes inside a block of size 128 alloc'd
==31115==    at 0x4026024: operator new[](unsigned int) 
(vg_replace_malloc.c:258)
==31115==    by 0x80598A7: StreamBuffer::grow(long) (StreamBuffer.cc:99)
==31115==    by 0x8059AAE: StreamBuffer::append(void const*, long) 
(StreamBuffer.h:42)
==31115==    by 0x805D6C7: 
StreamProtocolParser::Protocol::compileFormat(StreamBuffer&, char const*&, 
FormatType, StreamProtocolParser::Client*) (StreamBuffer.h:118)
==31115==    by 0x806065B: 
StreamProtocolParser::Protocol::compileString(StreamBuffer&, char const*&, 
FormatType, StreamProtocolParser::Client*, int) (StreamProtocol.cc:1115)
==31115==    by 0x80666C5: 
StreamCore::compileCommand(StreamProtocolParser::Protocol*, StreamBuffer&, 
char const*, char const*&) (StreamCore.cc:306)
==31115==    by 0x805C9B8: 
StreamProtocolParser::Protocol::compileCommands(StreamBuffer&, char const*&, 
StreamProtocolParser::Client*) (StreamProtocol.cc:1646)
==31115==    by 0x805CB72: StreamProtocolParser::Protocol::getCommands(char 
const*, StreamBuffer&, StreamProtocolParser::Client*) 
(StreamProtocol.cc:924)
==31115==    by 0x8064586: 
StreamCore::compile(StreamProtocolParser::Protocol*) (StreamCore.cc:274)
==31115==    by 0x806482A: StreamCore::parse(char const*, char const*) 
(StreamCore.cc:222)
==31115==    by 0x80588E7: Stream::initRecord() (StreamEpics.cc:620)
==31115==    by 0x8058C3E: streamInitRecord (StreamEpics.cc:426)
==31115== 
save_restore: Can't figure out which seq file is most recent,
save_restore: so I'm just going to start with 
'/projects/ctl/franksen/epics/ioc/MLS-Controls/work-
scopes/log/autoSaveRestore/auto_settings.sav0'.
save_restore: Can't find a file to restore from...save_restore: ...last 
tried '/projects/ctl/franksen/epics/ioc/MLS-Controls/work-
scopes/log/autoSaveRestore/auto_settings.sav2'. I give up.
iocInit: All initialization complete
## Report Installed and Configured I/O-Hardware Information
dbior 0 1 > /projects/ctl/franksen/epics/ioc/MLS-Controls/work-
scopes/log/Database/SIOC3CP.dbior
dbhcr     > /projects/ctl/franksen/epics/ioc/MLS-Controls/work-
scopes/log/Database/SIOC3CP.dbhcr
dbl       > /projects/ctl/franksen/epics/ioc/MLS-Controls/work-
scopes/log/Database/SIOC3CP.dbl
system "cp iocBoot/version /projects/ctl/franksen/epics/ioc/MLS-
Controls/work-scopes/log/Database/SIOC3CP.version"
cp: cannot stat `iocBoot/version': No such file or directory
system "pwd | tee /projects/ctl/franksen/epics/ioc/MLS-Controls/work-
scopes/log/Database/SIOC3CP.pwd"
/net/csr/srv/projects/ctl/franksen/epics/ioc/MLS-Controls/work-scopes
############################################################ Sequence 
programs
#seq sncxxx var=value
################################################# Create autosave monitor 
sets
#create_monitor_set db/ScopeMeas.req 5 "DEVN=SCOPE1ZCP"
#create_monitor_set db/ScopeMeas.req 5 "DEVN=SCOPEC2S1GP"
########################################################### Start 
caPutLogging
#caPutLogInit ${EPICS_CA_PUT_LOG_INET} 0
#asynSetTraceMask ${GPIB_LINK} ${GPIB_ADDR} 0x0000
#system "cat iocBoot/version"
exit
epics> ^C==31115== 
==31115== HEAP SUMMARY:
==31115==     in use at exit: 1,226,282 bytes in 11,551 blocks
==31115==   total heap usage: 12,520 allocs, 969 frees, 1,426,883 bytes 
allocated
==31115== 
==31115== LEAK SUMMARY:
==31115==    definitely lost: 367 bytes in 14 blocks
==31115==    indirectly lost: 0 bytes in 0 blocks
==31115==      possibly lost: 380,001 bytes in 8,611 blocks
==31115==    still reachable: 845,914 bytes in 2,926 blocks
==31115==         suppressed: 0 bytes in 0 blocks
==31115== Rerun with --leak-check=full to see details of leaked memory
==31115== 
==31115== For counts of detected and suppressed errors, rerun with: -v
==31115== ERROR SUMMARY: 81 errors from 4 contexts (suppressed: 27 from 6)
[1]    31115 killed     valgrind ../../bin/linux-x86/SIOC3CP ./st.cmd
franksen@tiber:~/ctl/MLS-Controls/work-scopes/iocBoot/iocSIOC3CP ___________ 
12:57:48


Replies:
Re: Tektronic Scope DPO7254 over VXI-11 crashes IOC Kazuro FURUKAWA
Re: Tektronic Scope DPO7254 over VXI-11 crashes IOC Benjamin Franksen
References:
Tektronic Scope DPO7254 over VXI-11 crashes IOC Benjamin Franksen

Navigate by Date:
Prev: Tektronic Scope DPO7254 over VXI-11 crashes IOC Benjamin Franksen
Next: RE: Help Request: Setting up NIXI-1042/NI-MXI-4/DXP-XMAP withdxpStandalone_2-10 David Ehle
Index: 1994  1995  1996  1997  1998  1999  2000  2001  2002  2003  2004  2005  2006  2007  2008  2009  <20102011  2012  2013  2014  2015  2016  2017  2018  2019 
Navigate by Thread:
Prev: Tektronic Scope DPO7254 over VXI-11 crashes IOC Benjamin Franksen
Next: Re: Tektronic Scope DPO7254 over VXI-11 crashes IOC Kazuro FURUKAWA
Index: 1994  1995  1996  1997  1998  1999  2000  2001  2002  2003  2004  2005  2006  2007  2008  2009  <20102011  2012  2013  2014  2015  2016  2017  2018  2019 
ANJ, 02 Sep 2010 Valid HTML 4.01! · Home · News · About · Base · Modules · Extensions · Distributions · Download ·
· Search · EPICS V4 · IRMIS · Talk · Bugs · Documents · Links · Licensing ·