Logging before or after surgery?

Question

I am thinking about where to write a journal entry around the operation. Here are two different styles. First, write down the journal before the operation.

Before:

log.info("Perform operation XXX") operation() 

And here is another style, write a magazine after surgery.

After:

 operation() log.info("Operation XXX is done.") 

Using the before-style, the log entries say what to do now. About this style is that when something goes wrong, the developer can easily find it, because they know what the program is doing now. But con is that you are not sure that the operation is completed correctly, if something is wrong inside the operation, for example, a function call is blocked and never returns, you cannot know this by reading the logging entries. After completing the style, you are sure that the operation is complete.

Of course we can mix these two styles together

AND

 log.info("Perform operation XXX") operation() log.info("Operation XXX is done.") 

But I feel that this is a bit detailed, it is recording with double logging. So here is my question: what is a good journal style? I would like to know what you think.

Thanks.

Answer 1

I usually used two different levels of magazines .

The first one I installed at the debug level, and the second at the info level. This way, typical production machines will only log what is being done, but I can turn on debug logging and see what it is trying to do before the errors are fixed.

Answer 2

It all depends on what you want to register. If you are interested in the code reaching the moment when it is going to complete the operation. If you want to make sure that the operation was successful, do it after. If you want both, do both.

Answer 3

Last form:

 log.info("Start XXX") operation() log.info("End XXX") 

since it provides most of the information.

You can obviously turn off the logging level, so in normal use it will not be too detailed.

Answer 4

There, another style that I saw was used in Linux boot scripts and in strace . It got the benefits of your combined style with less granularity, but you need to make sure that your logger is not buffering. I do not know log.info , so here is an example with print :

 print "Doing XXX... ", # Note lack of newline :) operation() print "Done." 

(Since print uses buffering in most cases, using this example verbatim will not work properly. You will not see “Doing XXX” until you see “Done.” But you get a general idea.)

Another disadvantage of this style is that things can mix if you have multiple threads writing the same journal.

Answer 5

Maybe you could use something like try catch? Here is an example of a naive python:

 try : operation() log.info("Operation XXX is done.") except Exception: log.info("Operation xxx Failed") raise Exception() # optional : if you want to propagate failure to another try catch statement and/or crash eventually. 

The operation will start. If this does not work (no exception is thrown), you will receive success instructions in the logs.

If this fails (by throwing an exception. Like a full disk or something else that you are trying to do), the Exception is caught and you get a failure instruction.

Logging makes more sense. You can remain faithful in oneliner and see if the operation succeeded. The best choice.

Oh, and you get a hook point where you can add code that will be executed in the event of a failure.

Hope this helps.