From 668d1d525509604ab4ccd7382022dfb469c99841 Mon Sep 17 00:00:00 2001 From: Dirk Zimoch Date: Thu, 6 Jun 2024 11:28:46 +0200 Subject: [PATCH] add some per-record debugging --- docs/setup.html | 36 +++++++++++++++++++++++------------- src/StreamCore.cc | 2 ++ src/StreamCore.h | 1 + src/StreamEpics.cc | 20 ++++++++++++++++++++ 4 files changed, 46 insertions(+), 13 deletions(-) diff --git a/docs/setup.html b/docs/setup.html index b8f1f3a..2d909f7 100644 --- a/docs/setup.html +++ b/docs/setup.html @@ -385,35 +385,45 @@

5. Debug and Error Messages

Generation of debug and error messages is controlled with two shell variables, streamDebug and streamError. Setting those variables to 1 (actually to any number but 0) enables the -messages. +messages. A few noisy and rarely useful debug messages are only enabled when +setting streamDebug to 2. Per default debug messages are switched off and error messages are switched on. Errors occuring while loading protocol files are always shown.

-Warning: Enabling debug messages can create a lot of output! -At the moment, there is no way to set filters on debug or error messages. +Warning: Enabling debug messages this way can create a lot of output! +Therefore, some limited debugging can be enabled per record, independent of +the streamDebug variable using the .TPRO field of +the record. Currently, setting .TPRO to 1 or 2 enables some +basic information about the processing of a record and its i/o.

Debug output can be redirected to a file with the command streamSetLogfile("filename"). -When called without a filename, debug output is directed back -to the console. +If the file already exists, it will be overwritten, not appended to. +While debug messages are only written to the defined log file, error messages +are still printed to stderr too. +Calling streamSetLogfile without a filename directs debug output +back to stderr and closes the log file.

-By default the debug/error output is set to be colored if the terminal allows -it but this can be set to always colored or never colored by setting -streamDebugColored to 1 or 0 respectively. +By default, error messages to the console are printed in red color if +stderr is a tty at startup time, using ANSI color codes. Some +terminals may not support this properly. +The variable streamDebugColored can be set to 0 or 1 to +disable or enable colored error messages explicitly. +Error messages written to a log file do not use colors.

Error and debug messages are prefixed with a time stamp unless the variable streamMsgTimeStamped is set to 0.

-When a device is disconnected StreamDevice can produce many repeated timeout -messages. To reduce this logging you can set streamErrorDeadTime -to an integer number of seconds. When this is set repeated timeout messages -will not be printed in the specified dead time after the last message. The -default dead time is 0, resulting in every message being printed. +when a device is unresponsive, StreamDevice may produce many repeated timeout +messages. To reduce this, you can set streamErrorDeadTime +to an integer number of seconds. In this case, repeated timeout messages +will not be printed during the specified dead time after the last printed +message. The default dead time is 0, resulting in every message being printed.

Example (vxWorks):

diff --git a/src/StreamCore.cc b/src/StreamCore.cc index e9dfd11..1a88cf8 100644 --- a/src/StreamCore.cc +++ b/src/StreamCore.cc @@ -603,6 +603,7 @@ evalOut() // flush all unread input unparsedInput = false; inputBuffer.clear(); + inputLine.clear(); if (!formatOutput()) { finishProtocol(FormatError); @@ -1011,6 +1012,7 @@ readCallback(StreamIoStatus status, finishProtocol(Fault); return 0; } + inputHook(input, size); inputBuffer.append(input, size); debug("StreamCore::readCallback(%s) inputBuffer=\"%s\", size %" Z "u\n", name(), inputBuffer.expand()(), inputBuffer.length()); diff --git a/src/StreamCore.h b/src/StreamCore.h index e22c10f..9c8218d 100644 --- a/src/StreamCore.h +++ b/src/StreamCore.h @@ -219,6 +219,7 @@ class StreamCore : // virtual methods virtual void protocolStartHook() {} + virtual void inputHook(const void* input, size_t size) {}; virtual void protocolFinishHook(ProtocolResult) {} virtual void startTimer(unsigned long timeout) = 0; virtual bool formatValue(const StreamFormat&, const void* fieldaddress) = 0; diff --git a/src/StreamEpics.cc b/src/StreamEpics.cc index bfc61a9..44b8d9e 100644 --- a/src/StreamEpics.cc +++ b/src/StreamEpics.cc @@ -137,6 +137,7 @@ class Stream : protected StreamCore #endif // StreamCore methods + void inputHook(const void* input, size_t size); void protocolFinishHook(ProtocolResult); void startTimer(unsigned long timeout); bool getFieldAddress(const char* fieldname, @@ -934,6 +935,10 @@ process() debug("Stream::process(%s) start\n", name()); status = NO_ALARM; convert = OK; + if (record->tpro) + { + StreamDebugClass(record->name).print("start protocol '%s'\n", protocolname()); + } if (!startProtocol(record->proc == 2 ? StreamCore::StartInit : StreamCore::StartNormal)) { debug("Stream::process(%s): could not start %sprotocol, status=%s (%d)\n", @@ -1028,11 +1033,26 @@ expire(const epicsTime&) // StreamCore virtual methods //////////////////////////////////////////// +void Stream:: +inputHook(const void* input, size_t size) +{ + if (record->tpro > 1) + { + StreamDebugClass(record->name).print("received \"%s\"\n", + StreamBuffer(input, size).expand()()); + } +} + void Stream:: protocolFinishHook(ProtocolResult result) { debug("Stream::protocolFinishHook(%s, %s)\n", name(), toStr(result)); + if (record->tpro) + { + StreamDebugClass(record->name).print("%s. out=\"%s\", in=\"%s\"\n", + toStr(result), outputLine.expand()(), inputLine.expand()()); + } switch (result) { case Success: