Re: asyn connetion to wti

[Hawi Stecher via Tech-talk <tech-talk at aps.anl.gov>]

Ah got it. Here's the output:

iocInit: Reached initHookAfterCallbackInit
iocInit: Reached initHookAfterCaLinkInit
iocInit: Reached initHookAfterInitDrvSup
iocInit: Reached initHookAfterInitRecSup
iocInit: Reached initHookAfterInitDevSup
2020/11/20 14:19:54.013 10.1.2.60:2302 write 7
*IDN?\r\n
2020/11/20 14:19:54.186 10.1.2.60:2302 read 12
\377\375\030\377\375 \377\375#\377\375\'
2020/11/20 14:19:54.286377 LS325_IP top:TC1:ID: Timeout after reading 12 bytes "<ff>?<18><ff>"
2020/11/20 14:19:54.286501 _main_ top:TC1:ID: @init handler failed
2020/11/20 14:19:54.286527 _main_ top:TC1:ID: Record initialization failed
iocInit: Reached initHookAfterInitDatabase
iocInit: Reached initHookAfterFinishDevSup
iocInit: Reached initHookAfterScanInit
iocInit: Reached initHookAfterInitialProcess
iocInit: Reached initHookAfterCaServerInit
iocInit: Reached initHookAfterIocBuilt
iocInit: Reached initHookAtIocRun
iocInit: Reached initHookAfterDatabaseRunning
iocInit: Reached initHookAfterInterruptAccept
iocInit: Reached initHookAfterCaServerRunning
iocInit: Reached initHookAtEnd
iocRun: All initialization complete
iocInit: Reached initHookAfterIocRunning
## Start any sequence programs
#seq sncExample, "user=hstecherHost"
epics> 

On Fri, Nov 20, 2020 at 2:06 PM Mark Rivers <rivers at cars.uchicago.edu> wrote:

Hi Hawi,

 

Sorry, I was not being clear.

 

Please disable the StreamDevice debugging.

 

Please add the following lines to your startup script, right after the drvAsynIPPortConfigure line:

 

asynTraceTraceIOMask(PORT, 0, ESCAPE)

asynSetTraceMask(PORT, 0, ERROR|DRIVER)

 

where you replace PORT with the name of the asyn port you created. I think it might be LS325_IP.

 

Then restart the IOC and send all of the output.

 

Mark

 

 

From: Hawi Stecher <hstecher at gemini.edu>
Sent: Friday, November 20, 2020 5:53 PM
To: Mark Rivers <rivers at cars.uchicago.edu>
Subject: Re: asyn connetion to wti

 

Hi Mark,

 

Thanks for your help. Below is the complete output:

 

2020/11/20 13:47:01.010735 _main_ StreamEpics.cc:426: streamInitRecord(top:TC1:ID): SEVR=3
2020/11/20 13:47:01.010771 _main_ StreamEpics.cc:431: streamInitRecord(top:TC1:ID): create new Stream object
2020/11/20 13:47:01.010844 _main_ StreamEpics.cc:442: streamInitRecord(top:TC1:ID): parse link "LakeShore336.proto getID(top:TC1) LS325_IP 0"
2020/11/20 13:47:01.010868 _main_ StreamEpics.cc:447: streamInitRecord(top:TC1:ID): calling initRecord
2020/11/20 13:47:01.010878 _main_ StreamEpics.cc:630: Stream::initRecord top:TC1:ID: attachBus(LS325_IP, 0, "")
2020/11/20 13:47:01.010888 _main_ StreamBusInterface.cc:62: StreamBusInterface::find(top:TC1:ID, LS325_IP, 0, "")
2020/11/20 13:47:01.010896 _main_ StreamBusInterface.cc:68: StreamBusInterface::find top:TC1:ID check DebugInterface
2020/11/20 13:47:01.010906 _main_ StreamBusInterface.cc:71: StreamBusInterface::find DebugInterface does not match
2020/11/20 13:47:01.010913 _main_ StreamBusInterface.cc:68: StreamBusInterface::find top:TC1:ID check DummyInterface
2020/11/20 13:47:01.010929 _main_ StreamBusInterface.cc:71: StreamBusInterface::find DummyInterface does not match
2020/11/20 13:47:01.010937 _main_ StreamBusInterface.cc:68: StreamBusInterface::find top:TC1:ID check AsynDriverInterface
2020/11/20 13:47:01.010960 _main_ AsynDriverInterface.cc:334: AsynDriverInterface::getBusInterface(top:TC1:ID, LS325_IP, 0)
2020/11/20 13:47:01.010984 _main_ AsynDriverInterface.cc:253: AsynDriverInterface(top:TC1:ID)
2020/11/20 13:47:01.010994 _main_ AsynDriverInterface.cc:265: AsynDriverInterface(top:TC1:ID) createAsynUser
2020/11/20 13:47:01.011002 _main_ AsynDriverInterface.cc:276: AsynDriverInterface(top:TC1:ID) epicsTimerQueueActive::allocate(true)
2020/11/20 13:47:01.011010 _main_ AsynDriverInterface.cc:279: AsynDriverInterface(top:TC1:ID) timerQueue->createTimer()
2020/11/20 13:47:01.011018 _main_ AsynDriverInterface.cc:283: AsynDriverInterface(top:TC1:ID) done
2020/11/20 13:47:01.011027 _main_ AsynDriverInterface.cc:443: top:TC1:ID: AsynDriverInterface::connectToBus(LS325_IP, 0): pasynManager->connectDevice(0x940c88, LS325_IP, 0) = asynSuccess
2020/11/20 13:47:01.011037 _main_ AsynDriverInterface.cc:339: AsynDriverInterface::getBusInterface(LS325_IP, 0): new interface allocated
2020/11/20 13:47:01.011062 _main_ StreamBusInterface.cc:71: StreamBusInterface::find AsynDriverInterface matches
2020/11/20 13:47:01.011071 _main_ StreamCore.cc:172: StreamCore::attachBus(busname="LS325_IP", addr=0, param="") businterface=0x950870
2020/11/20 13:47:01.011080 _main_ StreamEpics.cc:640: Stream::initRecord top:TC1:ID: parse(LakeShore336.proto, getID(top:TC1))
2020/11/20 13:47:01.011110 _main_ StreamProtocol.cc:185: StreamProtocolParser::readFile: try '/gem_sw/test/hstecher/myLakeShore/db/LakeShore336.proto'
2020/11/20 13:47:01.013242 _main_ StreamProtocol.cc:547: StreamProtocolParser::readToken: Special ' '
2020/11/20 13:47:01.013270 _main_ StreamProtocol.cc:263: StreamProtocolParser::parseProtocol: token=' '
2020/11/20 13:47:01.013280 _main_ StreamProtocol.cc:553: StreamProtocolParser::readToken: word
2020/11/20 13:47:01.013290 _main_ StreamProtocol.cc:564: StreamProtocolParser::readToken: word='extrainput' c=' '
2020/11/20 13:47:01.013301 _main_ StreamProtocol.cc:263: StreamProtocolParser::parseProtocol: token='extrainput<00>&<00><00><00>'
2020/11/20 13:47:01.013311 _main_ StreamProtocol.cc:553: StreamProtocolParser::readToken: word
2020/11/20 13:47:01.013319 _main_ StreamProtocol.cc:564: StreamProtocolParser::readToken: word='ignore' c=';'
2020/11/20 13:47:01.013327 _main_ StreamProtocol.cc:592: StreamProtocolParser::parseValue:38: ignore<00>&<00><00><00>
2020/11/20 13:47:01.013335 _main_ StreamProtocol.cc:547: StreamProtocolParser::readToken: Special ';'
2020/11/20 13:47:01.013342 _main_ StreamProtocol.cc:592: StreamProtocolParser::parseValue:38: ;
2020/11/20 13:47:01.013352 _main_ StreamProtocol.cc:547: StreamProtocolParser::readToken: Special ' '
2020/11/20 13:47:01.013359 _main_ StreamProtocol.cc:263: StreamProtocolParser::parseProtocol: token=' '
2020/11/20 13:47:01.013366 _main_ StreamProtocol.cc:553: StreamProtocolParser::readToken: word
2020/11/20 13:47:01.013374 _main_ StreamProtocol.cc:564: StreamProtocolParser::readToken: word='replytimeout' c=' '
2020/11/20 13:47:01.013382 _main_ StreamProtocol.cc:263: StreamProtocolParser::parseProtocol: token='replytimeout<00>'<00><00><00>'
2020/11/20 13:47:01.013390 _main_ StreamProtocol.cc:553: StreamProtocolParser::readToken: word
2020/11/20 13:47:01.013397 _main_ StreamProtocol.cc:564: StreamProtocolParser::readToken: word='2000' c=';'
2020/11/20 13:47:01.013405 _main_ StreamProtocol.cc:592: StreamProtocolParser::parseValue:39: 2000<00>'<00><00><00>
2020/11/20 13:47:01.013413 _main_ StreamProtocol.cc:547: StreamProtocolParser::readToken: Special ';'
2020/11/20 13:47:01.013420 _main_ StreamProtocol.cc:592: StreamProtocolParser::parseValue:39: ;
2020/11/20 13:47:01.013429 _main_ StreamProtocol.cc:547: StreamProtocolParser::readToken: Special ' '
2020/11/20 13:47:01.013437 _main_ StreamProtocol.cc:263: StreamProtocolParser::parseProtocol: token=' '
2020/11/20 13:47:01.013444 _main_ StreamProtocol.cc:553: StreamProtocolParser::readToken: word
2020/11/20 13:47:01.013452 _main_ StreamProtocol.cc:564: StreamProtocolParser::readToken: word='terminator' c=' '
2020/11/20 13:47:01.013460 _main_ StreamProtocol.cc:263: StreamProtocolParser::parseProtocol: token='terminator<00>(<00><00><00>'
2020/11/20 13:47:01.013467 _main_ StreamProtocol.cc:553: StreamProtocolParser::readToken: word
2020/11/20 13:47:01.013475 _main_ StreamProtocol.cc:564: StreamProtocolParser::readToken: word='cr' c=' '
2020/11/20 13:47:01.013483 _main_ StreamProtocol.cc:592: StreamProtocolParser::parseValue:40: cr<00>(<00><00><00>
…

2020/11/20 13:47:01.287488 _main_ top:TC1:ID: @init handler failed
2020/11/20 13:47:01.287499 _main_ top:TC1:ID: Record initialization failed
2020/11/20 13:47:01.287507 _main_ StreamEpics.cc:460: streamInitRecord(top:TC1:ID) done status=0xffffffffffffffff

 

On Fri, Nov 20, 2020 at 1:45 PM Mark Rivers <rivers at cars.uchicago.edu> wrote:

Please send the complete output when using ASYN_TRACEIO_ESCAPE and ASYN_TRACEIO_DRIVER on the asyn port.  I want to see the write commands and read commands with timestamps.

 

Mark

 

 

From: Tech-talk <tech-talk-bounces at aps.anl.gov> On Behalf Of Hawi Stecher via Tech-talk
Sent: Friday, November 20, 2020 5:33 PM
To: tech-talk at aps.anl.gov
Subject: asyn connetion to wti

 

Dear All, 

 

I am trying to connect a softIOC using asyn and StreamDevice to a wti console server, which has a serial connection to a LakeShore325.

 

I am able to telnet to the wti and communicate with the LakeShore. I am also able to connect the softIOC to other devices and send messages.

 

There seems to be some issue between asyn and the wti, which is serving a standard telnet connection.

 

The protocol file is:

ExtraInput = Ignore;
ReplyTimeout = 2000;
Terminator = CR LF;

getID {
out "*IDN?";
        in "%s";
@init {out "*IDN?"; in "%s";}
}

 

Below is a log snippet from asyn. It seems to read the following data then timeout:

<ff>?<18><ff>?

 

 

Any help would be greatly appreciated. 

Thank you,

Hawi

 

asyn log:

2020/11/20 13:25:25.278974 LS325_IP AsynDriverInterface.cc:969: AsynDriverInterface::readHandler(top:TC1:ID): device is now connected
2020/11/20 13:25:25.278983 LS325_IP AsynDriverInterface.cc:1007: AsynDriverInterface::readHandler(top:TC1:ID): received 1 of 1 bytes "<ff>" eomReason=CNT
2020/11/20 13:25:25.278994 LS325_IP StreamCore.cc:953: StreamCore::readCallback(top:TC1:ID, status=StreamIoSuccess input="<ff>", size=1)
2020/11/20 13:25:25.279011 LS325_IP StreamCore.cc:1009: StreamCore::readCallback(top:TC1:ID) inputBuffer="<ff>", size 1
2020/11/20 13:25:25.279023 LS325_IP StreamCore.cc:1054: StreamCore::readCallback(top:TC1:ID) inTerminator <0d><0a> not found
2020/11/20 13:25:25.279031 LS325_IP StreamCore.cc:1090: StreamCore::readCallback(top:TC1:ID) wait for more input
2020/11/20 13:25:25.279062 LS325_IP AsynDriverInterface.cc:1133: AsynDriverInterface::readHandler(top:TC1:ID) readMore=-1 bytesToRead=63
2020/11/20 13:25:25.279072 LS325_IP AsynDriverInterface.cc:955: AsynDriverInterface::readHandler(top:TC1:ID): ioAction=Read read(..., bytesToRead=63, ...) [timeout=0.1 sec]
2020/11/20 13:25:25.379257 LS325_IP AsynDriverInterface.cc:962: AsynDriverInterface::readHandler(top:TC1:ID): read returned asynTimeout: ioAction=Read received=11, eomReason=NONE, buffer="?<18><ff>? <ff>?#<ff>?'"
2020/11/20 13:25:25.379297 LS325_IP AsynDriverInterface.cc:969: AsynDriverInterface::readHandler(top:TC1:ID): device is now connected
2020/11/20 13:25:25.379307 LS325_IP AsynDriverInterface.cc:1069: AsynDriverInterface::readHandler(top:TC1:ID): ioAction=Read, timeout [0.1 sec] after 11 of 63 bytes "?<18><ff>? <ff>?#<ff>?'"
2020/11/20 13:25:25.379322 LS325_IP StreamCore.cc:953: StreamCore::readCallback(top:TC1:ID, status=StreamIoTimeout input="?<18><ff>? <ff>?#<ff>?'", size=11)
2020/11/20 13:25:25.379332 LS325_IP StreamCore.cc:1009: StreamCore::readCallback(top:TC1:ID) inputBuffer="<ff>?<18><ff>? <ff>?#<ff>?'", size 12
2020/11/20 13:25:25.379342 LS325_IP StreamCore.cc:1054: StreamCore::readCallback(top:TC1:ID) inTerminator <0d><0a> not found
2020/11/20 13:25:25.379355 LS325_IP top:TC1:ID: Timeout after reading 12 bytes "<ff>?<18><ff>"
2020/11/20 13:25:25.379373 LS325_IP StreamCore.cc:1119: StreamCore::readCallback(top:TC1:ID) input line: "<ff>?<18><ff>? <ff>?#<ff>?'"
2020/11/20 13:25:25.379393 LS325_IP StreamCore.cc:1209: StreamCore::matchInput(top:TC1:ID): format = "%s"
2020/11/20 13:25:25.379408 LS325_IP StreamEpics.cc:522: streamScanfN(top:TC1:ID,format=%s,maxStringSize=40)
2020/11/20 13:25:25.379428 LS325_IP StreamCore.cc:1536: StreamCore::scanValue(top:TC1:ID, format=%s, char*, maxlen=40) input="<ff>?<18><ff>? <ff>?#<ff>?'"
2020/11/20 13:25:25.379447 LS325_IP StreamCore.cc:1550: StreamCore::scanValue(top:TC1:ID) scanned "<ff>?<18><ff>?<00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00><00>"
2020/11/20 13:25:25.379457 LS325_IP StreamEpics.cc:531: streamScanfN(top:TC1:ID) success, value="<ff>?<18><ff>?"
2020/11/20 13:25:25.379466 LS325_IP StreamCore.cc:513: starting exception handler