3

I've been noticing this exception in the CloudWatch logs for an AWS Lambda.

Everything seems to get processed so I think it is an exception within the AWS code (as opposed to something I've written) that is created after the Lambda has finished executing.

Since functionally it works I've been ignoring it but I'm concerned that there might be problems that I haven't noticed.


Lambda encountered an UnobservedTaskException via 'TaskScheduler.UnobservedTaskException' event:

{
    "errorType": "AggregateException",
    "errorMessage": "A Task's exception(s) were not observed either by Waiting on the Task or accessing its Exception property. As a result, the unobserved exception was rethrown by the finalizer thread. (Cannot access a disposed object.\nObject name: 'System.Net.Sockets.UdpClient'.)",
    "cause": {
        "errorType": "ObjectDisposedException",
        "errorMessage": "Cannot access a disposed object.\nObject name: 'System.Net.Sockets.UdpClient'.",
        "stackTrace": [
            "at System.Net.Sockets.UdpClient.EndReceive(IAsyncResult asyncResult, IPEndPoint& remoteEP)",
            "at System.Net.Sockets.UdpClient.<>c.<ReceiveAsync>b__56_1(IAsyncResult asyncResult)",
            "at System.Threading.Tasks.TaskFactory`1.FromAsyncCoreLogic(IAsyncResult iar, Func`2 endFunction, Action`1 endAction, Task`1 promise, Boolean requiresSynchronization)"
        ]
    },
    "causes": [ {
        "errorType": "ObjectDisposedException",
        "errorMessage": "Cannot access a disposed object.\nObject name: 'System.Net.Sockets.UdpClient'.",
        "stackTrace": [
            "at System.Net.Sockets.UdpClient.EndReceive(IAsyncResult asyncResult, IPEndPoint& remoteEP)",
            "at System.Net.Sockets.UdpClient.<>c.<ReceiveAsync>b__56_1(IAsyncResult asyncResult)",
            "at System.Threading.Tasks.TaskFactory`1.FromAsyncCoreLogic(IAsyncResult iar, Func`2 endFunction, Action`1 endAction, Task`1 promise, Boolean requiresSynchronization)"
        ]
    }]
}

The lambda code is pretty simple: It adds these SNS messages into an SQL database using Dapper.

I'm thinking that there might be some problem with how I'm doing async in the Fucntion handler. Any ideas?

public class Function
{
    private static string _connectionString;

    public async Task<IEnumerable<InsertSnsResult>> FunctionHandler(SNSEvent @event, ILambdaContext context)
    {
        try
        {
            context.Logger.LogLine("Adding SNS Messages");
            _connectionString = _connectionString ?? await DecryptHelper.DecryptEnvironmentVariableAsync("ConnectionString").ConfigureAwait(false);
            var handler = new AddSnsMessageHandler(new SnsMessagesRepository(_connectionString, context.Logger));
            return await handler.AddSnsEvents(@event).ConfigureAwait(false);
        }
        catch (Exception e)
        {
            context.Logger.LogLine(e.Message);
            throw;
        }
        finally
        {
            context.Logger.LogLine("Finished SNS Adding Messages");
        }
    }
}

[Edit]

Just be clear here, this exception does not get caught in the try/catch block. If it did it wouldn't be an UnobservedTaskException. That's why I'm having trouble getting to the root of the problem.

And this is the repository code

public async Task<List<InsertSnsResult>> InsertSnsMessages(IEnumerable<SnsEvent> records)
{
    using (var connection = new SqlConnection(_connectionString))
    {
        await connection.OpenAsync().ConfigureAwait(false);

        var results = new List<InsertSnsResult>();
        foreach (var record in records)
        {
            try
            {
                await connection.ExecuteAsync(InsertEventCommand, record).ConfigureAwait(false);
                results.Add(new InsertSnsResult(record.CorrelationId, true));
            }
            catch (Exception ex)
            {
                _logger.LogLine($"InsertSns failed for {record.Id}. {ex.Message}");
                results.Add(new InsertSnsResult(record.CorrelationId, false));
            }
        }

        return results;
    }            
}
John
  • 1,286
  • 2
  • 14
  • 22
  • Aside from your code, `"Finished SNS Adding Messages"` seems a bit of a misleading message: it sounds like a success, but isn't necessarily. I know the preceding message (error, or nothing) should indicate if it's a success or failure, but it still seems like it could be worded better. – ProgrammingLlama Sep 10 '18 at 01:38
  • Is `SnsMessagesRepository` from an external library or part of your own code? – ProgrammingLlama Sep 10 '18 at 01:39
  • Possibly related to: https://github.com/dotnet/corefx/issues/14638 – Parrish Husband Sep 10 '18 at 01:52
  • @John I've added the repository function to my question. – John Sep 11 '18 at 01:19
  • @ParrishHusband That's pretty interesting. The lambda is on .NET Core 2.1 so that shouldn't be the problem... – John Sep 11 '18 at 01:19

2 Answers2

5

The log messages are straightforward and explain what is happening:

  • You have an asynchronous task
  • That asynchronous task is accessing an object that has already been disposed, probably because you have some race condition in your workflow whereby an object in the asynchronous workflow is disposed out-of-order with another portion of the workflow that needs it. This means something is seriously broken in this workflow.
  • The asynchronous task is never waited on, either asynchronously with await, or (don't do this!) synchronously with Result or Wait. That means that the exceptional continuation path is never taken, and the task notices this when it is collected. Again, something is probably seriously broken in your workflow if you have a task that you never wait for the result. Combine this fact with the fact from the previous point: we now have two pieces of evidence that reinforce each other that there is something seriously broken in this workflow and that it involves a task that is not awaited when it should be to ensure an ordering constraint.
  • And therefore you get an exception on your finalizer thread, which is really bad.

Since functionally it works I've been ignoring it

I heard once that when a factory catches fire and burns to the ground, on average there were seven different safety systems that people ignored or disabled. Get out of this habit of thinking that it works, so it must be safe. Maybe it's nothing but I would consider these messages to be indicative of a serious problem until I had evidence otherwise.

Eric Lippert
  • 647,829
  • 179
  • 1,238
  • 2,067
  • 1
    @John: I'm not sure how that fact pertains to your question. You asked if there's a concern here; I'm telling you that you are right to be concerned, and that you should assume that something is broken until you've run it down, thoroughly analyzed the situation, and determined that the code is safe **and that it will continue to be safe if it is modified**. The fact that you're using someone else's possibly buggy broken code makes your job of dealing with it *harder*, I agree, but it doesn't make the buggy broken code not your *problem* to deal with. – Eric Lippert Sep 12 '18 at 18:16
  • I should have clarified. It seems to be coming from either the .NET Core libraries or the AWS SDK libraries. Not some buggy third party library. You said that it was something wrong it my workflow, it being from the core libraries means that it is difficult for me to do anything. I am looking for some specific advice related to this problem as it occurs for a .NET Core application running in a lambda. Not for generic advice on how to write async code. – John Sep 13 '18 at 00:52
0

I too have run into a place where I have a 3rd party library causing errors. I wanted log it outside of CloudWatch. In order to prevent Lambda from logging these I was able to do some evil reflection to reset the event handler.

Here is the code to do this yourself. Please note this is evil code. It is fragile and will break when code is changed in the CLR or even if the compiler does optimizations (which recently happened). However, it was the only way I could find to opt-out of this functionality provided by Lambda

private void ReplaceLambdaDefaultUnobservedTaskException()
{
    try
    {
        var bindingFlags = BindingFlags.NonPublic | BindingFlags.Static;
        Type type = typeof(TaskScheduler);

        var field = type.GetField("_unobservedTaskException", bindingFlags);

        if (field == null)
        {
            field = type.GetField("UnobservedTaskException", bindingFlags);
        }

        var handler = new EventHandler<UnobservedTaskExceptionEventArgs>(TaskSchedulerOnUnobservedTaskException);
        field.SetValue(null, handler);
    }
    catch (Exception ex)
    {
        logger.Warning(ex, "Unable to do evil reflection.");
    }

    TaskScheduler.UnobservedTaskException += TaskSchedulerOnUnobservedTaskException;
}

private void TaskSchedulerOnUnobservedTaskException(object sender, UnobservedTaskExceptionEventArgs e)
{
    e.SetObserved();
    logger.Error(e.Exception, "Lambda threw an UnobservedTaskException");
}
brianfeucht
  • 774
  • 8
  • 21