1 package org
.argeo
.init
.logging
;
3 import java
.io
.IOException
;
4 import java
.io
.PrintStream
;
5 import java
.io
.Serializable
;
6 import java
.lang
.System
.Logger
;
7 import java
.lang
.System
.Logger
.Level
;
8 import java
.nio
.charset
.StandardCharsets
;
9 import java
.nio
.file
.Files
;
10 import java
.nio
.file
.Path
;
11 import java
.nio
.file
.Paths
;
12 import java
.text
.MessageFormat
;
13 import java
.time
.Instant
;
14 import java
.util
.Collections
;
15 import java
.util
.HashMap
;
16 import java
.util
.Iterator
;
18 import java
.util
.NavigableMap
;
19 import java
.util
.Objects
;
20 import java
.util
.ResourceBundle
;
21 import java
.util
.SortedMap
;
22 import java
.util
.StringTokenizer
;
23 import java
.util
.TreeMap
;
24 import java
.util
.concurrent
.Flow
;
25 import java
.util
.concurrent
.Flow
.Subscription
;
26 import java
.util
.concurrent
.ForkJoinPool
;
27 import java
.util
.concurrent
.SubmissionPublisher
;
28 import java
.util
.concurrent
.TimeUnit
;
29 import java
.util
.concurrent
.atomic
.AtomicLong
;
30 import java
.util
.function
.Consumer
;
32 import org
.argeo
.api
.init
.RuntimeContext
;
33 import org
.argeo
.internal
.init
.InternalState
;
36 * A thin logging system based on the {@link Logger} framework. It is a
37 * {@link Consumer} of configuration, and can be registered as such.
39 class ThinLogging
implements Consumer
<Map
<String
, Object
>> {
40 final static String DEFAULT_LEVEL_NAME
= "";
42 final static String DEFAULT_LEVEL_PROPERTY
= "log";
43 final static String LEVEL_PROPERTY_PREFIX
= DEFAULT_LEVEL_PROPERTY
+ ".";
46 * Whether logged event are only immediately printed to the standard output.
47 * Required for native images.
49 final static String PROP_ARGEO_LOGGING_SYNCHRONOUS
= "argeo.logging.synchronous";
51 * Whether to enable journald compatible output, either: auto (default), true,
54 final static String PROP_ARGEO_LOGGING_JOURNALD
= "argeo.logging.journald";
55 /** A file to which additionally write log entries. */
56 final static String PROP_ARGEO_LOGGING_FILE
= "argeo.logging.file";
58 * The level from which call location (that is, line number in Java code) will
59 * be searched (default is WARNING)
61 final static String PROP_ARGEO_LOGGING_CALL_LOCATION_LEVEL
= "argeo.logging.callLocationLevel";
63 final static String ENV_INVOCATION_ID
= "INVOCATION_ID";
64 final static String ENV_GIO_LAUNCHED_DESKTOP_FILE_PID
= "GIO_LAUNCHED_DESKTOP_FILE_PID";
66 private final static AtomicLong nextEntry
= new AtomicLong(0l);
68 // we don't synchronize maps on purpose as it would be
69 // too expensive during normal operation
70 // updates to the config may be shortly inconsistent
71 private SortedMap
<String
, ThinLogger
> loggers
= Collections
.synchronizedSortedMap(new TreeMap
<>());
72 private NavigableMap
<String
, Level
> levels
= new TreeMap
<>();
73 private volatile boolean updatingConfiguration
= false;
75 private final LogEntryPublisher publisher
;
76 private PrintStreamSubscriber synchronousSubscriber
;
77 private PrintStream fileOut
;
79 private final boolean journald
;
80 private final Level callLocationLevel
;
82 private final boolean synchronous
;
85 synchronous
= Boolean
.parseBoolean(System
.getProperty(PROP_ARGEO_LOGGING_SYNCHRONOUS
, "false"));
87 synchronousSubscriber
= new PrintStreamSubscriber();
90 PrintStreamSubscriber subscriber
= new PrintStreamSubscriber();
91 publisher
= new LogEntryPublisher();
92 publisher
.subscribe(subscriber
);
93 String logFileStr
= System
.getProperty(PROP_ARGEO_LOGGING_FILE
);
94 if (logFileStr
!= null) {
95 Path logFilePath
= Paths
.get(logFileStr
);
96 if (!Files
.exists(logFilePath
.getParent())) {
97 System
.err
.println("Parent directory of " + logFilePath
+ " does not exist");
100 fileOut
= new PrintStream(Files
.newOutputStream(logFilePath
), true, StandardCharsets
.UTF_8
);
101 publisher
.subscribe(new PrintStreamSubscriber(fileOut
, fileOut
));
102 } catch (IOException e
) {
103 System
.err
.println("Cannot write log to " + logFilePath
);
109 Runtime
.getRuntime().addShutdownHook(new Thread(() -> close(), "Log shutdown"));
111 // initial default level
112 levels
.put(DEFAULT_LEVEL_NAME
, Level
.WARNING
);
114 // Logging system config
116 String journaldStr
= System
.getProperty(PROP_ARGEO_LOGGING_JOURNALD
, "auto");
117 switch (journaldStr
) {
119 String systemdInvocationId
= System
.getenv(ENV_INVOCATION_ID
);
120 if (systemdInvocationId
!= null) {// in systemd
121 // check whether we are indirectly in a desktop app (typically an IDE)
122 String desktopFilePid
= System
.getenv(ENV_GIO_LAUNCHED_DESKTOP_FILE_PID
);
123 if (desktopFilePid
!= null) {
124 Long javaPid
= ProcessHandle
.current().pid();
125 if (!javaPid
.toString().equals(desktopFilePid
)) {
144 throw new IllegalArgumentException(
145 "Unsupported value '" + journaldStr
+ "' for property " + PROP_ARGEO_LOGGING_JOURNALD
);
148 String callLocationStr
= System
.getProperty(PROP_ARGEO_LOGGING_CALL_LOCATION_LEVEL
, Level
.WARNING
.getName());
149 callLocationLevel
= Level
.valueOf(callLocationStr
);
152 private void close() {
153 RuntimeContext runtimeContext
= InternalState
.getMainRuntimeContext();
154 if (runtimeContext
!= null) {
156 runtimeContext
.waitForStop(0);
157 } catch (InterruptedException e
) {
165 // we wait a bit in order to make sure all messages are flushed
166 // TODO synchronize more efficiently
167 // executor.awaitTermination(300, TimeUnit.MILLISECONDS);
168 ForkJoinPool
.commonPool().awaitTermination(300, TimeUnit
.MILLISECONDS
);
169 } catch (InterruptedException e
) {
174 if (fileOut
!= null) {
177 } catch (Exception e
) {
183 private Level
computeApplicableLevel(String name
) {
184 Map
.Entry
<String
, Level
> entry
= levels
.floorEntry(name
);
185 assert entry
!= null;
186 if (name
.startsWith(entry
.getKey()))
187 return entry
.getValue();
189 return levels
.get(DEFAULT_LEVEL_NAME
);// default
193 public Logger
getLogger(String name
, Module module
) {
194 Objects
.requireNonNull(name
, "logger name");
195 if (!loggers
.containsKey(name
)) {
196 ThinLogger logger
= new ThinLogger(name
, computeApplicableLevel(name
));
197 loggers
.put(name
, logger
);
200 return loggers
.get(name
);
203 public void accept(Map
<String
, Object
> configuration
) {
204 synchronized (levels
) {
205 updatingConfiguration
= true;
207 Map
<String
, Level
> backup
= new TreeMap
<>(levels
);
209 boolean fullReset
= configuration
.containsKey(DEFAULT_LEVEL_PROPERTY
);
211 properties
: for (String property
: configuration
.keySet()) {
212 if (!property
.startsWith(LEVEL_PROPERTY_PREFIX
))
214 String levelStr
= configuration
.get(property
).toString();
215 Level level
= Level
.valueOf(levelStr
);
216 levels
.put(property
.substring(LEVEL_PROPERTY_PREFIX
.length()), level
);
220 Iterator
<Map
.Entry
<String
, Level
>> it
= levels
.entrySet().iterator();
221 while (it
.hasNext()) {
222 Map
.Entry
<String
, Level
> entry
= it
.next();
223 String name
= entry
.getKey();
224 if (!configuration
.containsKey(LEVEL_PROPERTY_PREFIX
+ name
)) {
228 Level newDefaultLevel
= Level
.valueOf(configuration
.get(DEFAULT_LEVEL_PROPERTY
).toString());
229 levels
.put(DEFAULT_LEVEL_NAME
, newDefaultLevel
);
230 // TODO notify everyone?
232 assert levels
.containsKey(DEFAULT_LEVEL_NAME
);
234 // recompute all levels
235 for (String name
: loggers
.keySet()) {
236 ThinLogger logger
= loggers
.get(name
);
237 logger
.setLevel(computeApplicableLevel(name
));
239 } catch (IllegalArgumentException e
) {
242 levels
.putAll(backup
);
244 updatingConfiguration
= false;
249 Flow
.Publisher
<Map
<String
, Serializable
>> getLogEntryPublisher() {
253 Map
<String
, Level
> getLevels() {
254 return Collections
.unmodifiableNavigableMap(levels
);
257 private void dispatchLogEntry(ThinLogger logger
, Level level
, ResourceBundle bundle
, String msg
, Instant instant
,
258 Thread thread
, Throwable thrown
, StackTraceElement callLocation
) {
259 assert level
!= null;
260 assert logger
!= null;
261 // assert msg != null;
262 assert instant
!= null;
263 assert thread
!= null;
268 final long sequence
= nextEntry
.incrementAndGet();
270 Map
<String
, Serializable
> logEntry
= new LogEntryMap(sequence
);
272 // same object as key class name
273 logEntry
.put(KEY_LEVEL
, level
);
274 logEntry
.put(KEY_MSG
, msg
);
275 logEntry
.put(KEY_INSTANT
, instant
);
277 logEntry
.put(KEY_THROWABLE
, thrown
);
278 if (callLocation
!= null)
279 logEntry
.put(KEY_CALL_LOCATION
, callLocation
);
281 // object is a string
282 logEntry
.put(KEY_LOGGER
, logger
.getName());
283 logEntry
.put(KEY_THREAD
, thread
.getName());
285 // should be unmodifiable for security reasons
287 assert synchronousSubscriber
!= null;
288 synchronousSubscriber
.onNext(logEntry
);
290 if (!publisher
.isClosed())
291 publisher
.submit(Collections
.unmodifiableMap(logEntry
));
300 private class ThinLogger
implements System
.Logger
{
301 private final String name
;
305 protected ThinLogger(String name
, Level level
) {
306 assert Objects
.nonNull(name
);
312 public String
getName() {
317 public boolean isLoggable(Level level
) {
318 return level
.getSeverity() >= getLevel().getSeverity();
319 // TODO optimise by referencing the applicable level in this class?
320 // return ThinLogging.this.isLoggable(name, level);
323 private Level
getLevel() {
324 if (updatingConfiguration
) {
325 synchronized (levels
) {
328 // TODO make exit more robust
329 } catch (InterruptedException e
) {
330 throw new IllegalStateException(e
);
338 public void log(Level level
, ResourceBundle bundle
, String msg
, Throwable thrown
) {
339 if (!isLoggable(level
))
341 // measure timestamp first
342 Instant now
= Instant
.now();
343 Thread thread
= Thread
.currentThread();
344 dispatchLogEntry(ThinLogger
.this, level
, bundle
, msg
, now
, thread
, thrown
, findCallLocation(level
, thread
));
348 public void log(Level level
, ResourceBundle bundle
, String format
, Object
... params
) {
349 if (!isLoggable(level
))
351 // measure timestamp first
352 Instant now
= Instant
.now();
353 Thread thread
= Thread
.currentThread();
355 // NOTE: this is the method called when logging a plain message without
356 // exception, so it should be considered as a format only when args are not null
357 // if (format.contains("{}"))// workaround for weird Jetty formatting
359 // TODO move this to slf4j wrapper?
360 if (format
.contains("{}")) {
361 StringBuilder sb
= new StringBuilder();
362 String
[] segments
= format
.split("\\{\\}");
363 for (int i
= 0; i
< segments
.length
; i
++) {
364 sb
.append(segments
[i
]);
365 if (i
!= (segments
.length
- 1))
366 sb
.append("{" + i
+ "}");
368 format
= sb
.toString();
370 String msg
= params
== null ? format
: MessageFormat
.format(format
, params
);
371 dispatchLogEntry(ThinLogger
.this, level
, bundle
, msg
, now
, thread
, (Throwable
) null,
372 findCallLocation(level
, thread
));
375 private void setLevel(Level level
) {
379 private StackTraceElement
findCallLocation(Level level
, Thread thread
) {
380 assert level
!= null;
381 assert thread
!= null;
382 // TODO rather use a StackWalker and make it smarter
383 StackTraceElement callLocation
= null;
384 if (level
.getSeverity() >= callLocationLevel
.getSeverity()) {
385 StackTraceElement
[] stack
= thread
.getStackTrace();
386 int lowestLoggerInterface
= 0;
387 stack
: for (int i
= 2; i
< stack
.length
; i
++) {
388 String className
= stack
[i
].getClassName();
390 // TODO make it more configurable
391 // FIXME deal with privileges stacks (in Equinox)
392 case "java.lang.System$Logger":
393 case "java.util.logging.Logger":
394 case "org.apache.commons.logging.Log":
395 case "org.osgi.service.log.Logger":
396 case "org.eclipse.osgi.internal.log.LoggerImpl":
397 case "org.argeo.api.cms.CmsLog":
398 case "org.eclipse.jetty.util.log.Slf4jLog":
399 case "sun.util.logging.internal.LoggingProviderImpl$JULWrapper":
400 case "org.slf4j.impl.ArgeoLogger":
401 case "org.argeo.cms.internal.osgi.CmsOsgiLogger":
402 case "org.argeo.init.osgi.OsgiBootUtils":
403 lowestLoggerInterface
= i
;
408 if (stack
.length
> lowestLoggerInterface
+ 1)
409 callLocation
= stack
[lowestLoggerInterface
+ 1];
416 private final static String KEY_LOGGER
= Logger
.class.getName();
417 private final static String KEY_LEVEL
= Level
.class.getName();
418 private final static String KEY_MSG
= String
.class.getName();
419 private final static String KEY_THROWABLE
= Throwable
.class.getName();
420 private final static String KEY_INSTANT
= Instant
.class.getName();
421 private final static String KEY_CALL_LOCATION
= StackTraceElement
.class.getName();
422 private final static String KEY_THREAD
= Thread
.class.getName();
424 private class LogEntryPublisher
extends SubmissionPublisher
<Map
<String
, Serializable
>> {
426 private LogEntryPublisher() {
430 // private void log(ThinLogger logger, Level level, ResourceBundle bundle, String msg, Instant instant,
431 // Thread thread, Throwable thrown, StackTraceElement callLocation) {
438 * An internal optimisation for collections. It should not be referred to
439 * directly as a type.
441 // TODO optimise memory with a custom map implementation?
442 // but access may be slower
443 private static class LogEntryMap
extends HashMap
<String
, Serializable
> {
444 private static final long serialVersionUID
= 7361434381922521356L;
446 private final long sequence
;
448 private LogEntryMap(long sequence
) {
449 // maximum 7 fields, so using default load factor 0.75
450 // an initial size of 10 should prevent rehashing (7 / 0.75 ~ 9.333)
451 // see HashMap class description for more details
453 this.sequence
= sequence
;
457 public boolean equals(Object o
) {
458 if (o
instanceof LogEntryMap
)
459 return sequence
== ((LogEntryMap
) o
).sequence
;
460 else if (o
instanceof Map
) {
461 Map
<?
, ?
> map
= (Map
<?
, ?
>) o
;
462 return get(KEY_INSTANT
).equals(map
.get(KEY_INSTANT
)) && get(KEY_THREAD
).equals(map
.get(KEY_THREAD
));
468 public int hashCode() {
469 return (int) sequence
;
474 private class PrintStreamSubscriber
implements Flow
.Subscriber
<Map
<String
, Serializable
>> {
475 private PrintStream out
;
476 private PrintStream err
;
477 private int writeToErrLevel
= Level
.WARNING
.getSeverity();
479 private Subscription subscription
;
481 protected PrintStreamSubscriber() {
482 this(System
.out
, System
.err
);
485 protected PrintStreamSubscriber(PrintStream out
, PrintStream err
) {
490 private Level
getLevel(Map
<String
, Serializable
> logEntry
) {
491 return (Level
) logEntry
.get(KEY_LEVEL
);
495 public void onSubscribe(Subscription subscription
) {
496 this.subscription
= subscription
;
497 this.subscription
.request(1);
501 public void onNext(Map
<String
, Serializable
> item
) {
502 if (getLevel(item
).getSeverity() >= writeToErrLevel
) {
503 err
.print(toPrint(item
));
505 out
.print(toPrint(item
));
507 // TODO flush for journald?
508 if (this.subscription
!= null)
509 this.subscription
.request(1);
513 public void onError(Throwable throwable
) {
514 throwable
.printStackTrace(err
);
518 public void onComplete() {
523 protected String
firstLinePrefix(Map
<String
, Serializable
> logEntry
) {
524 Level level
= getLevel(logEntry
);
542 throw new IllegalArgumentException("Unsupported level " + level
);
544 return journald ?
linePrefix(logEntry
) : logEntry
.get(KEY_INSTANT
) + " " + level
+ spaces
;
547 protected String
firstLineSuffix(Map
<String
, Serializable
> logEntry
) {
548 return " - " + (logEntry
.containsKey(KEY_CALL_LOCATION
) ? logEntry
.get(KEY_CALL_LOCATION
)
549 : logEntry
.get(KEY_LOGGER
)) + " [" + logEntry
.get(KEY_THREAD
) + "]";
552 protected String
linePrefix(Map
<String
, Serializable
> logEntry
) {
553 return journald ?
"<" + levelToJournald(getLevel(logEntry
)) + ">" : "";
556 protected int levelToJournald(Level level
) {
557 int severity
= level
.getSeverity();
558 if (severity
>= Level
.ERROR
.getSeverity())
560 else if (severity
>= Level
.WARNING
.getSeverity())
562 else if (severity
>= Level
.INFO
.getSeverity())
568 protected String
toPrint(Map
<String
, Serializable
> logEntry
) {
569 StringBuilder sb
= new StringBuilder();
570 StringTokenizer st
= new StringTokenizer((String
) logEntry
.get(KEY_MSG
), "\r\n");
573 String firstLine
= st
.hasMoreTokens() ? st
.nextToken() : "";
574 sb
.append(firstLinePrefix(logEntry
));
575 sb
.append(firstLine
);
576 sb
.append(firstLineSuffix(logEntry
));
580 String prefix
= linePrefix(logEntry
);
581 while (st
.hasMoreTokens()) {
583 sb
.append(st
.nextToken());
587 if (logEntry
.containsKey(KEY_THROWABLE
)) {
588 Throwable throwable
= (Throwable
) logEntry
.get(KEY_THROWABLE
);
590 addThrowable(sb
, prefix
, throwable
);
592 return sb
.toString();
595 protected void addThrowable(StringBuilder sb
, String prefix
, Throwable throwable
) {
596 sb
.append(throwable
.getClass().getName());
598 sb
.append(throwable
.getMessage());
600 for (StackTraceElement ste
: throwable
.getStackTrace()) {
603 sb
.append(ste
.toString());
606 if (throwable
.getCause() != null) {
608 sb
.append("Caused by: ");
609 addThrowable(sb
, prefix
, throwable
.getCause());
614 // public static void main(String args[]) {
615 // Logger logger = System.getLogger(ThinLogging.class.getName());
616 // logger.log(Logger.Level.ALL, "Log all");
617 // logger.log(Logger.Level.TRACE, "Multi\nline\ntrace");
618 // logger.log(Logger.Level.DEBUG, "Log debug");
619 // logger.log(Logger.Level.INFO, "Log info");
620 // logger.log(Logger.Level.WARNING, "Log warning");
621 // logger.log(Logger.Level.ERROR, "Log exception", new Throwable());
624 // // we wait a bit in order to make sure all messages are flushed
625 // // TODO synchronize more efficiently
626 // // executor.awaitTermination(300, TimeUnit.MILLISECONDS);
627 // ForkJoinPool.commonPool().awaitTermination(300, TimeUnit.MILLISECONDS);
628 // } catch (InterruptedException e) {