From 12f7cdebcff9ac91fbaa7f55a40ae4d511fec821 Mon Sep 17 00:00:00 2001 From: David Goulet Date: Wed, 7 May 2014 11:33:41 -0400 Subject: [PATCH] Fix: remove JUL loglevel filtering from the agent The loglevel filtering is now done on the UST side setup by liblttng-ctl. To achieve that, the agent has a new structure to support two semantic concepts being a LTTng event and a JUL logger that have a relation of N:1. This addition does not impact the current interfaces of the agent. Signed-off-by: David Goulet Signed-off-by: Mathieu Desnoyers --- .../org/lttng/ust/jul/LTTngEvent.java | 9 +- .../org/lttng/ust/jul/LTTngLogHandler.java | 166 +++++++++-------- .../lttng/ust/jul/LTTngSessiondCmd2_4.java | 170 +++++++++--------- .../lttng/ust/jul/LTTngTCPSessiondClient.java | 136 +++++++------- 4 files changed, 241 insertions(+), 240 deletions(-) diff --git a/liblttng-ust-jul/org/lttng/ust/jul/LTTngEvent.java b/liblttng-ust-jul/org/lttng/ust/jul/LTTngEvent.java index 6d81922e..4eacb361 100644 --- a/liblttng-ust-jul/org/lttng/ust/jul/LTTngEvent.java +++ b/liblttng-ust-jul/org/lttng/ust/jul/LTTngEvent.java @@ -17,7 +17,6 @@ package org.lttng.ust.jul; -import java.util.ArrayList; import java.lang.String; import org.lttng.ust.jul.LTTngUst; @@ -36,14 +35,10 @@ class LTTngLogLevel { public class LTTngEvent { /* Name of the event. */ public String name; - public ArrayList logLevels = new ArrayList(); - - public void addLogLevel(int loglevel, int loglevel_type) { - this.logLevels.add(new LTTngLogLevel(loglevel, loglevel_type)); - } + public LTTngLogLevel logLevel; public LTTngEvent(String name, int loglevel, int loglevel_type) { this.name = name; - this.addLogLevel(loglevel, loglevel_type); + this.logLevel = new LTTngLogLevel(loglevel, loglevel_type); } } diff --git a/liblttng-ust-jul/org/lttng/ust/jul/LTTngLogHandler.java b/liblttng-ust-jul/org/lttng/ust/jul/LTTngLogHandler.java index ddeb5eb3..8c795127 100644 --- a/liblttng-ust-jul/org/lttng/ust/jul/LTTngLogHandler.java +++ b/liblttng-ust-jul/org/lttng/ust/jul/LTTngLogHandler.java @@ -22,37 +22,49 @@ import java.util.logging.Handler; import java.util.logging.LogRecord; import java.util.logging.LogManager; import java.util.logging.Level; -import java.util.ArrayList; +import java.util.logging.Logger; +import java.util.Collections; import java.util.HashMap; +import java.util.Map; import org.lttng.ust.jul.LTTngUst; -/* Note: This is taken from the LTTng tools ABI. */ -class LTTngLogLevelABI { - /* Loglevel type. */ - public static final int LOGLEVEL_TYPE_ALL = 0; - public static final int LOGLEVEL_TYPE_RANGE = 1; - public static final int LOGLEVEL_TYPE_SINGLE = 2; -} - -public class LTTngLogHandler extends Handler { +class LTTngLogger { /* - * Indicate if the enable all event has been seen and if yes logger that we - * enabled should use the loglevel/type below. + * The log handler is attached to the logger when the reference count is + * nonzero. Each event referring to a logger holds a reference to that + * logger. If down to 0, this object is removed from the handler. */ - public int logLevelUseAll = 0; - public ArrayList logLevelsAll = - new ArrayList(); + public int refcount; + public String name; + Logger logger; + + public LTTngLogger(String name, Logger logger) { + this.name = name; + this.refcount = 0; + this.logger = logger; + } + public void attach(LTTngLogHandler handler) { + this.logger.addHandler(handler); + } + + public void detach(LTTngLogHandler handler) { + this.logger.removeHandler(handler); + } +} + +public class LTTngLogHandler extends Handler { /* Am I a root Log Handler. */ public int is_root = 0; public LogManager logManager; - /* Indexed by name and corresponding LTTngEvent. */ - private HashMap eventMap = - new HashMap(); + /* Logger object attached to this handler that can trigger a tracepoint. */ + private Map loggerMap = + Collections.synchronizedMap(new HashMap()); + /* Constructor */ public LTTngLogHandler(LogManager logManager) { super(); @@ -62,24 +74,61 @@ public class LTTngLogHandler extends Handler { LTTngUst.init(); } - /** - * Add event to handler hash map if new. - * - * @return 0 if it did not exist else 1. + /* + * Return true if the logger is enabled and attached. Else, if not found, + * return false. + */ + public boolean exists(String name) { + if (loggerMap.get(name) != null) { + return true; + } else { + return false; + } + } + + /* + * Attach an event to this handler. If no logger object exists, one is + * created else the refcount is incremented. */ - public int setEvent(LTTngEvent new_event) { - LTTngEvent event; - - event = eventMap.get(new_event.name); - if (event == null) { - eventMap.put(new_event.name, new_event); - /* Did not exists. */ - return 0; + public void attachEvent(LTTngEvent event) { + Logger logger; + LTTngLogger lttngLogger; + + /* Does the logger actually exist. */ + logger = this.logManager.getLogger(event.name); + if (logger == null) { + /* Stop attach right now. */ + return; + } + + lttngLogger = loggerMap.get(event.name); + if (lttngLogger == null) { + lttngLogger = new LTTngLogger(event.name, logger); + + /* Attach the handler to the logger and add is to the map. */ + lttngLogger.attach(this); + lttngLogger.refcount = 1; + loggerMap.put(lttngLogger.name, lttngLogger); } else { - /* Add new event loglevel to existing event. */ - event.logLevels.addAll(new_event.logLevels); - /* Already exists. */ - return 1; + lttngLogger.refcount += 1; + } + } + + /* + * Dettach an event from this handler. If the refcount goes down to 0, the + * logger object is removed thus not attached anymore. + */ + public void detachEvent(LTTngEvent event) { + LTTngLogger logger; + + logger = loggerMap.get(event.name); + if (logger != null) { + logger.refcount -= 1; + if (logger.refcount == 0) { + /* Dettach from handler since no more event is associated. */ + logger.detach(this); + loggerMap.remove(logger); + } } } @@ -87,8 +136,7 @@ public class LTTngLogHandler extends Handler { * Cleanup this handler state meaning put it back to a vanilla state. */ public void clear() { - this.eventMap.clear(); - this.logLevelsAll.clear(); + this.loggerMap.clear(); } @Override @@ -99,49 +147,11 @@ public class LTTngLogHandler extends Handler { @Override public void publish(LogRecord record) { - int fire_tp = 0, rec_log_level, ev_type, ev_log_level; - LTTngEvent event; - LTTngLogLevel lttngLogLevel; - String logger_name = record.getLoggerName(); - - /* Get back the event if any and check for loglevel. */ - event = eventMap.get(logger_name); - if (event != null) { - for (LTTngLogLevel ev_log : event.logLevels) { - /* Get record and event log level. */ - rec_log_level = record.getLevel().intValue(); - ev_log_level = ev_log.level; - - switch (ev_log.type) { - case LTTngLogLevelABI.LOGLEVEL_TYPE_RANGE: - if (ev_log_level <= rec_log_level) { - fire_tp = 1; - } - break; - case LTTngLogLevelABI.LOGLEVEL_TYPE_SINGLE: - if (ev_log_level == rec_log_level) { - fire_tp = 1; - } - break; - case LTTngLogLevelABI.LOGLEVEL_TYPE_ALL: - fire_tp = 1; - break; - } - - /* - * If we match, stop right now else continue to the next - * loglevel contained in the event. - */ - if (fire_tp == 1) { - break; - } - } - } else { - /* No loglevel attached thus fire tracepoint. */ - fire_tp = 1; - } + LTTngLogger logger; - if (fire_tp == 0) { + logger = loggerMap.get(record.getLoggerName()); + if (logger == null) { + /* Ignore and don't fire TP. */ return; } diff --git a/liblttng-ust-jul/org/lttng/ust/jul/LTTngSessiondCmd2_4.java b/liblttng-ust-jul/org/lttng/ust/jul/LTTngSessiondCmd2_4.java index 9b544be5..68083267 100644 --- a/liblttng-ust-jul/org/lttng/ust/jul/LTTngSessiondCmd2_4.java +++ b/liblttng-ust-jul/org/lttng/ust/jul/LTTngSessiondCmd2_4.java @@ -24,7 +24,9 @@ import java.lang.Object; import java.util.logging.Logger; import java.util.ArrayList; import java.util.HashMap; +import java.util.Map; import java.util.List; +import java.util.Set; import java.util.Enumeration; public interface LTTngSessiondCmd2_4 { @@ -143,33 +145,6 @@ public interface LTTngSessiondCmd2_4 { return data; } - /* - * Enable a logger meaning add our handler to it using an exiting - * event. If successful, the logger is added to the given enabled - * Loggers hashmap. - * - * @return 0 if NO logger is found else 1 if added. - */ - public int enableLogger(LTTngLogHandler handler, LTTngEvent event, - HashMap enabledLoggers) { - int ret; - Logger logger; - - logger = handler.logManager.getLogger(event.name); - if (logger == null) { - return 0; - } - - ret = handler.setEvent(event); - if (ret == 0) { - /* Newly created event, add the handler. */ - logger.addHandler(handler); - enabledLoggers.put(event.name, logger); - } - - return 1; - } - /** * Execute enable handler action which is to enable the given handler * to the received name. @@ -177,14 +152,14 @@ public interface LTTngSessiondCmd2_4 { * @return Event name as a string if the event is NOT found thus was * not enabled. */ - public LTTngEvent execute(LTTngLogHandler handler, HashMap enabledLoggers) { - int ret; - Logger logger; - LTTngEvent event = null; + public void execute(LTTngLogHandler handler, + Map> eventMap, Set wildCardSet) { + ArrayList bucket; + LTTngEvent event; if (name == null) { this.code = lttng_jul_ret_code.CODE_INVALID_CMD; - return null; + return; } /* Wild card to enable ALL logger. */ @@ -192,16 +167,14 @@ public interface LTTngSessiondCmd2_4 { String loggerName; Enumeration loggers = handler.logManager.getLoggerNames(); + /* Add event to the wildcard set. */ + wildCardSet.add(new LTTngEvent(name.trim(), lttngLogLevel, + lttngLogLevelType)); + /* - * Keep the loglevel value for all events in case an event - * appears later on. + * Create an event for each logger found and attach it to the + * handler. */ - if (lttngLogLevel != -1) { - handler.logLevelUseAll = 1; - handler.logLevelsAll.add(new LTTngLogLevel(lttngLogLevel, - lttngLogLevelType)); - } - while (loggers.hasMoreElements()) { loggerName = loggers.nextElement().toString(); /* Somehow there is always an empty string at the end. */ @@ -209,58 +182,69 @@ public interface LTTngSessiondCmd2_4 { continue; } + event = new LTTngEvent(loggerName, lttngLogLevel, + lttngLogLevelType); + /* Attach event to Log handler to it can be traced. */ + handler.attachEvent(event); + /* - * Create new event object and set it in the log handler so - * we can process the record entry with the right - * attributes like the loglevels. + * The agent timer call this function with eventMap set to + * null because it already has a reference to an existing + * event so is should not try to add a new one here. */ - event = new LTTngEvent(loggerName, 0, 0); - /* Clean up loglevel and merge the the ones from all events. */ - event.logLevels.clear(); - event.logLevels.addAll(handler.logLevelsAll); - enableLogger(handler, event, enabledLoggers); + if (eventMap != null) { + bucket = eventMap.get(loggerName); + if (bucket == null) { + bucket = new ArrayList(); + eventMap.put(loggerName, bucket); + } + bucket.add(event); + } } - this.code = lttng_jul_ret_code.CODE_SUCCESS_CMD; + } else { + event = new LTTngEvent(name.trim(), lttngLogLevel, + lttngLogLevelType); + /* Attach event to Log handler to it can be traced. */ + handler.attachEvent(event); /* - * Only return an event if this is a newly created event - * meaning the loglevel is valid. + * The agent timer call this function with eventMap set to + * null because it already has a reference to an existing + * event so is should not try to add a new one here. */ - if (lttngLogLevel != -1) { - event = new LTTngEvent("*", lttngLogLevel, lttngLogLevelType); + if (eventMap != null) { + bucket = eventMap.get(name.trim()); + if (bucket == null) { + bucket = new ArrayList(); + eventMap.put(name.trim(), bucket); + } + bucket.add(event); } - return event; } this.code = lttng_jul_ret_code.CODE_SUCCESS_CMD; - - /* - * Create new event object and set it in the log handler so we can - * process the record entry with the right attributes like the - * loglevels. - */ - event = new LTTngEvent(name.trim(), lttngLogLevel, - lttngLogLevelType); - ret = enableLogger(handler, event, enabledLoggers); - if (ret == 1) { - return null; - } - return event; + return; } } public class sessiond_disable_handler implements SessiondResponse, SessiondCommand { private final static int SIZE = 4; public String name; + public int lttngLogLevel; + public int lttngLogLevelType; /** Return status code to the session daemon. */ public lttng_jul_ret_code code; @Override public void populate(byte[] data) { + int data_offset = INT_SIZE * 2; + ByteBuffer buf = ByteBuffer.wrap(data); - buf.order(ByteOrder.BIG_ENDIAN); - name = new String(data, 0, data.length); + buf.order(ByteOrder.LITTLE_ENDIAN); + lttngLogLevel = buf.getInt(); + lttngLogLevelType = buf.getInt(); + name = new String(data, data_offset, data.length - data_offset); } @Override @@ -276,8 +260,10 @@ public interface LTTngSessiondCmd2_4 { * Execute disable handler action which is to disable the given handler * to the received name. */ - public void execute(LTTngLogHandler handler) { - Logger logger; + public void execute(LTTngLogHandler handler, + Map> eventMap, Set wildCardSet) { + ArrayList bucket; + LTTngEvent event; if (name == null) { this.code = lttng_jul_ret_code.CODE_INVALID_CMD; @@ -288,6 +274,11 @@ public interface LTTngSessiondCmd2_4 { if (name.trim().equals("*")) { String loggerName; Enumeration loggers = handler.logManager.getLoggerNames(); + + /* Remove event from the wildcard set. */ + wildCardSet.remove(new LTTngEvent(name.trim(), lttngLogLevel, + lttngLogLevelType)); + while (loggers.hasMoreElements()) { loggerName = loggers.nextElement().toString(); /* Somehow there is always an empty string at the end. */ @@ -295,20 +286,37 @@ public interface LTTngSessiondCmd2_4 { continue; } - logger = handler.logManager.getLogger(loggerName); - logger.removeHandler(handler); + event = new LTTngEvent(loggerName, lttngLogLevel, + lttngLogLevelType); + + bucket = eventMap.get(loggerName); + if (bucket != null) { + handler.detachEvent(event); + bucket.remove(event); + if (bucket.isEmpty() == true) { + eventMap.remove(bucket); + } + } } this.code = lttng_jul_ret_code.CODE_SUCCESS_CMD; - return; - } - - logger = handler.logManager.getLogger(name.trim()); - if (logger == null) { - this.code = lttng_jul_ret_code.CODE_UNK_LOGGER_NAME; } else { - logger.removeHandler(handler); - this.code = lttng_jul_ret_code.CODE_SUCCESS_CMD; + event = new LTTngEvent(this.name, lttngLogLevel, + lttngLogLevelType); + + bucket = eventMap.get(this.name); + if (bucket != null) { + handler.detachEvent(event); + bucket.remove(event); + if (bucket.isEmpty() == true) { + eventMap.remove(bucket); + } + this.code = lttng_jul_ret_code.CODE_SUCCESS_CMD; + } else { + this.code = lttng_jul_ret_code.CODE_UNK_LOGGER_NAME; + } } + + return; } } diff --git a/liblttng-ust-jul/org/lttng/ust/jul/LTTngTCPSessiondClient.java b/liblttng-ust-jul/org/lttng/ust/jul/LTTngTCPSessiondClient.java index 5fdb0498..a2d12fc3 100644 --- a/liblttng-ust-jul/org/lttng/ust/jul/LTTngTCPSessiondClient.java +++ b/liblttng-ust-jul/org/lttng/ust/jul/LTTngTCPSessiondClient.java @@ -34,8 +34,10 @@ import java.lang.management.ManagementFactory; import java.util.ArrayList; import java.util.HashMap; import java.util.HashSet; +import java.util.Map; import java.util.Iterator; import java.util.List; +import java.util.Enumeration; import java.util.Set; import java.util.Timer; import java.util.TimerTask; @@ -63,12 +65,18 @@ public class LTTngTCPSessiondClient { private Semaphore registerSem; private Timer eventTimer; - private Set enabledEventSet = - Collections.synchronizedSet(new HashSet()); + /* - * Map of Logger objects that have been enabled. They are indexed by name. + * Indexed by event name but can contains duplicates since multiple + * sessions can enable the same event with or without different loglevels. */ - private HashMap enabledLoggers = new HashMap(); + private Map> eventMap = + Collections.synchronizedMap( + new HashMap>()); + + private Set wildCardSet = + Collections.synchronizedSet(new HashSet()); + /* Timer delay at each 5 seconds. */ private final static long timerDelay = 5 * 1000; private static boolean timerInitialized; @@ -94,80 +102,67 @@ public class LTTngTCPSessiondClient { this.eventTimer.scheduleAtFixedRate(new TimerTask() { @Override public void run() { - synchronized (enabledEventSet) { - LTTngSessiondCmd2_4.sessiond_enable_handler enableCmd = new - LTTngSessiondCmd2_4.sessiond_enable_handler(); + LTTngSessiondCmd2_4.sessiond_enable_handler enableCmd = new + LTTngSessiondCmd2_4.sessiond_enable_handler(); + + synchronized (eventMap) { + String loggerName; + Enumeration loggers = handler.logManager.getLoggerNames(); + /* - * Modifying events in a Set will raise a - * ConcurrentModificationException. Thus, we remove an event - * and add its modified version to modifiedEvents when a - * modification is necessary. + * Create an event for each logger found and attach it to the + * handler. */ - Set modifiedEvents = new HashSet(); - Iterator it = enabledEventSet.iterator(); + while (loggers.hasMoreElements()) { + ArrayList bucket; - while (it.hasNext()) { - int ret; - Logger logger; - LTTngEvent event = it.next(); + loggerName = loggers.nextElement().toString(); - /* - * Check if this Logger name has been enabled already. Note - * that in the case of "*", it's never added in that hash - * table thus the enable command does a lookup for each - * logger name in that hash table for the * case in order - * to make sure we don't enable twice the same logger - * because JUL apparently accepts that the *same* - * LogHandler can be added twice on a Logger object... - * don't ask... - */ - logger = enabledLoggers.get(event.name); - if (logger != null) { + /* Logger is already enabled or end of list, skip it. */ + if (handler.exists(loggerName) == true || + loggerName.equals("")) { continue; } - /* - * Set to one means that the enable all event has been seen - * thus event from that point on must use loglevel for all - * events. Else the object has its own loglevel. - */ - if (handler.logLevelUseAll == 1) { - it.remove(); - event.logLevels.addAll(handler.logLevelsAll); - modifiedEvents.add(event); + bucket = eventMap.get(loggerName); + if (bucket == null) { + /* No event(s) exist for this logger. */ + continue; } - /* - * The all event is a special case since we have to iterate - * over every Logger to see which one was not enabled. - */ - if (event.name.equals("*")) { + for (LTTngEvent event : bucket) { enableCmd.name = event.name; - /* Tell the command NOT to add the loglevel. */ - enableCmd.lttngLogLevel = -1; - /* - * The return value is irrelevant since the * event is - * always kept in the set. - */ - enableCmd.execute(handler, enabledLoggers); - continue; - } + enableCmd.lttngLogLevel = event.logLevel.level; + enableCmd.lttngLogLevelType = event.logLevel.type; - ret = enableCmd.enableLogger(handler, event, enabledLoggers); - if (ret == 1) { - /* Enabled so remove the event from the set. */ - if (!modifiedEvents.remove(event)) { - /* - * event can only be present in one of - * the sets. - */ - it.remove(); - } + /* Event exist so pass null here. */ + enableCmd.execute(handler, null, wildCardSet); } } - enabledEventSet.addAll(modifiedEvents); } + /* Handle wild cards. */ + synchronized (wildCardSet) { + Map> modifiedEvents = + new HashMap>(); + Set tmpSet = new HashSet(); + Iterator it = wildCardSet.iterator(); + + while (it.hasNext()) { + LTTngEvent event = it.next(); + + /* Only support * for now. */ + if (event.name.equals("*")) { + enableCmd.name = event.name; + enableCmd.lttngLogLevel = event.logLevel.level; + enableCmd.lttngLogLevelType = event.logLevel.type; + + /* That might create a new event so pass the map. */ + enableCmd.execute(handler, modifiedEvents, tmpSet); + } + } + eventMap.putAll(modifiedEvents); + } } }, this.timerDelay, this.timerDelay); @@ -190,8 +185,8 @@ public class LTTngTCPSessiondClient { * Cleanup Agent state. */ private void cleanupState() { - enabledEventSet.clear(); - enabledLoggers.clear(); + eventMap.clear(); + wildCardSet.clear(); if (this.handler != null) { this.handler.clear(); } @@ -336,14 +331,7 @@ public class LTTngTCPSessiondClient { break; } enableCmd.populate(data); - event = enableCmd.execute(this.handler, this.enabledLoggers); - if (event != null) { - /* - * Add the event to the set so it can be enabled if - * the logger appears at some point in time. - */ - enabledEventSet.add(event); - } + enableCmd.execute(this.handler, this.eventMap, this.wildCardSet); data = enableCmd.getBytes(); break; } @@ -356,7 +344,7 @@ public class LTTngTCPSessiondClient { break; } disableCmd.populate(data); - disableCmd.execute(this.handler); + disableCmd.execute(this.handler, this.eventMap, this.wildCardSet); data = disableCmd.getBytes(); break; } -- 2.34.1