Sanity checks for incoming internal netconf

Hex debug of messages
This commit is contained in:
Olof Hagsand 2023-02-03 12:48:45 +01:00
parent 6681eb99d3
commit 48a0fb9968
5 changed files with 50 additions and 32 deletions

View file

@ -99,8 +99,8 @@ Developers may need to change their code
* Added maskable flags that can be combined when debugging: * Added maskable flags that can be combined when debugging:
* `DEFAULT` = 1: Basic debug message, espcially initialization * `DEFAULT` = 1: Basic debug message, espcially initialization
* `MSG` = 2: Input and output packets, read datastore * `MSG` = 2: Input and output packets, read datastore
* `DETAIL` = 4: Details: message dump in hex, xpath parse trees, etc * `DETAIL` = 4: xpath parse trees, etc
* `EXTRA` = 8: Extra detailed logs * `EXTRA` = 8: Extra detailed logs, message dump in hex
* Added `ISO/IEC 10646` encodings to XML parser: `&#[0-9]+;` and `&#[0-9a-fA-F]+;` * Added `ISO/IEC 10646` encodings to XML parser: `&#[0-9]+;` and `&#[0-9a-fA-F]+;`
* Added `CLIXON_CLIENT_SSH` to client API to communicate remotely via SSH netconf sub-system * Added `CLIXON_CLIENT_SSH` to client API to communicate remotely via SSH netconf sub-system

View file

@ -52,7 +52,7 @@
/* Debug-level masks */ /* Debug-level masks */
#define CLIXON_DBG_DEFAULT 1 /* Default logs */ #define CLIXON_DBG_DEFAULT 1 /* Default logs */
#define CLIXON_DBG_MSG 2 /* In/out messages and datastore reads */ #define CLIXON_DBG_MSG 2 /* In/out messages and datastore reads */
#define CLIXON_DBG_DETAIL 4 /* Detailed logs */ #define CLIXON_DBG_DETAIL 4 /* Details: traces, parse trees, etc */
#define CLIXON_DBG_EXTRA 8 /* Extra Detailed logs */ #define CLIXON_DBG_EXTRA 8 /* Extra Detailed logs */
/* /*

View file

@ -370,11 +370,12 @@ clicon_debug_get(void)
* The dbgdebug level strategy is a mask of the following masks: * The dbgdebug level strategy is a mask of the following masks:
* 1: Basic debug message, espcially initialization * 1: Basic debug message, espcially initialization
* 2: Input and output packets, read datastore * 2: Input and output packets, read datastore
* 4: Details: message dump in hex, xpath parse trees, etc * 4: Details: traces, parse trees, etc
* See CLIXON_DBG_* flags * 8: Extra detailed logs, temporary logs
* @param[in] dbglevel 0: No debug, 1-7 combined of the CLIXON_DBG_ flags above * @param[in] dbglevel Debug level 0: No debug, 1-7 combined of the CLIXON_DBG_ flags above
* @param[in] format Message to print as argv. * @param[in] format Message to print as argv.
* @see clicon_debug_xml Specialization for XML tree * @see clicon_debug_xml Specialization for XML tree
* @see CLIXON_DBG_DEFAULT and other flags
*/ */
int int
clicon_debug(int dbglevel, clicon_debug(int dbglevel,

View file

@ -293,13 +293,18 @@ atomicio(ssize_t (*fn) (int, void *, size_t),
return (pos); return (pos);
} }
#if 0 // Extra debug /*! Log message as hex on debug.
/*! Print message on debug. Log if syslog, stderr if not *
* @param[in] msg CLICON msg * @param[in] dbglevel Debug level
* @param[in] msg Byte stream
* @param[in] len Length of byte stream
* @param[in] file Calling file name
*/ */
static int static int
msg_dump(int dbglevel, msg_hex(int dbglevel,
struct clicon_msg *msg) const char *msg,
size_t len,
char const *file)
{ {
int retval = -1; int retval = -1;
cbuf *cb = NULL; cbuf *cb = NULL;
@ -311,13 +316,13 @@ msg_dump(int dbglevel,
clicon_err(OE_CFG, errno, "cbuf_new"); clicon_err(OE_CFG, errno, "cbuf_new");
goto done; goto done;
} }
cprintf(cb, "%s:", __FUNCTION__); cprintf(cb, "%s:", file);
for (i=0; i<ntohl(msg->op_len); i++){ for (i=0; i<len; i++){
cprintf(cb, "%02x", ((char*)msg)[i]&0xff); cprintf(cb, "%02x", ((char*)msg)[i]&0xff);
if ((i+1)%32==0){ if ((i+1)%32==0){
clicon_debug(CLIXON_DBG_DETAIL, "%s", cbuf_get(cb)); clicon_debug(dbglevel, "%s", cbuf_get(cb));
cbuf_reset(cb); cbuf_reset(cb);
cprintf(cb, "%s:", __FUNCTION__); cprintf(cb, "%s:", file);
} }
else else
if ((i+1)%4==0) if ((i+1)%4==0)
@ -331,7 +336,6 @@ msg_dump(int dbglevel,
cbuf_free(cb); cbuf_free(cb);
return retval; return retval;
} }
#endif
/*! Send a CLICON netconf message using internal IPC message /*! Send a CLICON netconf message using internal IPC message
* *
@ -346,12 +350,9 @@ clicon_msg_send(int s,
int retval = -1; int retval = -1;
int e; int e;
clicon_debug(CLIXON_DBG_DETAIL, "%s: send msg len=%d", clicon_debug(CLIXON_DBG_DETAIL, "%s: send msg len=%d", __FUNCTION__, ntohl(msg->op_len));
__FUNCTION__, ntohl(msg->op_len));
#if 0 // Extra debug
msg_dump(CLIXON_DBG_EXTRA, msg);
#endif
clicon_debug(CLIXON_DBG_MSG, "Send: %s", msg->op_body); clicon_debug(CLIXON_DBG_MSG, "Send: %s", msg->op_body);
msg_hex(CLIXON_DBG_EXTRA, (char*)msg, ntohl(msg->op_len), __FUNCTION__);
if (atomicio((ssize_t (*)(int, void *, size_t))write, if (atomicio((ssize_t (*)(int, void *, size_t))write,
s, msg, ntohl(msg->op_len)) < 0){ s, msg, ntohl(msg->op_len)) < 0){
e = errno; e = errno;
@ -402,35 +403,50 @@ clicon_msg_rcv(int s,
clicon_err(OE_CFG, errno, "atomicio"); clicon_err(OE_CFG, errno, "atomicio");
goto done; goto done;
} }
msg_hex(CLIXON_DBG_EXTRA, (char*)&hdr, hlen, __FUNCTION__);
if (hlen == 0){ if (hlen == 0){
retval = 0;
*eof = 1; *eof = 1;
goto done; goto ok;
} }
if (hlen != sizeof(hdr)){ if (hlen != sizeof(hdr)){
clicon_err(OE_CFG, errno, "header too short (%d)", hlen); clicon_err(OE_PROTO, errno, "header too short (%d)", hlen);
goto done; goto done;
} }
mlen = ntohl(hdr.op_len); mlen = ntohl(hdr.op_len);
clicon_debug(16, "op-len:%u op-id:%u",
mlen, ntohl(hdr.op_id));
clicon_debug(CLIXON_DBG_DETAIL, "%s: rcv msg len=%d", clicon_debug(CLIXON_DBG_DETAIL, "%s: rcv msg len=%d",
__FUNCTION__, mlen); __FUNCTION__, mlen);
if ((*msg = (struct clicon_msg *)malloc(mlen)) == NULL){ if (mlen <= sizeof(hdr)){
clicon_err(OE_CFG, errno, "malloc"); clicon_err(OE_PROTO, 0, "op_len:%u too short", mlen);
*eof = 1;
assert(0);
goto ok;
}
if ((*msg = (struct clicon_msg *)malloc(mlen+1)) == NULL){
clicon_err(OE_PROTO, errno, "malloc");
goto done; goto done;
} }
memcpy(*msg, &hdr, hlen); memcpy(*msg, &hdr, hlen);
if ((len2 = atomicio(read, s, (*msg)->op_body, mlen - sizeof(hdr))) < 0){ if ((len2 = atomicio(read, s, (*msg)->op_body, mlen - sizeof(hdr))) < 0){
clicon_err(OE_CFG, errno, "read"); clicon_err(OE_PROTO, errno, "read");
goto done; goto done;
} }
if (len2)
msg_hex(CLIXON_DBG_EXTRA, (*msg)->op_body, len2, __FUNCTION__);
if (len2 != mlen - sizeof(hdr)){ if (len2 != mlen - sizeof(hdr)){
clicon_err(OE_CFG, errno, "body too short"); clicon_err(OE_PROTO, 0, "body too short");
goto done; *eof = 1;
goto ok;
}
if (((char*)*msg)[mlen-1] != '\0'){
clicon_err(OE_PROTO, 0, "body not NULL terminated");
*eof = 1;
goto ok;
} }
#if 0 // Extra debug
msg_dump(CLIXON_DBG_EXTRA, *msg);
#endif
clicon_debug(CLIXON_DBG_MSG, "Recv: %s", (*msg)->op_body); clicon_debug(CLIXON_DBG_MSG, "Recv: %s", (*msg)->op_body);
ok:
retval = 0; retval = 0;
done: done:
clicon_debug(CLIXON_DBG_DETAIL, "%s retval:%d", __FUNCTION__, retval); clicon_debug(CLIXON_DBG_DETAIL, "%s retval:%d", __FUNCTION__, retval);

View file

@ -91,6 +91,7 @@ SH_SUFFIX=@SH_SUFFIX@
LIBSTATIC_SUFFIX=@LIBSTATIC_SUFFIX@ LIBSTATIC_SUFFIX=@LIBSTATIC_SUFFIX@
LIBS="@LIBS@" LIBS="@LIBS@"
CLIXON_YANG_PATCH=@CLIXON_YANG_PATCH@ CLIXON_YANG_PATCH=@CLIXON_YANG_PATCH@
CLIXON_YANG_SCHEMA_MOUNT=@CLIXON_YANG_SCHEMA_MOUNT@
YANG_STANDARD_DIR=@YANG_STANDARD_DIR@ YANG_STANDARD_DIR=@YANG_STANDARD_DIR@
YANG_INSTALLDIR=@YANG_INSTALLDIR@ YANG_INSTALLDIR=@YANG_INSTALLDIR@