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.

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

Introduce Log4j 2 #20235

Merged
merged 19 commits into from
Sep 1, 2016
Merged

Introduce Log4j 2 #20235

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
19 commits
Select commit Hold shift + click to select a range
5a8f2d7
Disable logger usage checks
jasontedor Aug 30, 2016
7da0cde
Introduce Log4j 2
jasontedor Aug 9, 2016
abf8a1a
Avoid allocating log parameterized messages
jasontedor Aug 30, 2016
0853fc8
Add missing cast to logging message supplier
jasontedor Aug 30, 2016
9a58fc2
Fix failing evil logger tests
jasontedor Aug 30, 2016
abe3efd
Fix failing max map count check test
jasontedor Aug 30, 2016
1f6a4be
Fix failing evil logging configuration tests
jasontedor Aug 31, 2016
4e69ac0
Add link to open logger usage issue
jasontedor Aug 31, 2016
0fdc5ca
Remove logger getter from DeprecationLogger
jasontedor Aug 31, 2016
1d197ed
Mark ESLoggerUsageTests as awaits fix
jasontedor Aug 31, 2016
21dbc5b
Add empty test to ESLoggerUsageTests
jasontedor Aug 31, 2016
ac8c2e9
Enable console logging for CLI tools
jasontedor Aug 31, 2016
e166459
Merge branch 'master' into log4j2
jasontedor Aug 31, 2016
487ffe8
Remove code references to logging.yml
jasontedor Aug 31, 2016
750033d
Update docs for Log4j 2
jasontedor Aug 31, 2016
07d1a72
Update packaging tests for Log4j 2
jasontedor Aug 31, 2016
76ab02e
Merge branch 'master' into log4j2
jasontedor Aug 31, 2016
c98e790
Merge branch 'master' into log4j2
jasontedor Sep 1, 2016
d9064f4
Fix additional exception logging calls
jasontedor Sep 1, 2016
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
The table of contents is too big for display.
Diff view
Diff view
  •  
  •  
  •  
4 changes: 2 additions & 2 deletions buildSrc/src/main/groovy/org/elasticsearch/gradle/plugin/PluginBuildPlugin.groovy
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -97,8 +97,8 @@ public class PluginBuildPlugin extends BuildPlugin {
// with a full elasticsearch server that includes optional deps
provided "org.locationtech.spatial4j:spatial4j:${project.versions.spatial4j}"
provided "com.vividsolutions:jts:${project.versions.jts}"
provided "log4j:log4j:${project.versions.log4j}"
provided "log4j:apache-log4j-extras:${project.versions.log4j}"
provided "org.apache.logging.log4j:log4j-api:${project.versions.log4j}"
provided "org.apache.logging.log4j:log4j-core:${project.versions.log4j}"
provided "net.java.dev.jna:jna:${project.versions.jna}"
}
}
Expand Down
3 changes: 2 additions & 1 deletion buildSrc/src/main/groovy/org/elasticsearch/gradle/precommit/PrecommitTasks.groovy
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -59,7 +59,8 @@ class PrecommitTasks {
* use the NamingConventionsCheck we break the circular dependency
* here.
*/
precommitTasks.add(configureLoggerUsage(project))
// https://github.com/elastic/elasticsearch/issues/20243
// precommitTasks.add(configureLoggerUsage(project))
Copy link
Member

Choose a reason for hiding this comment

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

Can you at least add a comment with this linking to a followup issue?

Copy link
Member Author

Choose a reason for hiding this comment

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

I opened #20243 and pushed 4e69ac0.

}


Expand Down
2 changes: 1 addition & 1 deletion buildSrc/version.properties
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -6,7 +6,7 @@ spatial4j = 0.6
jts = 1.13
jackson = 2.8.1
snakeyaml = 1.15
log4j = 1.2.17
log4j = 2.6.2
slf4j = 1.6.2
jna = 4.2.2

Expand Down
4 changes: 2 additions & 2 deletions ...enchmark/src/main/java/org/elasticsearch/client/benchmark/ops/bulk/BulkBenchmarkTask.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -18,13 +18,13 @@
*/
package org.elasticsearch.client.benchmark.ops.bulk;

import org.apache.logging.log4j.Logger;
import org.elasticsearch.ElasticsearchException;
import org.elasticsearch.client.benchmark.BenchmarkTask;
import org.elasticsearch.client.benchmark.metrics.Sample;
import org.elasticsearch.client.benchmark.metrics.SampleRecorder;
import org.elasticsearch.common.SuppressForbidden;
import org.elasticsearch.common.io.PathUtils;
import org.elasticsearch.common.logging.ESLogger;
import org.elasticsearch.common.logging.ESLoggerFactory;

import java.io.BufferedReader;
Expand Down Expand Up @@ -135,7 +135,7 @@ private void sendBulk(List<String> bulkData) throws InterruptedException {


private static final class BulkIndexer implements Runnable {
private static final ESLogger logger = ESLoggerFactory.getLogger(BulkIndexer.class.getName());
private static final Logger logger = ESLoggerFactory.getLogger(BulkIndexer.class.getName());

private final BlockingQueue<List<String>> bulkData;
private final int warmupIterations;
Expand Down
120 changes: 92 additions & 28 deletions core/build.gradle
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -85,8 +85,10 @@ dependencies {
compile "com.vividsolutions:jts:${versions.jts}", optional

// logging
compile "log4j:log4j:${versions.log4j}", optional
compile "log4j:apache-log4j-extras:${versions.log4j}", optional
compile "org.apache.logging.log4j:log4j-api:${versions.log4j}", optional
compile "org.apache.logging.log4j:log4j-core:${versions.log4j}", optional
// to bridge dependencies that are still on Log4j 1 to Log4j 2
compile "org.apache.logging.log4j:log4j-1.2-api:${versions.log4j}", optional

compile "net.java.dev.jna:jna:${versions.jna}"

Expand Down Expand Up @@ -154,32 +156,94 @@ thirdPartyAudit.excludes = [
// classes are missing!

// from com.fasterxml.jackson.dataformat.yaml.YAMLMapper (jackson-dataformat-yaml)
'com.fasterxml.jackson.databind.ObjectMapper',

// from org.apache.log4j.receivers.net.JMSReceiver (log4j-extras)
'javax.jms.Message',
'javax.jms.MessageListener',
'javax.jms.ObjectMessage',
'javax.jms.TopicConnection',
'javax.jms.TopicConnectionFactory',
'javax.jms.TopicPublisher',
'javax.jms.TopicSession',
'javax.jms.TopicSubscriber',

// from org.apache.log4j.net.SMTPAppender (log4j)
'javax.mail.Authenticator',
'javax.mail.Message$RecipientType',
'javax.mail.Message',
'javax.mail.Multipart',
'javax.mail.PasswordAuthentication',
'javax.mail.Session',
'javax.mail.Transport',
'javax.mail.internet.InternetAddress',
'javax.mail.internet.InternetHeaders',
'javax.mail.internet.MimeBodyPart',
'javax.mail.internet.MimeMessage',
'javax.mail.internet.MimeMultipart',
'javax.mail.internet.MimeUtility',
'com.fasterxml.jackson.databind.ObjectMapper',

// from log4j
'com.fasterxml.jackson.annotation.JsonInclude$Include',
'com.fasterxml.jackson.databind.DeserializationContext',
'com.fasterxml.jackson.databind.JsonMappingException',
'com.fasterxml.jackson.databind.JsonNode',
'com.fasterxml.jackson.databind.Module$SetupContext',
'com.fasterxml.jackson.databind.ObjectReader',
'com.fasterxml.jackson.databind.ObjectWriter',
'com.fasterxml.jackson.databind.SerializerProvider',
'com.fasterxml.jackson.databind.deser.std.StdDeserializer',
'com.fasterxml.jackson.databind.deser.std.StdScalarDeserializer',
'com.fasterxml.jackson.databind.module.SimpleModule',
'com.fasterxml.jackson.databind.ser.impl.SimpleBeanPropertyFilter',
'com.fasterxml.jackson.databind.ser.impl.SimpleFilterProvider',
'com.fasterxml.jackson.databind.ser.std.StdScalarSerializer',
'com.fasterxml.jackson.databind.ser.std.StdSerializer',
'com.fasterxml.jackson.dataformat.xml.JacksonXmlModule',
'com.fasterxml.jackson.dataformat.xml.XmlMapper',
'com.fasterxml.jackson.dataformat.xml.util.DefaultXmlPrettyPrinter',
'com.lmax.disruptor.BlockingWaitStrategy',
'com.lmax.disruptor.BusySpinWaitStrategy',
'com.lmax.disruptor.EventFactory',
'com.lmax.disruptor.EventTranslator',
'com.lmax.disruptor.EventTranslatorTwoArg',
'com.lmax.disruptor.EventTranslatorVararg',
'com.lmax.disruptor.ExceptionHandler',
'com.lmax.disruptor.LifecycleAware',
'com.lmax.disruptor.RingBuffer',
'com.lmax.disruptor.Sequence',
'com.lmax.disruptor.SequenceReportingEventHandler',
'com.lmax.disruptor.SleepingWaitStrategy',
'com.lmax.disruptor.TimeoutBlockingWaitStrategy',
'com.lmax.disruptor.WaitStrategy',
'com.lmax.disruptor.YieldingWaitStrategy',
'com.lmax.disruptor.dsl.Disruptor',
'com.lmax.disruptor.dsl.ProducerType',
'javax.jms.Connection',
'javax.jms.ConnectionFactory',
'javax.jms.Destination',
'javax.jms.Message',
'javax.jms.MessageConsumer',
'javax.jms.MessageListener',
'javax.jms.MessageProducer',
'javax.jms.ObjectMessage',
'javax.jms.Session',
'javax.mail.Authenticator',
'javax.mail.Message$RecipientType',
'javax.mail.PasswordAuthentication',
'javax.mail.Session',
'javax.mail.Transport',
'javax.mail.internet.InternetAddress',
'javax.mail.internet.InternetHeaders',
'javax.mail.internet.MimeBodyPart',
'javax.mail.internet.MimeMessage',
'javax.mail.internet.MimeMultipart',
'javax.mail.internet.MimeUtility',
'javax.mail.util.ByteArrayDataSource',
'javax.persistence.AttributeConverter',
'javax.persistence.EntityManager',
'javax.persistence.EntityManagerFactory',
'javax.persistence.EntityTransaction',
'javax.persistence.Persistence',
'javax.persistence.PersistenceException',
'org.apache.commons.compress.compressors.CompressorStreamFactory',
'org.apache.commons.compress.utils.IOUtils',
'org.apache.commons.csv.CSVFormat',
'org.apache.commons.csv.QuoteMode',
'org.apache.kafka.clients.producer.KafkaProducer',
'org.apache.kafka.clients.producer.Producer',
'org.apache.kafka.clients.producer.ProducerRecord',
'org.codehaus.stax2.XMLStreamWriter2',
'org.osgi.framework.AdaptPermission',
'org.osgi.framework.AdminPermission',
'org.osgi.framework.Bundle',
'org.osgi.framework.BundleActivator',
'org.osgi.framework.BundleContext',
'org.osgi.framework.BundleEvent',
'org.osgi.framework.BundleReference',
'org.osgi.framework.FrameworkUtil',
'org.osgi.framework.SynchronousBundleListener',
'org.osgi.framework.wiring.BundleWire',
'org.osgi.framework.wiring.BundleWiring',
'org.zeromq.ZMQ$Context',
'org.zeromq.ZMQ$Socket',
'org.zeromq.ZMQ',

// from org.locationtech.spatial4j.io.GeoJSONReader (spatial4j)
'org.noggit.JSONParser',
]
Expand Down
37 changes: 0 additions & 37 deletions core/src/main/java/org/apache/log4j/Java9Hack.java
View file
Open in desktop

This file was deleted.

23 changes: 0 additions & 23 deletions core/src/main/java/org/apache/log4j/package-info.java
View file
Open in desktop

This file was deleted.

1 change: 1 addition & 0 deletions core/src/main/java/org/elasticsearch/ElasticsearchException.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -19,6 +19,7 @@

package org.elasticsearch;

import org.apache.logging.log4j.message.ParameterizedMessage;
import org.elasticsearch.action.support.replication.ReplicationOperation;
import org.elasticsearch.cluster.action.shard.ShardStateAction;
import org.elasticsearch.common.io.stream.StreamInput;
Expand Down
4 changes: 2 additions & 2 deletions core/src/main/java/org/elasticsearch/ExceptionsHelper.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -19,12 +19,12 @@

package org.elasticsearch;

import org.apache.logging.log4j.Logger;
import org.apache.lucene.index.CorruptIndexException;
import org.apache.lucene.index.IndexFormatTooNewException;
import org.apache.lucene.index.IndexFormatTooOldException;
import org.elasticsearch.action.ShardOperationFailedException;
import org.elasticsearch.common.Nullable;
import org.elasticsearch.common.logging.ESLogger;
import org.elasticsearch.common.logging.Loggers;
import org.elasticsearch.index.Index;
import org.elasticsearch.rest.RestStatus;
Expand All @@ -39,7 +39,7 @@

public final class ExceptionsHelper {

private static final ESLogger logger = Loggers.getLogger(ExceptionsHelper.class);
private static final Logger logger = Loggers.getLogger(ExceptionsHelper.class);

public static RuntimeException convertToRuntime(Exception e) {
if (e instanceof RuntimeException) {
Expand Down
4 changes: 3 additions & 1 deletion ...main/java/org/elasticsearch/action/admin/cluster/health/TransportClusterHealthAction.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -19,6 +19,8 @@

package org.elasticsearch.action.admin.cluster.health;

import org.apache.logging.log4j.message.ParameterizedMessage;
import org.apache.logging.log4j.util.Supplier;
import org.elasticsearch.action.ActionListener;
import org.elasticsearch.action.support.ActionFilters;
import org.elasticsearch.action.support.ActiveShardCount;
Expand Down Expand Up @@ -106,7 +108,7 @@ public void onNoLongerMaster(String source) {

@Override
public void onFailure(String source, Exception e) {
logger.error("unexpected failure during [{}]", e, source);
logger.error((Supplier<?>) () -> new ParameterizedMessage("unexpected failure during [{}]", source), e);
Copy link
Member

@pickypg pickypg Aug 30, 2016 •
edited
Loading

Choose a reason for hiding this comment

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

I can't help but wonder if we shouldn't have a static helper function that does this for us?

public static Supplier<ParameterizedMessage> message(String message, Object... params) {
  return () -> new ParameterizedMessage(message, params);
}

EDIT: forgot the () -> in the return.

It's of course another import, but it will probably be better than staring at (Supplier<?>) () -> new ParameterizedMessage(...) in so many places.

Copy link
Member

@pickypg pickypg Aug 30, 2016 •
edited
Loading

Choose a reason for hiding this comment

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

Comment got erased by the last commit. I can't help but wonder if we shouldn't have a static helper function that does this for us?

public static Supplier<ParameterizedMessage> message(String message, Object... params) {
  return () -> new ParameterizedMessage(message, params);
}

It's of course another import, but it will probably be better than staring at (Supplier<?>) () -> new ParameterizedMessage(...) in so many places and it removes both of those imports.

Copy link
Member Author

Choose a reason for hiding this comment

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

Maybe, but then we would want to at least have a lot of extra overrides to avoid allocating a varargs array.

Copy link
Member

Choose a reason for hiding this comment

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

I think that would be a lot cleaner than what it is here. It can probably be a secondary PR that happens in smaller waves though.

Copy link
Member Author

Choose a reason for hiding this comment

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

The problem is that these overrides would then introduce boxing on any primitive arguments, and that is something that we want to avoid as well. I do not think it's feasible to do this.

Copy link
Member

Choose a reason for hiding this comment

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

But that's not any different than the current non-exception logging? log4j just creates a ton of overloads with Object parameters too to avoid the params, right?

Copy link
Member Author

Choose a reason for hiding this comment

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

But that's not any different than the current non-exception logging?

The whole point of going the org.apache.log4j.util.Supplier<?> route was to avoid creating a new instance of ParameterizedMessage if the log message is not going to be emitted. I don't think we want to go through this trouble to immediately turn around and trigger allocations from boxing and varargs (yes, the latter can be avoided with a lot of overrides but the former can not without adding silly overrides for every possible combination).

log4j just creates a ton of overloads with Object parameters too to avoid the params, right?

Yes.

Copy link
Member

Choose a reason for hiding this comment

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

Which boxing are you referring to? I'm not seeing what would be boxed here (that would not have already been boxed with the old code)?

Copy link
Member Author

Choose a reason for hiding this comment

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

@rjernst The proposal from @pickypg is for a method

public static Supplier<ParameterizedMessage> message(String message, Object... params) {
  return () -> new ParameterizedMessage(message, params);
}

This will cause an allocation of an Object[] and all primitive arguments will be boxed to Objects. Adding overrides like

public static Supplier<ParameterizedMessage> message(String message, Object p1, Object p2) {
  return () -> new ParameterizedMessage(message, params);
}

removes the Object[] allocation, but still any primitive arguments will be boxed to Objects.

These allocations/boxing will occur regardless of whether or not the log level is fine enough to emit the corresponding log message.

With the (Supplier<?>) () -> new ParameterizedMessage("{}", o) pattern (as in this PR) we avoid this boxing unless the log message is going to be emitted.

Copy link
Member

Choose a reason for hiding this comment

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

but still any primitive arguments will be boxed to Objects.

But this would have been the case with the old methods as well (so nothing would be changing).

Having to do the cast makes logging a pain to use parameterized messages. While creatinga bunch of overloaded helpers may be a pain, maybe it is worth it. Or maybe having this pain will lead us to not depend on logging so much, so it could be good. :) I could go either way.

listener.onFailure(e);
}

Expand Down
12 changes: 7 additions & 5 deletions ...in/java/org/elasticsearch/action/admin/cluster/reroute/TransportClusterRerouteAction.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -19,6 +19,9 @@

package org.elasticsearch.action.admin.cluster.reroute;

import org.apache.logging.log4j.Logger;
import org.apache.logging.log4j.message.ParameterizedMessage;
import org.apache.logging.log4j.util.Supplier;
import org.elasticsearch.action.ActionListener;
import org.elasticsearch.action.support.ActionFilters;
import org.elasticsearch.action.support.master.TransportMasterNodeAction;
Expand All @@ -33,7 +36,6 @@
import org.elasticsearch.cluster.service.ClusterService;
import org.elasticsearch.common.Priority;
import org.elasticsearch.common.inject.Inject;
import org.elasticsearch.common.logging.ESLogger;
import org.elasticsearch.common.settings.Settings;
import org.elasticsearch.threadpool.ThreadPool;
import org.elasticsearch.transport.TransportService;
Expand Down Expand Up @@ -77,13 +79,13 @@ static class ClusterRerouteResponseAckedClusterStateUpdateTask extends AckedClus

private final ClusterRerouteRequest request;
private final ActionListener<ClusterRerouteResponse> listener;
private final ESLogger logger;
private final Logger logger;
private final AllocationService allocationService;
private volatile ClusterState clusterStateToSend;
private volatile RoutingExplanations explanations;

ClusterRerouteResponseAckedClusterStateUpdateTask(ESLogger logger, AllocationService allocationService, ClusterRerouteRequest request,
ActionListener<ClusterRerouteResponse> listener) {
ClusterRerouteResponseAckedClusterStateUpdateTask(Logger logger, AllocationService allocationService, ClusterRerouteRequest request,
ActionListener<ClusterRerouteResponse> listener) {
super(Priority.IMMEDIATE, request, listener);
this.request = request;
this.listener = listener;
Expand All @@ -103,7 +105,7 @@ public void onAckTimeout() {

@Override
public void onFailure(String source, Exception e) {
logger.debug("failed to perform [{}]", e, source);
logger.debug((Supplier<?>) () -> new ParameterizedMessage("failed to perform [{}]", source), e);
super.onFailure(source, e);
}

Expand Down
6 changes: 4 additions & 2 deletions ...org/elasticsearch/action/admin/cluster/settings/TransportClusterUpdateSettingsAction.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -19,6 +19,8 @@

package org.elasticsearch.action.admin.cluster.settings;

import org.apache.logging.log4j.message.ParameterizedMessage;
import org.apache.logging.log4j.util.Supplier;
import org.elasticsearch.ElasticsearchException;
import org.elasticsearch.action.ActionListener;
import org.elasticsearch.action.support.ActionFilters;
Expand Down Expand Up @@ -148,7 +150,7 @@ public void onNoLongerMaster(String source) {
@Override
public void onFailure(String source, Exception e) {
//if the reroute fails we only log
logger.debug("failed to perform [{}]", e, source);
logger.debug((Supplier<?>) () -> new ParameterizedMessage("failed to perform [{}]", source), e);
listener.onFailure(new ElasticsearchException("reroute after update settings failed", e));
}

Expand All @@ -166,7 +168,7 @@ public ClusterState execute(final ClusterState currentState) {

@Override
public void onFailure(String source, Exception e) {
logger.debug("failed to perform [{}]", e, source);
logger.debug((Supplier<?>) () -> new ParameterizedMessage("failed to perform [{}]", source), e);
super.onFailure(source, e);
}

Expand Down
4 changes: 3 additions & 1 deletion ...src/main/java/org/elasticsearch/action/admin/indices/close/TransportCloseIndexAction.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -19,6 +19,8 @@

package org.elasticsearch.action.admin.indices.close;

import org.apache.logging.log4j.message.ParameterizedMessage;
import org.apache.logging.log4j.util.Supplier;
import org.elasticsearch.action.ActionListener;
import org.elasticsearch.action.support.ActionFilters;
import org.elasticsearch.action.support.DestructiveOperations;
Expand Down Expand Up @@ -108,7 +110,7 @@ public void onResponse(ClusterStateUpdateResponse response) {

@Override
public void onFailure(Exception t) {
logger.debug("failed to close indices [{}]", t, (Object)concreteIndices);
logger.debug((Supplier<?>) () -> new ParameterizedMessage("failed to close indices [{}]", (Object) concreteIndices), t);
listener.onFailure(t);
}
});
Expand Down
Loading