Skip to content

Add telemetry to System.Net.NameResolution #38409

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 14 commits into from
Jul 17, 2020

Conversation

MihaZupan
Copy link
Member

@MihaZupan MihaZupan commented Jun 25, 2020

Added 2 counters:

  • dns-lookups-requested - total number of lookups since process started*
  • dns-lookups-duration - EventCounter for min/mean/max duration of requests in the last event counter interval

Added 3 EventSource events:

  • ResolutionStart(hostNameOrAddress)
  • ResolutionStop()
  • ResolutionFailed()

*since telemetry was enabled. This can be changed to since process started by moving the Interlocked.Increment calls outside the IsEnabled() check. That would avoid the race condition mentioned for Net.Http at the cost of an extra Interlocked operation even when telemetry is disabled.

I've manually verified that the counters and events are emitted.

Contributes to #37428

@MihaZupan MihaZupan added this to the 5.0.0 milestone Jun 25, 2020
@MihaZupan MihaZupan requested review from stephentoub, noahfalk, davidsh and a team June 25, 2020 20:04
@ghost
Copy link

ghost commented Jun 25, 2020

Tagging subscribers to this area: @dotnet/ncl
Notify danmosemsft if you want to be subscribed.

@davidsh davidsh requested review from Tratcher and davidfowl June 25, 2020 20:20
@MihaZupan
Copy link
Member Author

/azp run runtime-libraries outerloop

@azure-pipelines
Copy link

Azure Pipelines successfully started running 1 pipeline(s).

// coreTask is not actually a base Task, but Task<IPHostEntry> / Task<IPAddress[]>
// We have to return it and not the continuation
return coreTask;
}
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'd rather this be a separate async method, e.g.

return NameResolutionTelemetry.IsEnabled ?
    WithLogging(hostName, justReturnParsedIp, throwOnIPAny, justAddresses) :
    NameResolutionPal.GetAddrInfoAsync(hostName, justAddresses);

static async Task WithLogging(string hostName, bool ustAddresses)
{
    ValueStopwatch stopwatch = NameResolutionTelemetry.Log.ResolutionStart(hostName);
    bool successful = true;
    try
    {
        await NameResolutionPal.GetAddrInfoAsync(hostName, justAddresses);
    }
    catch
    {
        LogFailure(hostName, stopwatch);
        successful = false;
    }

    NameResolutionTelemetry.Log.AfterResolution(hostName, stopwatch, successful);
}

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ah, I just saw your comment at the end. Ok.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

But NameResolutionPal.GetAddrInfoAsync returns a Task object that is actually Task<IPHostEntry> / Task<IPAddress[]>, so we have to return that task itself

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I suspect you could still do @stephentoub's suggestion by using a generic parameter and evaluating typeof(T) == typeof(IPAddress[]) in place of justAddresses parameter. For example:

class Program
{
    static async Task Main(string[] args)
    {
        await LogDoWork<IPAddress[]>();
        await LogDoWork<IPHostEntry>();
    }

    static Task<T> DoWork<T>()
    {
        Debug.Assert(typeof(T) == typeof(IPAddress[]) ||
                     typeof(T) == typeof(IPHostEntry));
        if (typeof(T) == typeof(IPAddress[]))
        {
            return Unsafe.As<Task<T>>(Task.FromResult(new IPAddress[1]));
        }
        else
        {
            return Unsafe.As<Task<T>>(Task.FromResult(new IPHostEntry()));
        }
    }

    static async Task<T> LogDoWork<T>()
    {
        Console.WriteLine("starting");
        T ret = await DoWork<T>();
        Console.WriteLine("ending:" + ret.GetType());
        return ret;
    }
}

class IPAddress { }
class IPHostEntry { }

I don't mean to push it though, its a style choice that you can feel free to use if you like it.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Unresolving this to make sure the comment I added is visible, resolve again any time

@MihaZupan
Copy link
Member Author

MihaZupan commented Jun 29, 2020

Gist of new changes:

  • Renamed ResolutionStart to ResolutionStarting
  • Made all [Event] methods void-returning
  • Added the IsEnabled(EventLevel.Informational) condition before writing events / fetching the timestamp
  • Only calling ContinueWith and allocating the state if events would be fired (IsEnabled(EventLevel.Informational))
  • Added a comment about ResolutionSuccess and ResolutionFailure signatures having to match
  • Added a comment about the Span WriteEvent overloads mimicking the behavior of string ones

Copy link
Member

@noahfalk noahfalk left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Great to see more telemetry being added : ) A few questions/recommendations inline

// coreTask is not actually a base Task, but Task<IPHostEntry> / Task<IPAddress[]>
// We have to return it and not the continuation
return coreTask;
}
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I suspect you could still do @stephentoub's suggestion by using a generic parameter and evaluating typeof(T) == typeof(IPAddress[]) in place of justAddresses parameter. For example:

class Program
{
    static async Task Main(string[] args)
    {
        await LogDoWork<IPAddress[]>();
        await LogDoWork<IPHostEntry>();
    }

    static Task<T> DoWork<T>()
    {
        Debug.Assert(typeof(T) == typeof(IPAddress[]) ||
                     typeof(T) == typeof(IPHostEntry));
        if (typeof(T) == typeof(IPAddress[]))
        {
            return Unsafe.As<Task<T>>(Task.FromResult(new IPAddress[1]));
        }
        else
        {
            return Unsafe.As<Task<T>>(Task.FromResult(new IPHostEntry()));
        }
    }

    static async Task<T> LogDoWork<T>()
    {
        Console.WriteLine("starting");
        T ret = await DoWork<T>();
        Console.WriteLine("ending:" + ret.GetType());
        return ret;
    }
}

class IPAddress { }
class IPHostEntry { }

I don't mean to push it though, its a style choice that you can feel free to use if you like it.

Copy link
Member

@ManickaP ManickaP left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM, no expert here though, you probably want other approvals as well.

{
name = NameResolutionPal.GetHostName();
}
catch when (LogFailure(stopwatch))
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Nice trick, I like it 😄

Copy link
Contributor

@alnikola alnikola left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Overall looks good, but please fix IsEnabled checks.

@MihaZupan
Copy link
Member Author

/azp run runtime-libraries outerloop

@azure-pipelines
Copy link

Azure Pipelines successfully started running 1 pipeline(s).

@MihaZupan
Copy link
Member Author

@brianrob You requested changes, I believe they were addressed. If so, please approve so that the PR can be merged.

Copy link
Member

@brianrob brianrob left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM, thanks!

@MihaZupan
Copy link
Member Author

/azp run runtime-libraries outerloop

@azure-pipelines
Copy link

Azure Pipelines successfully started running 1 pipeline(s).

@MihaZupan
Copy link
Member Author

/azp run runtime-libraries outerloop

@azure-pipelines
Copy link

Azure Pipelines successfully started running 1 pipeline(s).

@MihaZupan
Copy link
Member Author

Failure: #37540

@MihaZupan MihaZupan merged commit 940c49e into dotnet:master Jul 17, 2020
@ghost ghost locked as resolved and limited conversation to collaborators Dec 8, 2020
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

Successfully merging this pull request may close these issues.

8 participants