appcenter-sdk-dotnet icon indicating copy to clipboard operation
appcenter-sdk-dotnet copied to clipboard

TrackError is not send to server if done right before the WPF app is exiting

Open ThomasMader opened this issue 4 years ago • 8 comments

Description

TrackError is not send to server if done right before the WPF app is exiting and on the next restarts no other errors are tracked. In addition the same error will not be serialized into the DB anymore if the same error stayed in the DB from a previous app run.

Repro Steps

To reproduce just create a new WPF project with Visual Studio and replace App.xaml.cs with the following code and insert your AppCenter ID.

using Microsoft.AppCenter;
using Microsoft.AppCenter.Analytics;
using Microsoft.AppCenter.Crashes;
using System;
using System.Windows;

namespace WpfApp1
{
	/// <summary>
	/// Interaction logic for App.xaml
	/// </summary>
	public partial class App : Application
	{

		protected override void OnStartup(StartupEventArgs args)
		{
			base.OnStartup(args);
			AppCenter.LogLevel = LogLevel.Verbose;
			AppCenter.Start("insert-your-ID", typeof(Analytics), typeof(Crashes));
			AppCenter.SetEnabledAsync(true);
			Analytics.TrackEvent("Start");
			//try
			//{
			//	throw new ArgumentException("test1");
			//}
			//catch (Exception e)
			//{
			//	Crashes.TrackError(e);
			//}
		}

		protected override void OnExit(ExitEventArgs args)
		{
			base.OnExit(args);
			try
			{
				throw new ArgumentException("test2");
			}
			catch (Exception e)
			{
				Crashes.TrackError(e);
			}

			Analytics.TrackEvent("End");
		}
	}
}
  1. Start the application and stop it by closing the Windows.
  2. test2 exception and End event are in the DB.
  3. Start the application again and keep it running for some time.
  4. Check the DB to see that the test2 exception is still in the DB and was not uploaded to the server even though the End and Start event have been sent to the server.
  5. Close the Window
  6. After application terminated check the DB to see that a new End event was written but the timestamp of the test2 exception is still the same and there is no additional exception.
  7. 3 to 6 can be repeated multiple times with the same outcome.
  8. uncomment test1 exception block and start the app again and wait until AppCenter finished it's work. (Check log output)
  9. Check DB to see that no entries are left and everything was uploaded.

Details

This happens for me under .NET 5 with AppCenter 4.3.0 under Windows 10.

ThomasMader avatar Jul 22 '21 07:07 ThomasMader

Hi @ThomasMader

Thank you for getting in touch with us! I'm currently investigating your issue. I'll let you know when I have some updates.

DmitriyKirakosyan avatar Jul 23 '21 06:07 DmitriyKirakosyan

@ThomasMader we Created a bug on our board. We will notify you once the fix is released.

DmitriyKirakosyan avatar Jul 26 '21 13:07 DmitriyKirakosyan

@ThomasMader I prepared a PR "partly" fixing the issues you described. The PR fixes the issue when error logs, stored in DB, are not automatically sent on the App start.

Regarding sending events in OnExit, I wouldn't recommend doing it, as it is not going to be stable. Application may finish launching before the logs are actually stored in DB. In my case nothing was stored in DB when I tried to call App Center Api in the OnExit callback. Making Api call async might fix this issue for you. We already have a similar feature request: [MSCrashes] add option to have crash reporting be sync instead of async.

Also regarding the issue that only one error is stored in DB. Actually, I couldn't reproduce it. Could you please share more specific repro steps (without usage of OnExit) or a demo app to help me understand how to achieve such result?

DmitriyKirakosyan avatar Aug 09 '21 14:08 DmitriyKirakosyan

@DmitriyKirakosyan My guess is that it is hard to reproduce because as far as I remember the AppCenter library code does a lot of things async without the possibility to wait until it is actually finished. That is probably why some things are hard to reproduce.

Anyway I had to recreate the test from above on another computer and had to setup everything from scratch. Also the AppCenter app in the cloud. When I wanted to reproduce I was not able to get the test2 crash into the DB at all even after multiple starts and shutdowns. Only after I uncommented test1 I was able to get test2 into the DB. But when I deleted the DB folder I was able to reproduce the same behavior again. So there seems to be also some kind of "initialisation" problem until TrackError is working at all in OnExit. After I got this working again I was able to reproduce also the issue that the very first test2 stayed in the DB with the first timestamp and consecutive test2 errors got not serialized into the DB.

Regarding sending events in OnExit. I think that also in OnExit it should be guaranteed that at least the serialisation into the DB works correct. The rest can be done at the next start if there are concerns. Personally I don't see any reason why also sending shouldn't be done in OnExit. The only real reason probably is that an application should close as fast as possible but that should be possible to solve via async sending and cancellation after it could not be uploaded correctly after an specified amount of time. Same should apply for crashes too. There are error cases in which that will fail but offering at least an option with a changeable amount of time would be what I expect to be a workable solution and I guess that most of the errors could be send already on shutdown/crash when the Internet connection is good enough and no other problems occur which delay or entirely prevent the sending with a nicely enough selected cancellation timeout. Another solution is to delegate this problem to another process which only needs to be started from the terminating program. Probably the nicest solution. Anyway this is far outside the scope of this issue.

ThomasMader avatar Aug 18 '21 17:08 ThomasMader

Hi @ThomasMader

Let me try to summarize the feature you're asking about. In your scenario you would like to have Analytics.TrackEvent be async, so you could await it in OnExit to make sure the event is saved to DB and possibly sent to the backend. In some cases you would want it to save data to DB only, specifically when the app should close fast and avoid waiting for network requests. For this case we may introduce an additional parameter indicating whether we send request immediately or delay it to another thread/frame and it would look like this:

public static async Task<bool> TrackEvent(string name, bool delaySendingRequest = false, IDictionary<string, string> properties = null);

Did I get it correctly?

DmitriyKirakosyan avatar Aug 19 '21 09:08 DmitriyKirakosyan

Yes that is more or less the feature I described but I want to point out that this issue is mainly about TrackError and not TrackEvent. TrackEvent worked always as expected, at least for me. I think that is because TrackEvent waits properly until the serialization is done internally and the same should be done for TrackError. That is the easiest solution to the problem without changing the public API.

Changing or extending the public API is only needed for the advanced feature and outside the scope for this issue in my opinion. But in case you want to continue investigating the advanced feature I want to suggest to change your method example from above. First I would keep the properties as the second parameter. In addition I would not use a bool for enabling the option. Instead an int? cancelSendingAfter (milliseconds) would be better to give the caller the possibility to decide upon the time delay. Using a TimeSpan instead of an int? would also be an option I guess but it seems not worth it for this scenario. See also https://docs.microsoft.com/en-us/dotnet/csharp/programming-guide/concepts/async/cancel-async-tasks-after-a-period-of-time You probably can't use the code from the link because I guess you need to support earlier .NET versions than 5.0 too but it's good as an example.

It would look like this:

public static async Task<bool> TrackEvent(string name, IDictionary<string, string> properties = null, int? cancelSendingAfter = null);

And something similar for TrackError. What is still improvable with this is the naming of the methods. It's not obvious from the naming that also an immediate send is triggered that is why it is probably a good idea to put it into the method name.

e.g.: public static async Task<bool> TrackEventAndTrySend(string name, IDictionary<string, string> properties = null, int? cancelSendingAfter = null);

This way there is also a distinction to the blocking [1] version and it's more clear what each does only by reading the method names. With this separate naming it probably would make more sense to use a non nullable uint for the cancelSendingAfter without default parameter and it should be put as a second parameter instead because the method is explicitly doing just one thing and always triggers a send too. Like:

public static async Task<bool> TrackEventAndTrySend(string name, uint cancelSendingAfter, IDictionary<string, string> properties = null);

[1] public static void TrackEvent(string name, IDictionary<string, string> properties = null);

ThomasMader avatar Aug 20 '21 16:08 ThomasMader

Hi @ThomasMader , thank you for the details and your suggestions. I'm marking it as a feature request.

DmitriyKirakosyan avatar Aug 23 '21 06:08 DmitriyKirakosyan

I have a similar issue with UWP. The app sends TrackEvent right before exiting and it doesn't even make it into the DB.

ppoirier1 avatar Oct 05 '22 20:10 ppoirier1

As we do not have plans to add support for this feature in the next year, I'm closing the issue.

DmitriyKirakosyan avatar Sep 22 '23 06:09 DmitriyKirakosyan

Yes, I need to block the main thread to ensure the upload is complete : Thread.Sleep(10000); If it is closed, is there a better workaround ?

sigmarsson avatar Oct 04 '23 14:10 sigmarsson

Hi @sigmarsson, unfortunately, there's no workaround. However, we greatly appreciate contribution.

DmitriyKirakosyan avatar Oct 04 '23 14:10 DmitriyKirakosyan

@sigmarsson , in my case I just cached the event in local storage before exiting then sent it the next time the app was run

ppoirier1 avatar Oct 04 '23 16:10 ppoirier1

Hello @DmitriyKirakosyan , @ppoirier1

can we not harness these handlers ?

#region Crashes configuration
            Crashes.SendingErrorReport += (sender, e) =>
            {
                // Your code, e.g. to present a custom UI.
            };

            Crashes.SentErrorReport += (sender, e) =>
            {
                // Your code, e.g. to hide the custom UI.
            };

sigmarsson avatar Oct 04 '23 17:10 sigmarsson

My case only dealt with TrackEvent, not crashes.

ppoirier1 avatar Oct 04 '23 22:10 ppoirier1

Crashes.TrackError does not seem to raise those events. Does it on your desks ?

sigmarsson avatar Oct 05 '23 04:10 sigmarsson

can we not harness these handlers ?

@sigmarsson , yes, you can make use of SentErrorReport and exit the app once the callback is called.

DmitriyKirakosyan avatar Oct 05 '23 06:10 DmitriyKirakosyan

how ? it is resulting in a deadlock for me;

        public void PostCrash(Exception e)
        {
            var appCenterReady = new ManualResetEvent(false);

            Crashes.SentErrorReport += (sender, e) =>
            {
                appCenterReady.Set();
            };

            _crashHandler.PostCrash(e);

            appCenterReady.WaitOne();
        }

sigmarsson avatar Oct 05 '23 18:10 sigmarsson

@sigmarsson, I offered a potential approach, but it's not an official solution. The technical implementation is up to you. As mentioned before, the feature won't be added, and there's no alternative method.

DmitriyKirakosyan avatar Oct 06 '23 08:10 DmitriyKirakosyan

Okay, I thought the event is raised upon Crashes.TrackError(e, null, attachments.ToArray()); has finished. You said I could harness that event but when is it raised ?

sigmarsson avatar Oct 06 '23 13:10 sigmarsson

SentErrorReport is called when the error report is successfully sent. See https://github.com/microsoft/appcenter-sdk-dotnet/blob/6965c7f0408d2060f407ef7a6d4fab0e4750147c/SDK/AppCenterCrashes/Microsoft.AppCenter.Crashes.Shared.Windows/Crashes.cs#L457 https://github.com/microsoft/appcenter-sdk-dotnet/blob/6965c7f0408d2060f407ef7a6d4fab0e4750147c/SDK/AppCenter/Microsoft.AppCenter.Shared.Windows/Channel/Channel.cs#L539

If the callback isn't functioning, attempt to replicate the issue in a basic app. Additionally, turn on verbose logging to see the output reports from the App Center SDK.

DmitriyKirakosyan avatar Oct 09 '23 08:10 DmitriyKirakosyan

Sending/SentErrorReport only pertains to a crash - the app crashes/exits and leaves a crash record on the system. The next time the app is run it checks for a previous crash then allows the user to send an error report and uses those callbacks.

The callbacks don't apply to TrackError/TrackEvent, which are just methods for posting analytics. As I mentioned earlier, if you want to use the event tracking APIs reliably you need to cache whatever you want to send to local storage, let the app exit, then send the events/errors the next time the app is run, assuming the app will be active for at least a few seconds.

ppoirier1 avatar Oct 09 '23 16:10 ppoirier1

I am WPF developer, and found this issue happened on version 5.0.3. On 5.0.3, I can not get any callback in these code, But it works on 4.1.0.

Crashes.SentErrorReport += (sender, e) => { if(string.IsNullOrEmpty(e.Report?.StackTrace) == false) LogHelper.WriteLog(Utils.LogLevel.Info,"Sent Appcenter ErrorReport:" + e.Report?.StackTrace); }; Crashes.SendingErrorReport += (sender, e) => { if (string.IsNullOrEmpty(e.Report?.StackTrace) == false) LogHelper.WriteLog(Utils.LogLevel.Info, "Sending Appcenter ErrorReport:" + e.Report?.StackTrace); };

l1o2u3i45s avatar Apr 08 '24 07:04 l1o2u3i45s