drewcrawford/JucheLog — Issue #8: Function/Thread ID logging
Author: bionoren
Created: 2012-01-13 22:46:57+00:00
State: open

I'm going to discuss the python implementation because it is the worse offender, but this problem is present to a greater or lesser extent in any other language's implementation.
Consider the following block of code:
if shouldLoop:
for i in myList:
if i % 3 == 1:
doSomething()
Looks reasonable. Let's add logging:
if shouldLoop:
with juche.revolution("looping"):
for i in myList:
with juche.revolution("i = %d" % i):
if i % 3 == 1:
with juche.revolution("doing something"):
doSomething()
Wow. That's a lot of indentation. When I look at this code, it looks wrong, and it takes me a minute to sort out "Ok, this is really just 1 for loop and 2 if statements with a bunch of logging. Nothing crazy going on here, back to ... what was I looking for again? Oh yes." It's the same argument behind Hungarian Notation (the original intent, not it's corporatized misapplication) that code that is wrong should look wrong, and what we've created here is right code that looks wrong.

So I'm proposing that instead of doing these explicit scope declarations, we instead automatically log 2 things on every log call - the stack trace and the thread ID. The thread ID lets you keep an execution flow's logs together, and the stack trace tells you about where you are and where you came from, which provides the context information necessary for scoping (in the terminal, your indentation could have a 1 to 1 correspondance with stack depth).

This solves several problems:
1. Eliminates nesting\indentation creep
2. Less work for the developer to implement logging
3. Resolves problems like Issue #7 (there's no programmer specified context to collide with anymore)

Thoughts?