pvalink overhaul debug print controls

This commit is contained in:
Michael Davidsaver
2018-04-25 19:13:01 -07:00
parent 60699c48c2
commit b18777e8fe
6 changed files with 111 additions and 71 deletions

View File

@ -41,6 +41,9 @@ extern "C" {
# define TRACE(X) do {} while(0)
#endif
// pvaLink and pvaLinkChannel have ->debug
#define DEBUG(OBJ, X) do{ if((OBJ)->debug) std::cout X<<"\n"; }while(0)
namespace pvalink {
namespace pvd = epics::pvData;
@ -133,6 +136,7 @@ struct pvaLinkChannel : public pvac::ClientChannel::MonitorCallback,
bool connected_latched; // connection status at the run()
bool isatomic;
bool queued; // added to WorkQueue
bool debug; // set if any jlink::debug is set
std::tr1::shared_ptr<const void> previous_root;
struct LinkSort {

View File

@ -49,6 +49,7 @@ pvaLinkChannel::pvaLinkChannel(const pvaGlobal_t::channels_key_t &key, const pvd
,connected_latched(false)
,isatomic(false)
,queued(false)
,debug(false)
,links_changed(false)
{}
@ -70,18 +71,18 @@ void pvaLinkChannel::open()
try {
chan = pvaGlobal->provider_local.connect(key.first);
TRACE(<<"Local "<<key.first);
DEBUG(this, <<key.first<<" OPEN Local");
providerName = pvaGlobal->provider_local.name();
} catch(std::exception& e){
// The PDBProvider doesn't have a way to communicate to us
// whether this is an invalid record or group name,
// or if this is some sort of internal error.
// So we are forced to assume it is an invalid name.
TRACE(<<"Not local "<<e.what());
DEBUG(this, <<key.first<<" OPEN Not local "<<e.what());
}
if(!pvaLinkIsolate && !chan) {
chan = pvaGlobal->provider_remote.connect(key.first);
TRACE(<<"Remote "<<key.first);
DEBUG(this, <<key.first<<" OPEN Remote ");
providerName = pvaGlobal->provider_remote.name();
}
@ -152,8 +153,8 @@ void pvaLinkChannel::put(bool force)
}
pvReq->getSubFieldT<pvd::PVString>("record._options.process")->put(proc);
DEBUG(this, <<key.first<<"Start put "<<doit);
if(doit) {
TRACE(<<"start");
// start net Put, cancels in-progress put
op_put = chan.put(this, pvReq);
}
@ -161,7 +162,6 @@ void pvaLinkChannel::put(bool force)
void pvaLinkChannel::putBuild(const epics::pvData::StructureConstPtr& build, pvac::ClientChannel::PutCallback::Args& args)
{
TRACE();
Guard G(lock);
pvd::PVStructurePtr top(pvaGlobal->create->createPVStructure(build));
@ -181,36 +181,34 @@ void pvaLinkChannel::putBuild(const epics::pvData::StructureConstPtr& build, pva
value.swap(sub);
}
if(!value) return; // TODO: how to signal error?
if(!value) continue; // TODO: how to signal error?
pvd::PVStringArray::const_svector choices; // TODO populate from op_mon
TRACE(<<"store "<<value->getFullName());
DEBUG(this, <<key.first<<" <- "<<value->getFullName());
copyDBF2PVD(link->put_queue, value, args.tosend, choices);
link->put_queue.clear();
}
DEBUG(this, <<key.first<<" Put built");
args.root = top;
}
void pvaLinkChannel::putDone(const pvac::PutEvent& evt)
{
TRACE(<<evt.event<<" "<<evt.message);
if(evt.event==pvac::PutEvent::Fail) {
errlogPrintf("%s PVA link put ERROR: %s\n", key.first.c_str(), evt.message.c_str());
}
Guard G(lock);
DEBUG(this, <<key.first<<" Put result "<<evt.event);
op_put = pvac::Operation();
if(evt.event!=pvac::PutEvent::Success) {
TRACE(<<"skip");
} else {
TRACE(<<"repeat");
if(evt.event==pvac::PutEvent::Success) {
// see if we need start a queue'd put
put();
}
}
@ -220,7 +218,7 @@ void pvaLinkChannel::monitorEvent(const pvac::MonitorEvent& evt)
bool queue = false;
{
TRACE(<<evt.event);
DEBUG(this, <<key.first<<" EVENT "<<evt.event);
Guard G(lock);
switch(evt.event) {
@ -285,12 +283,12 @@ void pvaLinkChannel::run()
// pop next update from monitor queue.
// still under lock to safeguard concurrent calls to lset functions
if(connected && !op_mon.poll()) {
TRACE(<<"empty");
DEBUG(this, <<key.first<<" RUN "<<"empty");
run_done.signal();
return; // monitor queue is empty, nothing more to do here
}
TRACE(<<(connected_latched?"connected":"disconnected"));
DEBUG(this, <<key.first<<" RUN "<<(connected_latched?"connected":"disconnected"));
assert(!connected || !!op_mon.root);

View File

@ -34,6 +34,19 @@ pvaLink::~pvaLink()
lchan->links.erase(this);
lchan->links_changed = true;
bool new_debug = false;
for(pvaLinkChannel::links_t::const_iterator it(lchan->links.begin()), end(lchan->links.end())
; it!=end; ++it)
{
const pvaLink *pval = *it;
if(pval->debug) {
new_debug = true;
break;
}
}
lchan->debug = new_debug;
}
REFTRACE_DECREMENT(num_instances);
@ -96,7 +109,7 @@ pvd::PVField::const_shared_pointer pvaLink::getSubField(const char *name)
// call with channel lock held
void pvaLink::onDisconnect()
{
TRACE(<<"");
DEBUG(this,<<plink->precord->name<<" disconnect");
// TODO: option to remain queue'd while disconnected
used_queue = used_scratch = false;
@ -104,7 +117,8 @@ void pvaLink::onDisconnect()
void pvaLink::onTypeChange()
{
TRACE(<<"");
DEBUG(this,<<plink->precord->name<<" type change");
assert(lchan->connected_latched && !!lchan->op_mon.root); // we should only be called when connected
fld_value = getSubField("value");

View File

@ -4,6 +4,8 @@
#include <recGbl.h>
#include <epicsStdio.h> // redirect stdout/stderr
#include <pv/current_function.h>
#define epicsExportSharedSymbols
#include <shareLib.h>
@ -15,16 +17,27 @@ namespace {
using namespace pvalink;
#define TRY pvaLink *self = static_cast<pvaLink*>(plink->value.json.jlink); assert(self->alive); try
#define CATCH(LOC) catch(std::exception& e) { \
errlogPrintf("pvaLink " #LOC " fails %s: %s\n", plink->precord->name, e.what()); \
#define CATCH() catch(std::exception& e) { \
errlogPrintf("pvaLink %s fails %s: %s\n", CURRENT_FUNCTION, plink->precord->name, e.what()); \
}
#define CHECK_VALID() if(!self->valid()) { DEBUG(self, <<CURRENT_FUNCTION<<" "<<self->channelName<<" !valid"); return -1;}
void pvaOpenLink(DBLINK *plink)
{
try {
pvaLink* self((pvaLink*)plink->value.json.jlink);
TRACE(<<plink->precord->name<<" "<<self->channelName);
// workaround for Base not propagating info(base:lsetDebug to us
{
pdbRecordIterator rec(plink->precord);
if(epicsStrCaseCmp(rec.info("base:lsetDebug", "NO"), "YES")==0) {
self->debug = 1;
}
}
DEBUG(self, <<plink->precord->name<<" OPEN "<<self->channelName);
// still single threaded at this point.
// also, no pvaLinkChannel::lock yet
@ -76,6 +89,8 @@ void pvaOpenLink(DBLINK *plink)
chan->links_changed = true;
self->lchan.swap(chan); // we are now attached
self->lchan->debug |= !!self->debug;
} else {
// TODO: only print duing iocInit()?
fprintf(stderr, "%s Error: local:true link to '%s' can't be fulfilled\n",
@ -84,7 +99,7 @@ void pvaOpenLink(DBLINK *plink)
}
return;
}CATCH(pvaOpenLink)
}CATCH()
// on error, prevent any further calls to our lset functions
plink->lset = NULL;
}
@ -93,31 +108,30 @@ void pvaRemoveLink(struct dbLocker *locker, DBLINK *plink)
{
try {
p2p::auto_ptr<pvaLink> self((pvaLink*)plink->value.json.jlink);
TRACE(<<plink->precord->name<<" "<<self->channelName);
DEBUG(self, <<plink->precord->name<<" "<<CURRENT_FUNCTION<<" "<<self->channelName);
assert(self->alive);
Guard G(self->lchan->lock);
}CATCH(pvaRemoteLink)
}CATCH()
}
int pvaIsConnected(const DBLINK *plink)
{
TRY {
TRACE(<<plink->precord->name<<" "<<self->channelName);
Guard G(self->lchan->lock);
return self->valid();
bool ret = self->valid();
DEBUG(self, <<plink->precord->name<<" "<<CURRENT_FUNCTION<<" "<<self->channelName<<" "<<ret);
return ret;
}CATCH(pvaIsConnected)
}CATCH()
return 0;
}
int pvaGetDBFtype(const DBLINK *plink)
{
TRY {
TRACE(<<plink->precord->name<<" "<<self->channelName);
Guard G(self->lchan->lock);
if(!self->valid()) return -1;
CHECK_VALID();
// if fieldName is empty, use top struct value
// if fieldName not empty
@ -134,31 +148,37 @@ int pvaGetDBFtype(const DBLINK *plink)
else if(value->getField()->getType()==pvd::scalarArray)
ftype = static_cast<const pvd::ScalarArray*>(value->getField().get())->getElementType();
int ret;
switch(ftype) {
#define CASE(BASETYPE, PVATYPE, DBFTYPE, PVACODE) case pvd::pv##PVACODE: return DBF_##DBFTYPE;
#define CASE(BASETYPE, PVATYPE, DBFTYPE, PVACODE) case pvd::pv##PVACODE: ret = DBF_##DBFTYPE;
#define CASE_REAL_INT64
#include "pv/typemap.h"
#undef CASE_REAL_INT64
#undef CASE
case pvd::pvString: return DBF_STRING; // TODO: long string?
case pvd::pvString: ret = DBF_STRING; // TODO: long string?
}
}CATCH(pvaIsConnected)
DEBUG(self, <<plink->precord->name<<" "<<CURRENT_FUNCTION<<" "<<self->channelName<<" "<<dbGetFieldTypeString(ret));
return ret;
}CATCH()
return -1;
}
long pvaGetElements(const DBLINK *plink, long *nelements)
{
TRY {
TRACE(<<plink->precord->name<<" "<<self->channelName);
Guard G(self->lchan->lock);
if(!self->valid()) return -1;
CHECK_VALID();
long ret = 0;
if(self->fld_value && self->fld_value->getField()->getType()==pvd::scalarArray)
return static_cast<const pvd::PVScalarArray*>(self->fld_value.get())->getLength();
else
return 0;
}CATCH(pvaIsConnected)
ret = static_cast<const pvd::PVScalarArray*>(self->fld_value.get())->getLength();
DEBUG(self, <<plink->precord->name<<" "<<CURRENT_FUNCTION<<" "<<self->channelName<<" "<<ret);
return ret;
}CATCH()
return -1;
}
@ -168,8 +188,6 @@ long pvaGetValue(DBLINK *plink, short dbrType, void *pbuffer,
TRY {
Guard G(self->lchan->lock);
TRACE(<<plink->precord->name<<" "<<self->channelName<<" conn="<<(self->valid()?"T":"F"));
if(!self->valid()) {
// disconnected
if(self->ms != pvaLink::NMS) {
@ -180,12 +198,16 @@ long pvaGetValue(DBLINK *plink, short dbrType, void *pbuffer,
if(self->time) {
plink->precord->time = self->snap_time;
}
DEBUG(self, <<CURRENT_FUNCTION<<" "<<self->channelName<<" !valid");
return -1;
}
if(self->fld_value) {
long status = copyPVD2DBF(self->fld_value, pbuffer, dbrType, pnRequest);
if(status) return status;
if(status) {
DEBUG(self, <<plink->precord->name<<" "<<CURRENT_FUNCTION<<" "<<self->channelName<<" "<<status);
return status;
}
}
if(self->fld_seconds) {
@ -216,17 +238,17 @@ long pvaGetValue(DBLINK *plink, short dbrType, void *pbuffer,
plink->precord->time = self->snap_time;
}
DEBUG(self, <<plink->precord->name<<" "<<CURRENT_FUNCTION<<" "<<self->channelName<<" OK");
return 0;
}CATCH(pvaIsConnected)
}CATCH()
return -1;
}
long pvaGetControlLimits(const DBLINK *plink, double *lo, double *hi)
{
TRY {
TRACE(<<plink->precord->name<<" "<<self->channelName);
Guard G(self->lchan->lock);
if(!self->valid()) return -1;
CHECK_VALID();
if(self->fld_control) {
pvd::PVScalar::const_shared_pointer value;
@ -241,17 +263,17 @@ long pvaGetControlLimits(const DBLINK *plink, double *lo, double *hi)
} else {
*lo = *hi = 0.0;
}
DEBUG(self, <<plink->precord->name<<" "<<CURRENT_FUNCTION<<" "<<self->channelName<<" "<<(lo ? *lo : 0)<<" "<<(hi ? *hi : 0));
return 0;
}CATCH(pvaIsConnected)
}CATCH()
return -1;
}
long pvaGetGraphicLimits(const DBLINK *plink, double *lo, double *hi)
{
TRY {
TRACE(<<plink->precord->name<<" "<<self->channelName);
Guard G(self->lchan->lock);
if(!self->valid()) return -1;
CHECK_VALID();
if(self->fld_display) {
pvd::PVScalar::const_shared_pointer value;
@ -266,8 +288,9 @@ long pvaGetGraphicLimits(const DBLINK *plink, double *lo, double *hi)
} else {
*lo = *hi = 0.0;
}
DEBUG(self, <<plink->precord->name<<" "<<CURRENT_FUNCTION<<" "<<self->channelName<<" "<<(lo ? *lo : 0)<<" "<<(hi ? *hi : 0));
return 0;
}CATCH(pvaIsConnected)
}CATCH()
return -1;
}
@ -275,35 +298,34 @@ long pvaGetAlarmLimits(const DBLINK *plink, double *lolo, double *lo,
double *hi, double *hihi)
{
TRY {
TRACE(<<plink->precord->name<<" "<<self->channelName);
if(!self->valid()) return -1;
//Guard G(self->lchan->lock);
//CHECK_VALID();
*lolo = *lo = *hi = *hihi = 0.0;
DEBUG(self, <<plink->precord->name<<" "<<CURRENT_FUNCTION<<" "<<self->channelName<<" "<<(lolo ? *lolo : 0)<<" "<<(lo ? *lo : 0)<<" "<<(hi ? *hi : 0)<<" "<<(hihi ? *hihi : 0));
return 0;
}CATCH(pvaIsConnected)
}CATCH()
return -1;
}
long pvaGetPrecision(const DBLINK *plink, short *precision)
{
TRY {
TRACE(<<plink->precord->name<<" "<<self->channelName);
if(!self->valid()) return -1;
//Guard G(self->lchan->lock);
//CHECK_VALID();
// No sane way to recover precision from display.format string.
*precision = 0;
DEBUG(self, <<plink->precord->name<<" "<<CURRENT_FUNCTION<<" "<<self->channelName<<" "<<precision);
return 0;
}CATCH(pvaIsConnected)
}CATCH()
return -1;
}
long pvaGetUnits(const DBLINK *plink, char *units, int unitsSize)
{
TRY {
TRACE(<<plink->precord->name<<" "<<self->channelName);
Guard G(self->lchan->lock);
if(!self->valid()) return -1;
CHECK_VALID();
if(unitsSize==0) return 0;
@ -317,8 +339,9 @@ long pvaGetUnits(const DBLINK *plink, char *units, int unitsSize)
units[0] = '\0';
}
units[unitsSize-1] = '\0';
DEBUG(self, <<plink->precord->name<<" "<<CURRENT_FUNCTION<<" "<<self->channelName<<" "<<units);
return 0;
}CATCH(pvaIsConnected)
}CATCH()
return -1;
}
@ -326,9 +349,8 @@ long pvaGetAlarm(const DBLINK *plink, epicsEnum16 *status,
epicsEnum16 *severity)
{
TRY {
TRACE(<<plink->precord->name<<" "<<self->channelName);
Guard G(self->lchan->lock);
if(!self->valid()) return -1;
CHECK_VALID();
if(severity) {
*severity = self->snap_severity;
@ -337,24 +359,25 @@ long pvaGetAlarm(const DBLINK *plink, epicsEnum16 *status,
*status = self->snap_severity ? LINK_ALARM : NO_ALARM;
}
DEBUG(self, <<plink->precord->name<<" "<<CURRENT_FUNCTION<<" "<<self->channelName<<" "<<(severity ? *severity : 0)<<" "<<(status ? *status : 0));
return 0;
}CATCH(pvaIsConnected)
}CATCH()
return -1;
}
long pvaGetTimeStamp(const DBLINK *plink, epicsTimeStamp *pstamp)
{
TRY {
TRACE(<<plink->precord->name<<" "<<self->channelName);
if(!self->valid()) return -1;
Guard G(self->lchan->lock);
CHECK_VALID();
if(pstamp) {
*pstamp = self->snap_time;
}
DEBUG(self, <<plink->precord->name<<" "<<CURRENT_FUNCTION<<" "<<self->channelName<<" "<<(pstamp ? pstamp->secPastEpoch : 0)<<":"<<(pstamp ? pstamp->nsec: 0));
return 0;
}CATCH(pvaIsConnected)
}CATCH()
return -1;
}
@ -380,11 +403,10 @@ long pvaPutValue(DBLINK *plink, short dbrType,
(void)self;
Guard G(self->lchan->lock);
TRACE(<<plink->precord->name<<" "<<self->channelName<<" nReq="<<nRequest<<" conn="<<(self->valid()?"T":"F"));
if(nRequest < 0) return -1;
if(!self->retry && !self->valid()) {
DEBUG(self, <<CURRENT_FUNCTION<<" "<<self->channelName<<" !valid");
return -1;
}
@ -416,15 +438,15 @@ long pvaPutValue(DBLINK *plink, short dbrType,
if(!self->defer) self->lchan->put();
DEBUG(self, <<plink->precord->name<<" "<<CURRENT_FUNCTION<<" "<<self->channelName<<" "<<self->lchan->op_put.valid());
return 0;
}CATCH(pvaIsConnected)
}CATCH()
return -1;
}
void pvaScanForward(DBLINK *plink)
{
TRY {
TRACE(<<plink->precord->name<<" "<<self->channelName);
Guard G(self->lchan->lock);
if(!self->retry && !self->valid()) {
@ -433,7 +455,9 @@ void pvaScanForward(DBLINK *plink)
// FWD_LINK is never deferred, and always results in a Put
self->lchan->put(true);
}CATCH(pvaIsConnected)
DEBUG(self, <<plink->precord->name<<" "<<CURRENT_FUNCTION<<" "<<self->channelName<<" "<<self->lchan->op_put.valid());
}CATCH()
}
#undef TRY

View File

@ -123,6 +123,7 @@ struct pdbRecordIterator {
pdbRecordIterator(dbCommon *prec)
{
dbInitEntryFromRecord(prec, &ent);
m_done = false;
}
#endif
~pdbRecordIterator()

View File

@ -72,7 +72,6 @@ MAIN(testpvalink)
// Disable PVA client provider, use local/QSRV provider
pvaLinkIsolate = 1;
pvaLinkDebug = 5;
try {
TestIOC IOC;