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.

Sign up for GitHub

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
MihaZupan merged 14 commits into from
Jul 17, 2020
Merged

Add telemetry to System.Net.NameResolution #38409

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
14 commits
Select commit Hold shift + click to select a range
d4bc0df
Add telemetry to System.Net.NameResolution
MihaZupan Jun 25, 2020
1d29ced
Rename hostName to hostNameOrAddress
MihaZupan Jun 25, 2020
0646d45
Use constants for event IDs
MihaZupan Jun 25, 2020
ae6eb2a
Address PR feedback
MihaZupan Jun 29, 2020
1f5dcff
Reduce overhead when only the counter is needed
MihaZupan Jun 29, 2020
43e96ff
Merge branch 'master' into telemetry-dns
MihaZupan Jul 2, 2020
e70461c
Make NameResolution Telemetry an activity
MihaZupan Jul 2, 2020
ed0d693
Remove redundant check
MihaZupan Jul 4, 2020
e2a563a
Fix indentation
MihaZupan Jul 4, 2020
88aa1e9
Merge master
MihaZupan Jul 13, 2020
baa8685
Check IsEnabled before AfterResolution to help linker
MihaZupan Jul 13, 2020
7736192
Add Telemetry tests
MihaZupan Jul 14, 2020
d434348
Merge master
MihaZupan Jul 14, 2020
3ecd713
Throws => ThrowsAny
MihaZupan Jul 14, 2020
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
3 changes: 3 additions & 0 deletions src/libraries/System.Net.NameResolution/src/System.Net.NameResolution.csproj
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -13,13 +13,16 @@
<Compile Include="System\Net\Dns.cs" />
<Compile Include="System\Net\IPHostEntry.cs" />
<Compile Include="System\Net\NetEventSource.NameResolution.cs" />
<Compile Include="System\Net\NameResolutionTelemetry.cs" />
<!-- Logging -->
<Compile Include="$(CommonPath)System\Net\Logging\NetEventSource.Common.cs"
Link="Common\System\Net\Logging\NetEventSource.Common.cs" />
<Compile Include="$(CommonPath)System\Net\InternalException.cs"
Link="Common\System\Net\InternalException.cs" />
<Compile Include="$(CommonPath)System\Threading\Tasks\TaskToApm.cs"
Link="Common\System\Threading\Tasks\TaskToApm.cs" />
<Compile Include="$(CommonPath)Extensions\ValueStopwatch\ValueStopwatch.cs"
Link="Common\Extensions\ValueStopwatch\ValueStopwatch.cs" />
<!-- System.Net common -->
<Compile Include="$(CommonPath)System\Net\Sockets\ProtocolType.cs"
Link="Common\System\Net\Sockets\ProtocolType.cs" />
Expand Down
170 changes: 139 additions & 31 deletions src/libraries/System.Net.NameResolution/src/System/Net/Dns.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,11 +1,13 @@
// Licensed to the .NET Foundation under one or more agreements.
// The .NET Foundation licenses this file to you under the MIT license.

using System.Diagnostics;
using System.Globalization;
using System.Net.Internals;
using System.Net.Sockets;
using System.Threading;
using System.Threading.Tasks;
using Microsoft.Extensions.Internal;

namespace System.Net
{
Expand All @@ -17,7 +19,22 @@ public static string GetHostName()
{
NameResolutionPal.EnsureSocketsAreInitialized();

string name = NameResolutionPal.GetHostName();
ValueStopwatch stopwatch = NameResolutionTelemetry.Log.BeforeResolution(string.Empty);

string name;
try
{
name = NameResolutionPal.GetHostName();
}
catch when (LogFailure(stopwatch))

@ManickaP ManickaP Jul 3, 2020

Copy link
Copy Markdown
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 😄

{
Debug.Fail("LogFailure should return false");
throw;
}

if (NameResolutionTelemetry.Log.IsEnabled())
NameResolutionTelemetry.Log.AfterResolution(stopwatch, successful: true);

if (NetEventSource.Log.IsEnabled()) NetEventSource.Info(null, name);
return name;
}
Expand Down Expand Up @@ -293,22 +310,36 @@ private static object GetHostEntryOrAddressesCore(string hostName, bool justAddr
{
ValidateHostName(hostName);

SocketError errorCode = NameResolutionPal.TryGetAddrInfo(hostName, justAddresses, out string? newHostName, out string[] aliases, out IPAddress[] addresses, out int nativeErrorCode);
ValueStopwatch stopwatch = NameResolutionTelemetry.Log.BeforeResolution(hostName);

if (errorCode != SocketError.Success)
object result;
try
{
if (NetEventSource.Log.IsEnabled()) NetEventSource.Error(hostName, $"{hostName} DNS lookup failed with {errorCode}");
throw SocketExceptionFactory.CreateSocketException(errorCode, nativeErrorCode);
}
SocketError errorCode = NameResolutionPal.TryGetAddrInfo(hostName, justAddresses, out string? newHostName, out string[] aliases, out IPAddress[] addresses, out int nativeErrorCode);

object result = justAddresses ? (object)
addresses :
new IPHostEntry
if (errorCode != SocketError.Success)
{
AddressList = addresses,
HostName = newHostName!,
Aliases = aliases
};
if (NetEventSource.Log.IsEnabled()) NetEventSource.Error(hostName, $"{hostName} DNS lookup failed with {errorCode}");
throw SocketExceptionFactory.CreateSocketException(errorCode, nativeErrorCode);
}

result = justAddresses ? (object)
addresses :
new IPHostEntry
{
AddressList = addresses,
HostName = newHostName!,
Aliases = aliases
};
}
catch when (LogFailure(stopwatch))
{
Debug.Fail("LogFailure should return false");
throw;
}

if (NameResolutionTelemetry.Log.IsEnabled())
NameResolutionTelemetry.Log.AfterResolution(stopwatch, successful: true);

return result;
}
Expand All @@ -327,37 +358,70 @@ private static object GetHostEntryOrAddressesCore(IPAddress address, bool justAd
// will only return that address and not the full list.

// Do a reverse lookup to get the host name.
string? name = NameResolutionPal.TryGetNameInfo(address, out SocketError errorCode, out int nativeErrorCode);
if (errorCode != SocketError.Success)
ValueStopwatch stopwatch = NameResolutionTelemetry.Log.BeforeResolution(address);

SocketError errorCode;
string? name;
try
{
name = NameResolutionPal.TryGetNameInfo(address, out errorCode, out int nativeErrorCode);
if (errorCode != SocketError.Success)
{
if (NetEventSource.Log.IsEnabled()) NetEventSource.Error(address, $"{address} DNS lookup failed with {errorCode}");
throw SocketExceptionFactory.CreateSocketException(errorCode, nativeErrorCode);
}
Debug.Assert(name != null);
}
catch when (LogFailure(stopwatch))
{
Debug.Fail("LogFailure should return false");
throw;
}

if (NameResolutionTelemetry.Log.IsEnabled())
{
if (NetEventSource.Log.IsEnabled()) NetEventSource.Error(address, $"{address} DNS lookup failed with {errorCode}");
throw SocketExceptionFactory.CreateSocketException(errorCode, nativeErrorCode);
NameResolutionTelemetry.Log.AfterResolution(stopwatch, successful: true);

// Do the forward lookup to get the IPs for that host name
stopwatch = NameResolutionTelemetry.Log.BeforeResolution(name);
}

// Do the forward lookup to get the IPs for that host name
errorCode = NameResolutionPal.TryGetAddrInfo(name!, justAddresses, out string? hostName, out string[] aliases, out IPAddress[] addresses, out nativeErrorCode);
object result;
try
{
errorCode = NameResolutionPal.TryGetAddrInfo(name, justAddresses, out string? hostName, out string[] aliases, out IPAddress[] addresses, out int nativeErrorCode);

if (errorCode != SocketError.Success)
{
if (NetEventSource.Log.IsEnabled()) NetEventSource.Error(address, $"forward lookup for '{name}' failed with {errorCode}");
}

if (errorCode != SocketError.Success)
result = justAddresses ?
(object)addresses :
new IPHostEntry
{
HostName = hostName!,
Aliases = aliases,
AddressList = addresses
};
}
catch when (LogFailure(stopwatch))
{
if (NetEventSource.Log.IsEnabled()) NetEventSource.Error(address, $"forward lookup for '{name}' failed with {errorCode}");
Debug.Fail("LogFailure should return false");
throw;
}

if (NameResolutionTelemetry.Log.IsEnabled())
NameResolutionTelemetry.Log.AfterResolution(stopwatch, successful: true);

// One of three things happened:
// 1. Success.
// 2. There was a ptr record in dns, but not a corollary A/AAA record.
// 3. The IP was a local (non-loopback) IP that resolved to a connection specific dns suffix.
// - Workaround, Check "Use this connection's dns suffix in dns registration" on that network
// adapter's advanced dns settings.
// Return whatever we got.

return justAddresses ?
(object)addresses :
new IPHostEntry
{
HostName = hostName!,
Aliases = aliases,
AddressList = addresses
};
return result;
}

private static Task<IPHostEntry> GetHostEntryCoreAsync(string hostName, bool justReturnParsedIp, bool throwOnIIPAny) =>
Expand Down Expand Up @@ -399,7 +463,42 @@ private static Task GetHostEntryOrAddressesCoreAsync(string hostName, bool justR
if (NameResolutionPal.SupportsGetAddrInfoAsync && ipAddress is null)
{
ValidateHostName(hostName);
return NameResolutionPal.GetAddrInfoAsync(hostName, justAddresses);

if (NameResolutionTelemetry.Log.IsEnabled())
{
ValueStopwatch stopwatch = NameResolutionTelemetry.Log.BeforeResolution(hostName);

Task coreTask;
try
{
coreTask = NameResolutionPal.GetAddrInfoAsync(hostName, justAddresses);
}
catch when (LogFailure(stopwatch))
{
Debug.Fail("LogFailure should return false");
throw;
}

coreTask.ContinueWith(
Comment thread
MihaZupan marked this conversation as resolved.
(task, state) =>
{
NameResolutionTelemetry.Log.AfterResolution(
stopwatch: (ValueStopwatch)state!,
successful: task.IsCompletedSuccessfully);
},
state: stopwatch,
cancellationToken: default,
TaskContinuationOptions.ExecuteSynchronously,
TaskScheduler.Default);

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

@stephentoub stephentoub Jun 25, 2020

Copy link
Copy Markdown
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);
}

@stephentoub stephentoub Jun 25, 2020

Copy link
Copy Markdown
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.

@MihaZupan MihaZupan Jun 25, 2020

Copy link
Copy Markdown
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

@noahfalk noahfalk Jun 27, 2020

Copy link
Copy Markdown
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.

@noahfalk noahfalk Jul 2, 2020

Copy link
Copy Markdown
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

else
{
return NameResolutionPal.GetAddrInfoAsync(hostName, justAddresses);
}
}

return justAddresses ? (Task)
Expand Down Expand Up @@ -429,5 +528,14 @@ private static void ValidateHostName(string hostName)
SR.Format(SR.net_toolong, nameof(hostName), MaxHostName.ToString(NumberFormatInfo.CurrentInfo)));
}
}


private static bool LogFailure(ValueStopwatch stopwatch)
{
if (NameResolutionTelemetry.Log.IsEnabled())
NameResolutionTelemetry.Log.AfterResolution(stopwatch, successful: false);

return false;
}
}
}
Loading