Merge ~bhill/epics-base:db-tpro-show-values into ~epics-core/epics-base/+git/epics-base:3.16

Proposed by Bruce Hill
Status: Needs review
Proposed branch: ~bhill/epics-base:db-tpro-show-values
Merge into: ~epics-core/epics-base/+git/epics-base:3.16
Diff against target: 168 lines (+48/-0)
11 files modified
src/std/rec/aSubRecord.c (+2/-0)
src/std/rec/aiRecord.c (+4/-0)
src/std/rec/aoRecord.c (+4/-0)
src/std/rec/biRecord.c (+6/-0)
src/std/rec/boRecord.c (+5/-0)
src/std/rec/calcRecord.c (+5/-0)
src/std/rec/calcoutRecord.c (+5/-0)
src/std/rec/longinRecord.c (+4/-0)
src/std/rec/longoutRecord.c (+4/-0)
src/std/rec/mbbiRecord.c (+4/-0)
src/std/rec/mbboRecord.c (+5/-0)
Reviewer Review Type Date Requested Status
Andrew Johnson Needs Fixing
Ralph Lange Needs Fixing
Review via email: mp+341081@code.launchpad.net

Description of the change

Add diagnostic support for showing record values when TPRO is >= 2

To post a comment you must log in.
Revision history for this message
mdavidsaver (mdavidsaver) wrote :

See previous discussion at https://github.com/epics-base/epics-base/pull/20

I personally like the idea of using TPRO to control debug prints. So much so that I've been adding it to my drivers so the last couple of years.

I don't have a problem with overloading TPRO in this way in Base. I would make the threshold numbers it larger (5 and 10).

As this is Base, maybe we should add a new field instead? Is .DDBG taken (aka Device support DeBuG)?

Revision history for this message
Ralph Lange (ralph-lange) wrote :

I like the idea of separating the Device Support debug setting from Record Support debug setting (as I had stated in the GitHub discussion), so I would be in favor of a new field, and DDBG sounds good as a name.

Larger threshold values sound like a good idea.

I don't understand why the aSub does not get the VAL printed, and the message might be misleading (as OUTx are the output links, not the output values).
Also, for a debug function, I would expect it to print VALx values independent from the event posting setting. (As with all records that don't have such a setting.)

bi/bo should IMHO always print the numerical value, and add the string if ONAM/ZNAM are defined.

mbbi/mbbo should add the string representation if there is one defined.

For many record types, when used with other than Soft Device Support, the RVAL field is as interesting as the VAL field.

aai/aao/compress/dfanout/event/histogram/int64in/int64out/lsi/lso/mbbiDirect/mbboDirect/permissive/sel/seq/state/stringin/stringout/subArray/sub/waveform are missing.

review: Needs Fixing
Revision history for this message
Andrew Johnson (anj) wrote :

A Google search for "EPICS TPRO" came back with a tech-talk discussion:
  https://epics.anl.gov/tech-talk/2014/msg00129.php
This thread contained a response from me contrary to my github answer:

> I do like the idea of using TPRO > 1 to trigger debug messages from
> record processing, and this could also be used by device support. It
> should be up to the specific record/device support to document its usage
> though.

While writing that response in 2014 I also adjusted the Wiki description at
  https://wiki-ext.aps.anl.gov/epics/index.php/RRM_3-14_dbCommon
to say:

> If this field is non-zero a message is printed whenever this record is
> processed, and when any other record in the same lock-set is processed
> by a database link from this record.

Thus (following the legal principle of stare decisis) I rescind my github objection to the use of TPRO to enable debug messages, but I would like to see some kind of standardization in the values used, either globally or at least by the record type. If we're going to do this though we should also do all the record types in Base, not just the ones we use/like the most.

Question: Should the TPRO value be a verbosity level, page selector, a bit-mask or some combination of the 3?

I support Ralph's comments about the record-specific behaviors. The VAL field of an aSub record holds the status value returned by the subroutine and is less useful than that of a sub record, so I can understand not being interested in seeing that (printing SNAM when it changes would be useful though). The seq record has an even less useful VAL field, and I'm sure there are others like it so I think that what gets printed should be up to the record type.

Setting TPRO on a record also prints the record names of any other records in the same lockset that are processed directly by the record, but it does not change their TPRO fields, so those records will not have their debug print mechanisms triggered (unless they also have TPRO set). This is still reasonable behavior.

Setting TPRO to 255 could be used for a DOS attack if it results in a lot of output. We are probably already serializing all our record processing when TPRO is set though (through printing the record name to stdout in the dbProcess() routine) but this is really just another attack surface of which we already have too many for this to change.

review: Needs Fixing
Revision history for this message
Ralph Lange (ralph-lange) wrote :

> Question: Should the TPRO value be a verbosity level, page selector, a bit-mask or some combination of the 3?

Bit-masks may make sense in device support debugging that is often distributed over multiple layers - see ASYN's trace masks.

Record support is practically always one layer, and I see a verbosity level being more useful.

If we split Device Support debugging to a separate field, each device support can use it as it prefers: mask or page or level. In that case I would support TPRO being a verbosity level.

If TPRO is shared between Record and Device Support, things get messy.

Revision history for this message
mdavidsaver (mdavidsaver) wrote :

> Question: Should the TPRO value be a verbosity level, page selector, a bit-mask or some combination of the 3?

I've only used it as a verbosity level, aka. print if TPRO>=N for some value of N.

Revision history for this message
Bruce Hill (bhill) wrote :

I've found uses of TPRO as a verbosity level in several device support modules along w/ some that just enable
diagnostics for any non-zero tpro value.     That was what I was looking to do w/ this commit.

On 03/13/2018 08:12 AM, mdavidsaver wrote:
>> Question: Should the TPRO value be a verbosity level, page selector, a bit-mask or some combination of the 3?
> I've only used it as a verbosity level, aka. print if TPRO>=N for some value of N.

--
Bruce Hill
Member Technical Staff
SLAC National Accelerator Lab
2575 Sand Hill Road M/S 10
Menlo Park, CA 94025

Revision history for this message
Andrew Johnson (anj) wrote :

Core Meeting: Should be done for (and messages consistent from) all record types; TPRO value of 1 should be reserved for just the current trace processing, values for these messages should be sensible (higher numbers may print more stuff, leave room between numbers for device support, link support etc. to use as well); consider adding another message when beginning/ending an asynchronous I/O operation.

review: Needs Fixing

Unmerged commits

e13659d... by Bruce Hill

Add diagnostic support for showing record values when TPRO is >= 2

Preview Diff

[H/L] Next/Prev Comment, [J/K] Next/Prev File, [N/P] Next/Prev Hunk
1diff --git a/src/std/rec/aSubRecord.c b/src/std/rec/aSubRecord.c
2index b7d2286..608d54b 100644
3--- a/src/std/rec/aSubRecord.c
4+++ b/src/std/rec/aSubRecord.c
5@@ -429,6 +429,8 @@ static void monitor(aSubRecord *prec)
6 if (nev != onv || memcmp(povl, pval, alen)) {
7 memcpy(povl, pval, alen);
8 db_post_events(prec, pval, monitor_mask);
9+ if ( prec->tpro >= 5 )
10+ printf( "%s.OUT%c changed!\n", prec->name, 'A' + i );
11 if (nev != onv) {
12 *ponv = nev;
13 db_post_events(prec, pnev, monitor_mask);
14diff --git a/src/std/rec/aiRecord.c b/src/std/rec/aiRecord.c
15index 81f730f..e7c0377 100644
16--- a/src/std/rec/aiRecord.c
17+++ b/src/std/rec/aiRecord.c
18@@ -167,6 +167,10 @@ static long process(struct dbCommon *pcommon)
19 if (status==0) convert(prec);
20 else if (status==2) status=0;
21
22+ if ( prec->tpro >= 2 )
23+ printf( "%s: Process %s, val %f\n",
24+ epicsThreadGetNameSelf(), prec->name, prec->val );
25+
26 /* check for alarms */
27 checkAlarms(prec,&timeLast);
28 /* check event list */
29diff --git a/src/std/rec/aoRecord.c b/src/std/rec/aoRecord.c
30index 0d923af..defd6a4 100644
31--- a/src/std/rec/aoRecord.c
32+++ b/src/std/rec/aoRecord.c
33@@ -197,6 +197,10 @@ static long process(struct dbCommon *pcommon)
34 prec->udf = isnan(prec->val);
35 }
36
37+ if ( prec->tpro >= 2 )
38+ printf( "%s: Process %s, val %f\n",
39+ epicsThreadGetNameSelf(), prec->name, prec->val );
40+
41 /* check for alarms */
42 checkAlarms(prec);
43
44diff --git a/src/std/rec/biRecord.c b/src/std/rec/biRecord.c
45index 7afea3d..6c22116 100644
46--- a/src/std/rec/biRecord.c
47+++ b/src/std/rec/biRecord.c
48@@ -142,6 +142,12 @@ static long process(struct dbCommon *pcommon)
49 prec->udf = FALSE;
50 }
51 else if(status==2) status=0;
52+
53+ if ( prec->tpro >= 2 )
54+ printf( "%s: Process %s, val %s\n",
55+ epicsThreadGetNameSelf(), prec->name,
56+ ( prec->val ? prec->onam : prec->znam ) );
57+
58 /* check for alarms */
59 checkAlarms(prec);
60 /* check event list */
61diff --git a/src/std/rec/boRecord.c b/src/std/rec/boRecord.c
62index 8f60a0b..214f82d 100644
63--- a/src/std/rec/boRecord.c
64+++ b/src/std/rec/boRecord.c
65@@ -221,6 +221,11 @@ static long process(struct dbCommon *pcommon)
66 } else prec->rval = (epicsUInt32)prec->val;
67 }
68
69+ if ( prec->tpro >= 2 )
70+ printf( "%s: Process %s, val %s\n",
71+ epicsThreadGetNameSelf(), prec->name,
72+ ( prec->val ? prec->onam : prec->znam ) );
73+
74 /* check for alarms */
75 checkAlarms(prec);
76
77diff --git a/src/std/rec/calcRecord.c b/src/std/rec/calcRecord.c
78index 12a58d1..a45e879 100644
79--- a/src/std/rec/calcRecord.c
80+++ b/src/std/rec/calcRecord.c
81@@ -125,6 +125,11 @@ static long process(struct dbCommon *pcommon)
82
83 timeLast = prec->time;
84 recGblGetTimeStamp(prec);
85+
86+ if ( prec->tpro >= 2 )
87+ printf( "%s: Process %s, val %f\n",
88+ epicsThreadGetNameSelf(), prec->name, prec->val );
89+
90 /* check for alarms */
91 checkAlarms(prec, &timeLast);
92 /* check event list */
93diff --git a/src/std/rec/calcoutRecord.c b/src/std/rec/calcoutRecord.c
94index 8b55255..80071b3 100644
95--- a/src/std/rec/calcoutRecord.c
96+++ b/src/std/rec/calcoutRecord.c
97@@ -249,6 +249,11 @@ static long process(struct dbCommon *pcommon)
98 prec->udf = isnan(prec->val);
99 }
100 }
101+
102+ if ( prec->tpro >= 2 )
103+ printf( "%s: Process %s, val %f\n",
104+ epicsThreadGetNameSelf(), prec->name, prec->val );
105+
106 checkAlarms(prec);
107 /* check for output link execution */
108 switch (prec->oopt) {
109diff --git a/src/std/rec/longinRecord.c b/src/std/rec/longinRecord.c
110index bd3c24a..40e2242 100644
111--- a/src/std/rec/longinRecord.c
112+++ b/src/std/rec/longinRecord.c
113@@ -152,6 +152,10 @@ static long process(struct dbCommon *pcommon)
114 recGblGetTimeStamp(prec);
115 if (status==0) prec->udf = FALSE;
116
117+ if ( prec->tpro >= 2 )
118+ printf( "%s: Process %s, val %d\n",
119+ epicsThreadGetNameSelf(), prec->name, prec->val );
120+
121 /* check for alarms */
122 checkAlarms(prec, &timeLast);
123 /* check event list */
124diff --git a/src/std/rec/longoutRecord.c b/src/std/rec/longoutRecord.c
125index 6062ad7..0fba405 100644
126--- a/src/std/rec/longoutRecord.c
127+++ b/src/std/rec/longoutRecord.c
128@@ -154,6 +154,10 @@ static long process(struct dbCommon *pcommon)
129 if (!status) convert(prec,value);
130 }
131
132+ if ( prec->tpro >= 2 )
133+ printf( "%s: Process %s, val %d\n",
134+ epicsThreadGetNameSelf(), prec->name, prec->val );
135+
136 /* check for alarms */
137 checkAlarms(prec);
138
139diff --git a/src/std/rec/mbbiRecord.c b/src/std/rec/mbbiRecord.c
140index ad5a8ce..96d54ab 100644
141--- a/src/std/rec/mbbiRecord.c
142+++ b/src/std/rec/mbbiRecord.c
143@@ -201,6 +201,10 @@ static long process(struct dbCommon *pcommon)
144 else if (status == 2)
145 status = 0;
146
147+ if ( prec->tpro >= 2 )
148+ printf( "%s: Process %s, val %u\n",
149+ epicsThreadGetNameSelf(), prec->name, prec->val );
150+
151 checkAlarms(prec, &timeLast);
152 monitor(prec);
153
154diff --git a/src/std/rec/mbboRecord.c b/src/std/rec/mbboRecord.c
155index 0ae6a81..d99374a 100644
156--- a/src/std/rec/mbboRecord.c
157+++ b/src/std/rec/mbboRecord.c
158@@ -224,6 +224,11 @@ static long process(struct dbCommon *pcommon)
159 }
160
161 CONTINUE:
162+
163+ if ( prec->tpro >= 2 )
164+ printf( "%s: Process %s, val %u\n",
165+ epicsThreadGetNameSelf(), prec->name, prec->val );
166+
167 /* Check for alarms */
168 checkAlarms(prec);
169

Subscribers

People subscribed via source and target branches