2

I'm just profiling a UWP application running on a device trying to diagnose an observed memory leak.

Using snapshots, I've observed that I have a growing number of Task objects, which seem to be created from an internal component which raises logging events.

Here is a screenshot of a compared snapshot and the object that appears to be leaking.

Memory snapshot Path to root

I have two event listeners bound to OnLogReceived; they look like this:

ApplicationContext.Current.LoggerContext.OnLogReceived += LoggerContext_OnLogReceived;
ApplicationContext.Current.LoggerContext.OnLogReceived += (logLevel, timestamp, message) => RemoteLogHelper.SendMessage(logLevel, message);

Here is the definition of first handler. This displays the log in a scrolling viewer on the screen and truncates the entries to 1000. The LogEntryModel implements INotifyPropertyChanged via ViewModelBase to avoid leaking PropertyChanged.

private async void LoggerContext_OnLogReceived(LogLevel logLevel, DateTime timestamp, string message)
    {
        await Dispatcher.RunAsync(Windows.UI.Core.CoreDispatcherPriority.Normal, () =>
        {
            var entry = new LogEntryModel
            {
                Message = string.Format("[{0:h:mm:ss tt}] {1}", timestamp, message)
            };
            entry.SetDispatcher(ApplicationContext.Current.Dispatcher);

            lock (ApplicationContext.Current.ReceiverDetails.Log)
            {
                ApplicationContext.Current.ReceiverDetails.Log.Add(entry);

                while (ApplicationContext.Current.ReceiverDetails.Log.Count > 1000)
                {
                    ApplicationContext.Current.ReceiverDetails.Log.RemoveAt(0);
                }
            }

            if (!uxPreventLogFromScrolling.IsChecked ?? false)
            {
                LogScrollViewer.ChangeView(0.0d, double.MaxValue, 1.0f);
            }
        });
    }

And the send message handler (2) This sends the log lines to a remote API (if remote logging is enabled for this device) for debugging purposes. We want this to be fire & forget, meaning we don't want to wait around for the log to be successfully sent to the endpoint.

public static async void SendMessage(LogLevel logLevel, string message)
    {
        if (!IsEnabled())
            return;

        await Task.Run(() =>
        {
            try
            {
                ApplicationContext.Current.ApiClient.PostAsync<LogRequestModel, object>("/api/remote/receiver/log", new LogRequestModel { MacAddress = MacAddress, Text = message });
            }
            catch (Exception)
            {
                ; // we tried
            }
        });
    }

Changing this method to the following definition does not change the behavour (still showing a similar snapshot result)

public static async void SendMessage(LogLevel logLevel, string message)
    {
        if (!IsEnabled())
            return;

        try
        {
            await ApplicationContext.Current.ApiClient.PostAsync<LogRequestModel, object>("/api/remote/receiver/log", new LogRequestModel { MacAddress = MacAddress, Text = message });
        }
        catch (Exception)
        {
            ; // we tried
        }

    }

Can anyone pinpoint why this is leaking and how I avoid it? From research, I don't think I need to dispose the tasks and everything here looks like it should be getting cleaned up automatically on completion. However I can definitly see the memory usage growing and the snapshots confirm this.

agrath
  • 901
  • 1
  • 11
  • 25
  • I would suggest using a memory profiler that can trace the instances of `Task` back to a GC root. Something is holding a reference to them and you need to find out what that is. – Zer0 Nov 22 '16 at 23:29
  • It would seem that those tasks are being blocked at the locking mechanism, preventing them from being disposed. I think the likely culprit is a deadlock in the LoggerContext_OnLogReceived. A peculiar line of code sticks out to me in the SendMessage method as well as ApiClient.PostAsync says it is asynchronous, yet it's being ran in a Task.Run() call. Does this method not return a Task? If it does and it's executing a hot task, I'm not sure how Task.Run handles that as it's expecting the work to actually finish. – davidallyoung Nov 22 '16 at 23:53
  • @Zer0 the screengrab of snapshot appears to show the path to root for that Task if that helps – agrath Nov 23 '16 at 00:17
  • @DavidY the ApiClient.PostAsync does indeed return Task (but it's intentionally not awaited). This block was my most likely culprit too, but I am not sure how to call an async method which I don't care for the result of. The snapshot seems to indicate it is a Task that is leaking though. – agrath Nov 23 '16 at 00:19
  • @Zer0 I have added an additional screenshot showing the full path to root for the object that appears to be leaking – agrath Nov 23 '16 at 00:26
  • You can still await the Task even though you don't care about the result. Give that a try. – davidallyoung Nov 23 '16 at 00:42
  • @DavidY am I right in assuming that if I await it, then it becomes blocking and the call to SendMessage will block until the PostAsync method completes (which is calling a remote API so can be slow)? – agrath Nov 23 '16 at 00:43
  • @agrath Yes, an `await` will change functionality significantly. The method that uses `await` will not continue until the `Task` completes. – Zer0 Nov 23 '16 at 01:06
  • @agrath I do see the path now - just used to a more clear visual graph myself. Should be all the info you need to resolve the leak. It's literally showing you what is holding the references. I also agree with DavidY. Are you sure these tasks are completing? Worth looking into. You could add a continuation to these tasks to see if they are completing correctly. – Zer0 Nov 23 '16 at 01:11
  • @DavidY No dice, i've updated the question with the replaced function body for SendMessage (removing the additional Task.Run and await'ing PostAsync) – agrath Nov 23 '16 at 01:21
  • `ApplicationContext` is NOT supported in UWP app, yet you're saying that you're developing an UWP app. Assume that you've create a class named this and seems like you put some static method inside it, but with `HttpClient` for `PostAsync`, there could be possibilities which can cause memory leaks due to different reasons. Since you've narrowed down to your `SendMessage`, I suggest that wrapping your `PostAsync` with `using`. – Grace Feng Nov 23 '16 at 05:42

1 Answers1

1

Documenting the answer here in case someone else runs into this. We used .ContinueWith to prevent leaking the task

Source: http://stackoverflow.com/a/15524271/647728

    public static void SendMessage(LogLevel logLevel, string message)
    {
        if (!IsEnabled())
            return;

        //http://stackoverflow.com/a/15524271/647728
        ApplicationContext.Current.ApiClient.PostAsync<LogRequestModel, object>("/api/remote/receiver/log", new LogRequestModel { MacAddress = MacAddress, Text = message }).ContinueWith(t => { }, TaskContinuationOptions.OnlyOnFaulted);

    }

}

agrath
  • 901
  • 1
  • 11
  • 25
  • I don't quite understand why your 2nd SendMessage above was leaking. I thought `await` would unroll the exceptions to be caught properly. What am I missing? – Joe Phillips Jul 02 '18 at 03:05
  • @JoePhillips neither. We never got to the bottom of _why_ it leaked, only that it did, until we used ContinueWith to ensure completion of the task – agrath Jul 02 '18 at 03:48