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