logging-log4j2
logging-log4j2 copied to clipboard
Published
20 hours ago •
apache
apache
Debug level logs are getting printed when log level is set WARN
Hi Team,
Debug level logs are getting printed when log level is set WARN, please refer the below log4j configs and sample java code where Debug logs are getting printed.
<?xml version="1.0" encoding="UTF-8"?>
<Configuration>
<Properties>
<Property name="sourceApp">${bundle:application:spring.application.name}</Property>
<Property name="sourceAppVersion">${bundle:application:spring.application.version}</Property>
<Property name="subsystem">${bundle:application:spring.module.name}</Property>
</Properties>
<Appenders>
<Console name="console" target="SYSTEM_OUT">
<JsonTemplateLayout eventTemplateUri="classpath:JsonLayout.json">
<EventTemplateAdditionalField key="messageId" value="$${ctx:x-request-id:-}" />
<EventTemplateAdditionalField key="messageTimestamp" value="$${date:YYYY-MM-dd'T'HH:mm:ss.SSSZ}" />
<EventTemplateAdditionalField key="application" value="$${env:APP_NAME}" />
<EventTemplateAdditionalField key="microservice" value="$${env:MICROSERVICE_NAME}" />
<EventTemplateAdditionalField key="engVersion" value="$${env:ENGINEERING_VERSION}" />
<EventTemplateAdditionalField key="mktgVersion" value="$${env:MARKETING_VERSION}" />
<EventTemplateAdditionalField key="namespace" value="$${env:K8S_NAMESPACE}" />
<EventTemplateAdditionalField key="node" value="$${env:K8S_NODE}" />
<EventTemplateAdditionalField key="pod" value="$${env:POD_NAME}" />
<EventTemplateAdditionalField key="subsystem" value="${subsystem}" />
<EventTemplateAdditionalField key="instanceType" value="prod" />
<EventTemplateAdditionalField key="processId" value="$${sys:PID}" />
</JsonTemplateLayout>
</Console>
</Appenders>
<Loggers>
<Root level="info" additivity="false">
<AppenderRef ref="console" />
</Root>
</Loggers>
</Configuration>
java code:
import java.util.List;
import java.util.Map;
import java.util.Objects;
import java.util.Set;
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
import org.springframework.http.HttpHeaders;
public class LciUtility {
private static final Logger logger = LogManager.getLogger(LciUtility.class.getClass());
static PeerLciLocalCache peerLciLocalCache = null;
/**
* populateRelCapacityInPriorityMap method updates the priority map in which it calculates the
* effective and relative capacity of each destination weight and puts it back
* in the map.
*
* @param priorityMap
* @param routeList
* @param isInterPlmn
*/
public static void populateRelCapacityInPriorityMap(Map<Integer, Set<DestinationIndexAndCapacity>> priorityMap,
List<DestinationWeight> routeList, boolean isInterPlmn, StreamInfo streamInfo) {
if (logger.isDebugEnabled()) {
logger.debug("IN: LciUtility::populateRelCapacityInPriorityMap() priorityMap before update ::{} ", priorityMap);
}
int index = 0;
DestinationWeight destWt = null;
//int load = 0;
PeerLciData data = null;
int totalCapacity = 0;
DestinationIndexAndCapacity forwardRouteIndex = streamInfo.getDestinationList().getFwdRouteIndex();
boolean needForwardRouteIndexUpdate = false;
if(Objects.nonNull(forwardRouteIndex))
{
needForwardRouteIndexUpdate = true;
}
peerLciLocalCache = BeanUtil.getBean(PeerLciLocalCache.class);
for (Map.Entry<Integer, Set<DestinationIndexAndCapacity>> entry : priorityMap.entrySet()) {
totalCapacity = 0;
Set<DestinationIndexAndCapacity> indexCapSet = entry.getValue();
//Skipping the relative capacity calculation if set has only one element. Relative capacity for single member will
//always be 100
if(indexCapSet.size() == 1) {
if (logger.isDebugEnabled()) {
logger.debug("DestinationIndexAndCapacity set size is 1 for priority :{}", entry.getKey());
}
//indexCapSet.stream().findFirst().get().setCapacity(100);
DestinationIndexAndCapacity indexCap = indexCapSet.stream().findFirst().get();
indexCap.setCapacity(100);
if(needForwardRouteIndexUpdate && forwardRouteIndex.getIndex().equals(indexCap.getIndex())) {
forwardRouteIndex.setCapacity(indexCap.getCapacity());
if (logger.isDebugEnabled()) {
logger.debug(
"LciUtility::populateRelCapacityInPriorityMap()::forwardRouteIndex After update : {}",
forwardRouteIndex);
}
needForwardRouteIndexUpdate = false;
}
continue;
}
for (DestinationIndexAndCapacity destIndexCapcity : indexCapSet) {
index = destIndexCapcity.getIndex();
destWt = routeList.get(index);
if (logger.isDebugEnabled()) {
logger.debug("Host is {} RemoteHost {}, isInterPlmn {}", destWt.getDestination().getHost(),destWt.getIsRemoteapp(),isInterPlmn);
}
data = getPeerLciData(destWt, isInterPlmn, streamInfo.getNfServiceType());
if (Objects.isNull(data)) {
logger.debug("OUT: LciUtility::populateRelCapacityInPriorityMap():: LCI data is not present. ");
continue;
} else {
if (logger.isDebugEnabled()) {
logger.debug("LciUtility::populateRelCapacityInPriorityMap():: value of load from cache is :: {} ", data);
}
destIndexCapcity.setCapacity(calculateEffectiveCapacity(data.getP().getL(), destIndexCapcity.getCapacity()));
totalCapacity = totalCapacity + destIndexCapcity.getCapacity();
}
}
// setting the relative capacity of all weights
if (totalCapacity > 0) {
for (DestinationIndexAndCapacity destIndexCapcity : indexCapSet) {
destIndexCapcity.populateRelativeCapacity(totalCapacity);
if(needForwardRouteIndexUpdate && forwardRouteIndex.getIndex().equals(destIndexCapcity.getIndex())) {
forwardRouteIndex.setCapacity(destIndexCapcity.getCapacity());
if (logger.isDebugEnabled()) {
logger.debug(
"LciUtility::populateRelCapacityInPriorityMap()::forwardRouteIndex After update : {}",
forwardRouteIndex);
}
needForwardRouteIndexUpdate = false;
}
}
}
}
if (logger.isDebugEnabled()) {
logger.debug("OUT: LciUtility::populateRelCapacityInPriorityMap() priorityMap after update ::{} ",
priorityMap);
}
}
/**
* This method is calculating the effective capacity.
*
* @param load
* @param capacity
* @return
*/
private static int calculateEffectiveCapacity(int load, int capacity) {
int effectiveCapacity = ((100 - load) * capacity) / 100; // 50*5000/100
logger.debug("Original Calacity is {}, Effective Capacity is {}", capacity, effectiveCapacity);
return effectiveCapacity;
}
/**
* This method is fetch the LCI data from local cache for different request type.
*
* @param destWt
* @param isInterPlmn
* @return
*/
public static PeerLciData getPeerLciData(DestinationWeight destWt, boolean isInterPlmn, String srvName) {
logger.debug("IN: LciUtility::getPeerLciData()");
if(Objects.isNull(peerLciLocalCache)) {
peerLciLocalCache = BeanUtil.getBean(PeerLciLocalCache.class);
}
PeerLciData data = null;
if(isInterPlmn) {
data = peerLciLocalCache.getPeerLciBySeppFqdn(destWt.getDestination().getHost());
if (logger.isDebugEnabled()) {
logger.debug("PeerLciData for InterPLMN {}", data);
}
} else if (destWt.getIsRemoteapp() == true) {
data = peerLciLocalCache.getPeerLciByappFqdn(CommonUtils.getSelectedDestinationFqdn(destWt.getDestination().getHost()));
if (logger.isDebugEnabled()) {
logger.debug("PeerLciData for Interapp {}", data);
}
} else if (destWt.getIsRemoteapp() == false) {
if (logger.isDebugEnabled()) {
logger.debug("instanceId is {} , svcInstanceId is {}, srvName : {}", destWt.getOcappw_nf_instance_id(),
destWt.getOcappw_service_instance_id(), srvName);
}
if(srvName.equalsIgnoreCase(CommonConstants.getDefaultServiceType()) || srvName.equalsIgnoreCase(CommonConstants.getUnknown())) {
data = peerLciLocalCache.getPeerLciByNfInstAndSvcInst(destWt.getOcappw_nf_instance_id(), null);
} else {
data = peerLciLocalCache.getPeerLciByNfInstAndSvcInst(destWt.getOcappw_nf_instance_id(),
destWt.getOcappw_service_instance_id());
}
}
if (logger.isDebugEnabled()) {
logger.debug("OUT: LciUtility::getPeerLciData(), PeerLciData fetched::{}", data);
}
return data;
}
public static PeerLciData getPeerLciData(LciHeader lciHeader, String instanceId) {
Map<String, String> lcScope = lciHeader.getLcScope();
if (lcScope == null || lcScope.size() < 1) {
logger.debug("OUT: LciUtility::getPeerLciData() lcScope is Null or Empty key");
return null;
} else {
String lcScopeKey = null;
String nfInstId = instanceId;
String svcInstId = CommonConstants.DEFAULT;
String lcScopeValue = null;
for (Map.Entry<String, String> entry : lcScope.entrySet()) {
lcScopeKey = entry.getKey();
if (lcScopeKey.equals(CommonConstants.app_FQDN)) {
lcScopeValue = entry.getValue();
if (logger.isDebugEnabled()) {
logger.debug(
"OUT: LciUtility::getPeerLciData(lciHeader, instanceId). Lci scope is {}, value : {}",
lcScopeKey, lcScopeValue);
}
return peerLciLocalCache.getPeerLciByappFqdn(lcScopeValue);
}
if (lcScopeKey.equals(CommonConstants.SEPP_FQDN)) {
lcScopeValue = entry.getValue();
if (logger.isDebugEnabled()) {
logger.debug(
"OUT: LciUtility::getPeerLciData(lciHeader, instanceId). Lci scope is {}, value : {}",
lcScopeKey, lcScopeValue);
}
return peerLciLocalCache.getPeerLciBySeppFqdn(lcScopeValue);
} else {
if (lcScopeKey.equals(CommonConstants.NF_INSTANCE)) {
nfInstId = entry.getValue();
logger.debug("LciUtility::getPeerLciData(lciHeader, instanceId). nfInstId : {}", nfInstId);
if (StringUtils.isEmpty(nfInstId)) {
nfInstId = instanceId;
}
} else if (lcScopeKey
.equals(CommonConstants.NF_SVC_INSTANCE)) {
svcInstId = entry.getValue();
logger.debug("LciUtility::getPeerLciData(lciHeader, instanceId). svcInstId : {}", svcInstId);
}
}
}
if (StringUtils.isEmpty(nfInstId)) {
nfInstId = instanceId;
}
logger.debug("OUT: LciUtility::getPeerLciData(lciHeader, instanceId)");
return peerLciLocalCache.getPeerLciByNfInstAndSvcInst(nfInstId, svcInstId);
}
}
public static void updateLciHeader(StreamInfo streamInfo, HttpHeaders headers, Event eventType) {
logger.debug("IN: LciUtility::updateLciHeader()");
LciConfiguration lciConfiguration = BeanUtil.getBean(LciConfiguration.class);
if (headers.containsKey(CommonConstants.LCI_HEADER_NAME) == false) {
logger.debug("OUT: LciUtility::updateLciHeader()");
return;
}
if (lciConfiguration.isRelayPeerLci() == false) {
headers.remove(CommonConstants.LCI_HEADER_NAME);
logger.debug("OUT: LciUtility::updateLciHeader()");
return;
}
LciContext lciContext = streamInfo.getLciContext();
List<LciHeader> lciHeaders = eventType.equals(Event.Request) ? lciContext.getReqLciHeader()
: lciContext.getRspLciHeader();
if(lciHeaders == null || lciHeaders.isEmpty()) {
logger.debug("OUT: LciUtility::lciHeaders is null or Empty");
return;
}
headers.remove(CommonConstants.LCI_HEADER_NAME);
Map<String, String> lcScope;
String lcScopeKey;
String lciheader;
//boolean isPeerLciHeaderForwarded=false;
for (LciHeader lciHeader : lciHeaders) {
lcScope = lciHeader.getLcScope();
if(lcScope == null || lcScope.size() < 1) {
continue;
}
Map.Entry<String, String> entry = lcScope.entrySet().stream().findFirst().get();
lcScopeKey = entry.getKey();
lciheader = lciHeader.getRcvHeaderValue();
if (!lcScopeKey.equals(CommonConstants.LCI_app_FQDN) && !lcScopeKey.equals(CommonConstants.LCI_SEPP_FQDN)) {
headers.add(CommonConstants.LCI_HEADER_NAME, lciheader);
}
}
logger.debug("OUT: LciUtility::updateLciHeader()");
}
public static void updatelciHeaders(HttpHeaders httpHeaders, StreamInfo streamInfo,
LciConfiguration lciConfiguration, SutLciCacheMgr sutLciCacheMgr) {
if (logger.isDebugEnabled()) {
logger.debug("IN: LciUtility::updatelciHeaders() : IsRemoteappSelected : {}, TargetPlmnType() : {}",
streamInfo.getIsRemoteappSelected(), streamInfo.getTargetPlmnType());
}
if (lciConfiguration.isLciFeatureEnabled()) {
logger.debug("LciUtility::updatelciHeaders(). Lci feature is enabled so handling the lci response headers");
//app-C handling - this condition will true only for sepp-C
if (streamInfo.getIsRemoteappSelected() || streamInfo.getTargetPlmnType() == TargetPlmnType.TPT_INTER_PLMN) {
LciUtility.updateLciHeader(streamInfo, httpHeaders, Event.Response);
if (logger.isDebugEnabled()) {
logger.debug("LciUtility::updatelciHeaders() LciFeature is Enabled : headrrs :{}", httpHeaders);
}
}
//app-P handling - this condition will true only for sepp-p
else if (streamInfo.getIsReceivedInterappMessage() || streamInfo.isMessageReceivedFromSepp()) {
//do nothing
logger.debug("lci headers is not required to update");
}
else if (lciConfiguration.isRelayPeerLci() == false) {
logger.debug("lci relay flag is false ... so removing all lci headers from response");
httpHeaders.remove(CommonConstants.LCI_HEADER_NAME);
}
if (Objects.nonNull(httpHeaders.getFirst(CommonConstants.LCI_HEADER_NAME))) {
logger.debug("LciUtility::updatelciHeaders(). Pegging the nf_lci_tx header towards consumer");
}
}
populateSutLciForConsumer(streamInfo, httpHeaders, sutLciCacheMgr);
if (logger.isDebugEnabled()) {
logger.debug("OUT: LciUtility::updatelciHeaders() : headers: {}", httpHeaders);
}
}
public static void populateSutLciForConsumer(StreamInfo streamInfo, HttpHeaders httpHeaders,
SutLciCacheMgr sutLciCacheMgr) {
logger.debug("IN: LciUtility::populateSutLciForConsumer()");
sutLciCacheMgr.populateLciHeaderForConsumer(streamInfo);
LciHeader lciHeader = streamInfo.getSutLciForConsumer();
if (lciHeader == null) {
logger.debug("OUT: LciUtility::populateSutLciForConsumer() - null");
return;
}
String lciHeaderStr = LciHeader.encode(lciHeader);
if (StringUtils.isEmpty(lciHeaderStr)) {
logger.debug("OUT: LciUtility::populateSutLciForConsumer() - empty");
return;
}
httpHeaders.add(CommonConstants.LCI_HEADER_NAME,lciHeaderStr);
if (logger.isDebugEnabled()) {
logger.debug("OUT: LciUtility::populateSutLciForConsumer() : lciHeaderStr: {}", lciHeaderStr);
}
}
}
I am updating log level dynamically and log controller with below code reference.
Configurator.setLevel("com.comp.cgbu.cne", Level.toLevel(loggingLevels.getAppLogLevel())); --> org.apache.logging.log4j.core.config.Configurator#setLevel(java.lang.String, org.apache.logging.log4j.Level)
private void updateFilter(int rate, String filterNewLoglevel) {
LoggerContext ctx = (LoggerContext) LogManager.getContext(false);
Configuration config = ctx.getConfiguration();
LoggerConfig loggerConfig = config.getLoggerConfig(LogManager.ROOT_LOGGER_NAME);
Filter filter = loggerConfig.getFilter();
if (logger.isLogLevelEnabled(LOGLEVEL.DEBUG)) {
logger.construct("logMsg", "updateFilter .");
logger.construct("rate: ", rate);
logger.construct("filterLoglevel: ", filterNewLoglevel);
logger.submit();
}
// Remove Filter:
if (filter != null) {
if (logger.isLogLevelEnabled(LOGLEVEL.DEBUG)) {
logger.construct("logMsg",
"filter to be removed.");
logger.construct("filter: ", filter);
logger.submit();
}
// in case of more than one filter, remove the burst filter only
if (filter instanceof CompositeFilter) {
CompositeFilter compositeFilter = (CompositeFilter) filter;
compositeFilter.iterator().forEachRemaining(ftr -> {
if (ftr instanceof BurstFilter) {
loggerConfig.removeFilter(ftr);
}
});
} else {
//remove only if the type is burst filter
if (filter instanceof BurstFilter) {
loggerConfig.removeFilter(filter);
}
}
}
//Adding filter
addFilter(loggerConfig, rate, filterNewLoglevel);
if ( !filterNewLoglevel.equals(Level.OFF.toString()) ) {
BurstFilter burstFilter = BurstFilter.newBuilder().setLevel(Level.toLevel(filterNewLoglevel)).setRate(rate).setMaxBurst(rate)
.setOnMatch(Result.ACCEPT).setOnMismatch(Result.DENY).build();
loggerConfig.addFilter(burstFilter);
if (logger.isLogLevelEnabled(LOGLEVEL.DEBUG)) {
logger.construct("logMsg", "BrustFilter added.");
logger.construct("BrustFilter: ", burstFilter);
logger.submit();
}
} else {
if (logger.isLogLevelEnabled(LOGLEVEL.DEBUG)) {
logger.construct("logMsg",
"Level set as OFF, BrustFilter not added.");
logger.submit();
}
}
//updating loggers
ctx.updateLoggers(config);
}
Kindly suggest how we can to prevent this behaviour.
Regards, Mohammad.
