Logging as a way to debug code

Why is it important to prohibit debugging yourself?

When you debug a program, you, without realizing it, think that in one debugging session, fix all the problems that arose within the framework of this task. But our shortsightedness does not want to believe that in fact there is not one problem, but several. And in one debugging session you cannot solve all these problems.

Therefore, you will need to run this code several times in debug mode, spending hours of debugging on the same piece of code. And it is only you who have spent so much time on this part of the program. Each team member who is "lucky" to work with this code will be forced to live the same story that you lived.

Not to mention that people in teams change, teams change, and so on. Man-hours go to the same thing. Stop doing it. I'm serious. Take responsibility for other people. Help them not to experience the same stretch of your life.

Issues: Difficult to debug composite code


Possible algorithm for solving the problem:

  1. Split into separate parts
  2. We throw out debugging, we simply forbid to use the Debug mode
  3. We analyze individual parts (we come up with invalid situations for them, boundary cases)
  4. We write tests for each individual part of the entire algorithm
  5. In tests, sometimes you have to learn intermediate data, but ...
    Debugging is no longer available to us, so we stick Trace in those parts where there is a suspicion of incorrect execution of the algorithm
  6. By tracing you need to understand the cause of the problem
  7. If it’s not clear, then most often it’s worth writing another test or tracing one step earlier

The solution is automated testing using logging. You write tests for all (or almost all) situations that lead to problems. Plus, if there is a need for debugging, then you trace until you figure out the problem.

Thus, you save other people from debugging this code, as if a problem arises, then the person will look at your logs and understand what is the reason. Logging is only important parts of the algorithm.

Let's see an example. You know that individually all interface implementations work (because tests are written to prove this). But when everything comes together, incorrect behavior occurs. What you need? It is necessary to log responses from the "correct" interfaces:

void Register(User user)
{
	// на этом участке не нужно ничего логировать,
        // т.к. всё будет понятно из исключения
	var isExists = _userRepository.IsUserExists(user);
	if (isExists)
	{
		throw new InvalidOperationException($"User already exists: {user}");
	}
	// а вот это уже можно и залогировать, 
        // т.к. от этого зависят дальнейшие детали алгоритма
	var roleInOtherService = _removeService.GetRole(user);
	_log.Trace($"Remote role: {roleInOtherService}")
	switch (roleInOtherService)
	{
		case "...":
			break;
		...
	}
	// тут нам не критично, если пользователю не добавили 
        // определённые привелегии в каком-то удалённом сервисе,
        // но мы бы хотели знать об этом
	foreach (var privilege in Privileges)
	{
		var isSuccess = _privilegeRemoteService.Grant(user, privilege);
		if (isSuccess)
		{
			_log.Trace($"Add privilege: {privilege} to User: {user}");
		}
		else
		{
			_log.Trace($"Privilege: {privilege} not added to User: {user}");
		}
	}
	...
}

This example shows how we trace individual parts of the algorithm so that we can fix this or that stage of its execution. Looking at the logs, it becomes clear what is the reason. In real life, this whole algorithm should be divided into separate methods, but the essence of this does not change.

All this greatly speeds up code writing. You do not need to run the cycle with F10 in order to understand at what iteration of the cycle the problem occurred. Just pledge the state of the objects you need under certain conditions at a certain iteration of the cycle.

In the end, you leave important logs and delete side logs, for example, where you recognized the state of an object at a certain iteration of the loop. Such logs will not help your colleagues, because you most likely already understood the problem of the incorrect algorithm and fixed it. If not, then develop in your branch until you find the reason and fix the problem. But the logs that record important results from the execution of other algorithms will be needed by everyone. Therefore, they should be left.

What if we don’t need this garbage? In this case, trace only as part of debugging, and then clean up after yourself.

prosMinuses
It is possible to track the execution of the algorithm without debuggingI have to write a trace code
In production, the logs will sometimes collect the necessary data.In production, logs will sometimes collect unnecessary data
Debugging time is reduced because you often run the code and immediately see the results of its execution (everything is in full view)It is necessary to clean up after yourself. This sometimes leads to re-writing the trace code.
Colleagues can track the execution of the algorithm by logsColleagues have to look not only at the algorithm itself, but also at the trace of its execution
Logging is the only way to debug non-deterministic scripts (for example, multithreading or a network)In production, performance decreases due to I / O and CPU operations

In the end, I would like to say this: think with your own head. No need to jump from one extreme to another. Sometimes manual debugging will really solve the problem here and now. But as soon as you notice that something is fast, it doesn’t work here and now, it's time to switch to another mode.

Also popular now: