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 doPrivileged section in deprecation logger #81819

Merged
merged 6 commits into from
Dec 17, 2021
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
6 changes: 6 additions & 0 deletions docs/changelog/81819.yaml
Original file line number Diff line number Diff line change
@@ -0,0 +1,6 @@
pr: 81819
summary: Add `doPrivileged` section in deprecation logger
area: "Infra/Scripting, Infra/Logging"
type: bug
issues:
- 81708
Original file line number Diff line number Diff line change
Expand Up @@ -173,7 +173,7 @@ public void testConcurrentDeprecationLogger() throws IOException, UserException,
assertLogLine(
deprecationEvents.get(i),
DeprecationLogger.CRITICAL,
"org.elasticsearch.common.logging.DeprecationLogger.logDeprecation",
"org.elasticsearch.common.logging.DeprecationLogger.lambda\\$doPrivilegedLog\\$0",
"This is a maybe logged deprecation message" + i
);
}
Expand Down Expand Up @@ -206,7 +206,7 @@ public void testDeprecatedSettings() throws IOException, UserException {
assertLogLine(
deprecationEvents.get(0),
DeprecationLogger.CRITICAL,
"org.elasticsearch.common.logging.DeprecationLogger.logDeprecation",
"org.elasticsearch.common.logging.DeprecationLogger.lambda\\$doPrivilegedLog\\$0",
"\\[deprecated.foo\\] setting was deprecated in Elasticsearch and will be removed in a future release! "
+ "See the breaking changes documentation for the next major version."
);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -12,6 +12,9 @@
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;

import java.security.AccessController;
import java.security.PrivilegedAction;

/**
* A logger that logs deprecation notices. Logger should be initialized with a class or name which will be used
* for deprecation logger. For instance <code>DeprecationLogger.getLogger("org.elasticsearch.test.SomeClass")</code> will
Expand Down Expand Up @@ -97,10 +100,17 @@ private DeprecationLogger logDeprecation(Level level, DeprecationCategory catego
String opaqueId = HeaderWarning.getXOpaqueId();
String productOrigin = HeaderWarning.getProductOrigin();
ESLogMessage deprecationMessage = DeprecatedMessage.of(category, key, opaqueId, productOrigin, msg, params);
logger.log(level, deprecationMessage);
doPrivilegedLog(level, deprecationMessage);
return this;
}

private void doPrivilegedLog(Level level, ESLogMessage deprecationMessage) {
AccessController.doPrivileged((PrivilegedAction<Void>) () -> {
logger.log(level, deprecationMessage);
return null;
});
}

/**
* Used for handling previous version RestApiCompatible logic.
* Logs a message at the {@link DeprecationLogger#CRITICAL} level
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -8,16 +8,35 @@

package org.elasticsearch.common.logging;

import org.apache.logging.log4j.Level;
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.core.Logger;
import org.apache.logging.log4j.core.LoggerContext;
import org.apache.logging.log4j.spi.LoggerContextFactory;
import org.elasticsearch.test.ESTestCase;
import org.mockito.Mockito;

import java.security.AccessControlContext;
import java.security.AccessController;
import java.security.Permissions;
import java.security.PrivilegedAction;
import java.security.ProtectionDomain;
import java.util.concurrent.atomic.AtomicBoolean;

import static org.hamcrest.Matchers.equalTo;
import static org.hamcrest.Matchers.is;
import static org.mockito.ArgumentMatchers.any;
import static org.mockito.ArgumentMatchers.anyBoolean;
import static org.mockito.ArgumentMatchers.anyString;
import static org.mockito.ArgumentMatchers.eq;
import static org.mockito.Mockito.doAnswer;
import static org.mockito.Mockito.mock;
import static org.mockito.Mockito.when;

public class DeprecationLoggerTests extends ESTestCase {

public void testMultipleSlowLoggersUseSingleLog4jLogger() {
LoggerContext context = (LoggerContext) LogManager.getContext(false);
org.apache.logging.log4j.core.LoggerContext context = (org.apache.logging.log4j.core.LoggerContext) LogManager.getContext(false);

DeprecationLogger deprecationLogger = DeprecationLogger.getLogger(DeprecationLoggerTests.class);
int numberOfLoggersBefore = context.getLoggers().size();
Expand All @@ -30,4 +49,41 @@ class LoggerTest {}

assertThat(numberOfLoggersAfter, equalTo(numberOfLoggersBefore + 1));
}

public void testLogPermissions() {
final LoggerContextFactory originalFactory = LogManager.getFactory();
try {
AtomicBoolean supplierCalled = new AtomicBoolean(false);
// mocking the logger used inside DeprecationLogger requires heavy hacking...
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 super proud on how I had to set up that logging configuration but it is not far worse to what we had before https://github.com/elastic/elasticsearch/pull/37281/files#diff-70de5a6ba5c637e7f19c51341417760d6e957beb5a1fa5703049095ea2719ee0R322


Logger mockLogger = mock(Logger.class);
doAnswer(invocationOnMock -> {
supplierCalled.set(true);
createTempDir(); // trigger file permission, like rolling logs would
return null;
}).when(mockLogger).log(eq(Level.WARN), any(ESLogMessage.class));

final LoggerContext context = Mockito.mock(LoggerContext.class);
when(context.getLogger(anyString())).thenReturn(mockLogger);

// "extending" the existing factory to avoid creating new one which
// would result in LoaderUtil.getParent SM permission exception
final LoggerContextFactory spy = Mockito.spy(originalFactory);
Mockito.doReturn(context).when(spy).getContext(any(), any(), any(), anyBoolean(), any(), any());
LogManager.setFactory(spy);

DeprecationLogger deprecationLogger = DeprecationLogger.getLogger("name");

AccessControlContext noPermissionsAcc = new AccessControlContext(
new ProtectionDomain[] { new ProtectionDomain(null, new Permissions()) }
);
AccessController.doPrivileged((PrivilegedAction<Void>) () -> {
deprecationLogger.warn(DeprecationCategory.API, "key", "foo", "bar");
return null;
}, noPermissionsAcc);
assertThat("supplier called", supplierCalled.get(), is(true));
} finally {
LogManager.setFactory(originalFactory);
}
}
}