org.argeo.cms/src/org/argeo/cms/internal/kernel/NodeLogger.java

   1 package org.argeo.cms.internal.kernel;
   2
   3 import java.io.IOException;
   4 import java.net.URI;
   5 import java.nio.file.FileSystems;
   6 import java.nio.file.Path;
   7 import java.nio.file.Paths;
   8 import java.nio.file.StandardWatchEventKinds;
   9 import java.nio.file.WatchEvent;
  10 import java.nio.file.WatchKey;
  11 import java.nio.file.WatchService;
  12 import java.security.SignatureException;
  13 import java.util.ArrayList;
  14 import java.util.Collections;
  15 import java.util.Enumeration;
  16 import java.util.HashMap;
  17 import java.util.Iterator;
  18 import java.util.LinkedList;
  19 import java.util.List;
  20 import java.util.ListIterator;
  21 import java.util.Map;
  22 import java.util.Properties;
  23 import java.util.concurrent.BlockingQueue;
  24 import java.util.concurrent.LinkedBlockingQueue;
  25
  26 import org.apache.commons.logging.Log;
  27 import org.apache.commons.logging.LogFactory;
  28 import org.apache.log4j.AppenderSkeleton;
  29 import org.apache.log4j.Level;
  30 import org.apache.log4j.LogManager;
  31 import org.apache.log4j.Logger;
  32 import org.apache.log4j.PropertyConfigurator;
  33 import org.apache.log4j.spi.LoggingEvent;
  34 import org.argeo.api.ArgeoLogListener;
  35 import org.argeo.api.ArgeoLogger;
  36 import org.argeo.api.NodeConstants;
  37 import org.argeo.cms.CmsException;
  38 import org.argeo.cms.auth.CurrentUser;
  39 import org.argeo.osgi.useradmin.UserAdminConf;
  40 import org.osgi.framework.Bundle;
  41 import org.osgi.framework.Constants;
  42 import org.osgi.framework.ServiceReference;
  43 import org.osgi.service.cm.ConfigurationAdmin;
  44 import org.osgi.service.log.LogEntry;
  45 import org.osgi.service.log.LogLevel;
  46 import org.osgi.service.log.LogListener;
  47 import org.osgi.service.log.LogReaderService;
  48
  49 /** Not meant to be used directly in standard log4j config */
  50 class NodeLogger implements ArgeoLogger, LogListener {
  51         /** Internal debug for development purposes. */
  52         private static Boolean debug = false;
  53
  54         // private final static Log log = LogFactory.getLog(NodeLogger.class);
  55
  56         private Boolean disabled = false;
  57
  58         private String level = null;
  59
  60         private Level log4jLevel = null;
  61         // private Layout layout;
  62
  63         private Properties configuration;
  64
  65         private AppenderImpl appender;
  66
  67         private final List<ArgeoLogListener> everythingListeners = Collections
  68                         .synchronizedList(new ArrayList<ArgeoLogListener>());
  69         private final List<ArgeoLogListener> allUsersListeners = Collections
  70                         .synchronizedList(new ArrayList<ArgeoLogListener>());
  71         private final Map<String, List<ArgeoLogListener>> userListeners = Collections
  72                         .synchronizedMap(new HashMap<String, List<ArgeoLogListener>>());
  73
  74         private BlockingQueue<LogEvent> events;
  75         private LogDispatcherThread logDispatcherThread = new LogDispatcherThread();
  76
  77         private Integer maxLastEventsCount = 10 * 1000;
  78
  79         /** Marker to prevent stack overflow */
  80         private ThreadLocal<Boolean> dispatching = new ThreadLocal<Boolean>() {
  81
  82                 @Override
  83                 protected Boolean initialValue() {
  84                         return false;
  85                 }
  86         };
  87
  88         public NodeLogger(LogReaderService lrs) {
  89                 if (lrs != null) {
  90                         Enumeration<LogEntry> logEntries = lrs.getLog();
  91                         while (logEntries.hasMoreElements())
  92                                 logged(logEntries.nextElement());
  93                         lrs.addLogListener(this);
  94
  95                         // configure log4j watcher
  96                         String log4jConfiguration = KernelUtils.getFrameworkProp("log4j.configuration");
  97                         if (log4jConfiguration != null && log4jConfiguration.startsWith("file:")) {
  98                                 if (log4jConfiguration.contains("..")) {
  99                                         if (log4jConfiguration.startsWith("file://"))
 100                                                 log4jConfiguration = log4jConfiguration.substring("file://".length());
 101                                         else if (log4jConfiguration.startsWith("file:"))
 102                                                 log4jConfiguration = log4jConfiguration.substring("file:".length());
 103                                 }
 104                                 try {
 105                                         Path log4jconfigPath;
 106                                         if (log4jConfiguration.startsWith("file:"))
 107                                                 log4jconfigPath = Paths.get(new URI(log4jConfiguration));
 108                                         else
 109                                                 log4jconfigPath = Paths.get(log4jConfiguration);
 110                                         Thread log4jConfWatcher = new Log4jConfWatcherThread(log4jconfigPath);
 111                                         log4jConfWatcher.start();
 112                                 } catch (Exception e) {
 113                                         stdErr("Badly formatted log4j configuration URI " + log4jConfiguration + ": " + e.getMessage());
 114                                 }
 115                         }
 116                 }
 117         }
 118
 119         public void init() {
 120                 try {
 121                         events = new LinkedBlockingQueue<LogEvent>();
 122
 123                         // if (layout != null)
 124                         // setLayout(layout);
 125                         // else
 126                         // setLayout(new PatternLayout(pattern));
 127                         appender = new AppenderImpl();
 128                         reloadConfiguration();
 129                         Logger.getRootLogger().addAppender(appender);
 130
 131                         logDispatcherThread = new LogDispatcherThread();
 132                         logDispatcherThread.start();
 133                 } catch (Exception e) {
 134                         throw new CmsException("Cannot initialize log4j");
 135                 }
 136         }
 137
 138         public void destroy() throws Exception {
 139                 Logger.getRootLogger().removeAppender(appender);
 140                 allUsersListeners.clear();
 141                 for (List<ArgeoLogListener> lst : userListeners.values())
 142                         lst.clear();
 143                 userListeners.clear();
 144
 145                 events.clear();
 146                 events = null;
 147                 logDispatcherThread.interrupt();
 148         }
 149
 150         // public void setLayout(Layout layout) {
 151         // this.layout = layout;
 152         // }
 153
 154         public String toString() {
 155                 return "Node Logger";
 156         }
 157
 158         //
 159         // OSGi LOGGER
 160         //
 161         @Override
 162         public void logged(LogEntry status) {
 163                 Log pluginLog = LogFactory.getLog(status.getBundle().getSymbolicName());
 164                 LogLevel severity = status.getLogLevel();
 165                 if (severity.equals(LogLevel.ERROR) && pluginLog.isErrorEnabled()) {
 166                         // FIXME Fix Argeo TP
 167                         if (status.getException() instanceof SignatureException)
 168                                 return;
 169                         pluginLog.error(msg(status), status.getException());
 170                 } else if (severity.equals(LogLevel.WARN) && pluginLog.isWarnEnabled()) {
 171                         if (pluginLog.isTraceEnabled())
 172                                 pluginLog.warn(msg(status), status.getException());
 173                         else
 174                                 pluginLog.warn(msg(status));
 175                 } else if (severity.equals(LogLevel.INFO) && pluginLog.isDebugEnabled())
 176                         pluginLog.debug(msg(status), status.getException());
 177                 else if (severity.equals(LogLevel.DEBUG) && pluginLog.isTraceEnabled())
 178                         pluginLog.trace(msg(status), status.getException());
 179                 else if (severity.equals(LogLevel.TRACE) && pluginLog.isTraceEnabled())
 180                         pluginLog.trace(msg(status), status.getException());
 181         }
 182
 183         private String msg(LogEntry status) {
 184                 StringBuilder sb = new StringBuilder();
 185                 sb.append(status.getMessage());
 186                 Bundle bundle = status.getBundle();
 187                 if (bundle != null) {
 188                         sb.append(" '" + bundle.getSymbolicName() + "'");
 189                 }
 190                 ServiceReference<?> sr = status.getServiceReference();
 191                 if (sr != null) {
 192                         sb.append(' ');
 193                         String[] objectClasses = (String[]) sr.getProperty(Constants.OBJECTCLASS);
 194                         if (isSpringApplicationContext(objectClasses)) {
 195                                 sb.append("{org.springframework.context.ApplicationContext}");
 196                                 Object symbolicName = sr.getProperty(Constants.BUNDLE_SYMBOLICNAME);
 197                                 if (symbolicName != null)
 198                                         sb.append(" " + Constants.BUNDLE_SYMBOLICNAME + ": " + symbolicName);
 199                         } else {
 200                                 sb.append(arrayToString(objectClasses));
 201                         }
 202                         Object cn = sr.getProperty(NodeConstants.CN);
 203                         if (cn != null)
 204                                 sb.append(" " + NodeConstants.CN + ": " + cn);
 205                         Object factoryPid = sr.getProperty(ConfigurationAdmin.SERVICE_FACTORYPID);
 206                         if (factoryPid != null)
 207                                 sb.append(" " + ConfigurationAdmin.SERVICE_FACTORYPID + ": " + factoryPid);
 208                         // else {
 209                         // Object servicePid = sr.getProperty(Constants.SERVICE_PID);
 210                         // if (servicePid != null)
 211                         // sb.append(" " + Constants.SERVICE_PID + ": " + servicePid);
 212                         // }
 213                         // servlets
 214                         Object whiteBoardPattern = sr.getProperty(KernelConstants.WHITEBOARD_PATTERN_PROP);
 215                         if (whiteBoardPattern != null) {
 216                                 if (whiteBoardPattern instanceof String) {
 217                                         sb.append(" " + KernelConstants.WHITEBOARD_PATTERN_PROP + ": " + whiteBoardPattern);
 218                                 } else {
 219                                         sb.append(" " + KernelConstants.WHITEBOARD_PATTERN_PROP + ": "
 220                                                         + arrayToString((String[]) whiteBoardPattern));
 221                                 }
 222                         }
 223                         // RWT
 224                         Object contextName = sr.getProperty(KernelConstants.CONTEXT_NAME_PROP);
 225                         if (contextName != null)
 226                                 sb.append(" " + KernelConstants.CONTEXT_NAME_PROP + ": " + contextName);
 227
 228                         // user directories
 229                         Object baseDn = sr.getProperty(UserAdminConf.baseDn.name());
 230                         if (baseDn != null)
 231                                 sb.append(" " + UserAdminConf.baseDn.name() + ": " + baseDn);
 232
 233                 }
 234                 return sb.toString();
 235         }
 236
 237         private String arrayToString(Object[] arr) {
 238                 StringBuilder sb = new StringBuilder();
 239                 sb.append('[');
 240                 for (int i = 0; i < arr.length; i++) {
 241                         if (i != 0)
 242                                 sb.append(',');
 243                         sb.append(arr[i]);
 244                 }
 245                 sb.append(']');
 246                 return sb.toString();
 247         }
 248
 249         private boolean isSpringApplicationContext(String[] objectClasses) {
 250                 for (String clss : objectClasses) {
 251                         if (clss.equals("org.eclipse.gemini.blueprint.context.DelegatedExecutionOsgiBundleApplicationContext")) {
 252                                 return true;
 253                         }
 254                 }
 255                 return false;
 256         }
 257
 258         //
 259         // ARGEO LOGGER
 260         //
 261
 262         public synchronized void register(ArgeoLogListener listener, Integer numberOfPreviousEvents) {
 263                 String username = CurrentUser.getUsername();
 264                 if (username == null)
 265                         throw new CmsException("Only authenticated users can register a log listener");
 266
 267                 if (!userListeners.containsKey(username)) {
 268                         List<ArgeoLogListener> lst = Collections.synchronizedList(new ArrayList<ArgeoLogListener>());
 269                         userListeners.put(username, lst);
 270                 }
 271                 userListeners.get(username).add(listener);
 272                 List<LogEvent> lastEvents = logDispatcherThread.getLastEvents(username, numberOfPreviousEvents);
 273                 for (LogEvent evt : lastEvents)
 274                         dispatchEvent(listener, evt);
 275         }
 276
 277         public synchronized void registerForAll(ArgeoLogListener listener, Integer numberOfPreviousEvents,
 278                         boolean everything) {
 279                 if (everything)
 280                         everythingListeners.add(listener);
 281                 else
 282                         allUsersListeners.add(listener);
 283                 List<LogEvent> lastEvents = logDispatcherThread.getLastEvents(null, numberOfPreviousEvents);
 284                 for (LogEvent evt : lastEvents)
 285                         if (everything || evt.getUsername() != null)
 286                                 dispatchEvent(listener, evt);
 287         }
 288
 289         public synchronized void unregister(ArgeoLogListener listener) {
 290                 String username = CurrentUser.getUsername();
 291                 if (username == null)// FIXME
 292                         return;
 293                 if (!userListeners.containsKey(username))
 294                         throw new CmsException("No user listeners " + listener + " registered for user " + username);
 295                 if (!userListeners.get(username).contains(listener))
 296                         throw new CmsException("No user listeners " + listener + " registered for user " + username);
 297                 userListeners.get(username).remove(listener);
 298                 if (userListeners.get(username).isEmpty())
 299                         userListeners.remove(username);
 300
 301         }
 302
 303         public synchronized void unregisterForAll(ArgeoLogListener listener) {
 304                 everythingListeners.remove(listener);
 305                 allUsersListeners.remove(listener);
 306         }
 307
 308         /** For development purpose, since using regular logging is not easy here */
 309         private static void stdOut(Object obj) {
 310                 System.out.println(obj);
 311         }
 312
 313         private static void stdErr(Object obj) {
 314                 System.err.println(obj);
 315         }
 316
 317         private static void debug(Object obj) {
 318                 if (debug)
 319                         System.out.println(obj);
 320         }
 321
 322         private static boolean isInternalDebugEnabled() {
 323                 return debug;
 324         }
 325
 326         // public void setPattern(String pattern) {
 327         // this.pattern = pattern;
 328         // }
 329
 330         public void setDisabled(Boolean disabled) {
 331                 this.disabled = disabled;
 332         }
 333
 334         public void setLevel(String level) {
 335                 this.level = level;
 336         }
 337
 338         public void setConfiguration(Properties configuration) {
 339                 this.configuration = configuration;
 340         }
 341
 342         public void updateConfiguration(Properties configuration) {
 343                 setConfiguration(configuration);
 344                 reloadConfiguration();
 345         }
 346
 347         public Properties getConfiguration() {
 348                 return configuration;
 349         }
 350
 351         /**
 352          * Reloads configuration (if the configuration {@link Properties} is set)
 353          */
 354         protected void reloadConfiguration() {
 355                 if (configuration != null) {
 356                         LogManager.resetConfiguration();
 357                         PropertyConfigurator.configure(configuration);
 358                 }
 359         }
 360
 361         protected synchronized void processLoggingEvent(LogEvent event) {
 362                 if (disabled)
 363                         return;
 364
 365                 if (dispatching.get())
 366                         return;
 367
 368                 if (level != null && !level.trim().equals("")) {
 369                         if (log4jLevel == null || !log4jLevel.toString().equals(level))
 370                                 try {
 371                                         log4jLevel = Level.toLevel(level);
 372                                 } catch (Exception e) {
 373                                         System.err.println("Log4j level could not be set for level '" + level + "', resetting it to null.");
 374                                         e.printStackTrace();
 375                                         level = null;
 376                                 }
 377
 378                         if (log4jLevel != null && !event.getLoggingEvent().getLevel().isGreaterOrEqual(log4jLevel)) {
 379                                 return;
 380                         }
 381                 }
 382
 383                 try {
 384                         // admin listeners
 385                         Iterator<ArgeoLogListener> everythingIt = everythingListeners.iterator();
 386                         while (everythingIt.hasNext())
 387                                 dispatchEvent(everythingIt.next(), event);
 388
 389                         if (event.getUsername() != null) {
 390                                 Iterator<ArgeoLogListener> allUsersIt = allUsersListeners.iterator();
 391                                 while (allUsersIt.hasNext())
 392                                         dispatchEvent(allUsersIt.next(), event);
 393
 394                                 if (userListeners.containsKey(event.getUsername())) {
 395                                         Iterator<ArgeoLogListener> userIt = userListeners.get(event.getUsername()).iterator();
 396                                         while (userIt.hasNext())
 397                                                 dispatchEvent(userIt.next(), event);
 398                                 }
 399                         }
 400                 } catch (Exception e) {
 401                         stdOut("Cannot process logging event");
 402                         e.printStackTrace();
 403                 }
 404         }
 405
 406         protected void dispatchEvent(ArgeoLogListener logListener, LogEvent evt) {
 407                 LoggingEvent event = evt.getLoggingEvent();
 408                 logListener.appendLog(evt.getUsername(), event.getTimeStamp(), event.getLevel().toString(),
 409                                 event.getLoggerName(), event.getThreadName(), event.getMessage(), event.getThrowableStrRep());
 410         }
 411
 412         private class AppenderImpl extends AppenderSkeleton {
 413                 public boolean requiresLayout() {
 414                         return false;
 415                 }
 416
 417                 public void close() {
 418                 }
 419
 420                 @Override
 421                 protected void append(LoggingEvent event) {
 422                         if (events != null) {
 423                                 try {
 424                                         String username = CurrentUser.getUsername();
 425                                         events.put(new LogEvent(username, event));
 426                                 } catch (InterruptedException e) {
 427                                         // silent
 428                                 }
 429                         }
 430                 }
 431
 432         }
 433
 434         private class LogDispatcherThread extends Thread {
 435                 /** encapsulated in order to simplify concurrency management */
 436                 private LinkedList<LogEvent> lastEvents = new LinkedList<LogEvent>();
 437
 438                 public LogDispatcherThread() {
 439                         super("Argeo Logging Dispatcher Thread");
 440                 }
 441
 442                 public void run() {
 443                         while (events != null) {
 444                                 try {
 445                                         LogEvent loggingEvent = events.take();
 446                                         processLoggingEvent(loggingEvent);
 447                                         addLastEvent(loggingEvent);
 448                                 } catch (InterruptedException e) {
 449                                         if (events == null)
 450                                                 return;
 451                                 }
 452                         }
 453                 }
 454
 455                 protected synchronized void addLastEvent(LogEvent loggingEvent) {
 456                         if (lastEvents.size() >= maxLastEventsCount)
 457                                 lastEvents.poll();
 458                         lastEvents.add(loggingEvent);
 459                 }
 460
 461                 public synchronized List<LogEvent> getLastEvents(String username, Integer maxCount) {
 462                         LinkedList<LogEvent> evts = new LinkedList<LogEvent>();
 463                         ListIterator<LogEvent> it = lastEvents.listIterator(lastEvents.size());
 464                         int count = 0;
 465                         while (it.hasPrevious() && (count < maxCount)) {
 466                                 LogEvent evt = it.previous();
 467                                 if (username == null || username.equals(evt.getUsername())) {
 468                                         evts.push(evt);
 469                                         count++;
 470                                 }
 471                         }
 472                         return evts;
 473                 }
 474         }
 475
 476         private class LogEvent {
 477                 private final String username;
 478                 private final LoggingEvent loggingEvent;
 479
 480                 public LogEvent(String username, LoggingEvent loggingEvent) {
 481                         super();
 482                         this.username = username;
 483                         this.loggingEvent = loggingEvent;
 484                 }
 485
 486                 @Override
 487                 public int hashCode() {
 488                         return loggingEvent.hashCode();
 489                 }
 490
 491                 @Override
 492                 public boolean equals(Object obj) {
 493                         return loggingEvent.equals(obj);
 494                 }
 495
 496                 @Override
 497                 public String toString() {
 498                         return username + "@ " + loggingEvent.toString();
 499                 }
 500
 501                 public String getUsername() {
 502                         return username;
 503                 }
 504
 505                 public LoggingEvent getLoggingEvent() {
 506                         return loggingEvent;
 507                 }
 508
 509         }
 510
 511         private class Log4jConfWatcherThread extends Thread {
 512                 private Path log4jConfigurationPath;
 513
 514                 public Log4jConfWatcherThread(Path log4jConfigurationPath) {
 515                         super("Log4j Configuration Watcher");
 516                         try {
 517                                 this.log4jConfigurationPath = log4jConfigurationPath.toRealPath();
 518                         } catch (IOException e) {
 519                                 this.log4jConfigurationPath = log4jConfigurationPath.toAbsolutePath();
 520                                 stdOut("Cannot determine real path for " + log4jConfigurationPath + ": " + e.getMessage());
 521                         }
 522                 }
 523
 524                 public void run() {
 525                         Path parentDir = log4jConfigurationPath.getParent();
 526                         try (final WatchService watchService = FileSystems.getDefault().newWatchService()) {
 527                                 parentDir.register(watchService, StandardWatchEventKinds.ENTRY_MODIFY);
 528                                 WatchKey wk;
 529                                 watching: while ((wk = watchService.take()) != null) {
 530                                         for (WatchEvent<?> event : wk.pollEvents()) {
 531                                                 final Path changed = (Path) event.context();
 532                                                 if (log4jConfigurationPath.equals(parentDir.resolve(changed))) {
 533                                                         if (isInternalDebugEnabled())
 534                                                                 debug(log4jConfigurationPath + " has changed, reloading.");
 535                                                         PropertyConfigurator.configure(log4jConfigurationPath.toUri().toURL());
 536                                                 }
 537                                         }
 538                                         // reset the key
 539                                         boolean valid = wk.reset();
 540                                         if (!valid) {
 541                                                 break watching;
 542                                         }
 543                                 }
 544                         } catch (IOException | InterruptedException e) {
 545                                 stdErr("Log4j configuration watcher failed: " + e.getMessage());
 546                         }
 547                 }
 548         }
 549 }