Refactor Argeo init
[lgpl/argeo-commons.git] / org.argeo.init / src / org / argeo / init / logging / ThinLogging.java
index 16e792776566a51502a5aa0924f369cecb8adab3..30a149bc99811487af51d1cc90a07c254ab50821 100644 (file)
@@ -1,9 +1,14 @@
 package org.argeo.init.logging;
 
+import java.io.IOException;
 import java.io.PrintStream;
 import java.io.Serializable;
 import java.lang.System.Logger;
 import java.lang.System.Logger.Level;
+import java.nio.charset.StandardCharsets;
+import java.nio.file.Files;
+import java.nio.file.Path;
+import java.nio.file.Paths;
 import java.text.MessageFormat;
 import java.time.Instant;
 import java.util.Collections;
@@ -24,8 +29,8 @@ import java.util.concurrent.TimeUnit;
 import java.util.concurrent.atomic.AtomicLong;
 import java.util.function.Consumer;
 
-import org.argeo.init.RuntimeContext;
-import org.argeo.init.Service;
+import org.argeo.api.init.RuntimeContext;
+import org.argeo.internal.init.InternalState;
 
 /**
  * A thin logging system based on the {@link Logger} framework. It is a
@@ -37,8 +42,26 @@ class ThinLogging implements Consumer<Map<String, Object>> {
        final static String DEFAULT_LEVEL_PROPERTY = "log";
        final static String LEVEL_PROPERTY_PREFIX = DEFAULT_LEVEL_PROPERTY + ".";
 
-       final static String JOURNALD_PROPERTY = "argeo.logging.journald";
-       final static String CALL_LOCATION_PROPERTY = "argeo.logging.callLocation";
+       /**
+        * Whether logged event are only immediately printed to the standard output.
+        * Required for native images.
+        */
+       final static String PROP_ARGEO_LOGGING_SYNCHRONOUS = "argeo.logging.synchronous";
+       /**
+        * Whether to enable journald compatible output, either: auto (default), true,
+        * or false.
+        */
+       final static String PROP_ARGEO_LOGGING_JOURNALD = "argeo.logging.journald";
+       /** A file to which additionally write log entries. */
+       final static String PROP_ARGEO_LOGGING_FILE = "argeo.logging.file";
+       /**
+        * The level from which call location (that is, line number in Java code) will
+        * be searched (default is WARNING)
+        */
+       final static String PROP_ARGEO_LOGGING_CALL_LOCATION_LEVEL = "argeo.logging.callLocationLevel";
+
+       final static String ENV_INVOCATION_ID = "INVOCATION_ID";
+       final static String ENV_GIO_LAUNCHED_DESKTOP_FILE_PID = "GIO_LAUNCHED_DESKTOP_FILE_PID";
 
        private final static AtomicLong nextEntry = new AtomicLong(0l);
 
@@ -49,52 +72,54 @@ class ThinLogging implements Consumer<Map<String, Object>> {
        private NavigableMap<String, Level> levels = new TreeMap<>();
        private volatile boolean updatingConfiguration = false;
 
-//     private final ExecutorService executor;
        private final LogEntryPublisher publisher;
        private PrintStreamSubscriber synchronousSubscriber;
+       private PrintStream fileOut;
 
        private final boolean journald;
        private final Level callLocationLevel;
 
-       private boolean synchronous = true;
+       private final boolean synchronous;
 
        ThinLogging() {
-//             executor = Executors.newCachedThreadPool((r) -> {
-//                     Thread t = new Thread(r);
-//                     t.setDaemon(true);
-//                     return t;
-//             });
+               synchronous = Boolean.parseBoolean(System.getProperty(PROP_ARGEO_LOGGING_SYNCHRONOUS, "false"));
                if (synchronous) {
-                       publisher = new LogEntryPublisher();
                        synchronousSubscriber = new PrintStreamSubscriber();
+                       publisher = null;
                } else {
-                       publisher = new LogEntryPublisher();
-
                        PrintStreamSubscriber subscriber = new PrintStreamSubscriber();
+                       publisher = new LogEntryPublisher();
                        publisher.subscribe(subscriber);
-
-                       Runtime.getRuntime().addShutdownHook(new Thread(() -> close(), "Log shutdown"));
-
+                       String logFileStr = System.getProperty(PROP_ARGEO_LOGGING_FILE);
+                       if (logFileStr != null) {
+                               Path logFilePath = Paths.get(logFileStr);
+                               if (!Files.exists(logFilePath.getParent())) {
+                                       System.err.println("Parent directory of " + logFilePath + " does not exist");
+                               } else {
+                                       try {
+                                               fileOut = new PrintStream(Files.newOutputStream(logFilePath), true, StandardCharsets.UTF_8);
+                                               publisher.subscribe(new PrintStreamSubscriber(fileOut, fileOut));
+                                       } catch (IOException e) {
+                                               System.err.println("Cannot write log to " + logFilePath);
+                                               e.printStackTrace();
+                                       }
+                               }
+                       }
                }
+               Runtime.getRuntime().addShutdownHook(new Thread(() -> close(), "Log shutdown"));
 
                // initial default level
-               levels.put("", Level.WARNING);
+               levels.put(DEFAULT_LEVEL_NAME, Level.WARNING);
 
                // Logging system config
                // journald
-
-//             Map<String, String> env = new TreeMap<>(System.getenv());
-//             for (String key : env.keySet()) {
-//                     System.out.println(key + "=" + env.get(key));
-//             }
-
-               String journaldStr = System.getProperty(JOURNALD_PROPERTY, "auto");
+               String journaldStr = System.getProperty(PROP_ARGEO_LOGGING_JOURNALD, "auto");
                switch (journaldStr) {
                case "auto":
-                       String systemdInvocationId = System.getenv("INVOCATION_ID");
+                       String systemdInvocationId = System.getenv(ENV_INVOCATION_ID);
                        if (systemdInvocationId != null) {// in systemd
-                               // check whether we are indirectly in a desktop app (e.g. eclipse)
-                               String desktopFilePid = System.getenv("GIO_LAUNCHED_DESKTOP_FILE_PID");
+                               // check whether we are indirectly in a desktop app (typically an IDE)
+                               String desktopFilePid = System.getenv(ENV_GIO_LAUNCHED_DESKTOP_FILE_PID);
                                if (desktopFilePid != null) {
                                        Long javaPid = ProcessHandle.current().pid();
                                        if (!javaPid.toString().equals(desktopFilePid)) {
@@ -117,15 +142,15 @@ class ThinLogging implements Consumer<Map<String, Object>> {
                        break;
                default:
                        throw new IllegalArgumentException(
-                                       "Unsupported value '" + journaldStr + "' for property " + JOURNALD_PROPERTY);
+                                       "Unsupported value '" + journaldStr + "' for property " + PROP_ARGEO_LOGGING_JOURNALD);
                }
 
-               String callLocationStr = System.getProperty(CALL_LOCATION_PROPERTY, Level.WARNING.getName());
+               String callLocationStr = System.getProperty(PROP_ARGEO_LOGGING_CALL_LOCATION_LEVEL, Level.WARNING.getName());
                callLocationLevel = Level.valueOf(callLocationStr);
        }
 
        private void close() {
-               RuntimeContext runtimeContext = Service.getRuntimeContext();
+               RuntimeContext runtimeContext = InternalState.getMainRuntimeContext();
                if (runtimeContext != null) {
                        try {
                                runtimeContext.waitForStop(0);
@@ -134,42 +159,37 @@ class ThinLogging implements Consumer<Map<String, Object>> {
                        }
                }
 
-               publisher.close();
-               try {
-                       // we ait a bit in order to make sure all messages are flushed
-                       // TODO synchronize more efficiently
-                       // executor.awaitTermination(300, TimeUnit.MILLISECONDS);
-                       ForkJoinPool.commonPool().awaitTermination(300, TimeUnit.MILLISECONDS);
-               } catch (InterruptedException e) {
-                       // silent
+               if (!synchronous) {
+                       publisher.close();
+                       try {
+                               // we wait a bit in order to make sure all messages are flushed
+                               // TODO synchronize more efficiently
+                               // executor.awaitTermination(300, TimeUnit.MILLISECONDS);
+                               ForkJoinPool.commonPool().awaitTermination(300, TimeUnit.MILLISECONDS);
+                       } catch (InterruptedException e) {
+                               // silent
+                       }
+               }
+
+               if (fileOut != null) {
+                       try {
+                               fileOut.close();
+                       } catch (Exception e) {
+                               // silent
+                       }
                }
        }
 
        private Level computeApplicableLevel(String name) {
                Map.Entry<String, Level> entry = levels.floorEntry(name);
                assert entry != null;
-               return entry.getValue();
+               if (name.startsWith(entry.getKey()))
+                       return entry.getValue();
+               else
+                       return levels.get(DEFAULT_LEVEL_NAME);// default
 
        }
 
-//     private boolean isLoggable(String name, Level level) {
-//             Objects.requireNonNull(name);
-//             Objects.requireNonNull(level);
-//
-//             if (updatingConfiguration) {
-//                     synchronized (levels) {
-//                             try {
-//                                     levels.wait();
-//                                     // TODO make exit more robust
-//                             } catch (InterruptedException e) {
-//                                     throw new IllegalStateException(e);
-//                             }
-//                     }
-//             }
-//
-//             return level.getSeverity() >= computeApplicableLevel(name).getSeverity();
-//     }
-
        public Logger getLogger(String name, Module module) {
                if (!loggers.containsKey(name)) {
                        ThinLogger logger = new ThinLogger(name, computeApplicableLevel(name));
@@ -222,7 +242,6 @@ class ThinLogging implements Consumer<Map<String, Object>> {
                        updatingConfiguration = false;
                        levels.notifyAll();
                }
-
        }
 
        Flow.Publisher<Map<String, Serializable>> getLogEntryPublisher() {
@@ -233,6 +252,45 @@ class ThinLogging implements Consumer<Map<String, Object>> {
                return Collections.unmodifiableNavigableMap(levels);
        }
 
+       private void dispatchLogEntry(ThinLogger logger, Level level, ResourceBundle bundle, String msg, Instant instant,
+                       Thread thread, Throwable thrown, StackTraceElement callLocation) {
+               assert level != null;
+               assert logger != null;
+//             assert msg != null;
+               assert instant != null;
+               assert thread != null;
+
+               if (msg == null)
+                       msg = "null";
+
+               final long sequence = nextEntry.incrementAndGet();
+
+               Map<String, Serializable> logEntry = new LogEntryMap(sequence);
+
+               // same object as key class name
+               logEntry.put(KEY_LEVEL, level);
+               logEntry.put(KEY_MSG, msg);
+               logEntry.put(KEY_INSTANT, instant);
+               if (thrown != null)
+                       logEntry.put(KEY_THROWABLE, thrown);
+               if (callLocation != null)
+                       logEntry.put(KEY_CALL_LOCATION, callLocation);
+
+               // object is a string
+               logEntry.put(KEY_LOGGER, logger.getName());
+               logEntry.put(KEY_THREAD, thread.getName());
+
+               // should be unmodifiable for security reasons
+               if (synchronous) {
+                       assert synchronousSubscriber != null;
+                       synchronousSubscriber.onNext(logEntry);
+               } else {
+                       if (!publisher.isClosed())
+                               publisher.submit(Collections.unmodifiableMap(logEntry));
+               }
+
+       }
+
        /*
         * INTERNAL CLASSES
         */
@@ -281,7 +339,7 @@ class ThinLogging implements Consumer<Map<String, Object>> {
                        // measure timestamp first
                        Instant now = Instant.now();
                        Thread thread = Thread.currentThread();
-                       publisher.log(this, level, bundle, msg, now, thread, thrown, findCallLocation(level, thread));
+                       dispatchLogEntry(ThinLogger.this, level, bundle, msg, now, thread, thrown, findCallLocation(level, thread));
                }
 
                @Override
@@ -308,7 +366,8 @@ class ThinLogging implements Consumer<Map<String, Object>> {
                                format = sb.toString();
                        }
                        String msg = params == null ? format : MessageFormat.format(format, params);
-                       publisher.log(this, level, bundle, msg, now, thread, (Throwable) null, findCallLocation(level, thread));
+                       dispatchLogEntry(ThinLogger.this, level, bundle, msg, now, thread, (Throwable) null,
+                                       findCallLocation(level, thread));
                }
 
                private void setLevel(Level level) {
@@ -334,6 +393,7 @@ class ThinLogging implements Consumer<Map<String, Object>> {
                                        case "org.osgi.service.log.Logger":
                                        case "org.eclipse.osgi.internal.log.LoggerImpl":
                                        case "org.argeo.api.cms.CmsLog":
+                                       case "org.argeo.init.osgi.OsgiBootUtils":
                                        case "org.slf4j.impl.ArgeoLogger":
                                        case "org.argeo.cms.internal.osgi.CmsOsgiLogger":
                                        case "org.eclipse.jetty.util.log.Slf4jLog":
@@ -365,40 +425,10 @@ class ThinLogging implements Consumer<Map<String, Object>> {
                        super();
                }
 
-               private void log(ThinLogger logger, Level level, ResourceBundle bundle, String msg, Instant instant,
-                               Thread thread, Throwable thrown, StackTraceElement callLocation) {
-                       assert level != null;
-                       assert logger != null;
-                       assert msg != null;
-                       assert instant != null;
-                       assert thread != null;
-
-                       final long sequence = nextEntry.incrementAndGet();
-
-                       Map<String, Serializable> logEntry = new LogEntryMap(sequence);
-
-                       // same object as key class name
-                       logEntry.put(KEY_LEVEL, level);
-                       logEntry.put(KEY_MSG, msg);
-                       logEntry.put(KEY_INSTANT, instant);
-                       if (thrown != null)
-                               logEntry.put(KEY_THROWABLE, thrown);
-                       if (callLocation != null)
-                               logEntry.put(KEY_CALL_LOCATION, callLocation);
-
-                       // object is a string
-                       logEntry.put(KEY_LOGGER, logger.getName());
-                       logEntry.put(KEY_THREAD, thread.getName());
-
-                       // should be unmodifiable for security reasons
-                       if (synchronous) {
-                               assert synchronousSubscriber != null;
-                               synchronousSubscriber.onNext(logEntry);
-                       } else {
-                               if (!isClosed())
-                                       submit(Collections.unmodifiableMap(logEntry));
-                       }
-               }
+//             private void log(ThinLogger logger, Level level, ResourceBundle bundle, String msg, Instant instant,
+//                             Thread thread, Throwable thrown, StackTraceElement callLocation) {
+//
+//             }
 
        }
 
@@ -444,6 +474,8 @@ class ThinLogging implements Consumer<Map<String, Object>> {
                private PrintStream err;
                private int writeToErrLevel = Level.WARNING.getSeverity();
 
+               private Subscription subscription;
+
                protected PrintStreamSubscriber() {
                        this(System.out, System.err);
                }
@@ -459,7 +491,8 @@ class ThinLogging implements Consumer<Map<String, Object>> {
 
                @Override
                public void onSubscribe(Subscription subscription) {
-                       subscription.request(Long.MAX_VALUE);
+                       this.subscription = subscription;
+                       this.subscription.request(1);
                }
 
                @Override
@@ -470,6 +503,8 @@ class ThinLogging implements Consumer<Map<String, Object>> {
                                out.print(toPrint(item));
                        }
                        // TODO flush for journald?
+                       if (this.subscription != null)
+                               this.subscription.request(1);
                }
 
                @Override
@@ -531,10 +566,9 @@ class ThinLogging implements Consumer<Map<String, Object>> {
                protected String toPrint(Map<String, Serializable> logEntry) {
                        StringBuilder sb = new StringBuilder();
                        StringTokenizer st = new StringTokenizer((String) logEntry.get(KEY_MSG), "\r\n");
-                       assert st.hasMoreTokens();
 
                        // first line
-                       String firstLine = st.nextToken();
+                       String firstLine = st.hasMoreTokens() ? st.nextToken() : "";
                        sb.append(firstLinePrefix(logEntry));
                        sb.append(firstLine);
                        sb.append(firstLineSuffix(logEntry));
@@ -575,24 +609,24 @@ class ThinLogging implements Consumer<Map<String, Object>> {
                }
        }
 
-       public static void main(String args[]) {
-               Logger logger = System.getLogger(ThinLogging.class.getName());
-               logger.log(Logger.Level.ALL, "Log all");
-               logger.log(Logger.Level.TRACE, "Multi\nline\ntrace");
-               logger.log(Logger.Level.DEBUG, "Log debug");
-               logger.log(Logger.Level.INFO, "Log info");
-               logger.log(Logger.Level.WARNING, "Log warning");
-               logger.log(Logger.Level.ERROR, "Log exception", new Throwable());
-
-               try {
-                       // we ait a bit in order to make sure all messages are flushed
-                       // TODO synchronize more efficiently
-                       // executor.awaitTermination(300, TimeUnit.MILLISECONDS);
-                       ForkJoinPool.commonPool().awaitTermination(300, TimeUnit.MILLISECONDS);
-               } catch (InterruptedException e) {
-                       // silent
-               }
-
-       }
+//     public static void main(String args[]) {
+//             Logger logger = System.getLogger(ThinLogging.class.getName());
+//             logger.log(Logger.Level.ALL, "Log all");
+//             logger.log(Logger.Level.TRACE, "Multi\nline\ntrace");
+//             logger.log(Logger.Level.DEBUG, "Log debug");
+//             logger.log(Logger.Level.INFO, "Log info");
+//             logger.log(Logger.Level.WARNING, "Log warning");
+//             logger.log(Logger.Level.ERROR, "Log exception", new Throwable());
+//
+//             try {
+//                     // we wait a bit in order to make sure all messages are flushed
+//                     // TODO synchronize more efficiently
+//                     // executor.awaitTermination(300, TimeUnit.MILLISECONDS);
+//                     ForkJoinPool.commonPool().awaitTermination(300, TimeUnit.MILLISECONDS);
+//             } catch (InterruptedException e) {
+//                     // silent
+//             }
+//
+//     }
 
 }