Merge pull request #178 from Trivadis/feature/issue-177-improve-logging-native-image

Feature/issue 177 - Improve logging capabilities of standalone image and native image creation

Author: PhilippSalvisberg

settings/sql_developer/trivadis_custom_format.arbori

@@ -31,6 +31,7 @@ hs_err_pid*
 .project
 .classpath
 **/.settings
+.vscode
 
 # IntelliJ
 **/.idea

sqlcl/format.js

@@ -2,18 +2,66 @@
 
 ## Introduction
 
-This Maven project produces a standalone command line executable `tvdformat.jar` for the SQLcl script [`format.js`](../sqlcl/format.js). Optionally it produces also a GraalVM native image `tvdformat`.
+This Maven project produces a standalone command line executable `tvdformat.jar` for the SQLcl script [`format.js`](../sqlcl/format.js). Optionally it produces also a GraalVM [native image](https://www.graalvm.org/reference-manual/native-image/) `tvdformat`.
 
-The startup time of standalone JAR file and the native image are identical since the image still requires a JDK to execute. However, it is faster than running `format.js` from SQLcl.
+The startup time of standalone JAR file and the native image are similar since the image still requires a JDK to execute. However, it is faster than running `format.js` from SQLcl.
 
 This project contains JUnit tests for
 
 - the SQLDev/SQLcl formatter settings `trivadis_advanced_format.xml` and `trivadis_custom_format.arbori`
 - the SQLcl script `format.js`
 - the SQLcl command `tvdformat`
-- the standalone executable `tvdformat`
+- the standalone exectable `tvdformat` 
 
-The project requires a JDK 17, but it produces a Java 8 JAR file. A GraalVM JDK is required only if you want to produce a native image.
+The project requires a JDK 17, but it produces a Java 8 executable JAR file. A GraalVM JDK is required only if you want to build a [native image](https://www.graalvm.org/reference-manual/native-image/).
+
+## Running the Standalone Formatter
+
+### Configure Logging
+
+Optionally, you can define the following environment variables:
+
+Variable | Description
+-------- | -----------
+`TVDFORMAT_LOGGING_CONF_FILE` | Path to a [java.util.logging](https://docs.oracle.com/en/java/javase/17/core/java-logging-overview.html#GUID-B83B652C-17EA-48D9-93D2-563AE1FF8EDA) configuration file. Fully qualified or relative paths are supported. [This file](src/test/resources/logging.conf) is used for tests.
+`TVDFORMAT_DEBUG` | `true` enables Arbori debug messages.
+`TVDFORMAT_TIMING` |`true` enables Arbori query/callback timing messages.
+
+### Executable JAR
+
+The `tvdformat.jar` is a shaded, executable JAR. This means it contains all dependend Java classes. However, it still needs a JDK 8 or higher.
+
+To run it, open a terminal window and type
+
+```
+java -jar tvdformat.jar
+```
+
+The parameters are the same as for the [SQLcl command `tvdformat`](../sqlcl/README.md#register-script-formatjs-as-sqlcl-command-tvdformat). Except for formatting the SQLcl buffer, of course.
+
+### Native Image
+
+A native image is a platform specific executable. The following images can be produced with a GraalVM JDK 17:
+
+OS      | amd64)? | aarch64? | Requires JDK 8+? | No JDK required?
+------- | ------- | -------- | ---------------- | ---------------- 
+macOS   | yes     | no       | yes              | yes
+Linux   | yes     | yes      | yes              | yes
+Windows | yes     | no       | yes              | yes
+
+Currently there is no way to produce an ARM based (aarch64) native image for macOS and Windows. This reduces the possible combinations from 12 to 8 native images. Native images are not part of a release. You have to build them yourself as described [below](#how-to-build). 
+
+Native images produced with the `--force-fallback` option have a size of around 14 MB. They require a JDK 8+ at runtime and are considered stable. 
+
+Native images produced with the `--no-fallback` option have a size of around 500 MB. They do not require a JDK at runtime. Due to the absence of automatic tests, these images are considered experimental.
+
+To run a native image open a terminal window and type
+
+```
+./tvdformat
+```
+
+The parameters are the same as for the [executable JAR](#executable-jar).
 
 ## How to Build
 
@@ -25,12 +73,33 @@ The project requires a JDK 17, but it produces a Java 8 JAR file. A GraalVM JDK
 6. Clone the plsql-formatter-settings repository
 7. Open a terminal window in the plsql-formatter-settings root folder and type
 
-		cd standalone
+    ```
+    cd standalone
+    ```
+
+8. Run Maven build by the following command
+
+    ```
+    mvn -Dsqlcl.libdir=/usr/local/bin/sqlcl/lib clean package
+    ```
+
+    Amend the parameter `sqlcl.libdir` to match the path of the lib directory of your SQLcl installation. This folder is used to reference libraries such as `dbtools-common.jar` which contains the formatter and its dependencies. These libraries are not available in public Maven repositories.
+    
+    You can define the following optional parameters: 
 
-6. Run maven build by the following command
+    | Parameter                  | Value   | Meaning |
+    | -------------------------- | ------- | ------- |
+    | `skip.native`              | `true`  | Do not produce a native image (default) |
+    |                            | `false` | Produce a native image |
+    | `native.image.fallback`    | `no`    | Produce a native image of about 14 MB which requires a JDK at runtime (default) |
+    |                            | `force` | Produce a native image of about 500 MB that runs without JDK |
+    | `skipTests`                | `true`  | Run tests (default) |
+    |                            | `false` | Do not run tests |
+    | `disable.logging`          | `true`  | Disable logging message during test run (default) |
+    |                            | `false` | Enable logging message during test run |
 
-		mvn -Dsqlcl.libdir=/usr/local/bin/sqlcl/lib -Dskip.native=false clean package
+    Here's a fully qualified example to produce a native image:
 
-	Amend the parameter `sqlcl.libdir` to match the path of the lib directory of you SQLcl installation. This folder is used to reference the `dbtools-common.jar` library (containing the formatter and its dependencies) which is not available in public Maven repositories. 
-	
-	When you specifiy the parameter `-Dskip.native=false` a native image for your platform is created. When you pass the value `true` (default) then no native image is produced.
+    ```
+    mvn -Dsqlcl.libdir=/usr/local/bin/sqlcl/lib -Dskip.native=false -Dnative.image.fallback=no -DskipTests=true -Ddisable.logging=true clean package
+    ```

standalone/.gitignore

@@ -17,6 +17,9 @@
         <graalvm.version>21.3.0</graalvm.version>
         <graalvm.native.version>21.2.0</graalvm.native.version>
         <skip.native>true</skip.native>
+        <!-- relevant when skip.native is false, valid: "no", "force" -->
+        <native.image.fallback>force</native.image.fallback>
+        <disable.logging>true</disable.logging>
     </properties>
     <dependencies>
         <!-- GraalVM JavaScript engine used for testing format.js as if executed via SQLcl -->
@@ -90,6 +93,17 @@
             <version>5.8.2</version>
             <scope>test</scope>
         </dependency>
+        <!-- For native image with no-fallback option, used during build phase only -->
+        <dependency>
+            <groupId>org.reflections</groupId>
+            <artifactId>reflections</artifactId>
+            <version>0.10.2</version>
+        </dependency>
+        <dependency>
+            <groupId>org.slf4j</groupId>
+            <artifactId>slf4j-jdk14</artifactId>
+            <version>1.7.32</version>
+        </dependency>
     </dependencies>
 
     <!-- Reporting -->
@@ -179,6 +193,7 @@
                                 <exclude>META-INF/MANIFEST.MF</exclude>
                                 <exclude>module-info.class</exclude>
                                 <exclude>META-INF/versions/**</exclude>
+                                <exclude>META-INF/native-image/org.graalvm.*/**</exclude>
                             </excludes>
                         </filter>
                         <filter>
@@ -220,17 +235,27 @@
                     <skip>${skip.native}</skip>
                     <imageName>${project.artifactId}</imageName>
                     <mainClass>com.trivadis.plsql.formatter.TvdFormat</mainClass>
-                    <!-- Creating a native image with "-language:js -no-fallback -H:ReflectionConfigurationFiles=..."
-                         was e dead end. There were various issues, such as
-                             - different behavior between JS/Java Strings and their methods
-                             - laborious identification of classes used via reflection
-                             - long build times (~280 seconds)
-                             - very large image size (437MB)
-                         Therefore, creating a native image which requires a JDK was much simpler.
-                         The drawback is a slower startup time. However, loading 437MB is not fast ether, at least the first time.
+                    <!-- There are basically two options to create a native image
+
+                         a) with "force-fallback" option (stable)
+                            The resulting image is relatively small (14 MB) and works.
+                            The executable requires a JDK 8 or higher. The distribution does not matter.
+
+                         b) with "no-fallback" option (experimental)
+                            The resulting image is large (almost 500 MB).
+                            The executable does not require a JDK.
+                            Must be build for every target platform/architecture combination.
+                            It should work with the default Arbori program and the trivadis_custom_format.arbori.
+                            However, runtime errors are possible when using unconfigured Java classes.
 	                -->
                     <buildArgs>
-                        -H:IncludeResources=.* --force-fallback
+                        -H:IncludeResources=.*
+                        -H:DynamicProxyConfigurationFiles=${project.basedir}/src/main/resources/META-INF/native-image/${project.groupId}/${project.artifactId}/proxy-config.json
+                        -H:ReflectionConfigurationFiles=${project.basedir}/src/main/resources/META-INF/native-image/${project.groupId}/${project.artifactId}/reflect-config.json
+                        -H:+ReportExceptionStackTraces
+                        --language:js
+                        --features=com.trivadis.plsql.formatter.RuntimeReflectionRegistrationFeature
+                        --${native.image.fallback}-fallback
                     </buildArgs>
                 </configuration>
             </plugin>
@@ -243,6 +268,9 @@
                     <includes>
                         <include>**/*.java</include>
                     </includes>
+                    <systemPropertyVariables>
+                        <disable.logging>${disable.logging}</disable.logging>
+                    </systemPropertyVariables>
                 </configuration>
             </plugin>
         </plugins>

standalone/README.md

@@ -0,0 +1,71 @@
+package com.trivadis.plsql.formatter;
+
+import org.graalvm.nativeimage.hosted.Feature;
+import org.graalvm.nativeimage.hosted.RuntimeReflection;
+import org.reflections.Reflections;
+import org.reflections.scanners.Scanners;
+
+import java.lang.reflect.Constructor;
+import java.lang.reflect.Field;
+import java.lang.reflect.Method;
+import java.util.Set;
+
+@SuppressWarnings("unused")
+public class RuntimeReflectionRegistrationFeature implements Feature {
+    private static final String[] SKIP_CLASS_NAMES = {
+            "oracle.dbtools.util.Closeables",
+    };
+
+    private static void register(String packageName, boolean includeSubPackages, ClassLoader classLoader) {
+        Reflections reflections = new Reflections(packageName);
+        Set<String> allClassNames = reflections.getAll(Scanners.SubTypes);
+        // allClassNames contains also inner classes
+        for (String className : allClassNames) {
+            if (className.startsWith((packageName))) {
+                if (includeSubPackages || (!className.substring(packageName.length() + 1).contains("."))) {
+                    if (validClass(className)) {
+                        registerClass(className, classLoader);
+                    }
+                }
+            }
+        }
+    }
+
+    private static boolean validClass(String className) {
+        for (String skipClassName : SKIP_CLASS_NAMES) {
+            if (className.startsWith(skipClassName)) {
+                return false;
+            }
+        }
+        return true;
+    }
+
+    private static void registerClass(String className, ClassLoader classLoader) {
+        try {
+            Class<?> clazz = Class.forName(className, false, classLoader);
+            // calling getClass() on a clazz throws an Exception when not found on the classpath
+            RuntimeReflection.register(clazz.getClass());
+            for (Constructor<?> constructor : clazz.getDeclaredConstructors()) {
+                RuntimeReflection.register(constructor);
+            }
+            for (Method method : clazz.getDeclaredMethods()) {
+                RuntimeReflection.register((method));
+            }
+            for (Field field : clazz.getDeclaredFields()) {
+                RuntimeReflection.register(field);
+            }
+        } catch (Throwable t) {
+            // ignore
+        }
+    }
+
+    public void beforeAnalysis(BeforeAnalysisAccess access) {
+        ClassLoader classLoader = access.getApplicationClassLoader();
+        // register all classes in a package
+        register("oracle.dbtools.app", true, classLoader);
+        register("oracle.dbtools.arbori", true, classLoader);
+        register("oracle.dbtools.parser", true, classLoader);
+        register("oracle.dbtools.raptor", false, classLoader);
+        register("oracle.dbtools.util", true, classLoader);
+    }
+}

standalone/pom.xml

@@ -1,12 +1,13 @@
 package com.trivadis.plsql.formatter;
 
 import com.oracle.truffle.js.scriptengine.GraalJSScriptEngine;
+import oracle.dbtools.arbori.Program;
 import org.graalvm.polyglot.Context;
+import org.graalvm.polyglot.HostAccess;
 
 import javax.script.*;
 import java.io.*;
 import java.net.URL;
-import java.util.function.Predicate;
 import java.util.logging.LogManager;
 
 public class TvdFormat {
@@ -16,8 +17,8 @@ public class TvdFormat {
     TvdFormat() {
         scriptEngine = GraalJSScriptEngine.create(null,
                 Context.newBuilder("js")
-                        .option("js.nashorn-compat", "true")
-                        .allowAllAccess(true));
+                        .allowHostAccess(HostAccess.ALL)
+                        .allowHostClassLookup(s -> true));
         ctx = new ScriptRunnerContext();
         ctx.setOutputStream(System.out);
         scriptEngine.getContext().setAttribute("ctx", ctx, ScriptContext.ENGINE_SCOPE);
@@ -35,9 +36,33 @@ public void run(String[] arguments) throws IOException, ScriptException {
     }
 
     public static void main(String[] args) throws IOException, ScriptException {
+        // configure logging
         LogManager.getLogManager().reset();
+        String loggingConfFile = System.getenv("TVDFORMAT_LOGGING_CONF_FILE");
+        if (loggingConfFile != null) {
+            // enable logging according java.util.logging configuration file
+            try {
+                LogManager.getLogManager().readConfiguration(new FileInputStream(loggingConfFile));
+            } catch (FileNotFoundException e) {
+                System.out.println("\nWarning: The file '" + loggingConfFile +
+                        "' does not exist. Please update the environment variable TVDFORMAT_LOGGING_CONF_FILE.\n");
+            }
+        }
+        // enable Arbori program debug
+        String debug = System.getenv("TVDFORMAT_DEBUG");
+        if (debug != null && debug.trim().equalsIgnoreCase("true")) {
+            Program.debug = true;
+        }
+        // enable Arbori program timing
+        String timing = System.getenv("TVDFORMAT_TIMING");
+        if (timing != null && timing.trim().equalsIgnoreCase("true")) {
+            Program.timing = true;
+        }
+        // amend usage help in format.js for standalone tvdformat
         System.setProperty("tvdformat.standalone", "true");
+        // format.js is compiled at runtime with a GraalVM JDK but interpreted with other JDKs
         System.setProperty("polyglot.engine.WarnInterpreterOnly", "false");
+        // run formatter with command line parameters
         TvdFormat formatter = new TvdFormat();
         formatter.run(args);
     }

standalone/src/main/java/com/trivadis/plsql/formatter/RuntimeReflectionRegistrationFeature.java

@@ -0,0 +1,4 @@
+[
+  [],
+  ["java.util.function.Predicate"]
+]