Logging: use for Python API

Adds categories "bpy.context" & "bpy.rna"

7 files changed, 115 insertions, 36 deletions

diff --git a/source/blender/python/BPY_extern_clog.h b/source/blender/python/BPY_extern_clog.h
new file mode 100644
index 00000000000..fbe7139ba1b
--- /dev/null
+++ b/source/blender/python/BPY_extern_clog.h
@@ -0,0 +1,35 @@
+/*
+ * ***** BEGIN GPL LICENSE BLOCK *****
+ *
+ * This program is free software; you can redistribute it and/or
+ * modify it under the terms of the GNU General Public License
+ * as published by the Free Software Foundation; either version 2
+ * of the License, or (at your option) any later version.
+ *
+ * This program is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+ * GNU General Public License for more details.
+ *
+ * You should have received a copy of the GNU General Public License
+ * along with this program; if not, write to the Free Software Foundation,
+ * Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA.
+ *
+ * ***** END GPL LICENSE BLOCK *****
+ */
+
+/** \file BPY_extern_clog.h
+ *  \ingroup python
+ *
+ * Logging defines.
+ */
+
+#ifndef __BPY_EXTERN_CLOG_H__
+#define __BPY_EXTERN_CLOG_H__
+
+
+/* bpy_interface.c */
+extern struct CLG_LogRef *BPY_LOG_RNA;
+extern struct CLG_LogRef *BPY_LOG_CONTEXT;
+
+#endif  /* __BPY_EXTERN_CLOG_H__ */
diff --git a/source/blender/python/generic/py_capi_utils.c b/source/blender/python/generic/py_capi_utils.c
index 36609c6f29b..62ef1b773c7 100644
--- a/source/blender/python/generic/py_capi_utils.c
+++ b/source/blender/python/generic/py_capi_utils.c
@@ -38,6 +38,8 @@
 
 #include "python_utildefines.h"
 
+#include "BLI_string.h"
+
 #ifndef MATH_STANDALONE
 /* only for BLI_strncpy_wchar_from_utf8, should replace with py funcs but too late in release now */
 #include "BLI_string_utf8.h"
@@ -225,22 +227,49 @@ int PyC_ParseBool(PyObject *o, void *p)
 /* for debugging */
 void PyC_ObSpit(const char *name, PyObject *var)
 {
+	const char *null_str = "<null>";
 	fprintf(stderr, "<%s> : ", name);
 	if (var == NULL) {
-		fprintf(stderr, "<NIL>");
+		fprintf(stderr, "%s\n", null_str);
 	}
 	else {
 		PyObject_Print(var, stderr, 0);
-		fprintf(stderr, " ref:%d ", (int)var->ob_refcnt);
-		fprintf(stderr, " ptr:%p", (void *)var);
-		
-		fprintf(stderr, " type:");
-		if (Py_TYPE(var))
-			fprintf(stderr, "%s", Py_TYPE(var)->tp_name);
-		else
-			fprintf(stderr, "<NIL>");
+		const PyTypeObject *type = Py_TYPE(var);
+		fprintf(stderr,
+		        " ref:%d, ptr:%p, type: %s\n",
+		        (int)var->ob_refcnt, (void *)var, type ? type->tp_name : null_str);
+	}
+}
+
+/**
+ * A version of #PyC_ObSpit that writes into a string (and doesn't take a name argument).
+ * Use for logging.
+ */
+void PyC_ObSpitStr(char *result, size_t result_len, PyObject *var)
+{
+	/* No name, creator of string can manage that. */
+	const char *null_str = "<null>";
+	if (var == NULL) {
+		BLI_snprintf(result, result_len, "%s", null_str);
+	}
+	else {
+		const PyTypeObject *type = Py_TYPE(var);
+		PyObject *var_str = PyObject_Repr(var);
+		if (var_str == NULL) {
+			/* We could print error here, but this may be used for generating errors - so don't for now. */
+			PyErr_Clear();
+		}
+		BLI_snprintf(
+		        result, result_len,
+		        " ref=%d, ptr=%p, type=%s, value=%.200s",
+		        (int)var->ob_refcnt,
+		        (void *)var,
+		        type ? type->tp_name : null_str,
+		        var_str ? _PyUnicode_AsString(var_str) : "<error>");
+		if (var_str != NULL) {
+			Py_DECREF(var_str);
+		}
 	}
-	fprintf(stderr, "\n");
 }
 
 void PyC_LineSpit(void)
diff --git a/source/blender/python/generic/py_capi_utils.h b/source/blender/python/generic/py_capi_utils.h
index 25c88799027..e4d6d3fe557 100644
--- a/source/blender/python/generic/py_capi_utils.h
+++ b/source/blender/python/generic/py_capi_utils.h
@@ -31,6 +31,7 @@
 #include "BLI_utildefines_variadic.h"
 
 void			PyC_ObSpit(const char *name, PyObject *var);
+void			PyC_ObSpitStr(char *result, size_t result_len, PyObject *var);
 void			PyC_LineSpit(void);
 void			PyC_StackSpit(void);
 PyObject *		PyC_ExceptionBuffer(void);
diff --git a/source/blender/python/intern/CMakeLists.txt b/source/blender/python/intern/CMakeLists.txt
index 2b6dc54dad4..ae16bd4a145 100644
--- a/source/blender/python/intern/CMakeLists.txt
+++ b/source/blender/python/intern/CMakeLists.txt
@@ -23,7 +23,7 @@
 #
 # ***** END GPL LICENSE BLOCK *****
 
-set(INC 
+set(INC
 	..
 	../../blenkernel
 	../../blenlib
@@ -35,9 +35,10 @@ set(INC
 	../../makesdna
 	../../makesrna
 	../../windowmanager
-	../../../../intern/cycles/blender
-	../../../../intern/opencolorio
+	../../../../intern/clog
 	../../../../intern/guardedalloc
+	../../../../intern/opencolorio
+	../../../../intern/cycles/blender
 )
 
 set(INC_SYS
@@ -111,6 +112,7 @@ set(SRC
 	bpy_utils_units.h
 	gpu.h
 	../BPY_extern.h
+	../BPY_extern_clog.h
 )
 
 # only to check if buildinfo is available
diff --git a/source/blender/python/intern/bpy_interface.c b/source/blender/python/intern/bpy_interface.c
index ae8e35ae3fc..99f87c61c5a 100644
--- a/source/blender/python/intern/bpy_interface.c
+++ b/source/blender/python/intern/bpy_interface.c
@@ -33,6 +33,8 @@
 
 #include "MEM_guardedalloc.h"
 
+#include "CLG_log.h"
+
 #include "BLI_utildefines.h"
 #include "BLI_path_util.h"
 #include "BLI_fileops.h"
@@ -75,6 +77,9 @@
 #include "../bmesh/bmesh_py_api.h"
 #include "../mathutils/mathutils.h"
 
+/* Logging types to use anywhere in the Python modules. */
+CLG_LOGREF_DECLARE_GLOBAL(BPY_LOG_CONTEXT, "bpy.context");
+CLG_LOGREF_DECLARE_GLOBAL(BPY_LOG_RNA, "bpy.rna");
 
 /* for internal use, when starting and ending python scripts */
 
@@ -800,8 +805,9 @@ int BPY_context_member_get(bContext *C, const char *member, bContextDataResult *
 					CTX_data_list_add(result, ptr->id.data, ptr->type, ptr->data);
 				}
 				else {
-					printf("PyContext: '%s' list item not a valid type in sequece type '%s'\n",
-					       member, Py_TYPE(item)->tp_name);
+					CLOG_INFO(BPY_LOG_CONTEXT, 1,
+					          "'%s' list item not a valid type in sequence type '%s'",
+					          member, Py_TYPE(item)->tp_name);
 				}
 
 			}
@@ -813,16 +819,14 @@ int BPY_context_member_get(bContext *C, const char *member, bContextDataResult *
 
 	if (done == false) {
 		if (item) {
-			printf("PyContext '%s' not a valid type\n", member);
+			CLOG_INFO(BPY_LOG_CONTEXT, 1, "'%s' not a valid type", member);
 		}
 		else {
-			printf("PyContext '%s' not found\n", member);
+			CLOG_INFO(BPY_LOG_CONTEXT, 1, "'%s' not found\n", member);
 		}
 	}
 	else {
-		if (G.debug & G_DEBUG_PYTHON) {
-			printf("PyContext '%s' found\n", member);
-		}
+		CLOG_INFO(BPY_LOG_CONTEXT, 2, "'%s' found", member);
 	}
 
 	if (use_gil)
diff --git a/source/blender/python/intern/bpy_rna.c b/source/blender/python/intern/bpy_rna.c
index 87260d6e786..27eb1431295 100644
--- a/source/blender/python/intern/bpy_rna.c
+++ b/source/blender/python/intern/bpy_rna.c
@@ -45,6 +45,7 @@
 #include "BLI_utildefines.h"
 
 #include "BPY_extern.h"
+#include "BPY_extern_clog.h"
 
 #include "bpy_rna.h"
 #include "bpy_rna_anim.h"
@@ -61,6 +62,8 @@
 #include "RNA_define.h" /* RNA_def_property_free_identifier */
 #include "RNA_access.h"
 
+#include "CLG_log.h"
+
 #include "MEM_guardedalloc.h"
 
 #include "BKE_main.h"
@@ -1418,10 +1421,11 @@ static PyObject *pyrna_enum_to_py(PointerRNA *ptr, PropertyRNA *prop, int val)
 					const char *ptr_name = RNA_struct_name_get_alloc(ptr, NULL, 0, NULL);
 
 					/* prefer not fail silently in case of api errors, maybe disable it later */
-					printf("RNA Warning: Current value \"%d\" "
-					       "matches no enum in '%s', '%s', '%s'\n",
-					       val, RNA_struct_identifier(ptr->type),
-					       ptr_name, RNA_property_identifier(prop));
+					CLOG_WARN(BPY_LOG_RNA,
+					          "Current value \"%d\" "
+					          "matches no enum in '%s', '%s', '%s'\n",
+					          val, RNA_struct_identifier(ptr->type),
+					          ptr_name, RNA_property_identifier(prop));
 
 #if 0				/* gives python decoding errors while generating docs :( */
 					char error_str[256];
@@ -6596,7 +6600,7 @@ static PyObject *pyrna_srna_ExternalType(StructRNA *srna)
 		if (bpy_types == NULL) {
 			PyErr_Print();
 			PyErr_Clear();
-			fprintf(stderr, "%s: failed to find 'bpy_types' module\n", __func__);
+			CLOG_ERROR(BPY_LOG_RNA, "failed to find 'bpy_types' module\n");
 			return NULL;
 		}
 		bpy_types_dict = PyModule_GetDict(bpy_types);  /* borrow */
@@ -6614,20 +6618,22 @@ static PyObject *pyrna_srna_ExternalType(StructRNA *srna)
 		PyObject *tp_slots = PyDict_GetItem(((PyTypeObject *)newclass)->tp_dict, bpy_intern_str___slots__);
 
 		if (tp_slots == NULL) {
-			fprintf(stderr, "%s: expected class '%s' to have __slots__ defined\n\nSee bpy_types.py\n", __func__, idname);
+			CLOG_ERROR(BPY_LOG_RNA, "expected class '%s' to have __slots__ defined, see bpy_types.py\n", idname);
 			newclass = NULL;
 		}
 		else if (PyTuple_GET_SIZE(tp_bases)) {
 			PyObject *base = PyTuple_GET_ITEM(tp_bases, 0);
 
 			if (base_compare != base) {
-				fprintf(stderr, "%s: incorrect subclassing of SRNA '%s'\nSee bpy_types.py\n", __func__, idname);
-				PyC_ObSpit("Expected! ", base_compare);
+				char pyob_info[256];
+				PyC_ObSpitStr(pyob_info, sizeof(pyob_info), base_compare);
+				CLOG_ERROR(BPY_LOG_RNA,
+				           "incorrect subclassing of SRNA '%s', expected '%s', see bpy_types.py\n",
+				           idname, pyob_info);
 				newclass = NULL;
 			}
 			else {
-				if (G.debug & G_DEBUG_PYTHON)
-					fprintf(stderr, "SRNA Subclassed: '%s'\n", idname);
+				CLOG_INFO(BPY_LOG_RNA, 2, "SRNA sub-classed: '%s'\n", idname);
 			}
 		}
 	}
@@ -6725,7 +6731,7 @@ static PyObject *pyrna_srna_Subtype(StructRNA *srna)
 		}
 		else {
 			/* this should not happen */
-			printf("%s: error registering '%s'\n", __func__, idname);
+			CLOG_ERROR(BPY_LOG_RNA, "error registering '%s'", idname);
 			PyErr_Print();
 			PyErr_Clear();
 		}
@@ -6791,7 +6797,7 @@ PyObject *pyrna_struct_CreatePyObject(PointerRNA *ptr)
 			Py_DECREF(tp); /* srna owns, cant hold a ref */
 		}
 		else {
-			fprintf(stderr, "%s: could not make type\n", __func__);
+			CLOG_WARN(BPY_LOG_RNA, "could not make type '%s'", RNA_struct_identifier(ptr->type));
 			pyrna = (BPy_StructRNA *) PyObject_GC_New(BPy_StructRNA, &pyrna_struct_Type);
 #ifdef USE_WEAKREFS
 			pyrna->in_weakreflist = NULL;
@@ -7597,8 +7603,7 @@ static int bpy_class_call(bContext *C, PointerRNA *ptr, FunctionRNA *func, Param
 	py_class = RNA_struct_py_type_get(ptr->type);
 	/* rare case. can happen when registering subclasses */
 	if (py_class == NULL) {
-		fprintf(stderr, "%s: unable to get python class for rna struct '%.200s'\n",
-		        __func__, RNA_struct_identifier(ptr->type));
+		CLOG_WARN(BPY_LOG_RNA, "unable to get Python class for rna struct '%.200s'\n", RNA_struct_identifier(ptr->type));
 		return -1;
 	}
 
diff --git a/source/blender/python/intern/bpy_rna_array.c b/source/blender/python/intern/bpy_rna_array.c
index e0ca3634261..ed9d1e9c0e5 100644
--- a/source/blender/python/intern/bpy_rna_array.c
+++ b/source/blender/python/intern/bpy_rna_array.c
@@ -28,6 +28,8 @@
 
 #include <Python.h>
 
+#include "CLG_log.h"
+
 #include "BLI_utildefines.h"
 
 #include "RNA_types.h"
@@ -39,6 +41,8 @@
 
 #include "RNA_access.h"
 
+#include "BPY_extern_clog.h"
+
 #include "../generic/py_capi_utils.h"
 
 #define USE_MATHUTILS
@@ -785,8 +789,7 @@ PyObject *pyrna_py_from_array_index(BPy_PropertyArrayRNA *self, PointerRNA *ptr,
 	len = RNA_property_multi_array_length(ptr, prop, arraydim);
 	if (index >= len || index < 0) {
 		/* this shouldn't happen because higher level funcs must check for invalid index */
-		if (G.debug & G_DEBUG_PYTHON)
-			printf("%s: invalid index %d for array with length=%d\n", __func__, index, len);
+		CLOG_WARN(BPY_LOG_RNA, "invalid index %d for array with length=%d", index, len);
 
 		PyErr_SetString(PyExc_IndexError, "out of range");
 		return NULL;