Merge pull request #20501 from vespa-engine/hmusum/validate-jvm-options

Log JVM options [run-systemtest]

3 files changed, 166 insertions, 39 deletions

diff --git a/config-model/src/main/java/com/yahoo/vespa/model/container/xml/ContainerModelBuilder.java b/config-model/src/main/java/com/yahoo/vespa/model/container/xml/ContainerModelBuilder.java
index 562ccc44a37..6d184666bdb 100644
--- a/config-model/src/main/java/com/yahoo/vespa/model/container/xml/ContainerModelBuilder.java
+++ b/config-model/src/main/java/com/yahoo/vespa/model/container/xml/ContainerModelBuilder.java
@@ -100,6 +100,7 @@ import java.util.Map;
 import java.util.Optional;
 import java.util.Set;
 import java.util.function.Consumer;
+import java.util.logging.Level;
 import java.util.regex.Pattern;
 import java.util.stream.Collectors;
 
@@ -667,56 +668,51 @@ public class ContainerModelBuilder extends ConfigModelBuilder<ContainerModel> {
         return (gcAlgorithm.matcher(jvmargs).find() || cmsArgs.matcher(jvmargs).find());
     }
 
-    private static String buildJvmGCOptions(DeployState deployState, String jvmGCOptions) {
-        String options = (jvmGCOptions != null)
-                ? jvmGCOptions
-                : deployState.getProperties().jvmGCOptions();
-        return (options == null || options.isEmpty())
-                ? (deployState.isHosted() ? ContainerCluster.PARALLEL_GC : ContainerCluster.G1GC)
-                : options;
+    private static String buildJvmGCOptions(ConfigModelContext context, String jvmGCOptions) {
+        return new JvmGcOptions(context.getDeployState(), jvmGCOptions).build();
     }
 
-    private static String getJvmOptions(ApplicationContainerCluster cluster, Element nodesElement, DeployLogger deployLogger) {
-        String jvmOptions;
-        if (nodesElement.hasAttribute(VespaDomBuilder.JVM_OPTIONS)) {
-            jvmOptions = nodesElement.getAttribute(VespaDomBuilder.JVM_OPTIONS);
-            if (nodesElement.hasAttribute(VespaDomBuilder.JVMARGS_ATTRIB_NAME)) {
-                String jvmArgs = nodesElement.getAttribute(VespaDomBuilder.JVMARGS_ATTRIB_NAME);
-                throw new IllegalArgumentException("You have specified both jvm-options='" + jvmOptions + "'" +
-                        " and deprecated jvmargs='" + jvmArgs + "'. Merge jvmargs into jvm-options.");
-            }
-        } else {
-            jvmOptions = nodesElement.getAttribute(VespaDomBuilder.JVMARGS_ATTRIB_NAME);
-            if (incompatibleGCOptions(jvmOptions)) {
-                deployLogger.logApplicationPackage(WARNING, "You need to move out your GC-related options from deprecated 'jvmargs' to 'jvm-gc-options'");
-                cluster.setJvmGCOptions(ContainerCluster.G1GC);
-            }
-        }
-        return jvmOptions;
+    private static String getJvmOptions(ApplicationContainerCluster cluster,
+                                        Element nodesElement,
+                                        DeployState deployState,
+                                        boolean legacyOptions) {
+        return new JvmOptions(cluster, nodesElement, deployState, legacyOptions).build();
     }
 
     private static String extractAttribute(Element element, String attrName) {
         return element.hasAttribute(attrName) ? element.getAttribute(attrName) : null;
     }
 
-    void extractJvmFromLegacyNodesTag(List<ApplicationContainer> nodes, ApplicationContainerCluster cluster,
-                                      Element nodesElement, ConfigModelContext context) {
-        applyNodesTagJvmArgs(nodes, getJvmOptions(cluster, nodesElement, context.getDeployLogger()));
+    private void extractJvmOptions(List<ApplicationContainer> nodes,
+                                   ApplicationContainerCluster cluster,
+                                   Element nodesElement,
+                                   ConfigModelContext context) {
+        Element jvmElement = XML.getChild(nodesElement, "jvm");
+        if (jvmElement == null) {
+            extractJvmFromLegacyNodesTag(nodes, cluster, nodesElement, context);
+        } else {
+            extractJvmTag(nodes, cluster, nodesElement, jvmElement, context);
+        }
+    }
+
+    private void extractJvmFromLegacyNodesTag(List<ApplicationContainer> nodes, ApplicationContainerCluster cluster,
+                                              Element nodesElement, ConfigModelContext context) {
+        applyNodesTagJvmArgs(nodes, getJvmOptions(cluster, nodesElement, context.getDeployState(), true));
 
         if (cluster.getJvmGCOptions().isEmpty()) {
             String jvmGCOptions = extractAttribute(nodesElement, VespaDomBuilder.JVM_GC_OPTIONS);
-            cluster.setJvmGCOptions(buildJvmGCOptions(context.getDeployState(), jvmGCOptions));
+            cluster.setJvmGCOptions(buildJvmGCOptions(context, jvmGCOptions));
         }
 
         applyMemoryPercentage(cluster, nodesElement.getAttribute(VespaDomBuilder.Allocated_MEMORY_ATTRIB_NAME));
     }
 
-    void extractJvmTag(List<ApplicationContainer> nodes, ApplicationContainerCluster cluster,
-                       Element jvmElement, ConfigModelContext context) {
-        applyNodesTagJvmArgs(nodes, jvmElement.getAttribute(VespaDomBuilder.OPTIONS));
+    private void extractJvmTag(List<ApplicationContainer> nodes, ApplicationContainerCluster cluster,
+                               Element nodesElement, Element jvmElement, ConfigModelContext context) {
+        applyNodesTagJvmArgs(nodes, getJvmOptions(cluster, nodesElement, context.getDeployState(), false));
         applyMemoryPercentage(cluster, jvmElement.getAttribute(VespaDomBuilder.Allocated_MEMORY_ATTRIB_NAME));
         String jvmGCOptions = extractAttribute(jvmElement, VespaDomBuilder.GC_OPTIONS);
-        cluster.setJvmGCOptions(buildJvmGCOptions(context.getDeployState(), jvmGCOptions));
+        cluster.setJvmGCOptions(buildJvmGCOptions(context, jvmGCOptions));
     }
 
     /**
@@ -733,12 +729,7 @@ public class ContainerModelBuilder extends ConfigModelBuilder<ContainerModel> {
         } else {
             List<ApplicationContainer> nodes = createNodes(cluster, containerElement, nodesElement, context);
 
-            Element jvmElement = XML.getChild(nodesElement, "jvm");
-            if (jvmElement == null) {
-                extractJvmFromLegacyNodesTag(nodes, cluster, nodesElement, context);
-            } else {
-                extractJvmTag(nodes, cluster, jvmElement, context);
-            }
+            extractJvmOptions(nodes, cluster, nodesElement, context);
             applyRoutingAliasProperties(nodes, cluster);
             applyDefaultPreload(nodes, nodesElement);
             String environmentVars = getEnvironmentVariables(XML.getChild(nodesElement, ENVIRONMENT_VARIABLES_ELEMENT));
@@ -1077,4 +1068,97 @@ public class ContainerModelBuilder extends ConfigModelBuilder<ContainerModel> {
         return CONTAINER_TAG.equals(element.getTagName()) || DEPRECATED_CONTAINER_TAG.equals(element.getTagName());
     }
 
+    private static class JvmOptions {
+
+        private final ContainerCluster<?> cluster;
+        private final Element nodesElement;
+        private final DeployLogger logger;
+        private final boolean isHosted;
+        private final boolean legacyOptions;
+
+        public JvmOptions(ContainerCluster<?> cluster, Element nodesElement, DeployState deployState, boolean legacyOptions) {
+            this.cluster = cluster;
+            this.nodesElement = nodesElement;
+            this.logger = deployState.getDeployLogger();
+            this.isHosted = deployState.isHosted();
+            this.legacyOptions = legacyOptions;
+        }
+
+        String build() {
+            if (legacyOptions)
+                return buildLegacyOptions();
+
+            Element jvmElement = XML.getChild(nodesElement, "jvm");
+            if (jvmElement == null) return "";
+            String jvmOptions = jvmElement.getAttribute(VespaDomBuilder.OPTIONS);
+            if (jvmOptions == null) return "";
+            log(jvmOptions);
+            return jvmOptions;
+        }
+
+        String buildLegacyOptions() {
+            String jvmOptions;
+            if (nodesElement.hasAttribute(VespaDomBuilder.JVM_OPTIONS)) {
+                jvmOptions = nodesElement.getAttribute(VespaDomBuilder.JVM_OPTIONS);
+                log(jvmOptions);
+                if (nodesElement.hasAttribute(VespaDomBuilder.JVMARGS_ATTRIB_NAME)) {
+                    String jvmArgs = nodesElement.getAttribute(VespaDomBuilder.JVMARGS_ATTRIB_NAME);
+                    throw new IllegalArgumentException("You have specified both jvm-options='" + jvmOptions + "'" +
+                                                               " and deprecated jvmargs='" + jvmArgs +
+                                                               "'. Merge jvmargs into 'options' in 'jvm' element." +
+                                                               " See https://docs.vespa.ai/en/reference/services-container.html#jvm");
+                }
+            } else {
+                jvmOptions = nodesElement.getAttribute(VespaDomBuilder.JVMARGS_ATTRIB_NAME);
+                log(jvmOptions);
+                if (incompatibleGCOptions(jvmOptions)) {
+                    logger.logApplicationPackage(WARNING, "You need to move your GC-related options from deprecated 'jvmargs' to 'gc-options' in 'jvm' element." +
+                            " See https://docs.vespa.ai/en/reference/services-container.html#jvm");
+                    cluster.setJvmGCOptions(ContainerCluster.G1GC);
+                }
+            }
+            return jvmOptions;
+        }
+
+        private void log(String jvmOptions) {
+            if (isHosted && jvmOptions != null && !jvmOptions.isEmpty())
+                logger.logApplicationPackage(Level.INFO, "JVM options from services.xml: " + jvmOptions);
+        }
+    }
+
+    private static class JvmGcOptions {
+
+        private final DeployState deployState;
+        private final String jvmGcOptions;
+        private final DeployLogger logger;
+        private final boolean isHosted;
+
+        public JvmGcOptions(DeployState deployState, String jvmGcOptions) {
+            this.deployState = deployState;
+            this.jvmGcOptions = jvmGcOptions;
+            this.logger = deployState.getDeployLogger();
+            this.isHosted = deployState.isHosted();
+        }
+
+        private String build() {
+            String options = deployState.getProperties().jvmGCOptions();
+            if (jvmGcOptions != null) {
+                log(jvmGcOptions);
+                options = jvmGcOptions;
+                // TODO: Verify options against lists of allowed and/or disallowed options
+            }
+
+            if (options == null || options.isEmpty())
+                options = deployState.isHosted() ? ContainerCluster.PARALLEL_GC : ContainerCluster.G1GC;
+
+            return options;
+        }
+
+        private void log(String jvmGcOptions) {
+            if (isHosted)
+                logger.logApplicationPackage(Level.INFO, "JVM GC options from services.xml: " + jvmGcOptions);
+        }
+
+    }
+
 }
diff --git a/config-model/src/test/java/com/yahoo/config/model/provision/ModelProvisioningTest.java b/config-model/src/test/java/com/yahoo/config/model/provision/ModelProvisioningTest.java
index 2fcb9632357..0866e1174ee 100644
--- a/config-model/src/test/java/com/yahoo/config/model/provision/ModelProvisioningTest.java
+++ b/config-model/src/test/java/com/yahoo/config/model/provision/ModelProvisioningTest.java
@@ -1488,7 +1488,10 @@ public class ModelProvisioningTest {
             fail("Expected exception");
         }
         catch (IllegalArgumentException e) {
-            assertEquals("You have specified both jvm-options='xyz' and deprecated jvmargs='abc'. Merge jvmargs into jvm-options.", e.getMessage());
+            assertEquals("You have specified both jvm-options='xyz' and deprecated jvmargs='abc'. " +
+                                 "Merge jvmargs into 'options' in 'jvm' element. " +
+                                 "See https://docs.vespa.ai/en/reference/services-container.html#jvm",
+                         e.getMessage());
         }
     }
 
diff --git a/config-model/src/test/java/com/yahoo/vespa/model/container/xml/JvmOptionsTest.java b/config-model/src/test/java/com/yahoo/vespa/model/container/xml/JvmOptionsTest.java
index 9fda6016969..a674a06d45e 100644
--- a/config-model/src/test/java/com/yahoo/vespa/model/container/xml/JvmOptionsTest.java
+++ b/config-model/src/test/java/com/yahoo/vespa/model/container/xml/JvmOptionsTest.java
@@ -2,6 +2,7 @@
 
 package com.yahoo.vespa.model.container.xml;
 
+import com.yahoo.collections.Pair;
 import com.yahoo.config.application.api.ApplicationPackage;
 import com.yahoo.config.model.NullConfigModelRegistry;
 import com.yahoo.config.model.builder.xml.test.DomBuilderTest;
@@ -17,6 +18,7 @@ import org.w3c.dom.Element;
 import org.xml.sax.SAXException;
 
 import java.io.IOException;
+import java.util.logging.Level;
 
 import static org.junit.Assert.assertEquals;
 import static org.junit.Assert.assertFalse;
@@ -142,4 +144,42 @@ public class JvmOptionsTest extends ContainerModelBuilderTestBase {
         verifyJvmGCOptions(false, null, "-XX:+UseParallelGC", "-XX:+UseParallelGC");
     }
 
+    @Test
+    public void requireThatJvmGcOptionsAreLogged()  throws IOException, SAXException {
+        verifyLoggingOfJvmOptions(true, "gc-options", "-XX:+UseCMSInitiatingOccupancyOnly foo     bar");
+        verifyLoggingOfJvmOptions(true, "gc-options", "-XX:+UseConcMarkSweepGC");
+        verifyLoggingOfJvmOptions(false, "gc-options", "-XX:+UseConcMarkSweepGC");
+    }
+
+    private void verifyLoggingOfJvmOptions(boolean isHosted, String optionName, String override) throws IOException, SAXException  {
+        String servicesXml =
+                "<container version='1.0'>" +
+                "  <nodes>" +
+                "    <jvm " + optionName + "='" + override + "'/>" +
+                "    <node hostalias='mockhost'/>" +
+                "  </nodes>" +
+                "</container>";
+        ApplicationPackage app = new MockApplicationPackage.Builder().withServices(servicesXml).build();
+        TestLogger logger = new TestLogger();
+        new VespaModel(new NullConfigModelRegistry(), new DeployState.Builder()
+                .applicationPackage(app)
+                .deployLogger(logger)
+                .properties(new TestProperties().setHostedVespa(isHosted))
+                .build());
+        if (isHosted) {
+            Pair<Level, String> firstOption = logger.msgs.get(0);
+            assertEquals(Level.INFO, firstOption.getFirst());
+            assertEquals("JVM " + (optionName.equals("gc-options") ? "GC " : "") +
+                                 "options from services.xml: " + override, firstOption.getSecond());
+        } else {
+            assertEquals(0, logger.msgs.size());
+        }
+    }
+
+    @Test
+    public void requireThatJvmOptionsAreLogged()  throws IOException, SAXException {
+        verifyLoggingOfJvmOptions(true, "options", "-Xms2G");
+        verifyLoggingOfJvmOptions(false, "options", "-Xms2G");
+    }
+
 }