Skip to content
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

Add tracing to the Linux X509Chain implementation #65860

Merged
merged 5 commits into from
Mar 16, 2022
Merged
Show file tree
Hide file tree
Changes from 4 commits
Commits
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
Original file line number Diff line number Diff line change
Expand Up @@ -823,6 +823,7 @@
<Compile Include="System\Security\Cryptography\X509Certificates\OpenSslPkcs12Reader.cs" />
<Compile Include="System\Security\Cryptography\X509Certificates\OpenSslSingleCertLoader.cs" />
<Compile Include="System\Security\Cryptography\X509Certificates\OpenSslX509CertificateReader.cs" />
<Compile Include="System\Security\Cryptography\X509Certificates\OpenSslX509ChainEventSource.cs" />
<Compile Include="System\Security\Cryptography\X509Certificates\OpenSslX509ChainProcessor.cs" />
<Compile Include="System\Security\Cryptography\X509Certificates\OpenSslX509Encoder.cs" />
<Compile Include="System\Security\Cryptography\X509Certificates\StorePal.OpenSsl.cs" />
Expand Down Expand Up @@ -1789,6 +1790,7 @@
<Reference Include="System.Collections" />
<Reference Include="System.Collections.Concurrent" />
<Reference Include="System.Collections.NonGeneric" />
<Reference Include="System.Diagnostics.Tracing" />
<Reference Include="System.Diagnostics.StackTrace" />
<Reference Include="System.Formats.Asn1" />
<Reference Include="System.Memory" />
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -38,6 +38,44 @@ public static void FlushStores()
DateTime verificationTime,
TimeSpan timeout,
bool disableAia)
{
OpenSslX509ChainEventSource.Log.ChainStart();

try
{
return BuildChainCore(
useMachineContext,
cert,
extraStore,
applicationPolicy,
certificatePolicy,
revocationMode,
revocationFlag,
customTrustStore,
trustMode,
verificationTime,
timeout,
disableAia);
}
finally
{
OpenSslX509ChainEventSource.Log.ChainStop();
}
}

private static IChainPal? BuildChainCore(
bool useMachineContext,
ICertificatePal cert,
X509Certificate2Collection? extraStore,
OidCollection? applicationPolicy,
OidCollection? certificatePolicy,
X509RevocationMode revocationMode,
X509RevocationFlag revocationFlag,
X509Certificate2Collection? customTrustStore,
X509ChainTrustMode trustMode,
DateTime verificationTime,
TimeSpan timeout,
bool disableAia)
{
if (timeout == TimeSpan.Zero)
{
Expand Down Expand Up @@ -76,33 +114,45 @@ public static void FlushStores()
downloadTimeout);

Interop.Crypto.X509VerifyStatusCode status = chainPal.FindFirstChain(extraStore);
OpenSslX509ChainEventSource.Log.FindFirstChainFinished(status);

if (!OpenSslX509ChainProcessor.IsCompleteChain(status) && !disableAia)
if (!OpenSslX509ChainProcessor.IsCompleteChain(status))
{
List<X509Certificate2>? tmp = null;
status = chainPal.FindChainViaAia(ref tmp);

if (tmp != null)
if (disableAia)
{
if (status == Interop.Crypto.X509VerifyStatusCode.X509_V_OK)
{
SaveIntermediateCertificates(tmp);
}
OpenSslX509ChainEventSource.Log.AiaDisabled();
}
else
{
List<X509Certificate2>? tmp = null;
status = chainPal.FindChainViaAia(ref tmp);
OpenSslX509ChainEventSource.Log.FindChainViaAiaFinished(status, tmp?.Count ?? 0);

foreach (X509Certificate2 downloaded in tmp)
if (tmp != null)
{
downloaded.Dispose();
if (status == Interop.Crypto.X509VerifyStatusCode.X509_V_OK)
{
SaveIntermediateCertificates(tmp);
}

foreach (X509Certificate2 downloaded in tmp)
{
downloaded.Dispose();
}
}
}
}

// In NoCheck+OK then we don't need to build the chain any more, we already
// know it's error-free. So skip straight to finish.
if (status != Interop.Crypto.X509VerifyStatusCode.X509_V_OK ||
revocationMode != X509RevocationMode.NoCheck)
if (revocationMode != X509RevocationMode.NoCheck)
{
if (OpenSslX509ChainProcessor.IsCompleteChain(status))
{
if (status != Interop.Crypto.X509VerifyStatusCode.X509_V_OK)
{
OpenSslX509ChainEventSource.Log.UntrustedChainWithRevocation();
revocationMode = X509RevocationMode.NoCheck;
}

chainPal.CommitToChain();
chainPal.ProcessRevocation(revocationMode, revocationFlag);
}
Expand Down Expand Up @@ -132,18 +182,21 @@ private static void SaveIntermediateCertificates(List<X509Certificate2> download
catch (CryptographicException)
{
// Saving is opportunistic, just ignore failures
OpenSslX509ChainEventSource.Log.CouldNotOpenCAStore();
return;
}

foreach (X509Certificate2 cert in downloadedCerts)
{
try
{
OpenSslX509ChainEventSource.Log.CachingIntermediate(cert);
userIntermediate.Add(cert);
}
catch
{
// Saving is opportunistic, just ignore failures
OpenSslX509ChainEventSource.Log.CachingIntermediateFailed(cert);
}
}
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -31,6 +31,7 @@ internal static class OpenSslCertificateAssetDownloader
}
catch (CryptographicException)
{
OpenSslX509ChainEventSource.Log.InvalidDownloadedCertificate();
vcsjones marked this conversation as resolved.
Show resolved Hide resolved
return null;
}
}
Expand Down Expand Up @@ -70,6 +71,7 @@ internal static class OpenSslCertificateAssetDownloader
}
}

OpenSslX509ChainEventSource.Log.InvalidDownloadedCrl();
return null;
}

Expand All @@ -91,27 +93,42 @@ internal static class OpenSslCertificateAssetDownloader
// We're not going to report this error to a user, so clear it
// (to avoid tainting future exceptions)
Interop.Crypto.ErrClearError();
OpenSslX509ChainEventSource.Log.InvalidDownloadedOcsp();
}

return resp;
}

private static byte[]? DownloadAsset(string uri, TimeSpan downloadTimeout)
{
if (s_downloadBytes != null && downloadTimeout > TimeSpan.Zero)
if (s_downloadBytes is null)
{
long totalMillis = (long)downloadTimeout.TotalMilliseconds;
CancellationTokenSource? cts = totalMillis > int.MaxValue ? null : new CancellationTokenSource((int)totalMillis);
OpenSslX509ChainEventSource.Log.HttpClientNotAvailable();
return null;
}

try
{
return s_downloadBytes(uri, cts?.Token ?? default);
}
catch { }
finally
{
cts?.Dispose();
}
if (downloadTimeout <= TimeSpan.Zero)
{
OpenSslX509ChainEventSource.Log.DownloadTimeExceeded();
return null;
}

long totalMillis = (long)downloadTimeout.TotalMilliseconds;
OpenSslX509ChainEventSource.Log.AssetDownloadStart(totalMillis, uri);

CancellationTokenSource? cts = totalMillis > int.MaxValue ? null : new CancellationTokenSource((int)totalMillis);
byte[]? ret = null;

try
{
ret = s_downloadBytes(uri, cts?.Token ?? default);
return ret;
}
catch { }
vcsjones marked this conversation as resolved.
Show resolved Hide resolved
finally
{
cts?.Dispose();
OpenSslX509ChainEventSource.Log.AssetDownloadStop(ret?.Length ?? 0);
}

return null;
Expand Down Expand Up @@ -214,9 +231,12 @@ internal static class OpenSslCertificateAssetDownloader
redirections++;
if (redirections > MaxRedirections)
{
OpenSslX509ChainEventSource.Log.DownloadRedirectsExceeded();
return null;
}

OpenSslX509ChainEventSource.Log.DownloadRedirected(redirectUri);

// Equivalent of:
// requestMessage = new HttpRequestMessage() { RequestUri = redirectUri };
// requestMessage.RequestUri = redirectUri;
Expand Down Expand Up @@ -284,6 +304,7 @@ internal static class OpenSslCertificateAssetDownloader

if (!IsAllowedScheme(location.Scheme))
{
OpenSslX509ChainEventSource.Log.DownloadRedirectNotFollowed(location);
return null;
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -47,6 +47,7 @@ public static void AddCrlForCertificate(
}

string crlFileName = GetCrlFileName(cert, url);
OpenSslX509ChainEventSource.Log.CrlIdentifiersDetermined(cert, url, crlFileName);

if (AddCachedCrl(crlFileName, store, verificationTime))
{
Expand All @@ -56,6 +57,7 @@ public static void AddCrlForCertificate(
// Don't do any work if we're prohibited from fetching new CRLs
if (revocationMode != X509RevocationMode.Online)
{
OpenSslX509ChainEventSource.Log.CrlCheckOffline();
return;
}

Expand All @@ -65,11 +67,25 @@ public static void AddCrlForCertificate(
private static bool AddCachedCrl(string crlFileName, SafeX509StoreHandle store, DateTime verificationTime)
{
string crlFile = GetCachedCrlPath(crlFileName);
OpenSslX509ChainEventSource.Log.CrlCacheCheckStart();

try
{
return AddCachedCrlCore(crlFile, store, verificationTime);
}
finally
{
OpenSslX509ChainEventSource.Log.CrlCacheCheckStop();
}
}

private static bool AddCachedCrlCore(string crlFile, SafeX509StoreHandle store, DateTime verificationTime)
{
using (SafeBioHandle bio = Interop.Crypto.BioNewFile(crlFile, "rb"))
{
if (bio.IsInvalid)
{
OpenSslX509ChainEventSource.Log.CrlCacheOpenError();
Interop.Crypto.ErrClearError();
return false;
}
Expand All @@ -80,6 +96,7 @@ private static bool AddCachedCrl(string crlFileName, SafeX509StoreHandle store,
{
if (crl.IsInvalid)
{
OpenSslX509ChainEventSource.Log.CrlCacheDecodeError();
Interop.Crypto.ErrClearError();
return false;
}
Expand All @@ -97,6 +114,8 @@ private static bool AddCachedCrl(string crlFileName, SafeX509StoreHandle store,
// We'll cache it for a few days to cover the case it was a mistake.
if (nextUpdatePtr == IntPtr.Zero)
{
OpenSslX509ChainEventSource.Log.CrlCacheFileBasedExpiry();

try
{
nextUpdate = File.GetLastWriteTime(crlFile).AddDays(3);
Expand Down Expand Up @@ -124,6 +143,7 @@ private static bool AddCachedCrl(string crlFileName, SafeX509StoreHandle store,
// to be already expired.
if (nextUpdate <= verificationTime)
{
OpenSslX509ChainEventSource.Log.CrlCacheExpired(nextUpdate, verificationTime);
return false;
}

Expand All @@ -140,6 +160,7 @@ private static bool AddCachedCrl(string crlFileName, SafeX509StoreHandle store,
}
}

OpenSslX509ChainEventSource.Log.CrlCacheAcceptedFile(nextUpdate);
return true;
}
}
Expand Down Expand Up @@ -183,12 +204,15 @@ private static void DownloadAndAddCrl(
if (bio.IsInvalid || Interop.Crypto.PemWriteBioX509Crl(bio, crl) == 0)
{
// No bio, or write failed
OpenSslX509ChainEventSource.Log.CrlCacheWriteFailed(crlFile);
Interop.Crypto.ErrClearError();
}
}
}
catch (UnauthorizedAccessException) { }
catch (IOException) { }

OpenSslX509ChainEventSource.Log.CrlCacheWriteSucceeded();
}
}
}
Expand Down Expand Up @@ -248,6 +272,7 @@ private static string GetCachedCrlPath(string localFileName, bool mkDir=false)

if (crlDistributionPoints.Array == null)
{
OpenSslX509ChainEventSource.Log.NoCdpFound(cert);
return null;
}

Expand All @@ -268,13 +293,21 @@ private static string GetCachedCrlPath(string localFileName, bool mkDir=false)
{
foreach (GeneralNameAsn name in distributionPoint.DistributionPoint.Value.FullName)
{
if (name.Uri != null &&
Uri.TryCreate(name.Uri, UriKind.Absolute, out Uri? uri) &&
uri.Scheme == "http")
if (name.Uri != null)
{
return name.Uri;
if (Uri.TryCreate(name.Uri, UriKind.Absolute, out Uri? uri) &&
uri.Scheme == "http")
{
return name.Uri;
}
else
{
OpenSslX509ChainEventSource.Log.NonHttpCdpEntry(name.Uri);
Copy link
Member

Choose a reason for hiding this comment

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

It might be "http" but failed to parse because of some issue later in the uri. Is that ok?

Copy link
Member Author

@bartonjs bartonjs Mar 14, 2022

Choose a reason for hiding this comment

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

PerfView would just see it as NonHttpCdpEntry / http://test..?q=w.

Something that takes the message into account would see Skipping CDP entry 'http://test..?q=w' because the protocol is not HTTP., which seems less than ideal, but not too far off the mark.

}
}
}

OpenSslX509ChainEventSource.Log.NoMatchingCdpEntry();
Copy link
Member

Choose a reason for hiding this comment

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

FWIW, we've typically guarded all EventSource calls, even parameterless onces, with IsEnabled() checks. Part of that has been historical, and part of that has been in support of the linker being able to remove everything that's only referenced inside such a guard. @marek-safar should comment on whether this is 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.

And here I thought that was an artifact of older patterns.

So the correct style, for dotnet/runtime, at least, is an IsEnabled check on both the outside and the inside of the method? (I feel like EventSource's documentation said to have an IsEnabled check for each method, presumably to avoid things like creating the params array when it doesn't matter) Or do we do them outside-only?

Copy link
Contributor

Choose a reason for hiding this comment

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

Yep, linker will have right now difficulties propagating this information. The best is to call directly methods that are substituted when event source is disabled

}
}
}
Expand Down
Loading