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

Log "excessive" creation of factories and proxies #690

Conversation

rgallardo-netflix
Copy link
Contributor

Add logging to help users find leaks of Config proxies and their factories.

currentCount >= limit &&
(currentCount % limit == 0 )) {

String stackTraceForDebuggint;

Choose a reason for hiding this comment

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

nit: typo in stackTraceForDebuggint? (debugging)

@@ -189,6 +202,8 @@ interface PropertyValueGetter<T> {

@SuppressWarnings({"unchecked", "rawtypes"})
<T> T newProxy(final Class<T> type, final String initialPrefix, boolean immutable) {
warnWhenTooMany(PROXIES_COUNT, type, 50, String.format("Proxy(%s)", type));

Choose a reason for hiding this comment

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

would it make sense to make magic constants configurable?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Trick here is that some of this code could be running before config is fully initialized. Let me think it through.

@@ -98,6 +103,12 @@
public class ConfigProxyFactory {
private static final Logger LOG = LoggerFactory.getLogger(ConfigProxyFactory.class);

// Users sometimes leak both factories and proxies, leading to memory problems that get blamed on us ;-)

Choose a reason for hiding this comment

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

IMHO it would be nice to rewrite the message in lieu of the "true" Netflix culture instead of continuing "blame" culture :)

@@ -98,6 +103,12 @@
public class ConfigProxyFactory {
private static final Logger LOG = LoggerFactory.getLogger(ConfigProxyFactory.class);

// Users sometimes leak both factories and proxies, leading to memory problems that get blamed on us ;-)
// We'll use these maps to keep track of how many instances of each are created and make log noise to help them

Choose a reason for hiding this comment

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

extra nit: code style: different javadoc style from the rest of the file

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Not really a javadoc, more an internal comment for implementors :-)

@@ -189,6 +202,8 @@ interface PropertyValueGetter<T> {

@SuppressWarnings({"unchecked", "rawtypes"})
<T> T newProxy(final Class<T> type, final String initialPrefix, boolean immutable) {
warnWhenTooMany(PROXIES_COUNT, type, 50, String.format("Proxy(%s)", type));
Copy link
Contributor

Choose a reason for hiding this comment

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

50 seems a little high for this in general, is this to accommodate the possibility of someone having the same proxy class but with different prefixes? If so, would it make sense to combine that into the key?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Yeah, that's the thought.

…hold

By keeping track of created proxies on a per-factory basis and including the prefix in the count key we can lower the reporting limit. A user could potentially create up to 16 proxies for each uniq (config, interface, prefix) combination before triggering warnings.

Made reporting trigger configurable but not dynamic. Users with known bad usage patterns can quiet down the warnings until a fix can be made.

Added a manual test for logging. Set as @ignored, since CI can't verify it's working anyway.
currentCount >= limit &&
(currentCount % limit == 0 )) {

LOG.warn("Too many {} objects are being created. Please review the calling code to prevent memory leaks. Stack trace for debugging follows:",

Choose a reason for hiding this comment

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

Nit: Perhaps log the EXCESSIVE_PROXIES_LIMIT knob so users know how to adjust this if they have a legit reason to create so many of these proxies. But also log that you should only be creating a singleton.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Done :-)
New log message looks like

2023-10-30 13:30:48,612 WARN  ConfigProxyFactory:497  Too many ProxyFactory(Config:330084561) objects are being created (5 so far).
Please review the calling code to prevent memory leaks.
Normal usage for ConfigProxyFactory is to create singletons via your DI mechanism.
For special use cases that *require* creating multiple instances you can tune reporting
by setting the `archaius.excessiveProxiesLogging.limit` config key to a higher threshold.
Stack trace for debugging follows: [Test worker]
java.lang.Throwable
	at com.netflix.archaius.ConfigProxyFactory.warnWhenTooMany(ConfigProxyFactory.java:503)
	at com.netflix.archaius.ConfigProxyFactory.<init>(ConfigProxyFactory.java:146)
	at com.netflix.archaius.ProxyFactoryTest.testLogExcessiveUse(ProxyFactoryTest.java:563)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        ...

@rgallardo-netflix rgallardo-netflix merged commit 0332cef into Netflix:2.x Oct 30, 2023
5 checks passed
@rgallardo-netflix rgallardo-netflix deleted the feature/config-proxy-excessive-creations-RG branch October 30, 2023 20:42
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

4 participants