srd: make all debugging and error reporting uniform

5 files changed, 104 insertions, 70 deletions

diff --git a/controller.c b/controller.c
index a093102..c696dd3 100644
--- a/controller.c
+++ b/controller.c
@@ -26,7 +26,10 @@
 #include <stdlib.h>
 
 
+/* List of decoder instances. */
 static GSList *di_list = NULL;
+
+/* List of frontend callbacks to receive PD output. */
 static GSList *callbacks = NULL;
 
 /* lives in decoder.c */
@@ -65,9 +68,12 @@ int srd_init(void)
 {
 	int ret;
 
+	srd_dbg("srd: initializing");
+
+	/* Add our own module to the list of built-in modules. */
 	PyImport_AppendInittab("sigrokdecode", PyInit_sigrokdecode);
 
-	/* Py_Initialize() returns void and usually cannot fail. */
+	/* Initialize the python interpreter. */
 	Py_Initialize();
 
 	if ((ret = set_modulepath()) != SRD_OK) {
@@ -98,8 +104,9 @@ int srd_init(void)
  */
 int srd_exit(void)
 {
-	/* Unload/free all decoders, and then the list of decoders itself. */
-	/* TODO: Error handling. */
+
+	srd_dbg("srd: exiting");
+
 	srd_unload_all_decoders();
 	g_slist_free(pd_list);
 
@@ -216,7 +223,7 @@ int srd_instance_set_options(struct srd_decoder_instance *di,
 				if (!(py_optval = PyLong_FromString(value, NULL, 0))) {
 					/* ValueError Exception */
 					PyErr_Clear();
-					srd_err("Option %s has invalid value %s: expected integer",
+					srd_err("Option %s has invalid value %s: expected integer.",
 							key, value);
 					goto err_out;
 				}
@@ -235,7 +242,7 @@ int srd_instance_set_options(struct srd_decoder_instance *di,
 				if (val_ull == (unsigned long long)-1) {
 					/* OverFlowError exception */
 					PyErr_Clear();
-					srd_err("Invalid integer value for %s: expected integer", key);
+					srd_err("Invalid integer value for %s: expected integer.", key);
 					goto err_out;
 				}
 				if (!(py_optval = PyLong_FromUnsignedLongLong(val_ull)))
@@ -260,7 +267,7 @@ err_out:
 	if (key)
 		g_free(key);
 	if (PyErr_Occurred()) {
-		srd_dbg("stray exception!");
+		srd_dbg("srd: stray exception!");
 		PyErr_Print();
 		PyErr_Clear();
 	}
@@ -319,7 +326,7 @@ int srd_instance_set_probes(struct srd_decoder_instance *di,
 			/* Fall back on optional probes. */
 			if (!(sl = g_slist_find_custom(di->decoder->extra_probes,
 					probe_id, (GCompareFunc)compare_probe_id))) {
-				srd_err("Protocol decoder %s has no probe '%s'",
+				srd_err("Protocol decoder %s has no probe '%s'.",
 						di->decoder->name, probe_id);
 				g_free(new_probemap);
 				return SRD_ERR_ARG;
@@ -351,7 +358,7 @@ struct srd_decoder_instance *srd_instance_new(const char *decoder_id,
 	int i;
 	char *instance_id;
 
-	srd_dbg("%s: creating new %s instance", __func__, decoder_id);
+	srd_dbg("srd: creating new %s instance", decoder_id);
 
 	if (!(dec = srd_get_decoder_by_id(decoder_id))) {
 		srd_err("Protocol decoder %s not found.", decoder_id);
@@ -409,12 +416,12 @@ int srd_instance_stack(struct srd_decoder_instance *di_from,
 {
 
 	if (!di_from || !di_to) {
-		srd_err("invalid from/to instance pair");
+		srd_err("Invalid from/to instance pair.");
 		return SRD_ERR_ARG;
 	}
 
 	if (!g_slist_find(di_list, di_from)) {
-		srd_err("unstacked instance not found");
+		srd_err("Unstacked instance not found.");
 		return SRD_ERR_ARG;
 	}
 
@@ -450,10 +457,11 @@ int srd_instance_start(struct srd_decoder_instance *di, PyObject *args)
 {
 	PyObject *py_name, *py_res;
 
-	srd_dbg("calling start() method on protocol decoder instance %s", di->instance_id);
+	srd_dbg("srd: calling start() method on protocol decoder instance %s",
+			di->instance_id);
 
 	if (!(py_name = PyUnicode_FromString("start"))) {
-		srd_err("unable to build python object for 'start'");
+		srd_err("Unable to build python object for 'start'.");
 		if (PyErr_Occurred())
 			PyErr_Print();
 		return SRD_ERR_PYTHON;
@@ -475,31 +483,41 @@ int srd_instance_start(struct srd_decoder_instance *di, PyObject *args)
 /**
  * Run the specified decoder function.
  *
- * @param dec TODO
- * @param inbuf TODO
- * @param inbuflen TODO
+ * @param start_samplenum The starting sample number for the buffer's sample
+ * 		set, relative to the start of capture.
+ * @param di The decoder instance to call.
+ * @param inbuf The buffer to decode.
+ * @param inbuflen Length of the buffer.
  *
  * @return SRD_OK upon success, a (negative) error code otherwise.
  */
 int srd_instance_decode(uint64_t start_samplenum,
 		struct srd_decoder_instance *di, uint8_t *inbuf, uint64_t inbuflen)
 {
-	PyObject *py_instance, *py_res;
+	PyObject *py_res;
 	srd_logic *logic;
 	uint64_t end_samplenum;
 
-	/* Return an error upon unusable input. */
-	if (di == NULL)
-		return SRD_ERR_ARG; /* TODO: More specific error? */
-	if (inbuf == NULL)
-		return SRD_ERR_ARG; /* TODO: More specific error? */
-	if (inbuflen == 0) /* No point in working on empty buffers. */
-		return SRD_ERR_ARG; /* TODO: More specific error? */
+	srd_dbg("srd: calling decode() on instance %s with %d bytes starting "
+			"at sample %d", di->instance_id, inbuflen, start_samplenum);
 
-	/* TODO: Error handling. */
-	py_instance = di->py_instance;
-	Py_XINCREF(py_instance);
+	/* Return an error upon unusable input. */
+	if (di == NULL) {
+		srd_dbg("srd: empty decoder instance");
+		return SRD_ERR_ARG;
+	}
+	if (inbuf == NULL) {
+		srd_dbg("srd: NULL buffer pointer");
+		return SRD_ERR_ARG;
+	}
+	if (inbuflen == 0) {
+		srd_dbg("srd: empty buffer");
+		return SRD_ERR_ARG;
+	}
 
+	/* Create new srd_logic object. Each iteration around the PD's loop
+	 * will fill one sample into this object.
+	 */
 	logic = PyObject_New(srd_logic, &srd_logic_type);
 	Py_INCREF(logic);
 	logic->di = di;
@@ -510,16 +528,16 @@ int srd_instance_decode(uint64_t start_samplenum,
 	logic->sample = PyList_New(2);
 	Py_INCREF(logic->sample);
 
+	Py_IncRef(di->py_instance);
 	end_samplenum = start_samplenum + inbuflen / di->data_unitsize;
-	if (!(py_res = PyObject_CallMethod(py_instance, "decode",
+	if (!(py_res = PyObject_CallMethod(di->py_instance, "decode",
 			"KKO", logic->start_samplenum, end_samplenum, logic))) {
 		if (PyErr_Occurred())
 			PyErr_Print(); /* Returns void. */
 
 		return SRD_ERR_PYTHON; /* TODO: More specific error? */
 	}
-
-	Py_XDECREF(py_res);
+	Py_DecRef(py_res);
 
 	return SRD_OK;
 }
@@ -532,8 +550,14 @@ int srd_session_start(int num_probes, int unitsize, uint64_t samplerate)
 	struct srd_decoder_instance *di;
 	int ret;
 
+	srd_dbg("srd: calling start() on all instances with %d probes, "
+			"unitsize %d samplerate %d", num_probes, unitsize, samplerate);
+
+	/* Currently only one item of metadata is passed along to decoders,
+	 * samplerate. This can be extended as needed.
+	 */
 	if (!(args = Py_BuildValue("{s:l}", "samplerate", (long)samplerate))) {
-		srd_err("unable to build python object for metadata");
+		srd_err("Unable to build python object for metadata.");
 		return SRD_ERR_PYTHON;
 	}
 
@@ -555,7 +579,7 @@ int srd_session_start(int num_probes, int unitsize, uint64_t samplerate)
 		}
 	}
 
-	Py_DECREF(args);
+	Py_DecRef(args);
 
 	return SRD_OK;
 }
@@ -566,6 +590,10 @@ int srd_session_feed(uint64_t start_samplenum, uint8_t *inbuf, uint64_t inbuflen
 	GSList *d;
 	int ret;
 
+	srd_dbg("srd: calling decode() on all instances with starting sample "
+			"number %"PRIu64", %"PRIu64" bytes at 0x%p", start_samplenum,
+			inbuflen, inbuf);
+
 	for (d = di_list; d; d = d->next) {
 		if ((ret = srd_instance_decode(start_samplenum, d->data, inbuf,
 				inbuflen)) != SRD_OK)
@@ -576,11 +604,15 @@ int srd_session_feed(uint64_t start_samplenum, uint8_t *inbuf, uint64_t inbuflen
 }
 
 
+/* This is the backend function to python sigrokdecode.add() call. */
 int pd_add(struct srd_decoder_instance *di, int output_type,
 		char *proto_id)
 {
 	struct srd_pd_output *pdo;
 
+	srd_dbg("srd: instance %s creating new output type %d for %s",
+			di->instance_id, output_type, proto_id);
+
 	if (!(pdo = g_try_malloc(sizeof(struct srd_pd_output))))
 		return -1;
 
@@ -618,6 +650,8 @@ int srd_register_callback(int output_type, void *cb)
 {
 	struct srd_pd_callback *pd_cb;
 
+	srd_dbg("srd: registering new callback for output type %d", output_type);
+
 	if (!(pd_cb = g_try_malloc(sizeof(struct srd_pd_callback))))
 		return SRD_ERR_MALLOC;
 
diff --git a/decoder.c b/decoder.c
index d0e5734..a5c5e53 100644
--- a/decoder.c
+++ b/decoder.c
@@ -137,12 +137,12 @@ int srd_load_decoder(const char *name, struct srd_decoder **dec)
 	int alen, ret, i;
 	char **ann;
 
-	py_basedec = py_method = py_attr = NULL;
+	srd_dbg("srd: loading module '%s'", name);
 
-	srd_dbg("decoder: %s: loading module '%s'", __func__, name);
+	py_basedec = py_method = py_attr = NULL;
 
 	if (!(d = g_try_malloc0(sizeof(struct srd_decoder)))) {
-		srd_err("decoder: %s: d malloc failed", __func__);
+		srd_dbg("srd: Failed to malloc struct srd_decoder");
 		ret = SRD_ERR_MALLOC;
 		goto err_out;
 	}
@@ -152,7 +152,7 @@ int srd_load_decoder(const char *name, struct srd_decoder **dec)
 	/* Import the Python module. */
 	if (!(d->py_mod = PyImport_ImportModule(name))) {
 		/* TODO: Report exception message/traceback to err/dbg. */
-		srd_warn("decoder: %s: import of '%s' failed", __func__, name);
+		srd_warn("srd: import of '%s' failed.", name);
 		PyErr_Print();
 		PyErr_Clear();
 		goto err_out;
@@ -163,18 +163,18 @@ int srd_load_decoder(const char *name, struct srd_decoder **dec)
 		/* This generated an AttributeError exception. */
 		PyErr_Print();
 		PyErr_Clear();
-		srd_err("Decoder class not found in protocol decoder %s", name);
+		srd_err("Decoder class not found in protocol decoder %s.", name);
 		goto err_out;
 	}
 
 	if (!(py_basedec = PyObject_GetAttrString(mod_sigrokdecode, "Decoder"))) {
-		srd_dbg("sigrokdecode module not loaded");
+		srd_dbg("srd: sigrokdecode module not loaded");
 		goto err_out;
 	}
 
 	if (!PyObject_IsSubclass(d->py_dec, py_basedec)) {
 		srd_err("Decoder class in protocol decoder module %s is not "
-				"a subclass of sigrokdecode.Decoder", name);
+				"a subclass of sigrokdecode.Decoder.", name);
 		goto err_out;
 	}
 	Py_DecRef(py_basedec);
@@ -187,7 +187,7 @@ int srd_load_decoder(const char *name, struct srd_decoder **dec)
 	}
 	py_method = PyObject_GetAttrString(d->py_dec, "start");
 	if (!PyFunction_Check(py_method)) {
-		srd_err("Protocol decoder %s Decoder class attribute 'start'"
+		srd_err("Protocol decoder %s Decoder class attribute 'start' "
 				"is not a method.", name);
 		goto err_out;
 	}
@@ -251,15 +251,15 @@ int srd_load_decoder(const char *name, struct srd_decoder **dec)
 	if (PyObject_HasAttrString(d->py_dec, "annotations")) {
 		py_annlist = PyObject_GetAttrString(d->py_dec, "annotations");
 		if (!PyList_Check(py_annlist)) {
-			srd_err("Protocol decoder module %s annotations should be a list", name);
+			srd_err("Protocol decoder module %s annotations should be a list.", name);
 			goto err_out;
 		}
 		alen = PyList_Size(py_annlist);
 		for (i = 0; i < alen; i++) {
 			py_ann = PyList_GetItem(py_annlist, i);
 			if (!PyList_Check(py_ann) || PyList_Size(py_ann) != 2) {
-				srd_err("Protocol decoder module %s annotation %d should be a list with two elements",
-						name, i+1);
+				srd_err("Protocol decoder module %s annotation %d should "
+						"be a list with two elements.", name, i+1);
 				goto err_out;
 			}
 
diff --git a/log.c b/log.c
index af4196c..6b9a20d 100644
--- a/log.c
+++ b/log.c
@@ -39,14 +39,13 @@ static int srd_loglevel = SRD_LOG_WARN; /* Show errors+warnings per default. */
 int srd_set_loglevel(int loglevel)
 {
 	if (loglevel < SRD_LOG_NONE || loglevel > SRD_LOG_SPEW) {
-		srd_err("log: %s: invalid loglevel %d", __func__, loglevel);
+		srd_err("Invalid loglevel %d.", loglevel);
 		return SRD_ERR_ARG;
 	}
 
 	srd_loglevel = loglevel;
 
-	srd_dbg("log: %s: libsigrokdecode loglevel set to %d",
-		__func__, loglevel);
+	srd_dbg("srd: loglevel set to %d", loglevel);
 
 	return SRD_OK;
 }
diff --git a/type_decoder.c b/type_decoder.c
index e1e6796..ab5182f 100644
--- a/type_decoder.c
+++ b/type_decoder.c
@@ -31,15 +31,15 @@ static int convert_pyobj(struct srd_decoder_instance *di, PyObject *obj,
 
 	/* Should be a list of [annotation format, [string, ...]] */
 	if (!PyList_Check(obj) && !PyTuple_Check(obj)) {
-		srd_err("Protocol decoder %s submitted %s instead of list",
+		srd_err("Protocol decoder %s submitted %s instead of list.",
 				di->decoder->name, obj->ob_type->tp_name);
 		return SRD_ERR_PYTHON;
 	}
 
 	/* Should have 2 elements... */
 	if (PyList_Size(obj) != 2) {
-		srd_err("Protocol decoder %s submitted annotation list with %d elements instead of 2",
-				di->decoder->name, PyList_Size(obj));
+		srd_err("Protocol decoder %s submitted annotation list with %d elements "
+				"instead of 2", di->decoder->name, PyList_Size(obj));
 		return SRD_ERR_PYTHON;
 	}
 
@@ -47,15 +47,15 @@ static int convert_pyobj(struct srd_decoder_instance *di, PyObject *obj,
 	 * registered annotation format. */
 	py_tmp = PyList_GetItem(obj, 0);
 	if (!PyLong_Check(py_tmp)) {
-		srd_err("Protocol decoder %s submitted annotation list, but first element was not an integer",
-				di->decoder->name);
+		srd_err("Protocol decoder %s submitted annotation list, but first "
+				"element was not an integer.", di->decoder->name);
 		return SRD_ERR_PYTHON;
 	}
 
 	ann_id = PyLong_AsLong(py_tmp);
 	if (!(pdo = g_slist_nth_data(di->decoder->annotations, ann_id))) {
-		srd_err("Protocol decoder %s submitted data to non-existent annotation format %d",
-				di->decoder->name, ann_id);
+		srd_err("Protocol decoder %s submitted data to unregistered "
+				"annotation format %d.", di->decoder->name, ann_id);
 		return SRD_ERR_PYTHON;
 	}
 	*ann_format = ann_id;
@@ -63,13 +63,13 @@ static int convert_pyobj(struct srd_decoder_instance *di, PyObject *obj,
 	/* Second element must be a list */
 	py_tmp = PyList_GetItem(obj, 1);
 	if (!PyList_Check(py_tmp)) {
-		srd_err("Protocol decoder %s submitted annotation list, but second element was not a list",
-				di->decoder->name);
+		srd_err("Protocol decoder %s submitted annotation list, but "
+				"second element was not a list.", di->decoder->name);
 		return SRD_ERR_PYTHON;
 	}
 	if (py_strlist_to_char(py_tmp, ann) != SRD_OK) {
-		srd_err("Protocol decoder %s submitted annotation list, but second element was malformed",
-				di->decoder->name);
+		srd_err("Protocol decoder %s submitted annotation list, but "
+				"second element was malformed.", di->decoder->name);
 		return SRD_ERR_PYTHON;
 	}
 
@@ -94,7 +94,7 @@ static PyObject *Decoder_put(PyObject *self, PyObject *args)
 		return NULL;
 
 	if (!(l = g_slist_nth(di->pd_output, output_id))) {
-		srd_err("Protocol decoder %s submitted invalid output ID %d",
+		srd_err("Protocol decoder %s submitted invalid output ID %d.",
 				di->decoder->name, output_id);
 		return NULL;
 	}
@@ -133,10 +133,10 @@ static PyObject *Decoder_put(PyObject *self, PyObject *args)
 		}
 		break;
 	case SRD_OUTPUT_BINARY:
-		srd_err("SRD_OUTPUT_BINARY not yet supported");
+		srd_err("SRD_OUTPUT_BINARY not yet supported.");
 		break;
 	default:
-		srd_err("Protocol decoder %s submitted invalid output type %d",
+		srd_err("Protocol decoder %s submitted invalid output type %d.",
 				di->decoder->name, pdo->output_type);
 		break;
 	}
@@ -155,7 +155,7 @@ static PyObject *Decoder_add(PyObject *self, PyObject *args)
 	int output_type, pdo_id;
 
 	if (!(di = get_di_by_decobject(self))) {
-		srd_err("%s():%d decoder instance not found", __func__, __LINE__);
+		srd_dbg("srd: %s():%d decoder instance not found", __func__, __LINE__);
 		PyErr_SetString(PyExc_Exception, "decoder instance not found");
 		return NULL;
 	}
diff --git a/util.c b/util.c
index c65cbfd..75dd83e 100644
--- a/util.c
+++ b/util.c
@@ -40,7 +40,8 @@ int py_attr_as_str(PyObject *py_obj, const char *attr, char **outstr)
 	int ret;
 
 	if (!PyObject_HasAttrString(py_obj, attr)) {
-		srd_dbg("object has no attribute '%s'", attr);
+		srd_dbg("srd: %s object has no attribute '%s'.",
+				Py_TYPE(py_obj)->tp_name, attr);
 		return SRD_ERR_PYTHON;
 	}
 
@@ -51,8 +52,8 @@ int py_attr_as_str(PyObject *py_obj, const char *attr, char **outstr)
 	}
 
 	if (!PyUnicode_Check(py_str)) {
-		srd_err("%s attribute should be a string, but is a %s.",
-				attr, py_str->ob_type->tp_name);
+		srd_dbg("srd: %s attribute should be a string, but is a %s.",
+				attr, Py_TYPE(py_str)->tp_name);
 		Py_DecRef(py_str);
 		return SRD_ERR_PYTHON;
 	}
@@ -81,18 +82,18 @@ int py_dictitem_as_str(PyObject *py_obj, const char *key, char **outstr)
 	int ret;
 
 	if (!PyDict_Check(py_obj)) {
-		srd_err("Object is not a dictionary.");
+		srd_dbg("srd: Object is a %s, not a dictionary.", Py_TYPE(py_obj)->tp_name);
 		return SRD_ERR_PYTHON;
 	}
 
 	if (!(py_value = PyDict_GetItemString(py_obj, key))) {
-		srd_err("Dictionary has no attribute '%s'", key);
+		srd_dbg("srd: Dictionary has no attribute '%s'.", key);
 		return SRD_ERR_PYTHON;
 	}
 
 	if (!PyUnicode_Check(py_value)) {
-		srd_err("Dictionary value should be a string, but is a %s.",
-				key, py_value->ob_type->tp_name);
+		srd_dbg("srd: Dictionary value for %s should be a string, but is a %s.",
+				key, Py_TYPE(py_value)->tp_name);
 		return SRD_ERR_PYTHON;
 	}
 
@@ -123,7 +124,7 @@ int py_str_as_str(PyObject *py_str, char **outstr)
 	ret = SRD_OK;
 
 	if (!PyUnicode_Check(py_str)) {
-		srd_dbg("not a string object");
+		srd_dbg("srd: object is a %s, not a string object", Py_TYPE(py_str)->tp_name);
 		ret = SRD_ERR_PYTHON;
 		goto err_out;
 	}
@@ -138,7 +139,7 @@ int py_str_as_str(PyObject *py_str, char **outstr)
 	}
 
 	if (!(*outstr = g_strdup(str))) {
-		srd_dbg("malloc failed");
+		srd_dbg("srd: malloc failed");
 		ret = SRD_ERR_MALLOC;
 		goto err_out;
 	}
@@ -148,7 +149,7 @@ err_out:
 		Py_XDECREF(py_encstr);
 
 	if (PyErr_Occurred()) {
-		srd_dbg("string conversion failed");
+		srd_dbg("srd: string conversion failed");
 		/* TODO: dump exception to srd_dbg */
 		PyErr_Clear();
 	}