mirror of https://github.com/apache/lucene.git
SOLR-4825: Port SolrLogFormatter to log4j
git-svn-id: https://svn.apache.org/repos/asf/lucene/dev/trunk@1483088 13f79535-47bb-0310-9956-ffa450edef68
This commit is contained in:
Mark Robert Miller
parent
b56b7edd50
commit
971fae640f
|
|
@ -0,0 +1,367 @@
|
|||
package org.apache.solr.util;
|
||||
|
||||
import java.util.Collections;
|
||||
import java.util.HashMap;
|
||||
import java.util.Map;
|
||||
import java.util.WeakHashMap;
|
||||
|
||||
import org.apache.log4j.Layout;
|
||||
import org.apache.log4j.Level;
|
||||
import org.apache.log4j.spi.LoggingEvent;
|
||||
import org.apache.log4j.spi.ThrowableInformation;
|
||||
import org.apache.solr.cloud.ZkController;
|
||||
import org.apache.solr.common.SolrException;
|
||||
import org.apache.solr.common.cloud.Replica;
|
||||
import org.apache.solr.core.SolrCore;
|
||||
import org.apache.solr.request.SolrQueryRequest;
|
||||
import org.apache.solr.request.SolrRequestInfo;
|
||||
|
||||
/*
|
||||
* Licensed to the Apache Software Foundation (ASF) under one or more
|
||||
* contributor license agreements. See the NOTICE file distributed with
|
||||
* this work for additional information regarding copyright ownership.
|
||||
* The ASF licenses this file to You under the Apache License, Version 2.0
|
||||
* (the "License"); you may not use this file except in compliance with
|
||||
* the License. You may obtain a copy of the License at
|
||||
*
|
||||
* http://www.apache.org/licenses/LICENSE-2.0
|
||||
*
|
||||
* Unless required by applicable law or agreed to in writing, software
|
||||
* distributed under the License is distributed on an "AS IS" BASIS,
|
||||
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
|
||||
* See the License for the specific language governing permissions and
|
||||
* limitations under the License.
|
||||
*/
|
||||
|
||||
public class SolrLogLayout extends Layout {
|
||||
/**
|
||||
* Add this interface to a thread group and the string returned by getTag()
|
||||
* will appear in log statements of any threads under that group.
|
||||
*/
|
||||
public static interface TG {
|
||||
public String getTag();
|
||||
}
|
||||
|
||||
long startTime = System.currentTimeMillis();
|
||||
long lastTime = startTime;
|
||||
Map<Method,String> methodAlias = new HashMap<Method,String>();
|
||||
|
||||
public static class Method {
|
||||
public String className;
|
||||
public String methodName;
|
||||
|
||||
public Method(String className, String methodName) {
|
||||
this.className = className;
|
||||
this.methodName = methodName;
|
||||
}
|
||||
|
||||
@Override
|
||||
public int hashCode() {
|
||||
return className.hashCode() + methodName.hashCode();
|
||||
}
|
||||
|
||||
@Override
|
||||
public boolean equals(Object obj) {
|
||||
if (!(obj instanceof Method)) return false;
|
||||
Method other = (Method) obj;
|
||||
return (className.equals(other.className) && methodName
|
||||
.equals(other.methodName));
|
||||
}
|
||||
|
||||
@Override
|
||||
public String toString() {
|
||||
return className + '.' + methodName;
|
||||
}
|
||||
}
|
||||
|
||||
public static class CoreInfo {
|
||||
static int maxCoreNum;
|
||||
String shortId;
|
||||
String url;
|
||||
Map<String,Object> coreProps;
|
||||
}
|
||||
|
||||
Map<SolrCore,CoreInfo> coreInfoMap = new WeakHashMap<SolrCore,CoreInfo>(); // TODO:
|
||||
// use
|
||||
// something
|
||||
// that
|
||||
// survives
|
||||
// across
|
||||
// a
|
||||
// core
|
||||
// reload?
|
||||
|
||||
public Map<String,String> classAliases = new HashMap<String,String>();
|
||||
|
||||
public void appendThread(StringBuilder sb, LoggingEvent event) {
|
||||
Thread th = Thread.currentThread();
|
||||
|
||||
/******
|
||||
* sb.append(" T="); sb.append(th.getName()).append(' ');
|
||||
*
|
||||
* // NOTE: tried creating a thread group around jetty but we seem to lose
|
||||
* it and request // threads are in the normal "main" thread group
|
||||
* ThreadGroup tg = th.getThreadGroup(); while (tg != null) {
|
||||
* sb.append("(group_name=").append(tg.getName()).append(")");
|
||||
*
|
||||
* if (tg instanceof TG) { sb.append(((TG)tg).getTag()); sb.append('/'); }
|
||||
* try { tg = tg.getParent(); } catch (Throwable e) { tg = null; } }
|
||||
******/
|
||||
|
||||
// NOTE: LogRecord.getThreadID is *not* equal to Thread.getId()
|
||||
sb.append(" T");
|
||||
sb.append(th.getId());
|
||||
}
|
||||
|
||||
@Override
|
||||
public String format(LoggingEvent event) {
|
||||
return _format(event);
|
||||
}
|
||||
|
||||
public String _format(LoggingEvent event) {
|
||||
String message = (String) event.getMessage();
|
||||
|
||||
StringBuilder sb = new StringBuilder(message.length() + 80);
|
||||
|
||||
long now = event.timeStamp;
|
||||
long timeFromStart = now - startTime;
|
||||
long timeSinceLast = now - lastTime;
|
||||
lastTime = now;
|
||||
String shortClassName = getShortClassName(event.getLocationInformation().getClassName(),
|
||||
event.getLocationInformation().getMethodName());
|
||||
|
||||
/***
|
||||
* sb.append(timeFromStart).append(' ').append(timeSinceLast);
|
||||
* sb.append(' ');
|
||||
* sb.append(record.getSourceClassName()).append('.').append(
|
||||
* record.getSourceMethodName()); sb.append(' ');
|
||||
* sb.append(record.getLevel());
|
||||
***/
|
||||
|
||||
SolrRequestInfo requestInfo = SolrRequestInfo.getRequestInfo();
|
||||
SolrQueryRequest req = requestInfo == null ? null : requestInfo.getReq();
|
||||
SolrCore core = req == null ? null : req.getCore();
|
||||
ZkController zkController = null;
|
||||
CoreInfo info = null;
|
||||
|
||||
if (core != null) {
|
||||
info = coreInfoMap.get(core);
|
||||
if (info == null) {
|
||||
info = new CoreInfo();
|
||||
info.shortId = "C" + Integer.toString(CoreInfo.maxCoreNum++);
|
||||
coreInfoMap.put(core, info);
|
||||
|
||||
if (sb.length() == 0) sb.append("ASYNC ");
|
||||
sb.append(" NEW_CORE " + info.shortId);
|
||||
sb.append(" name=" + core.getName());
|
||||
sb.append(" " + core);
|
||||
}
|
||||
|
||||
if (zkController == null) {
|
||||
zkController = core.getCoreDescriptor().getCoreContainer()
|
||||
.getZkController();
|
||||
}
|
||||
if (zkController != null) {
|
||||
if (info.url == null) {
|
||||
info.url = zkController.getBaseUrl() + "/" + core.getName();
|
||||
sb.append(" url=" + info.url + " node=" + zkController.getNodeName());
|
||||
}
|
||||
|
||||
Map<String,Object> coreProps = getReplicaProps(zkController, core);
|
||||
if (info.coreProps == null || !coreProps.equals(info.coreProps)) {
|
||||
info.coreProps = coreProps;
|
||||
final String corePropsString = "coll:"
|
||||
+ core.getCoreDescriptor().getCloudDescriptor()
|
||||
.getCollectionName() + " core:" + core.getName() + " props:"
|
||||
+ coreProps;
|
||||
sb.append(" " + info.shortId + "_STATE=" + corePropsString);
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
if (sb.length() > 0) sb.append('\n');
|
||||
sb.append(timeFromStart);
|
||||
|
||||
// sb.append("\nL").append(record.getSequenceNumber()); // log number is
|
||||
// useful for sequencing when looking at multiple parts of a log file, but
|
||||
// ms since start should be fine.
|
||||
appendThread(sb, event);
|
||||
|
||||
if (info != null) {
|
||||
sb.append(' ').append(info.shortId); // core
|
||||
}
|
||||
if (zkController != null) {
|
||||
sb.append(" P").append(zkController.getHostPort()); // todo: should be
|
||||
// able to get this
|
||||
// from core container
|
||||
// for non zk tests
|
||||
}
|
||||
|
||||
if (shortClassName.length() > 0) {
|
||||
sb.append(' ').append(shortClassName);
|
||||
}
|
||||
|
||||
if (event.getLevel() != Level.INFO) {
|
||||
sb.append(' ').append(event.getLevel());
|
||||
}
|
||||
|
||||
sb.append(' ');
|
||||
appendMultiLineString(sb, message);
|
||||
ThrowableInformation thInfo = event.getThrowableInformation();
|
||||
if (thInfo != null) {
|
||||
Throwable th = event.getThrowableInformation().getThrowable();
|
||||
if (th != null) {
|
||||
sb.append(' ');
|
||||
String err = SolrException.toStr(th);
|
||||
String ignoredMsg = SolrException.doIgnore(th, err);
|
||||
if (ignoredMsg != null) {
|
||||
sb.append(ignoredMsg);
|
||||
} else {
|
||||
sb.append(err);
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
sb.append('\n');
|
||||
|
||||
/***
|
||||
* Isn't core specific... prob better logged from zkController if (info !=
|
||||
* null) { ClusterState clusterState = zkController.getClusterState(); if
|
||||
* (info.clusterState != clusterState) { // something has changed in the
|
||||
* matrix... sb.append(zkController.getBaseUrl() +
|
||||
* " sees new ClusterState:"); } }
|
||||
***/
|
||||
|
||||
return sb.toString();
|
||||
}
|
||||
|
||||
private Map<String,Object> getReplicaProps(ZkController zkController, SolrCore core) {
|
||||
final String collection = core.getCoreDescriptor().getCloudDescriptor().getCollectionName();
|
||||
Replica replica = zkController.getClusterState().getReplica(collection, zkController.getCoreNodeName(core.getCoreDescriptor()));
|
||||
if(replica!=null) {
|
||||
return replica.getProperties();
|
||||
}
|
||||
return Collections.EMPTY_MAP;
|
||||
}
|
||||
|
||||
private void addFirstLine(StringBuilder sb, String msg) {
|
||||
// INFO: [] webapp=/solr path=/select params={q=foobarbaz} hits=0 status=0
|
||||
// QTime=1
|
||||
|
||||
if (!shorterFormat || !msg.startsWith("[")) {
|
||||
sb.append(msg);
|
||||
return;
|
||||
}
|
||||
|
||||
int idx = msg.indexOf(']');
|
||||
if (idx < 0 || !msg.startsWith(" webapp=", idx + 1)) {
|
||||
sb.append(msg);
|
||||
return;
|
||||
}
|
||||
|
||||
idx = msg.indexOf(' ', idx + 8); // space after webapp=
|
||||
if (idx < 0) {
|
||||
sb.append(msg);
|
||||
return;
|
||||
}
|
||||
idx = msg.indexOf('=', idx + 1); // = in path=
|
||||
if (idx < 0) {
|
||||
sb.append(msg);
|
||||
return;
|
||||
}
|
||||
|
||||
int idx2 = msg.indexOf(' ', idx + 1);
|
||||
if (idx2 < 0) {
|
||||
sb.append(msg);
|
||||
return;
|
||||
}
|
||||
|
||||
sb.append(msg.substring(idx + 1, idx2 + 1)); // path
|
||||
|
||||
idx = msg.indexOf("params=", idx2);
|
||||
if (idx < 0) {
|
||||
sb.append(msg.substring(idx2));
|
||||
} else {
|
||||
sb.append(msg.substring(idx + 7));
|
||||
}
|
||||
}
|
||||
|
||||
private void appendMultiLineString(StringBuilder sb, String msg) {
|
||||
int idx = msg.indexOf('\n');
|
||||
if (idx < 0) {
|
||||
addFirstLine(sb, msg);
|
||||
return;
|
||||
}
|
||||
|
||||
int lastIdx = -1;
|
||||
for (;;) {
|
||||
if (idx < 0) {
|
||||
if (lastIdx == -1) {
|
||||
addFirstLine(sb, msg.substring(lastIdx + 1));
|
||||
} else {
|
||||
sb.append(msg.substring(lastIdx + 1));
|
||||
}
|
||||
break;
|
||||
}
|
||||
if (lastIdx == -1) {
|
||||
addFirstLine(sb, msg.substring(lastIdx + 1, idx));
|
||||
} else {
|
||||
sb.append(msg.substring(lastIdx + 1, idx));
|
||||
}
|
||||
|
||||
sb.append("\n\t");
|
||||
lastIdx = idx;
|
||||
idx = msg.indexOf('\n', lastIdx + 1);
|
||||
}
|
||||
}
|
||||
|
||||
// TODO: name this better... it's only for cloud tests where every core
|
||||
// container has just one solr server so Port/Core are fine
|
||||
public boolean shorterFormat = false;
|
||||
|
||||
public void setShorterFormat() {
|
||||
shorterFormat = true;
|
||||
// looking at /update is enough... we don't need "UPDATE /update"
|
||||
methodAlias.put(new Method(
|
||||
"org.apache.solr.update.processor.LogUpdateProcessor", "finish"), "");
|
||||
}
|
||||
|
||||
private Method classAndMethod = new Method(null, null); // don't need to be
|
||||
// thread safe
|
||||
|
||||
private String getShortClassName(String name, String method) {
|
||||
classAndMethod.className = name;
|
||||
classAndMethod.methodName = method;
|
||||
|
||||
String out = methodAlias.get(classAndMethod);
|
||||
if (out != null) return out;
|
||||
|
||||
StringBuilder sb = new StringBuilder();
|
||||
|
||||
int lastDot = name.lastIndexOf('.');
|
||||
if (lastDot < 0) return name + '.' + method;
|
||||
|
||||
int prevIndex = -1;
|
||||
for (;;) {
|
||||
char ch = name.charAt(prevIndex + 1);
|
||||
sb.append(ch);
|
||||
int idx = name.indexOf('.', prevIndex + 1);
|
||||
ch = name.charAt(idx + 1);
|
||||
if (idx >= lastDot || Character.isUpperCase(ch)) {
|
||||
sb.append(name.substring(idx));
|
||||
break;
|
||||
}
|
||||
prevIndex = idx;
|
||||
}
|
||||
|
||||
return sb.toString() + '.' + method;
|
||||
}
|
||||
|
||||
@Override
|
||||
public void activateOptions() {}
|
||||
|
||||
@Override
|
||||
public boolean ignoresThrowable() {
|
||||
return false;
|
||||
}
|
||||
}
|
||||
|
|
@ -3,7 +3,7 @@ log4j.rootLogger=INFO, CONSOLE
|
|||
|
||||
log4j.appender.CONSOLE=org.apache.log4j.ConsoleAppender
|
||||
log4j.appender.CONSOLE.Target=System.err
|
||||
log4j.appender.CONSOLE.layout=org.apache.log4j.PatternLayout
|
||||
log4j.appender.CONSOLE.layout=org.apache.solr.util.SolrLogLayout
|
||||
log4j.appender.CONSOLE.layout.ConversionPattern=%-5p - %d{yyyy-MM-dd HH:mm:ss.SSS}; %C; %m\n
|
||||
|
||||
log4j.logger.org.apache.zookeeper=WARN
|
||||
|
|
|
|||
|
|
@ -2,8 +2,8 @@
|
|||
log4j.rootLogger=INFO, CONSOLE
|
||||
|
||||
log4j.appender.CONSOLE=org.apache.log4j.ConsoleAppender
|
||||
|
||||
log4j.appender.CONSOLE.layout=org.apache.log4j.PatternLayout
|
||||
log4j.appender.CONSOLE.Target=System.err
|
||||
log4j.appender.CONSOLE.layout=org.apache.solr.util.SolrLogLayout
|
||||
log4j.appender.CONSOLE.layout.ConversionPattern=%-5p - %d{yyyy-MM-dd HH:mm:ss.SSS}; %C; %m\n
|
||||
|
||||
log4j.logger.org.apache.zookeeper=WARN
|
||||
Loading…
Reference in New Issue