12/25/20

Obtaining debugging information from released application

The article describes various methods of obtaining debugging information.

There are situations when a developer needs debugging information from an application without the use of the IDE (Integrated Development Environment) debugger tools. The preconditions of these situations could be:

  • necessity for bug fixing when the bug does not appear under the debugging tool;
  • necessity for optimizing or fixing an application that is already in production (remotely or with the client’s help).

The point of the developer’s interest in these cases could be the information from a certain point of the code or general information about the application as well:

  • data in a certain investigated point;
  • the call stack, which has led to the investigated point;
  • counter values that characterize the application.

The techniques described in the article could be implemented into the application and could help the developer to obtain information without debugging. The article will describe:

  • intercepting information from the output console and its transfer to an alternative display element;
  • obtaining the call stack;
  • obtaining the number of caught application exceptions;
  • obtaining the application availability information;
  • obtaining the number of GC (Garbage Collection) operations.

At the end, an example application, which implements the described functionality, will be observed.


Intercepting information from output console

The ConsoleWritter class was developed to intercept information from the output console. Its code is shown in Listing 1.

Listing 1

public class ConsoleWritter : TextWriter
{
    private static ConsoleWritter _Instance = null;
    private readonly IConsoleReceiver _Receiver;

    private ConsoleWritter(IConsoleReceiver currentReceiver)
    {
        _Receiver = currentReceiver;
        System.Console.SetOut(this);
    }

    public static void Initialize(IConsoleReceiver currentReceiver)
    {
        if (_Instance == null)
        {
            _Instance = new ConsoleWritter(currentReceiver);
        }
    }

    public override Encoding Encoding
    {
        get
        {
            return Encoding.UTF8;
        }
    }

    public override void Write(char value)
    {
        _Receiver.Put(new string(value, 1));
    }

    public override void Write(char[] buffer)
    {
        _Receiver.Put(new string(buffer));
    }

    public override void Write(string value)
    {
        _Receiver.Put(value);
    }

    public override void Write(char[] buffer, int index, int count)
    {
        _Receiver.Put(new string(buffer, index, count));
    }
}

Implementation. The developed ConsoleWritter class is inherited from the TextWritter class because an object of the TextWritter type should be set as a parameter of the Console.SetOut call to start intercepting information from the output console.

The initialization function of the developed ConsoleWritter class receives an object of the IConsoleReceiver interface as a parameter. The IConsoleReceiver interface is shown in Listing 2.

Listing 2

public interface IConsoleReceiver
{
    void Put(string value);
}

To simplify the application structure, a restriction was imposed on the developed class, which also requires its only initialization in the application. If it’s necessary to use several viewing elements of the output console, storing and calling for several instances of the IConsoleReceiver interface should be provided.

Usage. To start an interception of the output console, the function ConsoleWritter.Initialize should be called. An object of the IConsoleReceiver interface should be transferred to it as a parameter.

After that, all the application calls Console.Write and Console.WriteLine will be redirected to the function Put of the IConsoleReceiver interface. Thus the developer can get information from a certain point of the code.

When the call of the Put function is done from different threads, the developer should implement some of the following:

  • critical sections;
  • data transferring through «Invoke» calls.

When the call of the Put function happens, the developer can process information in the following ways:

  • write it to log for further analysis;
  • display it into the alternative display element;
  • store it into the buffer and then provide it by request.

There is an implementation of the API function that provides information from the console by the request in Listing 3. This implementation allows viewing information remotely from the ASP .Net Core application.

Listing 3

private static ConsoleWrapper _ConsoleWrapper;

static ConsoleController()
{
    _ConsoleWrapper = new ConsoleWrapper();
}

private class ConsoleWrapper : IConsoleReceiver
{
    private readonly Queue _ConsoleQueue;

    public ConsoleWrapper()
    {
        _ConsoleQueue = new Queue();
        ConsoleWritter.Initialize(this);
    }

    public void Put(string value)
    {
        lock (_ConsoleQueue)
        {
            _ConsoleQueue.Enqueue(value);
            if (_ConsoleQueue.Count > 100)
                _ConsoleQueue.Dequeue();
        }
    }

    public List Get()
    {
        List Result = new List();

        if (_ConsoleQueue.Count > 0)
        {
            lock (_ConsoleQueue)
            {
                while (_ConsoleQueue.Count > 0)
                    Result.Add(_ConsoleQueue.Dequeue());
            }
        }
        return Result;
    }
}

[HttpGet("/api/console")]
public List GetConsoleLines()
{
    return _ConsoleWrapper.Get();
}

Result. Intercepting the information from the output console allows viewing, writing, and data analysis from certain execution points of the application.


Obtaining call stack

To obtain information about the call stack, the TraceBuilder class was developed. There is only one static function Build in it. The code is shown in Listing 4.

Listing 4

public static IEnumerable Build()
{
    StackTrace stackTrace = new StackTrace(true);

    for (int j = 0; j < stackTrace.FrameCount; j++)
    {
        StackFrame frame = stackTrace.GetFrame(j);

        if (frame != null)
        {
            MethodBase method = frame.GetMethod();
            if (method.MethodImplementationFlags != MethodImplAttributes.IL) break;

            yield return method;
        }
    }
}

Implementation. For implementation, the StackTrace class from the System.Diagnostics namespace was used.

Usage. The Build function from the developed class returns an enumeration of the objects with the type MethodBase. Their order corresponds to the order of function calls in the application from the point where the Build function was called. The fields of these objects of the type MethodBase contain information about function names, parameter names, and so on.

The necessity for this technique happens when the developer needs to know the trace of the reached code when there are several ways to reach it. The code presented in Listing 5 shows one of the variants that could be used for enumerating the call stack.

Listing 5

IEnumerable methods = TraceBuilder.Build();

foreach (var method in methods)
{
    ParameterInfo[] parameters = method.GetParameters();

    Console.WriteLine("Function: " + method.Name);
    Console.Write("Parameters: ");

    for (int i = 0; i < parameters.Length; i++)
    {
        if (i > 0) Console.Write(", ");
        Console.Write(string.Format("\t{0}: {1}", parameters[i].Name, parameters[i].ParameterType.ToString()));
    }
    Console.WriteLine();
}

Result. The usage of the TraceBuilder class allows to obtain the list of the function calls at a certain point of the application, especially in the case when there are several opportunities to reach this point.


Obtaining number of caught application exceptions

To obtain information about the number of caught application exceptions, the ExceptionCounter class was developed. There is only one static function Calculate in it. The code is shown in Listing 6.

Listing 6

public class ExceptionCounter
{
    private static object _SyncObject = new object();
    private static PerformanceCounter _PerfomanceCounter = null;

    public static long Calculate(string instanceName)
    {
        lock (_SyncObject)
        {
            if (_PerfomanceCounter == null)
            {
                _PerfomanceCounter = new PerformanceCounter();
                _PerfomanceCounter.CategoryName = ".NET CLR Exceptions";
                _PerfomanceCounter.CounterName = "# of Exceps Thrown";
                _PerfomanceCounter.InstanceName = instanceName;
                _PerfomanceCounter.BeginInit();
            }
        }
        return _PerfomanceCounter.RawValue;
    }
}

Implementation. The PerfomanceCounter class was used for implementation. Its usage is restricted by the executing environment.

The first call of the Calculate function creates an object of the PerfomanceCounter type. Its creation could slow up the application execution.

The check of the first call and the object of the PerfomanceCounter type creation is implemented under the critical section. That’s why it is not recommended to use multiple calls of the Calculate function, especially from different threads.

Usage. The Calculate function of the developed class returns the number of caught application exceptions. There is one parameter in the function – the name of the application instance. The preparation of the call and the call of this function are presented in Listing 7.

Listing 7

var c = new PerformanceCounterCategory(".NET CLR Exceptions");
var inst = c.GetInstanceNames();
Assembly asm = Assembly.GetExecutingAssembly();

int indexComa = asm.ToString().IndexOf(',');
string asmName = asm.ToString().Substring(0, indexComa);
string s = inst.FirstOrDefault(a => a == asmName);
if (string.IsNullOrEmpty(s) == true)
	s = "w3wp";

Console.WriteLine($"Exceptions count: {ExceptionCounter.Calculate(s)}");

Usage of this technique may be helpful in the following cases:

  • search for high CPU utilization. The caught exceptions may be the reason for the application slow down;
  • code refactoring, when the developer uses try/catch construction instead of if/then construction. Functions TryCatchFunction and IfThenFunction presented in Listing 8 are equal, but the function IfThenFunction is preferred.

Listing 8

private int TryCatchFunction(string value)
{
	try
	{
		int Temp = int.Parse(value.Substring(1));
		return Temp * Temp;
	}
	catch
	{
		return -1;
	}
}

private int IfThenFunction(string value)
{
	int Temp;

	if (value == null || value.Length < 2)
		return -1;

	if (int.TryParse(value.Substring(1), out Temp) == false)
		return -1;

	return Temp * Temp;
}

Result. The usage of the ExceptionCounter class allows obtaining the number of caught application exceptions for its performance rating and efficiency analysis.


Obtaining application availability information

To obtain information about application availability, the DelaysCounter class was developed. The code is shown in Listing 9.

Listing 9

public static class DelaysCounter
{
    private static readonly Thread _Thread;
    private static long _Threshold;

    static DelaysCounter()
    {
        _Threshold = 50;
        _Thread = new Thread(ThreadDelaysCounter) { Name = "Thread Delays Counter" };
        _Thread.IsBackground = true;
        _Thread.Start();
    }

    private static void ThreadDelaysCounter()
    {
        Stopwatch stopwatch = new Stopwatch();
        stopwatch.Start();

        while (true)
        {
            long Time = stopwatch.ElapsedMilliseconds;
            Thread.Sleep(1);
            Time = stopwatch.ElapsedMilliseconds - Time;

            if (Time >= 500)
                Delays500ms++;
            else if (Time >= 100)
                Delays100ms++;
            else if (Time >= 50)
                Delays50ms++;

            if (Time > MaxDelay)
                MaxDelay = Time;

            if (Time >= _Threshold)
                TotalDelays += Time;
        }
    }

    public static void Reset(long threshold)
    {
        _Threshold = threshold;

        Delays500ms = 0;
        Delays100ms = 0;
        Delays50ms = 0;
        MaxDelay = 0;
        TotalDelays = 0;
    }

    public static long MaxDelay { get; private set; }
    public static long TotalDelays { get; private set; }
    public static long Delays500ms { get; private set; }
    public static long Delays100ms { get; private set; }
    public static long Delays50ms { get; private set; }
}

Implementation. The DelaysCounter class contains a thread, where the function Thread.Sleep with the 1 value as a parameter is called on every iteration. So the delay should be 1 ms for it. The object of Stopwatch type determines the real value of the delay of the Thread.Sleep function. If this value is greater than a threshold then the corresponding counter is incremented.

When the thread is created, its property IsBackground is initialized with the true value. This ensures the thread to be stopped and removed at application closing.

The DelaysCounter class contains a static Reset function, which sets counters to 0 value. That is implemented without the use of the critical section to increase application performance as the inaccuracy is not significant in this case.

Usage. There are Delays500ms, Delays100ms, Delays50ms properties in the DelaysCounter class, which returns the number of delays longer than 500, 100, 50 milliseconds respectively.

There is MaxDelay property in the DelaysCounter class, which returns the biggest value of delay that was registered.

There is TotalDelays property in the DelaysCounter class, which returns all the delay values sum. The delay is in this sum if its value is greater than a threshold. The threshold is set by the parameter of the Reset function.

To launch the thread from the DelaysCounter class, it’s necessary to refer to any of its elements. It is recommended to call the Reset function first with the value of the threshold.

If the values of the DelaysCounter class properties increase it is the signal that threads are displaced from their execution queue and actions should be done to reduce displacement.

The usage of the mentioned properties is presented in Listing 10.

Listing 10

Console.WriteLine($"Max delay: {DelaysCounter.MaxDelay:N0}ms");
Console.WriteLine($"Total delay: {DelaysCounter.TotalDelays:N0}ms");
Console.WriteLine($"Delays 500ms: {DelaysCounter.Delays500ms:N0}");
Console.WriteLine($"Delays 100ms: {DelaysCounter.Delays100ms:N0}");
Console.WriteLine($"Delays 50ms:  {DelaysCounter.Delays50ms:N0}");

Usage of these properties provides the developer with the following opportunities:

  • predicting the maximum time of the application response;
  • calculating the required size of the memory between application parts that use a network or shared-memory communication, shown in picture 1;
  • understanding whether the application should be optimized.

Picture 1 – Memory buffer for data transfer between application parts

When the developer knows the maximum value of delay of the thread and the speed of the data received by one part of the application, he can calculate the required size of the memory buffer(queue) for that data, multiplying the speed by the maximum delay value.

Result. The usage of the developed DelaysCounter class gives the developer an opportunity to see threads displacement from the thread execution queue. Also, the developer receives an opportunity to make a decision about the application optimization and memory arrangement.


Obtaining number of GC operations in application

To obtain information about the number of GC operations in the application, the MemoryWatcher class, which calculates calculation for the last hour of work, is developed. The code is shown in Listing 11.

Listing 11

public class MemoryWatcher
{
    private static readonly Thread _Thread;
    private static long[] _MemoryValues;
    private static int _Index = 0;

    static MemoryWatcher()
    {
        _Index = 0;
        _MemoryValues = new long[360];
        _Thread = new Thread(ThreadWatcher) { Name = "Thread Memory Watcher" };
        _Thread.IsBackground = true;
        _Thread.Start();
    }

    private static void ThreadWatcher()
    {
        while (_Thread != null)
        {
            lock (_MemoryValues)
            {
                _MemoryValues[_Index] = GC.GetTotalMemory(false);
                Calculate(_Index);
            }

            _Index = (_Index + 1) % _MemoryValues.Length;

            Thread.Sleep(10000);
        }
    }

    private static void Calculate(int index)
    {
        int Count = 0;
        long Last = 0;
        long Memory = 0;

        for (int i = 0, l = _MemoryValues.Length; i < l; i++)
        {
            long Current = _MemoryValues[(l - i + index) % l];
            long Delta = Current - Last;

            if (Current == 0)
                break;

            if (Delta > 0 && Last > 0)
            {
                if (Delta > Memory)
                    Memory = Delta;
                Count++;
            }

            Last = Current;
        }

        CurrentGCCount = Count;
        CurrentMemoryCleaning = Memory;

        if (Count > WorstGCCount)
            WorstGCCount = Count;
        if (Memory > MaximumMemoryCleaning)
            MaximumMemoryCleaning = Memory;
    }

    public static void Reset()
    {
        lock (_MemoryValues)
        {
            CurrentGCCount = 0;
            WorstGCCount = 0;
            Array.ForEach(_MemoryValues, item => item = 0);
        }
    }

    public static long CurrentGCCount { get; private set; }
    public static long WorstGCCount { get; private set; }
    public static long CurrentMemoryCleaning { get; private set; }
    public static long MaximumMemoryCleaning { get; private set; }
}

Implementation. The MemoryWatcher class contains a thread, where the memory usage is saved and the calculation of the GC operations number is done on every iteration. Each iteration happens every 10 seconds.

To get the application memory usage, the call GC.GetTotalMemory(false) is made. The false parameter means that the GC will not be called in the memory calculation call.

The number of GC operations is calculated by comparing the saved values of the memory usage. When the value is reduced on the next iteration it is considered that the GC operation happens.

The accuracy of the developed class doesn’t allow getting the correct number of GC operations more than 180 per hour (but the value could be more than 180), as the measurement happens every 10 seconds. The measurement interval can be reduced but the algorithm will count long-continued GC operations several times. The measurement interval can be increased but the algorithm can skip GC operations in this case.

Anyway, the value 180 (the half of measure operations) and more means problems with the GC in the application.

Usage. There are CurrentGCCount, WorstGCCount, CurrentMemoryCleaning, MaximumMemoryCleaning properties in the MemoryWatcher class.

The property CurrentGCCount returns the number of GC operations during the last hour.

The property WorstGCCount returns the biggest number of the GC operations during an hour, which was registered during application work.

The property CurrentMemoryCleaning returns the maximum value of freed memory during the last hour.

The property MaximumMemoryCleaning returns the maximum value of freed memory during the whole time of the application work.

The usage of the mentioned properties is presented in Listing 12.

Listing 12

Console.WriteLine($"Number of GC Handling: {MemoryWatcher.CurrentGCCount}");
Console.WriteLine($"Worst GC Handling: {MemoryWatcher.WorstGCCount}");
Console.WriteLine($"Current Cleaning: {MemoryWatcher.CurrentMemoryCleaning}");
Console.WriteLine($"Maximum Cleaning: {MemoryWatcher.MaximumMemoryCleaning}");
Console.WriteLine($"Memory usage: {GC.GetTotalMemory(false)}");

For the usage of these properties, there are several approaches:

  • when values of properties CurrentGCCount or WorstGCCount are near 180 or greater, that means that the GC works too often and the memory allocation/deletion should be revised in the application;
  • when values of properties CurrentMemoryCleaning or MaximumMemoryCleaning is too small in comparison with the application memory usage, that means that the memory leak happens;
  • when values of properties CurrentMemoryCleaning or MaximumMemoryCleaning are too large in comparison with the application memory usage and values of properties CurrentGCCount or WorstGCCount are not significant, that means that the application could be inaccessible during the GC process and the values of the application availability information should be studied.

Result. The usage of the developed MemoryWatcher class gives an opportunity to the developer to decide if the application memory arrangement should be optimized or not.


Example application, which implements described functionality

For testing the described ways of obtaining and processing the debugging information, the following application was developed. This application is shown in picture 2. Its source code can be downloaded by the link.

Picture 2 — Example application

The example application is a Windows Forms application which uses .Net Framework 4.5. For the demonstration of different abilities, the following components of the application are used:

  1. The output console interception is carried out into the text area in the central part of the application window. The initialization is implemented in the constructor of the application main form.

    The Put function implementation of the IConsoleReceiver interface is shown in Listing 13.

    Listing 13

    public void Put(string value)
    		{
    		    edConsole.Text += value;
    
    		    if (edConsole.Lines.Length >= CONSOLE_SIZE)
    		    {
    		        int firstIndex = edConsole.Lines[0].Length;
    		        int secondIndex = edConsole.Text.IndexOf(edConsole.Lines[1], firstIndex);
    		        if (firstIndex == secondIndex && secondIndex < edConsole.Text.Length) secondIndex++;
    		        edConsole.Text = edConsole.Text.Substring(secondIndex);
    		    }
    		    edConsole.SelectionStart = edConsole.Text.Length;
    		    edConsole.ScrollToCaret();
    		}
    		

    This function receives a string from the output console and adds it to an edConsole component of the type TextBox. The total number of lines is calculated and if this number is greater than the CONSOLE_SIZE constant then the text information truncation happens.

    It is important to know that the current implementation of the Put function is simplified and is not thread-safe. That’s why the calls Console.Write and Console.WriteLine are allowed only from the main window thread.

  2. The group of commands «Trace 2 Functions» and «Trace 3 Functions» on the application toolbar demonstrates the opportunity of obtaining the call stack. The execution of these commands calls the sequence of functions and writes their names with parameters into the output console.

  3. The group of commands «Out of range», «Divide by zero», «Count Exceptions» on the application’s toolbar demonstrates the opportunity of obtaining the number of caught application exceptions.

    Commands «Out of range», «Divide by zero» throw exceptions, catch them and write the text of the caught exception into the output console.

    The «Count Exceptions» command writes the current number of caught exceptions into the output console.

  4. The «Count delays» command on the application toolbar demonstrates the opportunity of obtaining the application availability information. The information about thread execution delays is written into the output console.

  5. The «Count GC Count» command on the application toolbar demonstrates the opportunity of the information about the number of GC operations per hour in the application obtaining. The information about the GC operations count is written into the output console.

  6. The group of commands «Run Work» and «Work Info» are additional commands for demonstrating possibilities to obtain information about the application availability and the number of GC operations per hour when the application is busy with data handling.

    The «Run Work» command execution makes to run and stop the following process:

    • strings of the special format are generated in the first thread;
    • these strings are pushed into the queue;
    • the second thread reads these strings from the queue and handles them.

This job is implemented in “an inaccurate way” to increase the influence on the CPU and GC overloading.

To check the opportunity of obtaining information about the application’s availability and the number of GC operations, two application launches were made for 24 hours. The first launch was the one with the executed command «Run Work», and the second one was without it. Values of the parameters are presented in table 1.

Table 1. Values after application launch for 24 hours.

Property Value
With «Run Work» Without
Max delay 194 41
Total delay 2587 0
Delays 500ms 0 0
Delays 100ms 6 0
Delays 50ms 28 0
Number of GC Handling 181 0
Worst number of GC Handling 193 1

Summary

The developed classes allow getting various information from a certain point of the code as well as to get the general information about the work of the application during its debugging or optimization.

The developed example application allows to demonstrate opportunities for the developed classes and shows how to use them.

By: Timur Ovcharov