C Logging: use instead of printf for messages

- See `--log` help message for usage.
- Supports enabling categories.
- Color severity.
- Optionally logs to a file.
- Currently use to replace printf calls in wm module.

See D3120 for details.

15 files changed, 208 insertions, 81 deletions

diff --git a/source/blender/blenkernel/BKE_global.h b/source/blender/blenkernel/BKE_global.h
index 832b4164613..ce8de456697 100644
--- a/source/blender/blenkernel/BKE_global.h
+++ b/source/blender/blenkernel/BKE_global.h
@@ -80,6 +80,13 @@ typedef struct Global {
 	 * however this is now only used for runtime options */
 	int f;
 
+	struct {
+		/* Logging vars (different loggers may use). */
+		int level;
+		/* FILE handle or use stderr (we own this so close when done). */
+		void *file;
+	} log;
+
 	/* debug flag, G_DEBUG, G_DEBUG_PYTHON & friends, set python or command line args */
 	int debug;
 
diff --git a/source/blender/blenkernel/CMakeLists.txt b/source/blender/blenkernel/CMakeLists.txt
index 231810aee31..25954f277b8 100644
--- a/source/blender/blenkernel/CMakeLists.txt
+++ b/source/blender/blenkernel/CMakeLists.txt
@@ -48,6 +48,7 @@ set(INC
 	../../../intern/mikktspace
 	../../../intern/smoke/extern
 	../../../intern/atomic
+	../../../intern/clog
 	../../../intern/libmv
 	../../../extern/curve_fit_nd
 )
diff --git a/source/blender/blenkernel/intern/blender.c b/source/blender/blenkernel/intern/blender.c
index a27f075a346..55b2d5b9c0d 100644
--- a/source/blender/blenkernel/intern/blender.c
+++ b/source/blender/blenkernel/intern/blender.c
@@ -83,6 +83,10 @@ void BKE_blender_free(void)
 	BKE_main_free(G.main);
 	G.main = NULL;
 
+	if (G.log.file != NULL) {
+		fclose(G.log.file);
+	}
+
 	BKE_spacetypes_free();      /* after free main, it uses space callbacks */
 	
 	IMB_exit();
@@ -130,6 +134,8 @@ void BKE_blender_globals_init(void)
 #else
 	G.f &= ~G_SCRIPT_AUTOEXEC;
 #endif
+
+	G.log.level = 1;
 }
 
 void BKE_blender_globals_clear(void)
diff --git a/source/blender/depsgraph/intern/eval/deg_eval.cc b/source/blender/depsgraph/intern/eval/deg_eval.cc
index fc71b5ccb7b..92518ba73e4 100644
--- a/source/blender/depsgraph/intern/eval/deg_eval.cc
+++ b/source/blender/depsgraph/intern/eval/deg_eval.cc
@@ -252,9 +252,6 @@ void deg_evaluate_on_refresh(EvaluationContext *eval_ctx,
                              Depsgraph *graph,
                              const unsigned int layers)
 {
-	/* Set time for the current graph evaluation context. */
-	TimeSourceDepsNode *time_src = graph->find_time_source();
-	eval_ctx->ctime = time_src->cfra;
 	/* Nothing to update, early out. */
 	if (BLI_gset_len(graph->entry_tags) == 0) {
 		return;
@@ -265,6 +262,9 @@ void deg_evaluate_on_refresh(EvaluationContext *eval_ctx,
 	                 graph->layers);
 	const bool do_time_debug = ((G.debug & G_DEBUG_DEPSGRAPH_TIME) != 0);
 	const double start_time = do_time_debug ? PIL_check_seconds_timer() : 0;
+	/* Set time for the current graph evaluation context. */
+	TimeSourceDepsNode *time_src = graph->find_time_source();
+	eval_ctx->ctime = time_src->cfra;
 	/* Set up evaluation context for depsgraph itself. */
 	DepsgraphEvalState state;
 	state.eval_ctx = eval_ctx;
diff --git a/source/blender/editors/util/CMakeLists.txt b/source/blender/editors/util/CMakeLists.txt
index c0b30f93939..a8225bb64d1 100644
--- a/source/blender/editors/util/CMakeLists.txt
+++ b/source/blender/editors/util/CMakeLists.txt
@@ -30,6 +30,7 @@ set(INC
 	../../makesrna
 	../../windowmanager
 	../../../../intern/guardedalloc
+	../../../../intern/clog
 	../../../../intern/glew-mx
 )
 
diff --git a/source/blender/python/mathutils/mathutils_Euler.c b/source/blender/python/mathutils/mathutils_Euler.c
index 026384743bd..9492b6d67f3 100644
--- a/source/blender/python/mathutils/mathutils_Euler.c
+++ b/source/blender/python/mathutils/mathutils_Euler.c
@@ -689,8 +689,6 @@ PyDoc_STRVAR(euler_doc,
 "\n"
 "   This object gives access to Eulers in Blender.\n"
 "\n"
-"   .. seealso:: `Euler angles <https://en.wikipedia.org/wiki/Euler_angles>`__ on Wikipedia.\n"
-"\n"
 "   :param angles: Three angles, in radians.\n"
 "   :type angles: 3d vector\n"
 "   :param order: Optional order of the angles, a permutation of ``XYZ``.\n"
diff --git a/source/blender/windowmanager/CMakeLists.txt b/source/blender/windowmanager/CMakeLists.txt
index c9278822b9a..50f99251489 100644
--- a/source/blender/windowmanager/CMakeLists.txt
+++ b/source/blender/windowmanager/CMakeLists.txt
@@ -39,6 +39,7 @@ set(INC
 	../nodes
 	../render/extern/include
 	../../gameengine/BlenderRoutines
+	../../../intern/clog
 	../../../intern/ghost
 	../../../intern/guardedalloc
 	../../../intern/glew-mx
diff --git a/source/blender/windowmanager/WM_types.h b/source/blender/windowmanager/WM_types.h
index 8fca0ce959e..8c94c2ff043 100644
--- a/source/blender/windowmanager/WM_types.h
+++ b/source/blender/windowmanager/WM_types.h
@@ -719,6 +719,14 @@ typedef struct RecentFile {
 	char *filepath;
 } RecentFile;
 
+/* Logging */
+struct CLG_LogRef;
+/* wm_init_exit.c */
+extern struct CLG_LogRef *WM_LOG_OPERATORS;
+extern struct CLG_LogRef *WM_LOG_HANDLERS;
+extern struct CLG_LogRef *WM_LOG_EVENTS;
+extern struct CLG_LogRef *WM_LOG_KEYMAPS;
+
 
 #ifdef __cplusplus
 }
diff --git a/source/blender/windowmanager/intern/wm_event_system.c b/source/blender/windowmanager/intern/wm_event_system.c
index b18e9f050c2..b2df53321c0 100644
--- a/source/blender/windowmanager/intern/wm_event_system.c
+++ b/source/blender/windowmanager/intern/wm_event_system.c
@@ -43,6 +43,8 @@
 
 #include "MEM_guardedalloc.h"
 
+#include "CLG_log.h"
+
 #include "GHOST_C-api.h"
 
 #include "BLI_blenlib.h"
@@ -353,13 +355,11 @@ void wm_event_do_notifiers(bContext *C)
 
 
 						ED_screen_set(C, note->reference);  // XXX hrms, think this over!
-						if (G.debug & G_DEBUG_EVENTS)
-							printf("%s: screen set %p\n", __func__, note->reference);
+						CLOG_INFO(WM_LOG_EVENTS, 1, "screen set %p", note->reference);
 					}
 					else if (note->data == ND_SCREENDELETE) {
 						ED_screen_delete(C, note->reference);   // XXX hrms, think this over!
-						if (G.debug & G_DEBUG_EVENTS)
-							printf("%s: screen delete %p\n", __func__, note->reference);
+						CLOG_INFO(WM_LOG_EVENTS, 1, "screen delete %p", note->reference);
 					}
 				}
 			}
@@ -545,14 +545,6 @@ int WM_operator_poll_context(bContext *C, wmOperatorType *ot, short context)
 	return wm_operator_call_internal(C, ot, NULL, NULL, context, true);
 }
 
-static void wm_operator_print(bContext *C, wmOperator *op)
-{
-	/* context is needed for enum function */
-	char *buf = WM_operator_pystring(C, op, false, true);
-	puts(buf);
-	MEM_freeN(buf);
-}
-
 /**
  * Sets the active region for this space from the context.
  *
@@ -711,12 +703,9 @@ static void wm_operator_reports(bContext *C, wmOperator *op, int retval, bool ca
 			CTX_wm_region_set(C, ar_prev);
 		}
 	}
-	
+
 	if (retval & OPERATOR_FINISHED) {
-		if (G.debug & G_DEBUG_WM) {
-			/* todo - this print may double up, might want to check more flags then the FINISHED */
-			wm_operator_print(C, op);
-		}
+		CLOG_STR_INFO_N(WM_LOG_OPERATORS, 1, WM_operator_pystring(C, op, false, true));
 
 		if (caller_owns_reports == false) {
 			BKE_reports_print(op->reports, RPT_DEBUG); /* print out reports to console. */
@@ -1041,9 +1030,7 @@ bool WM_operator_last_properties_init(wmOperator *op)
 		IDProperty *replaceprops = IDP_New(IDP_GROUP, &val, "wmOperatorProperties");
 		PropertyRNA *iterprop;
 
-		if (G.debug & G_DEBUG_WM) {
-			printf("%s: loading previous properties for '%s'\n", __func__, op->type->idname);
-		}
+		CLOG_INFO(WM_LOG_OPERATORS, 1, "loading previous properties for '%s'", op->type->idname);
 
 		iterprop = RNA_struct_iterator_property(op->type->srna);
 
@@ -1088,9 +1075,7 @@ bool WM_operator_last_properties_store(wmOperator *op)
 	}
 
 	if (op->properties) {
-		if (G.debug & G_DEBUG_WM) {
-			printf("%s: storing properties for '%s'\n", __func__, op->type->idname);
-		}
+		CLOG_INFO(WM_LOG_OPERATORS, 1, "storing properties for '%s'", op->type->idname);
 		op->type->last_properties = IDP_CopyProperty(op->properties);
 		return true;
 	}
@@ -1140,11 +1125,12 @@ static int wm_operator_invoke(
 			WM_operator_last_properties_init(op);
 		}
 
-		if ((G.debug & G_DEBUG_HANDLERS) && ((event == NULL) || (event->type != MOUSEMOVE))) {
-			printf("%s: handle evt %d win %d op %s\n",
-			       __func__, event ? event->type : 0, CTX_wm_screen(C)->subwinactive, ot->idname);
+		if ((event == NULL) || (event->type != MOUSEMOVE)) {
+			CLOG_INFO(WM_LOG_HANDLERS, 2,
+			          "handle evt %d win %d op %s",
+			          event ? event->type : 0, CTX_wm_screen(C)->subwinactive, ot->idname);
 		}
-		
+
 		if (op->type->invoke && event) {
 			wm_region_mouse_co(C, event);
 
@@ -1169,9 +1155,9 @@ static int wm_operator_invoke(
 		}
 		else {
 			/* debug, important to leave a while, should never happen */
-			printf("%s: invalid operator call '%s'\n", __func__, ot->idname);
+			CLOG_ERROR(WM_LOG_OPERATORS, "invalid operator call '%s'", op->idname);
 		}
-		
+
 		/* Note, if the report is given as an argument then assume the caller will deal with displaying them
 		 * currently python only uses this */
 		if (!(retval & OPERATOR_HANDLED) && (retval & (OPERATOR_FINISHED | OPERATOR_CANCELLED))) {
@@ -1446,8 +1432,10 @@ int WM_operator_call_py(
 		if (is_undo && op->type->flag & OPTYPE_UNDO && CTX_wm_manager(C) == wm)
 			wm->op_undo_depth--;
 	}
-	else
-		printf("error \"%s\" operator has no exec function, python cannot call it\n", op->type->name);
+	else {
+		CLOG_WARN(WM_LOG_OPERATORS, "\"%s\" operator has no exec function, Python cannot call it", op->type->name);
+	}
+
 #endif
 
 	/* not especially nice using undo depth here, its used so py never
@@ -1491,8 +1479,9 @@ static void wm_handler_op_context(bContext *C, wmEventHandler *handler, const wm
 			if (sa == NULL) {
 				/* when changing screen layouts with running modal handlers (like render display), this
 				 * is not an error to print */
-				if (handler->op == NULL)
-					printf("internal error: handler (%s) has invalid area\n", handler->op->type->idname);
+				if (handler->op == NULL) {
+					CLOG_ERROR(WM_LOG_HANDLERS, "internal error: handler (%s) has invalid area", handler->op->type->idname);
+				}
 			}
 			else {
 				ARegion *ar;
@@ -1805,10 +1794,9 @@ static int wm_handler_operator_call(bContext *C, ListBase *handlers, wmEventHand
 					//retval &= ~OPERATOR_PASS_THROUGH;
 				}
 			}
-			
 		}
 		else {
-			printf("%s: error '%s' missing modal\n", __func__, op->idname);
+			CLOG_ERROR(WM_LOG_HANDLERS, "missing modal '%s'", op->idname);
 		}
 	}
 	else {
@@ -2099,19 +2087,15 @@ static int wm_handlers_do_intern(bContext *C, wmEvent *event, ListBase *handlers
 							action |= wm_handler_operator_call(C, handlers, handler, event, kmi->ptr);
 							if (action & WM_HANDLER_BREAK) {
 								/* not always_pass here, it denotes removed handler */
-								
-								if (G.debug & (G_DEBUG_EVENTS | G_DEBUG_HANDLERS))
-									printf("%s:       handled! '%s'\n", __func__, kmi->idname);
-
+								CLOG_INFO(WM_LOG_HANDLERS, 2, "handled! '%s'", kmi->idname);
 								break;
 							}
 							else {
 								if (action & WM_HANDLER_HANDLED) {
-									if (G.debug & (G_DEBUG_EVENTS | G_DEBUG_HANDLERS))
-										printf("%s:       handled - and pass on! '%s'\n", __func__, kmi->idname);
+									CLOG_INFO(WM_LOG_HANDLERS, 2, "handled - and pass on! '%s'", kmi->idname);
 								}
 								else {
-									PRINT("%s:       un-handled '%s'\n", __func__, kmi->idname);
+									CLOG_INFO(WM_LOG_HANDLERS, 2, "un-handled '%s'", kmi->idname);
 								}
 							}
 						}
@@ -2237,10 +2221,8 @@ static int wm_handlers_do(bContext *C, wmEvent *event, ListBase *handlers)
 					{
 						event->val = KM_CLICK;
 
-						if (G.debug & (G_DEBUG_HANDLERS)) {
-							printf("%s: handling CLICK\n", __func__);
-						}
-
+						CLOG_INFO(WM_LOG_HANDLERS, 1, "handling CLICK");
+	
 						action |= wm_handlers_do_intern(C, event, handlers);
 
 						event->val = KM_RELEASE;
@@ -2461,13 +2443,14 @@ void wm_event_do_handlers(bContext *C)
 
 			if (G.debug & (G_DEBUG_HANDLERS | G_DEBUG_EVENTS) && !ELEM(event->type, MOUSEMOVE, INBETWEEN_MOUSEMOVE)) {
 				printf("\n%s: Handling event\n", __func__);
+
 				WM_event_print(event);
 			}
 
 			/* take care of pie event filter */
 			if (wm_event_pie_filter(win, event)) {
-				if (G.debug & (G_DEBUG_HANDLERS | G_DEBUG_EVENTS) && !ELEM(event->type, MOUSEMOVE, INBETWEEN_MOUSEMOVE)) {
-					printf("\n%s: event filtered due to pie button pressed\n", __func__);
+				if (!ELEM(event->type, MOUSEMOVE, INBETWEEN_MOUSEMOVE)) {
+					CLOG_INFO(WM_LOG_HANDLERS, 1, "event filtered due to pie button pressed");
 				}
 				BLI_remlink(&win->queue, event);
 				wm_event_free(event);
@@ -2751,7 +2734,7 @@ wmEventHandler *WM_event_add_keymap_handler(ListBase *handlers, wmKeyMap *keymap
 	wmEventHandler *handler;
 
 	if (!keymap) {
-		printf("%s: called with NULL keymap\n", __func__);
+		CLOG_WARN(WM_LOG_HANDLERS, "called with NULL keymap");
 		return NULL;
 	}
 
@@ -3372,8 +3355,7 @@ void wm_event_add_ghostevent(wmWindowManager *wm, wmWindow *win, int type, int U
 			
 			/* double click test */
 			if (wm_event_is_double_click(&event, evt)) {
-				if (G.debug & (G_DEBUG_HANDLERS | G_DEBUG_EVENTS))
-					printf("%s Send double click\n", __func__);
+				CLOG_INFO(WM_LOG_HANDLERS, 1, "Send double click");
 				event.val = KM_DBL_CLICK;
 			}
 			if (event.val == KM_PRESS) {
@@ -3427,7 +3409,7 @@ void wm_event_add_ghostevent(wmWindowManager *wm, wmWindow *win, int type, int U
 
 				/* ghost should do this already for key up */
 				if (event.utf8_buf[0]) {
-					printf("%s: ghost on your platform is misbehaving, utf8 events on key up!\n", __func__);
+					CLOG_ERROR(WM_LOG_EVENTS, "ghost on your platform is misbehaving, utf8 events on key up!");
 				}
 				event.utf8_buf[0] = '\0';
 			}
@@ -3440,8 +3422,9 @@ void wm_event_add_ghostevent(wmWindowManager *wm, wmWindow *win, int type, int U
 
 			if (event.utf8_buf[0]) {
 				if (BLI_str_utf8_size(event.utf8_buf) == -1) {
-					printf("%s: ghost detected an invalid unicode character '%d'!\n",
-					       __func__, (int)(unsigned char)event.utf8_buf[0]);
+					CLOG_ERROR(WM_LOG_EVENTS,
+					           "ghost detected an invalid unicode character '%d'",
+					           (int)(unsigned char)event.utf8_buf[0]);
 					event.utf8_buf[0] = '\0';
 				}
 			}
@@ -3490,8 +3473,7 @@ void wm_event_add_ghostevent(wmWindowManager *wm, wmWindow *win, int type, int U
 			/* double click test */
 			/* if previous event was same type, and previous was release, and now it presses... */
 			if (wm_event_is_double_click(&event, evt)) {
-				if (G.debug & (G_DEBUG_HANDLERS | G_DEBUG_EVENTS))
-					printf("%s Send double click\n", __func__);
+				CLOG_INFO(WM_LOG_HANDLERS, 1, "Send double click");
 				evt->val = event.val = KM_DBL_CLICK;
 			}
 			
@@ -3561,9 +3543,7 @@ void wm_event_add_ghostevent(wmWindowManager *wm, wmWindow *win, int type, int U
 			attach_ndof_data(&event, customdata);
 			wm_event_add(win, &event);
 
-			if (G.debug & (G_DEBUG_HANDLERS | G_DEBUG_EVENTS))
-				printf("%s sending NDOF_MOTION, prev = %d %d\n", __func__, event.x, event.y);
-
+			CLOG_INFO(WM_LOG_HANDLERS, 1, "sending NDOF_MOTION, prev = %d %d", event.x, event.y);
 			break;
 		}
 
diff --git a/source/blender/windowmanager/intern/wm_init_exit.c b/source/blender/windowmanager/intern/wm_init_exit.c
index 9b4868523dc..2743216ee07 100644
--- a/source/blender/windowmanager/intern/wm_init_exit.c
+++ b/source/blender/windowmanager/intern/wm_init_exit.c
@@ -40,6 +40,8 @@
 
 #include "MEM_guardedalloc.h"
 
+#include "CLG_log.h"
+
 #include "DNA_genfile.h"
 #include "DNA_scene_types.h"
 #include "DNA_userdef_types.h"
@@ -127,6 +129,11 @@
 #  include "BKE_subsurf.h"
 #endif
 
+CLG_LOGREF_DECLARE_GLOBAL(WM_LOG_OPERATORS, "wm.operator");
+CLG_LOGREF_DECLARE_GLOBAL(WM_LOG_HANDLERS, "wm.handler");
+CLG_LOGREF_DECLARE_GLOBAL(WM_LOG_EVENTS, "wm.event");
+CLG_LOGREF_DECLARE_GLOBAL(WM_LOG_KEYMAPS, "wm.keymap");
+
 static void wm_init_reports(bContext *C)
 {
 	ReportList *reports = CTX_wm_reports(C);
@@ -613,6 +620,8 @@ void WM_exit_ext(bContext *C, const bool do_python)
 	 * see also T50676. */
 	BKE_sound_exit();
 
+	CLG_exit();
+
 	BKE_blender_atexit();
 
 	if (MEM_get_memory_blocks_in_use() != 0) {
diff --git a/source/blender/windowmanager/intern/wm_keymap.c b/source/blender/windowmanager/intern/wm_keymap.c
index 45ed44d83d6..bcfc97a1e23 100644
--- a/source/blender/windowmanager/intern/wm_keymap.c
+++ b/source/blender/windowmanager/intern/wm_keymap.c
@@ -1,4 +1,5 @@
 /*
+ * 
  * ***** BEGIN GPL LICENSE BLOCK *****
  *
  * This program is free software; you can redistribute it and/or
@@ -39,6 +40,7 @@
 #include "DNA_windowmanager_types.h"
 
 #include "MEM_guardedalloc.h"
+#include "CLG_log.h"
 
 #include "BLI_blenlib.h"
 #include "BLI_utildefines.h"
@@ -886,11 +888,13 @@ wmKeyMapItem *WM_modalkeymap_find_propvalue(wmKeyMap *km, const int propvalue)
 void WM_modalkeymap_assign(wmKeyMap *km, const char *opname)
 {
 	wmOperatorType *ot = WM_operatortype_find(opname, 0);
-	
-	if (ot)
+
+	if (ot) {
 		ot->modalkeymap = km;
-	else
-		printf("error: modalkeymap_assign, unknown operator %s\n", opname);
+	}
+	else {
+		CLOG_ERROR(WM_LOG_KEYMAPS, "unknown operator '%s'", opname);
+	}
 }
 
 static void wm_user_modal_keymap_set_items(wmWindowManager *wm, wmKeyMap *km)
diff --git a/source/blender/windowmanager/intern/wm_operators.c b/source/blender/windowmanager/intern/wm_operators.c
index 814d8823817..b05b2596719 100644
--- a/source/blender/windowmanager/intern/wm_operators.c
+++ b/source/blender/windowmanager/intern/wm_operators.c
@@ -46,6 +46,8 @@
 
 #include "MEM_guardedalloc.h"
 
+#include "CLG_log.h"
+
 #include "DNA_ID.h"
 #include "DNA_object_types.h"
 #include "DNA_screen_types.h"
@@ -139,12 +141,12 @@ wmOperatorType *WM_operatortype_find(const char *idname, bool quiet)
 		}
 
 		if (!quiet) {
-			printf("search for unknown operator '%s', '%s'\n", idname_bl, idname);
+			CLOG_INFO(WM_LOG_OPERATORS, 0, "search for unknown operator '%s', '%s'\n", idname_bl, idname);
 		}
 	}
 	else {
 		if (!quiet) {
-			printf("search for empty operator\n");
+			CLOG_INFO(WM_LOG_OPERATORS, 0, "search for empty operator");
 		}
 	}
 
@@ -170,8 +172,7 @@ void WM_operatortype_append(void (*opfunc)(wmOperatorType *))
 	opfunc(ot);
 
 	if (ot->name == NULL) {
-		fprintf(stderr, "ERROR: Operator %s has no name property!\n", ot->idname);
-		ot->name = N_("Dummy Name");
+		CLOG_ERROR(WM_LOG_OPERATORS, "Operator '%s' has no name property", ot->idname);
 	}
 
 	/* XXX All ops should have a description but for now allow them not to. */
@@ -255,7 +256,7 @@ static int wm_macro_exec(bContext *C, wmOperator *op)
 			}
 		}
 		else {
-			printf("%s: '%s' cant exec macro\n", __func__, opm->type->idname);
+			CLOG_WARN(WM_LOG_OPERATORS, "'%s' cant exec macro", opm->type->idname);
 		}
 	}
 	
@@ -300,8 +301,9 @@ static int wm_macro_modal(bContext *C, wmOperator *op, const wmEvent *event)
 	wmOperator *opm = op->opm;
 	int retval = OPERATOR_FINISHED;
 	
-	if (opm == NULL)
-		printf("%s: macro error, calling NULL modal()\n", __func__);
+	if (opm == NULL) {
+		CLOG_ERROR(WM_LOG_OPERATORS, "macro error, calling NULL modal()");
+	}
 	else {
 		retval = opm->type->modal(C, opm, event);
 		OPERATOR_RETVAL_CHECK(retval);
@@ -375,7 +377,7 @@ wmOperatorType *WM_operatortype_append_macro(const char *idname, const char *nam
 	const char *i18n_context;
 	
 	if (WM_operatortype_find(idname, true)) {
-		printf("%s: macro error: operator %s exists\n", __func__, idname);
+		CLOG_ERROR(WM_LOG_OPERATORS, "operator %s exists, cannot create macro", idname);
 		return NULL;
 	}
 	
@@ -1135,11 +1137,14 @@ int WM_menu_invoke_ex(bContext *C, wmOperator *op, int opcontext)
 	uiLayout *layout;
 
 	if (prop == NULL) {
-		printf("%s: %s has no enum property set\n", __func__, op->type->idname);
+		CLOG_ERROR(WM_LOG_OPERATORS,
+		           "'%s' has no enum property set",
+		           op->type->idname);
 	}
 	else if (RNA_property_type(prop) != PROP_ENUM) {
-		printf("%s: %s \"%s\" is not an enum property\n",
-		       __func__, op->type->idname, RNA_property_identifier(prop));
+		CLOG_ERROR(WM_LOG_OPERATORS,
+		           "'%s', '%s' is not an enum property",
+		           op->type->idname, RNA_property_identifier(prop));
 	}
 	else if (RNA_property_is_set(op->ptr, prop)) {
 		const int retval = op->type->exec(C, op);
@@ -1827,8 +1832,9 @@ static uiBlock *wm_block_create_splash(bContext *C, ARegion *ar, void *UNUSED(ar
 					memcpy(ibuf->rect, ibuf_template->rect, ibuf_template->x * ibuf_template->y * sizeof(char[4]));
 				}
 				else {
-					printf("Splash expected %dx%d found %dx%d, ignoring: %s\n",
-					       x_expect, y_expect, ibuf_template->x, ibuf_template->y, splash_filepath);
+					CLOG_ERROR(WM_LOG_OPERATORS,
+					           "Splash expected %dx%d found %dx%d, ignoring: %s\n",
+					           x_expect, y_expect, ibuf_template->x, ibuf_template->y, splash_filepath);
 				}
 				IMB_freeImBuf(ibuf_template);
 			}
diff --git a/source/creator/CMakeLists.txt b/source/creator/CMakeLists.txt
index a155f060335..a71c1bb1984 100644
--- a/source/creator/CMakeLists.txt
+++ b/source/creator/CMakeLists.txt
@@ -26,6 +26,7 @@
 setup_libdirs()
 
 blender_include_dirs(
+	../../intern/clog
 	../../intern/guardedalloc
 	../../intern/glew-mx
 	../blender/blenlib
diff --git a/source/creator/creator.c b/source/creator/creator.c
index a59a45f885c..962d6720760 100644
--- a/source/creator/creator.c
+++ b/source/creator/creator.c
@@ -42,6 +42,8 @@
 
 #include "MEM_guardedalloc.h"
 
+#include "CLG_log.h"
+
 #include "DNA_genfile.h"
 
 #include "BLI_args.h"
@@ -49,6 +51,7 @@
 #include "BLI_utildefines.h"
 #include "BLI_callbacks.h"
 #include "BLI_string.h"
+#include "BLI_system.h"
 
 /* mostly init functions */
 #include "BKE_appdir.h"
@@ -180,6 +183,11 @@ static void callback_main_atexit(void *user_data)
 #endif
 }
 
+static void callback_clg_fatal(void *fp)
+{
+	BLI_system_backtrace(fp);
+}
+
 /** \} */
 
 
@@ -304,6 +312,10 @@ int main(
 	sdlewInit();
 #endif
 
+	/* Initialize logging */
+	CLG_init();
+	CLG_fatal_fn_set(callback_clg_fatal);
+
 	C = CTX_create();
 
 #ifdef WITH_PYTHON_MODULE
diff --git a/source/creator/creator_args.c b/source/creator/creator_args.c
index 25f8d732c58..17fa18916fd 100644
--- a/source/creator/creator_args.c
+++ b/source/creator/creator_args.c
@@ -30,6 +30,8 @@
 
 #include "MEM_guardedalloc.h"
 
+#include "CLG_log.h"
+
 #ifdef WIN32
 #  include "BLI_winstuff.h"
 #endif
@@ -529,6 +531,11 @@ static int arg_handle_print_help(int UNUSED(argc), const char **UNUSED(argv), vo
 	BLI_argsPrintArgDoc(ba, "--python-exit-code");
 	BLI_argsPrintArgDoc(ba, "--addons");
 
+	printf("\n");
+	printf("Logging Options:\n");
+	BLI_argsPrintArgDoc(ba, "--log");
+	BLI_argsPrintArgDoc(ba, "--log-level");
+	BLI_argsPrintArgDoc(ba, "--log-file");
 
 	printf("\n");
 	printf("Debug Options:\n");
@@ -704,6 +711,88 @@ static int arg_handle_background_mode_set(int UNUSED(argc), const char **UNUSED(
 	return 0;
 }
 
+static const char arg_handle_log_level_set_doc[] =
+"\n\tSet the logging verbosity level (higher for more details) defaults to 1."
+;
+static int arg_handle_log_level_set(int argc, const char **argv, void *UNUSED(data))
+{
+	const char *arg_id = "--log-level";
+	if (argc > 1) {
+		const char *err_msg = NULL;
+		if (!parse_int_clamp(argv[1], NULL, 0, INT_MAX, &G.log.level, &err_msg)) {
+			printf("\nError: %s '%s %s'.\n", err_msg, arg_id, argv[1]);
+		}
+		return 1;
+	}
+	else {
+		printf("\nError: '%s' no args given.\n", arg_id);
+		return 0;
+	}
+}
+
+static const char arg_handle_log_file_set_doc[] =
+"\n\tSet a file to output the log to."
+;
+static int arg_handle_log_file_set(int argc, const char **argv, void *UNUSED(data))
+{
+	const char *arg_id = "--log-file";
+	if (argc > 1) {
+		errno = 0;
+		FILE *fp = BLI_fopen(argv[1], "w");
+		if (fp == NULL) {
+			const char *err_msg = errno ? strerror(errno) : "unknown";
+			printf("\nError: %s '%s %s'.\n", err_msg, arg_id, argv[1]);
+		}
+		else {
+			if (UNLIKELY(G.log.file != NULL)) {
+				fclose(G.log.file);
+			}
+			G.log.file = fp;
+			CLG_output_set(G.log.file);
+		}
+		return 1;
+	}
+	else {
+		printf("\nError: '%s' no args given.\n", arg_id);
+		return 0;
+	}
+}
+
+static const char arg_handle_log_set_doc[] =
+"\n\tEnable logging categories, taking a single comma separated argument.\n"
+"\tMultiple categories can be matched using a '.*' suffix, so '--log \"wm.*\"' logs every kind of window-manager message.\n"
+"\tUse \"*\" to log everything."
+;
+static int arg_handle_log_set(int argc, const char **argv, void *UNUSED(data))
+{
+	const char *arg_id = "--log";
+	if (argc > 1) {
+		const char *str_step = argv[1];
+		while (*str_step) {
+			const char *str_step_end = strchr(str_step, ',');
+			int str_step_len = str_step_end ? (str_step_end - str_step) : strlen(str_step);
+
+			CLG_type_filter(str_step, str_step_len);
+
+			if (str_step_end) {
+				/* typically only be one, but don't fail on multiple.*/
+				while (*str_step_end == ',') {
+					str_step_end++;
+				}
+				str_step = str_step_end;
+			}
+			else {
+				break;
+			}
+		}
+		return 1;
+	}
+	else {
+		printf("\nError: '%s' no args given.\n", arg_id);
+		return 0;
+	}
+}
+
 static const char arg_handle_debug_mode_set_doc[] =
 "\n"
 "\tTurn debugging on.\n"
@@ -1827,6 +1916,10 @@ void main_args_setup(bContext *C, bArgs *ba, SYS_SystemHandle *syshandle)
 
 	BLI_argsAdd(ba, 1, "-a", NULL, CB(arg_handle_playback_mode), NULL);
 
+	BLI_argsAdd(ba, 1, NULL, "--log-level", CB(arg_handle_log_level_set), ba);
+	BLI_argsAdd(ba, 1, NULL, "--log-file", CB(arg_handle_log_file_set), ba);
+	BLI_argsAdd(ba, 1, NULL, "--log", CB(arg_handle_log_set), ba);
+
 	BLI_argsAdd(ba, 1, "-d", "--debug", CB(arg_handle_debug_mode_set), ba);
 
 #ifdef WITH_FFMPEG