ProcessExit event handler improvements

[tonyredondo]

This PR improves the way we handle the ProcessExit event by ensuring that the tracer handler is the last one to be executed from the event.

The background:

The process signals received on the CLR are handled this way:

1. SIGTERM is handled by AppDomain.CurrentDomain.ProcessExit
2. SIGINT and SIGQUIT is handled by Console.CancelKeyPress
3. SIGKILL can't be caught or ignored.

#1323 (comment)

In scenarios where IHostApplicationLifetime is being used we can face the case where the tracer handles the ProcessExit event where the traces are flushed and the writer is closed but the actual application can still be creating new spans. As @andrewlock describes in the discussion here: #1323 (comment)

This PR solves the issue by ensuring the tracer handler for ProcessExit will be the last one of the event, to send all the spans generated on previous handlers.

Also on SIGINT and SIGQUIT signals changes the actual behavior to only flush and not close due we can receive a SIGTERM later.

@DataDog/apm-dotnet

[andrewlock]

Nice! 😄 Witchcraft! 🧙

[zacharycmontoya]

Seriously, some pure wizardry right here!

[lucaspimentel]

I see a lot of comments about SIGTERM, SIGINT, SIGQUIT, and SIGKILL. Was any of this tested on Windows (.NET Core and .NET Framework)?

[tonyredondo]

I see a lot of comments about SIGTERM, SIGINT, SIGQUIT, and SIGKILL. Was any of this tested on Windows (.NET Core and .NET Framework)?

The principal delegates functionality is being tested with the unit tests in all platforms and framework versions, including arm64.

About both events CTRL+C and ProcessExit. The behavior is pretty similar, the only difference is now we don’t close the agent writer on CTRL+C. Because we were assuming that key combination always finish the process and that’s not true as seen in the example with the dd-trace tool and the .Cancel property in the event args.

However I’ll run a simple console app test with a tracer instance before merge to be 100% sure.

For the edge case we are solving here, @andrewlock ran a basic test using a prototype of this solution before the PR creation. The console app test will include this scenario using the tracer.

[tonyredondo]

I ended up using the same logic for CancelKeyPress event as well... to handle all the cases...

Scenario 1 and 2:

Code:

        static async Task Main(string[] args)
        {
            _ = Tracer.Instance;
            Console.WriteLine("Hello World!");
            await Task.Delay(5000).ConfigureAwait(false);
        }

1. Wait for normal exit (ProcessExit handler):

Hello World!
  FlushAndCloseAsync

2. Ctrl+C before finishing the Task.Delay (CancelKeyPress handler / ProcessExit didn't trigger):

Hello World!
  FlushAndCloseAsync
^C

Scenario 3 and 4:

Code:

        static async Task Main(string[] args)
        {
            _ = Tracer.Instance;
            AppDomain.CurrentDomain.ProcessExit += CurrentDomain_ProcessExit;
            Console.WriteLine("Hello World!");
            await Task.Delay(5000).ConfigureAwait(false);
        }

        private static void CurrentDomain_ProcessExit(object sender, EventArgs e)
        {
            Console.WriteLine("Finishing the application...");
        }

1. Wait for normal exit (ProcessExit handler):

Hello World!
Finishing the application...
  FlushAndCloseAsync

2. Ctrl+C before finishing the Task.Delay (CancelKeyPress handler / ProcessExit didn't trigger):

Hello World!
  FlushAndCloseAsync
^C

Scenario 5 and 6:

Code:

        static async Task Main(string[] args)
        {
            _ = Tracer.Instance;
            Console.CancelKeyPress += Console_CancelKeyPress;
            Console.WriteLine("Hello World!");
            await Task.Delay(5000).ConfigureAwait(false);
        }

        private static void Console_CancelKeyPress(object sender, ConsoleCancelEventArgs e)
        {
            Console.WriteLine($"Cancel Key Pressed: {e.Cancel}");
            e.Cancel = true; // Don't exit the process
        }

1. Wait for normal exit (ProcessExit handler):

Hello World!
  FlushAndCloseAsync

2. Ctrl+C before finishing the Task.Delay [CancelKeyPress handler (FlushTracesAsync) and ProcessExit handler (FlushAndCloseAsync)]:

Hello World!
Cancel Key Pressed: False
  FlushTracesAsync
  FlushAndCloseAsync

Scenario 7 and 8:

Code:

        static async Task Main(string[] args)
        {
            _ = Tracer.Instance;
            Console.CancelKeyPress += Console_CancelKeyPress;
            Console.WriteLine("Hello World!");
            await Task.Delay(5000).ConfigureAwait(false);
        }

        private static void Console_CancelKeyPress(object sender, ConsoleCancelEventArgs e)
        {
            Console.WriteLine($"Cancel Key Pressed: {e.Cancel}");
            e.Cancel = false; // Exit the process
        }

1. Wait for normal exit (ProcessExit handler):

Hello World!
  FlushAndCloseAsync

2. Ctrl+C before finishing the Task.Delay [CancelKeyPress handler (FlushAndCloseAsync)]:

Hello World!
Cancel Key Pressed: False
  FlushAndCloseAsync
^C

Scenario 9 and 10:

Code:

    class Program
    {
        static async Task Main(string[] args)
        {
            _ = Tracer.Instance;
            Console.CancelKeyPress += Console_CancelKeyPress;
            AppDomain.CurrentDomain.ProcessExit += CurrentDomain_ProcessExit;
            Console.WriteLine("Hello World!");
            await Task.Delay(5000).ConfigureAwait(false);
        }

        private static void CurrentDomain_ProcessExit(object sender, EventArgs e)
        {
            Console.WriteLine("Finishing the application...");
        }

        private static void Console_CancelKeyPress(object sender, ConsoleCancelEventArgs e)
        {
            Console.WriteLine($"Cancel Key Pressed: {e.Cancel}");
            e.Cancel = true; // Don't exit the process
        }
    }

1. Wait for normal exit (ProcessExit handler):

Hello World!
Finishing the application...
  FlushAndCloseAsync

2. Ctrl+C before finishing the Task.Delay [CancelKeyPress handler (FlushTracesAsync) and ProcessExit handler (FlushAndCloseAsync)]:

Hello World!
Cancel Key Pressed: False
  FlushTracesAsync
Finishing the application...
  FlushAndCloseAsync

Scenario 11 and 12:

Code:

    class Program
    {
        static async Task Main(string[] args)
        {
            _ = Tracer.Instance;
            Console.CancelKeyPress += Console_CancelKeyPress;
            AppDomain.CurrentDomain.ProcessExit += CurrentDomain_ProcessExit;
            Console.WriteLine("Hello World!");
            await Task.Delay(5000).ConfigureAwait(false);
        }

        private static void CurrentDomain_ProcessExit(object sender, EventArgs e)
        {
            Console.WriteLine("Finishing the application...");
        }

        private static void Console_CancelKeyPress(object sender, ConsoleCancelEventArgs e)
        {
            Console.WriteLine($"Cancel Key Pressed: {e.Cancel}");
            e.Cancel = false; // Exit the process
        }
    }

1. Wait for normal exit (ProcessExit handler):

Hello World!
Finishing the application...
  FlushAndCloseAsync

2. Ctrl+C before finishing the Task.Delay [CancelKeyPress handler (FlushTracesAsync) and ProcessExit handler (FlushAndCloseAsync)]:

Hello World!
Cancel Key Pressed: False
  FlushAndCloseAsync
^C

[tonyredondo]

For IHostApplicationLifetime I've tested it with a simple Worker app:

    public class Program
    {
        public static void Main(string[] args)
        {
            _ = Tracer.Instance;
            CreateHostBuilder(args).Build().Run();
        }

        public static IHostBuilder CreateHostBuilder(string[] args) =>
            Host.CreateDefaultBuilder(args)
                .ConfigureServices((hostContext, services) =>
                {
                    services.AddHostedService<Worker>();
                });
    }

    public class Worker : BackgroundService
    {
        private readonly ILogger<Worker> _logger;

        public Worker(ILogger<Worker> logger)
        {
            _logger = logger;
        }

        public override Task StartAsync(CancellationToken cancellationToken)
        {
            _logger.LogInformation("StartAsync");
            return base.StartAsync(cancellationToken);
        }

        public override Task StopAsync(CancellationToken cancellationToken)
        {
            _logger.LogInformation("StopAsync");
            return base.StopAsync(cancellationToken);
        }

        protected override async Task ExecuteAsync(CancellationToken stoppingToken)
        {
            while (!stoppingToken.IsCancellationRequested)
            {
                _logger.LogInformation("Worker running at: {time}", DateTimeOffset.Now);
                await Task.Delay(1000, stoppingToken);
            }
        }
    }

Output after pressing CTRL+C:

info: WorkerService1.Worker[0]
      StartAsync
info: WorkerService1.Worker[0]
      Worker running at: 04/05/2021 14:56:03 +02:00
info: Microsoft.Hosting.Lifetime[0]
      Application started. Press Ctrl+C to shut down.
info: Microsoft.Hosting.Lifetime[0]
      Hosting environment: Development
info: Microsoft.Hosting.Lifetime[0]
      Content root path: C:\Users\danielredondo\source\repos\WorkerService1\WorkerService1
info: WorkerService1.Worker[0]
      Worker running at: 04/05/2021 14:56:04 +02:00
info: WorkerService1.Worker[0]
      Worker running at: 04/05/2021 14:56:05 +02:00
info: WorkerService1.Worker[0]
      Worker running at: 04/05/2021 14:56:06 +02:00
  FlushTracesAsync
info: Microsoft.Hosting.Lifetime[0]
      Application is shutting down...
info: WorkerService1.Worker[0]
      StopAsync
  FlushAndCloseAsync