To assist in troubleshooting issue with ECL queries slowness would it be possible to add extra tracing fields in the COMPLETE log line [complete in 4272 msecs ] that would give timings to "call out to address cleaner", " call out to gateway". This would allow for operations to find out if there is slowness from the ECL query coming from an outside source other then the Roxie cluster or vice versa. Having these added timings would be a very big advantage to finding issues on the Roxie side.
Currently transactional ESP's give us this option with there "COMPLETE" line in the log.
=====example of ESP complete line==== "TxSummary[active=6;user=websterxml@12.216.192.20;ver=1.120000;service=wsidentity;port=7507;contLen=1475;rcvdReq=0;basicAuthTime=4;startHttpPost=4;procRequestStart=4;soap=InstantIDRequest;txid=26261890R168410;startCallOut=7;endCallOut=367;startQxHPoolTrans=368;initedQxHPoolTrans=368;endQxHPoolTrans=368;Platform_IP=172.16.70.157;SDX_applid=InstantID;Bytes_tot=7247;ResponseTime=362;Records_in=1;Records_tot=1;startSendLogInfo=368;tranxId=26261890R168410;recCount=1;logFnName=InstantID;tranxType=I;endSendLogInfo=369;startSendGenericLogInfo=369;endSendGenericLogInfo=370;startSendDeltaBaseLogInfo=370;startSendOutcomeTrackingLogInfo=370;startSendLogInfo=370;tranxId=26261890R168410;recCount=1;logFnName=InstantID;tranxType=I;endSendLogInfo=371;endSendOutcomeTrackingLogInfo=371;procRequestEnd=371;RspSndSt=371;RspSndEnd=371;ResourcePool_Sybase=0ms;SybaseTime=4ms;comp=371;]"
Conclusion
None
Activity
Show:
Gavin Halliday September 24, 2014 at 1:36 PM
Yes, it should be possible to gather all the interesting stats in one place and then generate them to the log.
Richard Chapman September 24, 2014 at 9:13 AM
I think this would probably be easier with the new stats code in place. Do you agree?
Richard Chapman August 22, 2014 at 7:25 AM
It's probably doable, but beware that the information may be misleading, as things execute in parallel on roxie. Thus you could end up with a total execution time of 2 seconds of which 4 seconds was spent on external gateway calls.
Fixed
Pinned fields
Click on the next to a field label to start pinning.
To assist in troubleshooting issue with ECL queries slowness would it be possible to add extra tracing fields in the COMPLETE log line [complete in 4272 msecs ] that would give timings to "call out to address cleaner", " call out to gateway". This would allow for operations to find out if there is slowness from the ECL query coming from an outside source other then the Roxie cluster or vice versa. Having these added timings would be a very big advantage to finding issues on the Roxie side.
==current COMPLETE line====
COMPLETE: Models.RecoverScore_Batch_Service 1408641730006-50649-246-61 from 10.121.146.160 complete in 4272 msecs memory 264 Mb priority 0 slavesreply 10840738 resultsize 49940 continue 0"
Currently transactional ESP's give us this option with there "COMPLETE" line in the log.
=====example of ESP complete line====
"TxSummary[active=6;user=websterxml@12.216.192.20;ver=1.120000;service=wsidentity;port=7507;contLen=1475;rcvdReq=0;basicAuthTime=4;startHttpPost=4;procRequestStart=4;soap=InstantIDRequest;txid=26261890R168410;startCallOut=7;endCallOut=367;startQxHPoolTrans=368;initedQxHPoolTrans=368;endQxHPoolTrans=368;Platform_IP=172.16.70.157;SDX_applid=InstantID;Bytes_tot=7247;ResponseTime=362;Records_in=1;Records_tot=1;startSendLogInfo=368;tranxId=26261890R168410;recCount=1;logFnName=InstantID;tranxType=I;endSendLogInfo=369;startSendGenericLogInfo=369;endSendGenericLogInfo=370;startSendDeltaBaseLogInfo=370;startSendOutcomeTrackingLogInfo=370;startSendLogInfo=370;tranxId=26261890R168410;recCount=1;logFnName=InstantID;tranxType=I;endSendLogInfo=371;endSendOutcomeTrackingLogInfo=371;procRequestEnd=371;RspSndSt=371;RspSndEnd=371;ResourcePool_Sybase=0ms;SybaseTime=4ms;comp=371;]"