Merge pull request #24743 from dmatej/fix-logging

Fixes around logging

nucleus/admin/launcher/src/main/java/com/sun/enterprise/admin/launcher/GFLauncher.java

@@ -1,4 +1,5 @@
 /*
+ * Copyright (c) 2024 Contributors to the Eclipse Foundation
  * Copyright (c) 2008, 2020 Oracle and/or its affiliates. All rights reserved.
  *
  * This program and the accompanying materials are made available under the
@@ -83,7 +84,7 @@ public abstract class GFLauncher {
      * parameters (GF DAS or Instance).
      *
      */
-    private GFLauncherInfo callerParameters;
+    private final GFLauncherInfo callerParameters;
 
     /**
      * Properties from asenv.conf, such as <code>AS_DEF_DOMAINS_PATH="../domains"</code>
@@ -119,7 +120,7 @@ public abstract class GFLauncher {
     /**
      * Same data as domainXMLjvmOptions, but as list
      */
-    private List<String> domainXMLJvmOptionsAsList = new ArrayList<>();
+    private final List<String> domainXMLJvmOptionsAsList = new ArrayList<>();
 
     /**
      * The <code>profiler<code> from <code>java-config</code> in domain.xml
@@ -160,7 +161,7 @@ public abstract class GFLauncher {
     /**
      * The full commandline string used to start GlassFish in process <code<>glassFishProcess</code>
      */
-    private List<String> commandLine = new ArrayList<>();
+    private final List<String> commandLine = new ArrayList<>();
 
     /**
      * Time when GlassFish was launched
@@ -470,6 +471,10 @@ void launchInstance() throws GFLauncherException, MiniXmlParserException {
         try {
             closeStandardStreamsMaybe();
 
+            // We have to abandon server.log file to avoid file locking issues on Windows.
+            // From now on the server.log file is owned by the server, not by launcher.
+            GFLauncherLogger.removeLogFileHandler();
+
             // Startup GlassFish
             glassFishProcess = processBuilder.start();
 
@@ -1108,7 +1113,7 @@ private void closeStandardStreamsMaybe() {
     ///////////////////////////////////////////////////////////////////////////
     private static class ProcessWhacker implements Runnable {
 
-        private String message;
+        private final String message;
         private Process process;
 
         ProcessWhacker(Process p, String msg) {

nucleus/admin/server-mgmt/src/main/java/com/sun/enterprise/admin/servermgmt/cli/LocalStrings.properties

@@ -114,9 +114,6 @@ Domain.badDomainDir=CLI301: There is no such domain directory: {0}
 Domain.noDomainXml=CLI304: Cannot find domain.xml.  It should be here: {0}
 
 ## stop-domain command
-StopDomain.dasNotRunning=CLI306: Warning - The server located at {0} is not running.
-StopDomain.dasNotRunningRemotely=CLI307: Warning - remote server is not running, unable to force it to stop.\n\
-Try running stop-domain on the remote server.
 StopDomain.WaitDASDeath=Waiting for the domain to stop
 StopDomain.DASNotDead=Timed out ({0} seconds) waiting for the domain to stop.
 StopDomain.noDomainNameAllowed=No domain name allowed with --host option.

nucleus/admin/server-mgmt/src/main/java/com/sun/enterprise/admin/servermgmt/cli/StopDomainCommand.java

@@ -1,5 +1,5 @@
 /*
- * Copyright (c) 2022 Contributors to the Eclipse Foundation
+ * Copyright (c) 2022, 2024 Contributors to the Eclipse Foundation
  * Copyright (c) 1997, 2018 Oracle and/or its affiliates. All rights reserved.
  *
  * This program and the accompanying materials are made available under the
@@ -25,9 +25,10 @@
 import com.sun.enterprise.util.HostAndPort;
 
 import java.io.File;
+import java.lang.System.Logger;
+import java.lang.System.Logger.Level;
 import java.time.Duration;
 import java.util.function.Supplier;
-import java.util.logging.Level;
 
 import org.glassfish.api.Param;
 import org.glassfish.api.admin.CommandException;
@@ -45,6 +46,7 @@
 @Service(name = "stop-domain")
 @PerLookup
 public class StopDomainCommand extends LocalDomainCommand {
+    private static final Logger LOG = System.getLogger(StopDomainCommand.class.getName());
 
     @Param(name = "domain_name", primary = true, optional = true)
     private String userArgDomainName;
@@ -94,7 +96,7 @@ protected int executeCommand() throws CommandException {
             // cmd line has higher priority, but if not set, use domain.xml or defaults
             addr = getAdminAddress();
             programOpts.setHostAndPort(addr);
-            logger.log(Level.FINER, "Stopping local domain on port {0}", programOpts.getPort());
+            LOG.log(Level.DEBUG, "Stopping local domain on port {0}", programOpts.getPort());
 
             /*
              * If we're using the local password, we don't want to prompt
@@ -108,15 +110,15 @@ protected int executeCommand() throws CommandException {
                 return dasNotRunning();
             }
 
-            logger.finer("It's the correct DAS");
+            LOG.log(Level.DEBUG, "It's the correct DAS");
         } else {
             // remote
             // Verify that the DAS is running and reachable
             if (!DASUtils.pingDASQuietly(programOpts, env)) {
                 return dasNotRunning();
             }
 
-            logger.finer("DAS is running");
+            LOG.log(Level.DEBUG, "DAS is running");
             programOpts.setInteractive(false);
         }
 
@@ -136,7 +138,7 @@ protected int executeCommand() throws CommandException {
      * Print message and return exit code when we detect that the DAS is not running.
      */
     protected int dasNotRunning() throws CommandException {
-        logger.log(Level.FINE, "dasNotRunning()");
+        LOG.log(Level.DEBUG, "dasNotRunning()");
         if (kill) {
             if (isLocal()) {
                 try {
@@ -154,9 +156,10 @@ protected int dasNotRunning() throws CommandException {
         // by definition this is not an error
         // https://glassfish.dev.java.net/issues/show_bug.cgi?id=8387
         if (isLocal()) {
-            logger.warning(Strings.get("StopDomain.dasNotRunning", getDomainRootDir()));
+            LOG.log(Level.WARNING, "CLI306: Warning - The server located at {0} is not running.", getDomainRootDir());
         } else {
-            logger.warning(Strings.get("StopDomain.dasNotRunningRemotely"));
+            LOG.log(Level.WARNING, "CLI307: Warning - remote server is not running, unable to force it to stop.\n"
+                + "Try running stop-domain on the remote server.");
         }
         return 0;
     }
@@ -174,7 +177,7 @@ protected void doCommand() throws CommandException {
         } catch (Exception e) {
             // The domain server may have died so fast we didn't have time to
             // get the (always successful!!) return data.  This is NOT AN ERROR!
-            logger.log(Level.CONFIG, "Remote stop-domain call failed.", e);
+            LOG.log(Level.DEBUG, "Remote stop-domain call failed.", e);
             if (kill && isLocal()) {
                 try {
                     File prevPid = getServerDirs().getLastPidFile();

nucleus/core/logging/src/main/java/com/sun/enterprise/server/logging/LogFacade.java

@@ -1,4 +1,5 @@
 /*
+ * Copyright (c) 2024 Contributors to the Eclipse Foundation
  * Copyright (c) 2012, 2018 Oracle and/or its affiliates. All rights reserved.
  *
  * This program and the accompanying materials are made available under the
@@ -56,9 +57,17 @@ public class LogFacade {
     @LogMessageInfo(message = "Updated logger levels successfully.", level="INFO")
     public static final String UPDATED_LOG_LEVELS = "NCLS-LOGGING-00003";
 
-    @LogMessageInfo(message = "The logging configuration file {0} has been deleted.", level="WARNING")
+    @LogMessageInfo(
+        message = "The logging configuration file {0} has been deleted."
+        + " The server will wait until the file reappears.",
+        cause="The file was deleted.",
+        action="Create the file again using the Admin Console or asadmin command.",
+        level="SEVERE")
     public static final String CONF_FILE_DELETED = "NCLS-LOGGING-00004";
 
+    @LogMessageInfo(message = "The logging configuration file {0} has reappeared.", level="INFO")
+    public static final String CONF_FILE_REAPPEARED = "NCLS-LOGGING-00004-1";
+
     @LogMessageInfo(message = "Error executing query to fetch log records.", level="SEVERE",
             cause="There was an exception thrown while executing log query.",
             action="Take appropriate action based on the exception message.")

nucleus/core/logging/src/main/java/com/sun/enterprise/server/logging/LogManagerService.java

@@ -1,5 +1,5 @@
 /*
- * Copyright (c) 2022, 2023 Contributors to the Eclipse Foundation
+ * Copyright (c) 2022, 2024 Contributors to the Eclipse Foundation
  * Copyright (c) 2009, 2018 Oracle and/or its affiliates. All rights reserved.
  *
  * This program and the accompanying materials are made available under the
@@ -45,6 +45,7 @@
 
 import org.glassfish.api.VersionInfo;
 import org.glassfish.api.admin.FileMonitoring;
+import org.glassfish.api.admin.FileMonitoring.FileChangeListener;
 import org.glassfish.common.util.Constants;
 import org.glassfish.config.support.TranslatedConfigView;
 import org.glassfish.hk2.api.Rank;
@@ -121,9 +122,7 @@ public void postConstruct() {
 
         final File loggingPropertiesFile = getOrCreateLoggingProperties();
         reconfigure(loggingPropertiesFile);
-        LOG.config("Configuring change detection of the configuration file ...");
-        fileMonitoring.monitors(loggingPropertiesFile, new LoggingCfgFileChangeListener(this::reconfigure));
-
+        configureFileMonitoring(loggingPropertiesFile);
         LOG.config("LogManagerService completed successfuly ...");
         LOG.log(Level.INFO, LogFacade.GF_VERSION_INFO, Version.getProductIdInfo());
     }
@@ -349,6 +348,13 @@ private void reconfigure(final File configFile) {
     }
 
 
+    private void configureFileMonitoring(File loggingPropertiesFile) {
+        LOG.config("Configuring change detection of the configuration file ...");
+        fileMonitoring.monitors(loggingPropertiesFile,
+            new LoggingCfgFileChangeListener(this::reconfigure, this::configureFileMonitoring));
+    }
+
+
     private void reconfigureGlassFishLogHandler() {
         final GlassFishLogHandler handler = JULHelperFactory.getHelper().findGlassFishLogHandler();
         if (handler == null) {
@@ -433,26 +439,52 @@ private boolean isKnownHandlerClass(final String name) {
     }
 
 
-    private static final class LoggingCfgFileChangeListener implements FileMonitoring.FileChangeListener {
+    private static final class LoggingCfgFileChangeListener implements FileChangeListener {
 
-        private final Consumer<File> action;
+        private final Consumer<File> reconfiguration;
+        private final Consumer<File> fileMonitoring;
 
 
-        LoggingCfgFileChangeListener(final Consumer<File> action) {
-            this.action = action;
+        LoggingCfgFileChangeListener(final Consumer<File> reconfiguration, final Consumer<File> fileMonitoring) {
+            this.reconfiguration = reconfiguration;
+            this.fileMonitoring = fileMonitoring;
         }
 
 
         @Override
         public void changed(File changedFile) {
             LOG.info(() -> "Detected change of file: " + changedFile);
-            action.accept(changedFile);
+            reconfiguration.accept(changedFile);
         }
 
 
         @Override
         public void deleted(File deletedFile) {
-            LOG.log(Level.WARNING, LogFacade.CONF_FILE_DELETED, deletedFile.getAbsolutePath());
+            LOG.log(Level.SEVERE, LogFacade.CONF_FILE_DELETED, deletedFile.getAbsolutePath());
+            final Runnable waitingJob = () -> this.waitUntilFileReappears(deletedFile);
+            final Thread thread = new Thread(waitingJob, "Wait-to-reappear-" + deletedFile.getName());
+            thread.setDaemon(true);
+            thread.start();
+        }
+
+
+        /**
+         * Ie. the Vim editor can quickly remove and create the file on saving changes.
+         * Sometimes GF monitoring notices that the file vanished, then stops
+         * the monitoring and notifies this listener.
+         * <p>
+         * If the file is back again, we do the reconfiguration and we also reset
+         * the monitoring again.
+         * <p>
+         * If the file is really lost, we have a serious problem.
+         */
+        private void waitUntilFileReappears(File deletedFile) {
+            while (!deletedFile.exists()) {
+                Thread.onSpinWait();
+            }
+            LOG.log(Level.INFO, LogFacade.CONF_FILE_REAPPEARED, deletedFile.getAbsolutePath());
+            reconfiguration.accept(deletedFile);
+            fileMonitoring.accept(deletedFile);
         }
     }
 }