dotnet / runtime

.NET is a cross-platform runtime for cloud, mobile, desktop, and IoT apps.
https://docs.microsoft.com/dotnet/core/
MIT License
14.23k stars 4.45k forks source link

add hooks to debug OpenSSL memory #101626

Open wfurt opened 2 weeks ago

wfurt commented 2 weeks ago

We had several cases when users complained about large memory use. For than native it is quite difficult to figure out where the memory goes. This PR aims to make that somewhat easier.

OpenSSL provides hooks for memory function so this PR adds switch to optimally hook into that. The only one caveat that the CRYPTO_set_mem_functions works only if called before any allocations e.g. it needs to be done very early in the process. So I end up putting into initialization process .... even if I originally envisioned it somewhere else.

The simple use pattern is something like

export DOTNET_SYSTEM_NET_SECURITY_OPENSSL_MEMORY_DEBUG=1
var ci = typeof(SslStream).Assembly.GetTypes().First(t => t.Name == "CryptoInitializer");

do some TLS/crypto work

Console.WriteLine($"Bytes known to GC [{GC.GetTotalMemory(false)}], process working set [{process.WorkingSet64}]");
Console.WriteLine("OpenSSL memory {0}", ci.InvokeMember("TotalAllocatedMemory", BindingFlags.GetField | BindingFlags.NonPublic | BindingFlags.Static, null, null, null));

That provides insight how much memory is actually used by OpenSSL. It allocates little bit more memory to store extra info but it should be reasonably cheap.

If somebody cares about more details they can do something like

ci.InvokeMember("EnableTracking", BindingFlags.InvokeMethod | BindingFlags.NonPublic | BindingFlags.Public | BindingFlags.Static, null, null, null);

do some TLS/crypto work

Tuple<IntPtr, int, string>[] allocations = (Tuple<IntPtr, int, string>[])si.InvokeMember("GetIncrementalAllocations", BindingFlags.InvokeMethod | BindingFlags.NonPublic | BindingFlags.Public | BindingFlags.Static | BindingFlags.Instance , null, null, null);
for (int j = 0; j < allocations.Length; j++)
{
    (IntPtr ptr, int size, string src) = allocations[j];
    Console.WriteLine("Allocated {0} bytes at 0x{1:x} from {2}", size, ptr, src);
}

this would provide something like

Allocated 81 bytes at 0x7f0c8013d448 from ../crypto/err/err.c:820
Allocated 3 bytes at 0x7f0c8000bd28 from ../crypto/asn1/asn1_lib.c:308
Allocated 81 bytes at 0x7f0c8c13a108 from ../crypto/err/err.c:820
Allocated 40 bytes at 0x7f0c80126df8 from ../crypto/x509/x_name.c:92
Allocated 13 bytes at 0x7f0c8013b438 from ../crypto/asn1/asn1_lib.c:308

dumping large allocation data set is slow and expensive. It is done under local so it blocks all other OpenSSL allocations. I feel this is ok for now but it should be used with caution. I also feel that access through Reflection is OK since this is only last resort debug hook e.g. it does not need stable API and convenient access.

wfurt commented 2 weeks ago

It looks like the build is failing because we are trying to build agains OpenSSL 1.0 that is EOS since 2019.

 -- Found OpenSSL: /crossrootfs/x64/usr/lib/x86_64-linux-gnu/libcrypto.so (found version "1.0.2g")  

I was tempted to simply disable the debug feature for that version as the very old OpenSSL has different prototype. But it seems like we would loose that for all platforms.

Any thoughts @bartonjs on moving the build to at least 1.1.1 that is EOS only since last year and some distributions we support are still using it?

There are probably different ways how to solve the build problems but I feel it is perhaps finally time to ditch 1.0.

jkotas commented 2 weeks ago

the build problems

We build against Ubuntu 16.04 headers and libs currently https://github.com/dotnet/runtime/issues/83428 . It is likely going to stay that way for .NET 9.

wfurt commented 2 weeks ago

the build problems

We build against Ubuntu 16.04 headers and libs currently #83428 . It is likely going to stay that way for .NET 9.

What is reason for it @jkotas? It seems like even 8.0 does not support 16.04: https://github.com/dotnet/core/blob/main/release-notes/8.0/supported-os.md

jkotas commented 2 weeks ago

It is same deal as Windows 7. It is not supported, but we avoid intentionally breaking it to help some important customers.

vcsjones commented 2 weeks ago

trying to build agains OpenSSL 1.0 that is EOS since 2019.

OpenSSL version support is not as simple as the OpenSSL support policy. Distros will continue to use EOL versions of OpenSSL but backport fixes under their own LTS support policy.

I don't think .NET actually "officially" supports any Linux distros with 1.0.2 anymore. However 1.0.2k/g has played an important role far past its 2019 EOL and there are a number of Linux distros that still support it today.

vcsjones commented 2 weeks ago

That said, since this is a diagnostic feature, I don't know that it makes sense to go through any particular lengths to get it working with 1.0.

jkotas commented 2 weeks ago

malloc/free can be used in more places than it is ok to run managed code. For example, you can use malloc/free in thread detach callback, but running managed code in thread detach callback is not safe/reliable. What's our confidence level that OpenSSL only ever calls malloc/free in places where it is safe to run managed code? At minimum, this should get a full CI run with this instrumentation unconditionally enabled to see whether it is going to hit any crashes.

wfurt commented 2 weeks ago

malloc/free can be used in more places than it is ok to run managed code. For example, you can use malloc/free in thread detach callback, but running managed code in thread detach callback is not safe/reliable. What's our confidence level that OpenSSL only ever calls malloc/free in places where it is safe to run managed code? At minimum, this should get a full CI run with this instrumentation unconditionally enabled to see whether it is going to hit any crashes.

I can enable it for SslStream test runs. I can also switch the implementation and p/invoke malloc/free. From what I know OpenSSL does not do any internal threading. so all actions are triggered synchronously from managed code AFAIK. I don't know if that cover all the cases you are concern about @jkotas

jkotas commented 2 weeks ago

What's our confidence level that OpenSSL only ever calls malloc/free in places where it is safe to run managed code? At minimum, this should get a full CI run with this instrumentation unconditionally enabled to see whether it is going to hit any crashes.

If this does not work, an alternative can be an unmanaged library that one preloads using LD_PRELOAD. There are number of memory leak / instrumentation libraries like that out there. https://github.com/WuBingzheng/libleak showed up at the top of my search results. It may be harder to deploy, but it can be used for any leak diagnostics, not specific to OpenSSL.

jkotas commented 2 weeks ago

From what I know OpenSSL does not do any internal threading. so all actions are triggered synchronously from managed code AFAIK. I don't know if that cover all the cases you are concern about @jkotas

I see OpenSSL installing thread-detach callbacks and freeing memory inside them here: https://github.com/openssl/openssl/blob/6a4a714045415be6720f4165c4d70a0ff229a26a/crypto/initthread.c#L358 . This won't be triggered synchronously from managed code.

wfurt commented 2 weeks ago

That is new in 3.0x and related to providers ... like FIPS. I can explore more. Is it not safe to use just the allocation functions or any managed code @jkotas?

And I used generic tools before. They are difficult to use as it is difficult to focus only one particular part ... like SSL ... and tracking all runtime allocations is expensive. And my intention goes beyond just leaks. We have tight integration with OpenSSL and it would be good to havr more insight to what is happening inside. And the available hooks provide additional and useful information.

I was originally thinking about make it available only in debug builds. That would certainly limit the scope of troubles. But that would make it really difficult IMHO to answer question if memory growth even comes from OpenSSL or some other native component.

jkotas commented 2 weeks ago

Is it not safe to use just the allocation functions or any managed code @jkotas?

Any managed code.

janvorli commented 2 weeks ago

I think the logging is simple enough to be written in C and placed into the openssl PAL. That should make it easy to get rid of the concerns raised here. We can possibly make it even simpler, just writing the log entries into a log file and creating a simple tool to analyze it instead of processing the information in the runtime. I think for debugging problems in customer scenarios, having it in the runtime is better than having a separate library. My experience from debugging the memory related issues with customers is that for some of them, things like preloading a lib are sometimes a problem in the production environment.

filipnavara commented 2 weeks ago

I think for debugging problems in customer scenarios, having it in the runtime is better than having a separate library.

Agreed.

That said, I have a distilled version of the same concept (https://gist.github.com/filipnavara/7bf3791fb795266fe46f4383a075423c) deployed on a .NET 8 app (doesn't care about OpenSSL versioning since it's a one trick pony for diagnosing specific issue in a specific environment). It's likely possible to have that in separate library but it would come with additional complexities if the allocation callbacks needed to be written in C and compiled for multiple platforms. Having the C code in runtime takes care of this tricky part.

We can possibly make it even simpler, just writing the log entries into a log file and creating a simple tool to analyze it instead of processing the information in the runtime.

I'm not sure that would cut it. The app where we would use this diagnostic is operating on a scale where the allocations are multiple gigabytes at any given time and the allocation/free events are frequent, so summary information is what we need. Logging the calls [even in a compressed formats] would produce way too much information.

jkotas commented 2 weeks ago

I have a distilled version of the same concept (https://gist.github.com/filipnavara/7bf3791fb795266fe46f4383a075423c) deployed on a .NET 8 app

Thank you for sharing this example. I like the flexibility of including it as source in the app. For example, you can monitor the total crypto memory consumption via performance counter using your existing monitoring solution as this example shows; you can add logging of stacktraces and only for certain allocation if you need that to diagnose them problem; etc.

wfurt commented 2 weeks ago

I have a distilled version of the same concept (https://gist.github.com/filipnavara/7bf3791fb795266fe46f4383a075423c) deployed on a .NET 8 app

Thank you for sharing this example. I like the flexibility of including it as source in the app. For example, you can monitor the total crypto memory consumption via performance counter using your existing monitoring solution as this example shows; you can add logging of stacktraces and only for certain allocation if you need that to diagnose them problem; etc.

Since it is managed code the callbacks will have same safety problem, right @jkotas? I was thinking about similar solution @janvorli suggested - get the basic counters and hooks in c to make them safe. And find better way how to expose the details - either as event source, plain file writes as @janvorli suggested or whatever we agree to.

wfurt commented 2 weeks ago

one more note that the hooks are sensitive to the fact that it needs to be done before any allocations. That is not problem for the simple console app but it may be difficult for Kestrel where many things may happen IMHO before user code runs.

jkotas commented 2 weeks ago

Since it is managed code the callbacks will have same safety problem, right

Yes - if the app usage pattern results into OpenSSL calling malloc/free in places where it is not safe to run managed code.

That is not problem for the simple console app but it may be difficult for Kestrel where many things may happen IMHO before user code runs.

It can be problem even for a console app - if some code in the app (e.g. 3rd party library) ends initializing OpenSSL before we get a chance to initialize it.

filipnavara commented 6 days ago

Since it is managed code the callbacks will have same safety problem, right?

Correct. We didn't encounter any issue in production with the managed callbacks. That said, we definitely use only subset of the OpenSSL functionality (a couple of crypto ciphers, Kestrel, SslStream, HttpClient).

one more note that the hooks are sensitive to the fact that it needs to be done before any allocations. That is not problem for the simple console app but it may be difficult for Kestrel where many things may happen IMHO before user code runs.

We didn't have any problem injecting it early enough in the startup in the app that uses Kestrel.

We had several cases when users complained about large memory use. For than native it is quite difficult to figure out where the memory goes.

Initial results from our experiment show that we don't see any OpenSSL related leaks. We still observe working set growing over time even if it's unaccounted for in the GC heap or other .NET heaps (eg. compiled code).

image

image

Notably these graphs don't make the original issue entirely obvious. They just show that OpenSSL memory seems to stay at stable levels. Each instance has a HTTP endpoint for registration and then runs a large number of pollers that check for new email messages over variety of protocols (IMAP, Exchange Web Services, etc.) on numerous servers. We have a mechanism that rebalances all the polling registrations to a different instance so we should end up basically in the same "empty" state as on startup. When we do this and force a GC we see the managed heap going down but the working set never returns to the initial levels and it exceeds it by gigabyte(s).

rzikm commented 5 days ago

Sorry for off-topic

We had several cases when users complained about large memory use. For than native it is quite difficult to figure out where the memory goes.

@filipnavara recently I have seen high memory usage due to lots of memory buffers being cached by malloc internally, see https://github.com/dotnet/runtime/issues/101552

filipnavara commented 8 hours ago

recently I have seen high memory usage due to lots of memory buffers being cached by malloc internally, see #101552

OT: Turns out this was immensely useful hint. We added tracking of the malloc metrics from mallinfo2. The data after a few days show that the memory usage growth is the malloc arena and that the size of the free list also grows. There may not be a memory leak after all, just a lot of reserved memory from the native allocator.