* Changed debug levels in clicon_debug() to be based on maskable flags

* Added flag names: `CLIXON_DBG_*`
  * Added maskable flags that can be combined when debugging:
    * `DEFAULT` = 1: Basic debug message, espcially initialization
    * `MSG` = 2: Input and output packets, read datastore
    * `DETAIL` = 4: Details: message dump in hex, xpath parse trees, etc
    * `EXTRA` = 8: Extra detailed logs
* Test: some errors in yang-lib where content-id was in wrong place
This commit is contained in:
Olof hagsand 2023-01-27 10:08:07 +01:00 committed by Olof Hagsand
parent 8342b74968
commit da9bfcbb53
47 changed files with 425 additions and 210 deletions

View file

@ -1532,7 +1532,7 @@ from_client_msg(clicon_handle h,
char *namespace = NULL;
int nr = 0;
clicon_debug(2, "%s", __FUNCTION__);
clicon_debug(CLIXON_DBG_DETAIL, "%s", __FUNCTION__);
yspec = clicon_dbspec_yang(h);
/* Return netconf message. Should be filled in by the dispatch(sub) functions
* as wither rpc-error or by positive response.
@ -1708,7 +1708,7 @@ from_client_msg(clicon_handle h,
if (cbuf_len(cbret) == 0)
if (netconf_operation_failed(cbret, "application", clicon_errno?clicon_err_reason:"unknown")< 0)
goto done;
clicon_debug(2, "%s cbret:%s", __FUNCTION__, cbuf_get(cbret));
// XXX clicon_debug(CLIXON_DBG_MSG, "Reply:%s", cbuf_get(cbret));
/* XXX problem here is that cbret has not been parsed so may contain
parse errors */
if (send_msg_reply(ce->ce_s, cbuf_get(cbret), cbuf_len(cbret)+1) < 0){
@ -1731,7 +1731,7 @@ from_client_msg(clicon_handle h,
// ok:
retval = 0;
done:
clicon_debug(1, "%s retval:%d", __FUNCTION__, retval);
clicon_debug(CLIXON_DBG_DETAIL, "%s retval:%d", __FUNCTION__, retval);
if (xnacm){
xml_free(xnacm);
if (clicon_nacm_cache_set(h, NULL) < 0)
@ -1768,7 +1768,7 @@ from_client(int s,
clicon_handle h = ce->ce_handle;
int eof = 0;
clicon_debug(2, "%s", __FUNCTION__);
clicon_debug(CLIXON_DBG_DETAIL, "%s", __FUNCTION__);
if (s != ce->ce_s){
clicon_err(OE_NETCONF, EINVAL, "Internal error: s != ce->ce_s");
goto done;
@ -1782,7 +1782,7 @@ from_client(int s,
goto done;
retval = 0;
done:
clicon_debug(1, "%s retval=%d", __FUNCTION__, retval);
clicon_debug(CLIXON_DBG_DETAIL, "%s retval=%d", __FUNCTION__, retval);
if (msg)
free(msg);
return retval; /* -1 here terminates backend */

View file

@ -518,8 +518,7 @@ validate_common(clicon_handle h,
&td->td_tcvec, /* changed: wanted values */
&td->td_clen) < 0)
goto done;
if (clicon_debug_get()>1)
transaction_print(stderr, td);
transaction_dbg(h, CLIXON_DBG_DEFAULT, td, __FUNCTION__);
/* Mark as changed in tree */
for (i=0; i<td->td_dlen; i++){ /* Also down */
xn = td->td_dvec[i];

View file

@ -199,11 +199,11 @@ client_get_streams(clicon_handle h,
*
*/
static int
get_client_statedata(clicon_handle h,
char *xpath,
cvec *nsc,
withdefaults_type wdef,
cxobj **xret)
get_statedata(clicon_handle h,
char *xpath,
cvec *nsc,
withdefaults_type wdef,
cxobj **xret)
{
int retval = -1;
yang_stmt *yspec;
@ -872,7 +872,8 @@ get_common(clicon_handle h,
#else
wdef = WITHDEFAULTS_EXPLICIT;
#endif
clicon_debug(2, "%s", __FUNCTION__);
clicon_debug(CLIXON_DBG_DETAIL, "%s", __FUNCTION__);
username = clicon_username_get(h);
if ((yspec = clicon_dbspec_yang(h)) == NULL){
clicon_err(OE_YANG, ENOENT, "No yang spec9");
@ -997,7 +998,7 @@ get_common(clicon_handle h,
break;
case CONTENT_ALL: /* both config and state */
case CONTENT_NONCONFIG: /* state data only */
if ((ret = get_client_statedata(h, xpath?xpath:"/", nsc, wdef, &xret)) < 0)
if ((ret = get_statedata(h, xpath?xpath:"/", nsc, wdef, &xret)) < 0)
goto done;
if (ret == 0){ /* Error from callback (error in xret) */
if (clixon_xml2cbuf(cbret, xret, 0, 0, -1, 0) < 0)
@ -1049,7 +1050,7 @@ get_common(clicon_handle h,
ok:
retval = 0;
done:
clicon_debug(2, "%s retval:%d", __FUNCTION__, retval);
clicon_debug(CLIXON_DBG_DETAIL, "%s retval:%d", __FUNCTION__, retval);
if (xvec)
free(xvec);
if (xret)

View file

@ -112,8 +112,9 @@ backend_terminate(clicon_handle h)
/* Free changelog */
if ((x = clicon_xml_changelog_get(h)) != NULL)
xml_free(x);
if ((yspec = clicon_dbspec_yang(h)) != NULL)
if ((yspec = clicon_dbspec_yang(h)) != NULL){
ys_free(yspec);
}
if ((yspec = clicon_config_yang(h)) != NULL)
ys_free(yspec);
if ((yspec = clicon_nacm_ext_yang(h)) != NULL)
@ -133,6 +134,7 @@ backend_terminate(clicon_handle h)
xpath_optimize_exit();
clixon_pagination_free(h);
if (pidfile)
unlink(pidfile);
if (sockfamily==AF_UNIX && lstat(sockpath, &st) == 0)
@ -1045,8 +1047,8 @@ main(int argc,
goto done;
if (clicon_socket_set(h, ss) < 0)
goto done;
if (dbg)
clicon_option_dump(h, dbg);
clicon_option_dump(h, 1);
/* Depending on configure setting, privileges may be dropped here after
* initializations */
if (check_drop_priv(h, gid, yspec) < 0)

View file

@ -115,7 +115,7 @@ clixon_plugin_reset_all(clicon_handle h,
int retval = -1;
clixon_plugin_t *cp = NULL;
clicon_debug(1, "%s", __FUNCTION__);
clicon_debug(CLIXON_DBG_DETAIL, "%s", __FUNCTION__);
/* Loop through all plugins, call callbacks in each */
while ((cp = clixon_plugin_each(h, cp)) != NULL) {
if (clixon_plugin_reset_one(cp, h, db) < 0)
@ -176,7 +176,7 @@ clixon_plugin_pre_daemon_all(clicon_handle h)
int retval = -1;
clixon_plugin_t *cp = NULL;
clicon_debug(1, "%s", __FUNCTION__);
clicon_debug(CLIXON_DBG_DETAIL, "%s", __FUNCTION__);
/* Loop through all plugins, call callbacks in each */
while ((cp = clixon_plugin_each(h, cp)) != NULL) {
if (clixon_plugin_pre_daemon_one(cp, h) < 0)
@ -238,7 +238,7 @@ clixon_plugin_daemon_all(clicon_handle h)
int retval = -1;
clixon_plugin_t *cp = NULL;
clicon_debug(1, "%s", __FUNCTION__);
clicon_debug(CLIXON_DBG_DETAIL, "%s", __FUNCTION__);
/* Loop through all plugins, call callbacks in each */
while ((cp = clixon_plugin_each(h, cp)) != NULL) {
if (clixon_plugin_daemon_one(cp, h) < 0)
@ -342,7 +342,7 @@ clixon_plugin_statedata_all(clicon_handle h,
cbuf *cberr = NULL;
cxobj *xerr = NULL;
clicon_debug(1, "%s", __FUNCTION__);
clicon_debug(CLIXON_DBG_DETAIL, "%s", __FUNCTION__);
while ((cp = clixon_plugin_each(h, cp)) != NULL) {
if ((ret = clixon_plugin_statedata_one(cp, h, nsc, xpath, &x)) < 0)
goto done;
@ -368,7 +368,7 @@ clixon_plugin_statedata_all(clicon_handle h,
x = NULL;
continue;
}
clicon_debug_xml(2, x, "%s %s STATE:", __FUNCTION__, clixon_plugin_name_get(cp));
clicon_debug_xml(CLIXON_DBG_DETAIL, x, "%s %s STATE:", __FUNCTION__, clixon_plugin_name_get(cp));
/* XXX: ret == 0 invalid yang binding should be handled as internal error */
if ((ret = xml_bind_yang(x, YB_MODULE, yspec, &xerr)) < 0)
goto done;
@ -464,7 +464,7 @@ clixon_plugin_lockdb_all(clicon_handle h,
int retval = -1;
clixon_plugin_t *cp = NULL;
clicon_debug(1, "%s", __FUNCTION__);
clicon_debug(CLIXON_DBG_DETAIL, "%s", __FUNCTION__);
while ((cp = clixon_plugin_each(h, cp)) != NULL) {
if (clixon_plugin_lockdb_one(cp, h, db, lock, id) < 0)
goto done;
@ -641,7 +641,7 @@ plugin_transaction_begin_all(clicon_handle h,
int retval = -1;
clixon_plugin_t *cp = NULL;
clicon_debug(1, "%s", __FUNCTION__);
clicon_debug(CLIXON_DBG_DETAIL, "%s", __FUNCTION__);
while ((cp = clixon_plugin_each(h, cp)) != NULL) {
if (plugin_transaction_begin_one(cp, h, td) < 0)
goto done;
@ -976,7 +976,7 @@ plugin_transaction_end_all(clicon_handle h,
int retval = -1;
clixon_plugin_t *cp = NULL;
clicon_debug(1, "%s", __FUNCTION__);
clicon_debug(CLIXON_DBG_DETAIL, "%s", __FUNCTION__);
while ((cp = clixon_plugin_each(h, cp)) != NULL) {
if (plugin_transaction_end_one(cp, h, td) < 0)
goto done;
@ -1028,7 +1028,7 @@ plugin_transaction_abort_all(clicon_handle h,
int retval = -1;
clixon_plugin_t *cp = NULL;
clicon_debug(1, "%s", __FUNCTION__);
clicon_debug(CLIXON_DBG_DETAIL, "%s", __FUNCTION__);
while ((cp = clixon_plugin_each(h, cp)) != NULL) {
if (plugin_transaction_abort_one(cp, h, td) < 0)
; /* dont abort on error */

View file

@ -241,7 +241,7 @@ backend_accept_client(int fd,
uid_t guid;
#endif
clicon_debug(2, "%s", __FUNCTION__);
clicon_debug(CLIXON_DBG_DETAIL, "%s", __FUNCTION__);
len = sizeof(from);
if ((s = accept(fd, &from, &len)) < 0){
clicon_err(OE_UNIX, errno, "accept");

View file

@ -201,12 +201,15 @@ transaction_clen(transaction_data td)
return ((transaction_data_t *)td)->td_clen;
}
/*! Print transaction on FILE for debug
* @see transaction_log
/*! Print info about transaction on FILE, including what has changed
*
* @param[in] f stdio FILE
* @param[in] th Transaction data
* @see transaction_dbg
*/
int
transaction_print(FILE *f,
transaction_data th)
transaction_print(FILE *f,
transaction_data th)
{
cxobj *xn;
int i;
@ -235,6 +238,66 @@ transaction_print(FILE *f,
return 0;
}
/*! Log debug info about transaction on FILE, including what has changed
*
* @param[in] h Clixon handle
* @param[in] dbglevel Debuglevel as defined by CLIXON_DBG_* flags
* @param[in] th Transaction data
* @param[in] msg Debug msg tag
*/
int
transaction_dbg(clicon_handle h,
int dbglevel,
transaction_data th,
const char *msg)
{
cxobj *xn;
int i;
transaction_data_t *td;
cbuf *cb = NULL;
td = (transaction_data_t *)th;
if ((cb = cbuf_new()) == NULL){
clicon_err(OE_CFG, errno, "cbuf_new");
goto done;
}
for (i=0; i<td->td_dlen; i++){
xn = td->td_dvec[i];
if (clixon_xml2cbuf(cb, xn, 0, 0, -1, 0) < 0)
goto done;
}
if (i)
clicon_debug(dbglevel, "%s %" PRIu64 " %s del: %s",
__FUNCTION__, td->td_id, msg, cbuf_get(cb));
cbuf_reset(cb);
for (i=0; i<td->td_alen; i++){
xn = td->td_avec[i];
if (clixon_xml2cbuf(cb, xn, 0, 0, -1, 0) < 0)
goto done;
}
if (i)
clicon_debug(dbglevel, "%s %" PRIu64 " %s add: %s",
__FUNCTION__, td->td_id, msg, cbuf_get(cb));
cbuf_reset(cb);
for (i=0; i<td->td_clen; i++){
if (td->td_scvec){
xn = td->td_scvec[i];
if (clixon_xml2cbuf(cb, xn, 0, 0, -1, 0) < 0)
goto done;
}
xn = td->td_tcvec[i];
if (clixon_xml2cbuf(cb, xn, 0, 0, -1, 0) < 0)
goto done;
}
if (i)
clicon_debug(dbglevel, "%s %" PRIu64 " %s change: %s",
__FUNCTION__, td->td_id, msg, cbuf_get(cb));
done:
if (cb)
cbuf_free(cb);
return 0;
}
/*! Log a transaction
*
*/

View file

@ -62,7 +62,9 @@ cxobj **transaction_tcvec(transaction_data td);
size_t transaction_clen(transaction_data td);
int transaction_print(FILE *f, transaction_data th);
int transaction_log(clicon_handle h, transaction_data th, int level, const char *id);
int transaction_dbg(clicon_handle h, int dbglevel, transaction_data th, const char *msg);
int transaction_log(clicon_handle h, transaction_data th, int level, const char *op);
/* Pagination callbacks
* @see pagination_data_t internal structure

View file

@ -1385,7 +1385,7 @@ yang2cli_yspec(clicon_handle h,
clicon_log(LOG_NOTICE, "%s: Top-level cli-spec %s:\n%s",
__FUNCTION__, treename, cbuf_get(cb));
else
clicon_debug(2, "%s: Top-level cli-spec %s:\n%s",
clicon_debug(CLIXON_DBG_DETAIL, "%s: Top-level cli-spec %s:\n%s",
__FUNCTION__, treename, cbuf_get(cb));
if (cligen_parsetree_merge(pt0, NULL, pt) < 0){
clicon_err(OE_YANG, errno, "cligen_parsetree_merge");

View file

@ -780,8 +780,7 @@ main(int argc,
if (logclisyntax)
cli_logsyntax_set(h, logclisyntax);
if (dbg)
clicon_option_dump(h, dbg);
clicon_option_dump(h, 1);
/* Join rest of argv to a single command */
restarg = clicon_strjoin(argc, argv, " ");

View file

@ -404,8 +404,8 @@ netconf_input_frame(clicon_handle h,
int ret;
netconf_framing_type framing;
clicon_debug(1, "%s", __FUNCTION__);
clicon_debug(2, "%s: \"%s\"", __FUNCTION__, cbuf_get(cb));
clicon_debug(CLIXON_DBG_DETAIL, "%s", __FUNCTION__);
clicon_debug(CLIXON_DBG_MSG, "Recv ext: %s", cbuf_get(cb));
framing = clicon_option_int(h, "netconf-framing");
yspec = clicon_dbspec_yang(h);
if ((str = strdup(cbuf_get(cb))) == NULL){
@ -1011,8 +1011,7 @@ main(int argc,
#endif
if (clixon_event_reg_fd(0, netconf_input_cb, h, "netconf socket") < 0)
goto done;
if (dbg)
clicon_option_dump(h, dbg);
clicon_option_dump(h, 1);
if (tv.tv_sec || tv.tv_usec){
struct timeval t;
gettimeofday(&t, NULL);

View file

@ -529,8 +529,7 @@ main(int argc,
goto done;
/* Dump configuration options on debug */
if (dbg)
clicon_option_dump(h, dbg);
clicon_option_dump(h, 1);
/* Call start function in all plugins before we go interactive */
if (clixon_plugin_start_all(h) < 0)

View file

@ -837,10 +837,7 @@ restconf_openssl_init(clicon_handle h,
/* If debug was enabled here from config and not initially,
* print clixn options and loaded yang files
*/
if (dbg) {
clicon_option_dump(h, dbg);
yang_spec_dump(clicon_dbspec_yang(h), dbg);
}
clicon_option_dump(h, 1);
}
if ((x = xpath_first(xrestconf, nsc, "enable-core-dump")) != NULL) {
/* core dump is enabled on RESTCONF process */
@ -1273,8 +1270,7 @@ main(int argc,
restconf_auth_type_set(h, CLIXON_AUTH_NONE);
/* Dump configuration options on debug */
if (dbg)
clicon_option_dump(h, dbg);
clicon_option_dump(h, 1);
/* Initialize plugin module by creating a handle holding plugin and callback lists */
if (clixon_plugin_module_init(h) < 0)

View file

@ -718,7 +718,7 @@ clixon_snmp_scalar_handler1(netsnmp_mib_handler *handler,
netsnmp_variable_list *requestvb = request->requestvb;
int ret;
clicon_debug(2, "%s", __FUNCTION__);
clicon_debug(CLIXON_DBG_DETAIL, "%s", __FUNCTION__);
if (snmp_common_handler(handler, nhreg, reqinfo, request, 0, &sh) < 0)
goto done;
/* see net-snmp/agent/snmp_agent.h / net-snmp/library/snmp.h */
@ -1293,7 +1293,7 @@ clixon_snmp_table_handler1(netsnmp_mib_handler *handler,
netsnmp_variable_list *requestvb;
int err = 0;
clicon_debug(2, "%s", __FUNCTION__);
clicon_debug(CLIXON_DBG_DETAIL, "%s", __FUNCTION__);
if ((ret = snmp_common_handler(handler, nhreg, reqinfo, request, 1, &sh)) < 0)
goto done;
if (sh->sh_ys == NULL){

View file

@ -639,7 +639,7 @@ type_snmp2xml(yang_stmt *ys,
}
retval = 1;
done:
clicon_debug(2, "%s %d", __FUNCTION__, retval);
clicon_debug(CLIXON_DBG_DETAIL, "%s %d", __FUNCTION__, retval);
if (origtype)
free(origtype);
if (cv)
@ -709,7 +709,7 @@ type_xml2snmp_pre(char *xmlstr0,
}
retval = 1;
done:
clicon_debug(2, "%s %d", __FUNCTION__, retval);
clicon_debug(CLIXON_DBG_DETAIL, "%s %d", __FUNCTION__, retval);
return retval;
fail:
retval = 0;
@ -852,7 +852,7 @@ type_xml2snmp(char *snmpstr,
}
retval = 1;
done:
clicon_debug(2, "%s %d", __FUNCTION__, retval);
clicon_debug(CLIXON_DBG_DETAIL, "%s %d", __FUNCTION__, retval);
return retval;
fail:
retval = 0;

View file

@ -198,7 +198,7 @@ clixon_snmp_input_cb(int s,
clicon_handle h = (clicon_handle)arg;
int ret;
clicon_debug(2, "%s %d", __FUNCTION__, s);
clicon_debug(CLIXON_DBG_DETAIL, "%s %d", __FUNCTION__, s);
FD_ZERO(&readfds);
FD_SET(s, &readfds);
(void)snmp_read(&readfds);
@ -514,8 +514,7 @@ main(int argc,
if (clicon_nsctx_global_set(h, nsctx_global) < 0)
goto done;
if (dbg)
clicon_option_dump(h, dbg);
clicon_option_dump(h, 1);
/* Send hello request to backend to get session-id back
* This is done once at the beginning of the session and then this is