changeset 9771:c8ba58405e6b

ework -XX:+TraceModules for the unified logging framework, changed to -Xlog:modules.
author rprotacio
date Tue, 08 Dec 2015 10:45:38 -0500
parents 1bd1e18ccdb0
children 34b06d7ab75a
files src/share/vm/classfile/moduleEntry.cpp src/share/vm/classfile/modules.cpp src/share/vm/logging/logTag.hpp src/share/vm/oops/instanceKlass.cpp src/share/vm/runtime/globals.hpp test/runtime/logging/ModulesTest.java
diffstat 6 files changed, 139 insertions(+), 110 deletions(-) [+]
line wrap: on
line diff
--- a/src/share/vm/classfile/moduleEntry.cpp	Thu Dec 03 03:55:20 2015 -0800
+++ b/src/share/vm/classfile/moduleEntry.cpp	Tue Dec 08 10:45:38 2015 -0500
@@ -26,6 +26,7 @@
 #include "classfile/classLoaderData.hpp"
 #include "classfile/javaClasses.hpp"
 #include "classfile/moduleEntry.hpp"
+#include "logging/log.hpp"
 #include "memory/resourceArea.hpp"
 #include "oops/symbol.hpp"
 #include "prims/jni.h"
@@ -135,11 +136,9 @@
       // read next before freeing.
       m = m->next();
 
-      if (TraceModules) {
-        ResourceMark rm;
-        tty->print_cr("[ModuleEntryTable: deleting module: %s]", to_remove->name() != NULL ?
-                      to_remove->name()->as_C_string() : UNNAMED_MODULE);
-      }
+      ResourceMark rm;
+      log_debug(modules)("ModuleEntryTable: deleting module: %s", to_remove->name() != NULL ?
+                         to_remove->name()->as_C_string() : UNNAMED_MODULE);
 
       // Clean out the C heap allocated reads list first before freeing the entry
       to_remove->delete_reads();
--- a/src/share/vm/classfile/modules.cpp	Thu Dec 03 03:55:20 2015 -0800
+++ b/src/share/vm/classfile/modules.cpp	Tue Dec 08 10:45:38 2015 -0500
@@ -34,6 +34,7 @@
 #include "classfile/stringTable.hpp"
 #include "classfile/symbolTable.hpp"
 #include "classfile/vmSymbols.hpp"
+#include "logging/log.hpp"
 #include "oops/instanceKlass.hpp"
 #include "oops/objArrayKlass.hpp"
 #include "oops/objArrayOop.inline.hpp"
@@ -297,17 +298,16 @@
     ModuleEntryTable::finalize_javabase(jlrM_handle, version_symbol, location_symbol);
   }
 
-  if (TraceModules) {
-    tty->print("[define_javabase_module(): Definition of module: java.base, version: %s, location: %s, ",
-               module_version != NULL ? module_version : "NULL",
-               module_location != NULL ? module_location : "NULL");
-    tty->print_cr("package #: %d]", pkg_list->length());
+  log_debug(modules)("define_javabase_module(): Definition of module: java.base,"
+                     " version: %s, location: %s, package #: %d",
+                     module_version != NULL ? module_version : "NULL",
+                     module_location != NULL ? module_location : "NULL",
+                     pkg_list->length());
 
-    // packages defined to java.base
-    for (int x = 0; x < pkg_list->length(); x++) {
-      tty->print_cr("[define_javabase_module(): creation of package %s for module java.base]",
-                     (pkg_list->at(x))->as_C_string());
-    }
+  // packages defined to java.base
+  for (int x = 0; x < pkg_list->length(); x++) {
+    log_trace(modules)("define_javabase_module(): creation of package %s for module java.base",
+                       (pkg_list->at(x))->as_C_string());
   }
 
   // Patch any previously loaded classes' module field with java.base's jlr.Module.
@@ -479,15 +479,16 @@
                       pkg_list->at(dupl_pkg_index)->as_C_string(), module_name));
   }
 
-  if (TraceModules) {
-    tty->print("[define_module(): creation of module: %s, version: %s, location: %s, ",
-      module_name, module_version != NULL ? module_version : "NULL",
-      module_location != NULL ? module_location : "NULL");
-    loader_data->print_value();
-    tty->print_cr(", package #: %d]", pkg_list->length());
+  if (log_is_enabled(Debug, modules)) {
+    outputStream* logst = LogHandle(modules)::debug_stream();
+    logst->print("define_module(): creation of module: %s, version: %s, location: %s, ",
+                 module_name, module_version != NULL ? module_version : "NULL",
+                 module_location != NULL ? module_location : "NULL");
+    loader_data->print_value_on(logst);
+    logst->print_cr(", package #: %d", pkg_list->length());
     for (int y = 0; y < pkg_list->length(); y++) {
-      tty->print_cr("[define_module(): creation of package %s for module %s]",
-                    (pkg_list->at(y))->as_C_string(), module_name);
+      log_trace(modules)("define_module(): creation of package %s for module %s",
+                         (pkg_list->at(y))->as_C_string(), module_name);
     }
   }
 
@@ -529,9 +530,7 @@
   }
   Handle h_loader = Handle(THREAD, loader);
 
-  if (TraceModules) {
-    tty->print_cr("[set_bootloader_unnamed_module(): recording unnamed module for boot loader]");
-  }
+  log_debug(modules)("set_bootloader_unnamed_module(): recording unnamed module for boot loader");
 
   // Ensure the boot loader's PackageEntryTable has been created
   ModuleEntryTable* module_table = get_module_entry_table(h_loader, CHECK);
@@ -576,9 +575,8 @@
   }
 
   PackageEntry *package_entry = get_package_entry(from_module_entry, package, CHECK);
-
+  ResourceMark rm;
   if (package_entry == NULL) {
-    ResourceMark rm;
     const char *package_name = java_lang_String::as_utf8_string(JNIHandles::resolve_non_null(package));
     THROW_MSG(vmSymbols::java_lang_IllegalArgumentException(),
               err_msg("Package %s not found in from_module %s",
@@ -586,7 +584,6 @@
                       from_module_entry->name()->as_C_string()));
   }
   if (package_entry->module() != from_module_entry) {
-    ResourceMark rm;
     THROW_MSG(vmSymbols::java_lang_IllegalArgumentException(),
               err_msg("Package: %s found in module %s, not in from_module: %s",
                       package_entry->name()->as_C_string(),
@@ -594,15 +591,12 @@
                       from_module_entry->name()->as_C_string()));
   }
 
-  if (TraceModules) {
-    ResourceMark rm;
-    tty->print_cr("[add_module_exports(): package %s in module %s is exported to module %s]",
-                  package_entry->name()->as_C_string(),
-                  from_module_entry->name()->as_C_string(),
-                  to_module_entry == NULL ? "NULL" :
-                    to_module_entry->is_named() ?
-                      to_module_entry->name()->as_C_string() : UNNAMED_MODULE);
-  }
+  log_debug(modules)("add_module_exports(): package %s in module %s is exported to module %s",
+                     package_entry->name()->as_C_string(),
+                     from_module_entry->name()->as_C_string(),
+                     to_module_entry == NULL ? "NULL" :
+                      to_module_entry->is_named() ?
+                        to_module_entry->name()->as_C_string() : UNNAMED_MODULE);
 
   // If this is a qualified export, make sure the entry has not already been exported
   // unqualifiedly.
@@ -654,13 +648,13 @@
     to_module_entry = NULL;
   }
 
-  if (TraceModules) {
-    ResourceMark rm;
-    tty->print_cr("[add_reads_module(): Adding read from module %s to module %s]",
-      from_module_entry->is_named() ? from_module_entry->name()->as_C_string() : UNNAMED_MODULE,
-      to_module_entry == NULL ? "all unnamed" :
-        (to_module_entry->is_named() ? to_module_entry->name()->as_C_string() : UNNAMED_MODULE));
-  }
+  ResourceMark rm;
+  log_debug(modules)("add_reads_module(): Adding read from module %s to module %s",
+                     from_module_entry->is_named() ?
+                     from_module_entry->name()->as_C_string() : UNNAMED_MODULE,
+                      to_module_entry == NULL ? "all unnamed" :
+                        (to_module_entry->is_named() ?
+                          to_module_entry->name()->as_C_string() : UNNAMED_MODULE));
 
   // if modules are the same or if from_module is unnamed then no need to add the read.
   if (from_module_entry != to_module_entry && from_module_entry->is_named()) {
@@ -693,18 +687,16 @@
                "target_module is invalid", JNI_FALSE);
   }
 
-  if (TraceModules) {
-    ResourceMark rm;
-    tty->print_cr("[can_read_module(): module %s trying to read module %s, allowed = %s",
-      asking_module_entry->is_named() ?
-        asking_module_entry->name()->as_C_string() : UNNAMED_MODULE,
-      target_module_entry->is_named() ?
-        target_module_entry->name()->as_C_string() : UNNAMED_MODULE,
-      BOOL_TO_STR(asking_module_entry == target_module_entry ||
-                  (asking_module_entry->can_read_unnamed() &&
-                    !target_module_entry->is_named()) ||
-                  asking_module_entry->can_read(target_module_entry)));
-  }
+  ResourceMark rm;
+  log_debug(modules)("can_read_module(): module %s trying to read module %s, allowed = %s",
+                     asking_module_entry->is_named() ?
+                       asking_module_entry->name()->as_C_string() : UNNAMED_MODULE,
+                     target_module_entry->is_named() ?
+                       target_module_entry->name()->as_C_string() : UNNAMED_MODULE,
+                     BOOL_TO_STR(asking_module_entry == target_module_entry ||
+                                 (asking_module_entry->can_read_unnamed() &&
+                                  !target_module_entry->is_named()) ||
+                                  asking_module_entry->can_read(target_module_entry)));
 
   // Return true if:
   // 1. the modules are the same, or
@@ -746,9 +738,9 @@
   }
 
   PackageEntry *package_entry = get_package_entry(from_module_entry, package,
-    CHECK_false);
+                                                  CHECK_false);
+  ResourceMark rm;
   if (package_entry == NULL) {
-    ResourceMark rm;
     THROW_MSG_(vmSymbols::java_lang_IllegalArgumentException(),
                err_msg("Package not found in from_module: %s",
                        from_module_entry->is_named() ?
@@ -756,7 +748,6 @@
                JNI_FALSE);
   }
   if (package_entry->module() != from_module_entry) {
-    ResourceMark rm;
     THROW_MSG_(vmSymbols::java_lang_IllegalArgumentException(),
                err_msg("Package: %s found in module %s, not in from_module: %s",
                        package_entry->name()->as_C_string(),
@@ -767,19 +758,17 @@
                JNI_FALSE);
   }
 
-  if (TraceModules) {
-    ResourceMark rm;
-    tty->print_cr("[is_exported_to_module: package %s from module %s checking if exported to module %s, exported? = %s",
-                  package_entry->name()->as_C_string(),
-                  from_module_entry->is_named() ?
-                    from_module_entry->name()->as_C_string() : UNNAMED_MODULE,
-                  to_module_entry->is_named() ?
-                    to_module_entry->name()->as_C_string() : UNNAMED_MODULE,
-                  BOOL_TO_STR(!from_module_entry->is_named() ||
-                    package_entry->is_unqual_exported() ||
-                    from_module_entry == to_module_entry ||
-                    package_entry->is_qexported_to(to_module_entry)));
-  }
+  log_debug(modules)("is_exported_to_module: package %s from module %s checking"
+                     " if exported to module %s, exported? = %s",
+                     package_entry->name()->as_C_string(),
+                     from_module_entry->is_named() ?
+                       from_module_entry->name()->as_C_string() : UNNAMED_MODULE,
+                     to_module_entry->is_named() ?
+                       to_module_entry->name()->as_C_string() : UNNAMED_MODULE,
+                     BOOL_TO_STR(!from_module_entry->is_named() ||
+                       package_entry->is_unqual_exported() ||
+                       from_module_entry == to_module_entry ||
+                       package_entry->is_qexported_to(to_module_entry)));
 
   // Return true if:
   // 1. from_module is unnamed because unnamed modules export all their packages (by default), or
@@ -803,9 +792,7 @@
   }
   oop mirror = JNIHandles::resolve_non_null(clazz);
   if (mirror == NULL) {
-    if (TraceModules) {
-      tty->print_cr("[get_module(): no mirror, returning NULL]");
-    }
+    log_debug(modules)("get_module(): no mirror, returning NULL");
     return NULL;
   }
   if (!java_lang_Class::is_instance(mirror)) {
@@ -838,19 +825,20 @@
     }
   }
 
-  if (TraceModules) {
+  if (log_is_enabled(Debug, modules)) {
     ResourceMark rm;
+    outputStream* logst = LogHandle(modules)::debug_stream();
     oop module_name = java_lang_reflect_Module::name(module);
     if (module_name != NULL) {
-      tty->print("[get_module(): module ");
+      logst->print("get_module(): module ");
       java_lang_String::print(module_name, tty);
     } else {
-      tty->print("[get_module(): Unamed Module");
+      logst->print("get_module(): Unamed Module");
     }
     if (klass != NULL) {
-      tty->print_cr(" for class %s]", klass->external_name());
+      logst->print_cr(" for class %s", klass->external_name());
     } else {
-      tty->print_cr(" for primitive class]");
+      logst->print_cr(" for primitive class");
     }
   }
 
@@ -904,11 +892,8 @@
               err_msg("Invalid package name: %s", package_name));
   }
 
-  if (TraceModules) {
-    ResourceMark rm;
-    tty->print_cr("[add_module_package(): Adding package %s to module %s]",
-                  package_name, module_entry->name()->as_C_string());
-  }
+  log_debug(modules)("add_module_package(): Adding package %s to module %s",
+                     package_name, module_entry->name()->as_C_string());
 
   TempNewSymbol pkg_symbol = SymbolTable::new_symbol(package_name, CHECK);
   PackageEntryTable* package_table = module_entry->loader()->packages();
@@ -955,8 +940,8 @@
   }
 
   PackageEntry *package_entry = get_package_entry(module_entry, package, CHECK);
+  ResourceMark rm;
   if (package_entry == NULL) {
-    ResourceMark rm;
     const char *package_name = java_lang_String::as_utf8_string(JNIHandles::resolve_non_null(package));
     THROW_MSG(vmSymbols::java_lang_IllegalArgumentException(),
               err_msg("Package %s not found in module %s",
@@ -964,7 +949,6 @@
                       module_entry->name()->as_C_string()));
   }
   if (package_entry->module() != module_entry) {
-    ResourceMark rm;
     THROW_MSG(vmSymbols::java_lang_IllegalArgumentException(),
               err_msg("Package: %s found in module %s, not in module: %s",
                       package_entry->name()->as_C_string(),
@@ -972,12 +956,10 @@
                       module_entry->name()->as_C_string()));
   }
 
-  if (TraceModules) {
-    ResourceMark rm;
-    tty->print_cr("[add_module_exports_to_all_unnamed(): package %s in module %s is exported to all unnamed modules]",
-                  package_entry->name()->as_C_string(),
-                  module_entry->name()->as_C_string());
-  }
+  log_debug(modules)("add_module_exports_to_all_unnamed(): package %s in module"
+                     " %s is exported to all unnamed modules",
+                     package_entry->name()->as_C_string(),
+                     module_entry->name()->as_C_string());
 
   // Mark package as exported to all unnamed modules, unless already
   // unqualifiedly exported.
--- a/src/share/vm/logging/logTag.hpp	Thu Dec 03 03:55:20 2015 -0800
+++ b/src/share/vm/logging/logTag.hpp	Tue Dec 08 10:45:38 2015 -0500
@@ -33,6 +33,7 @@
 #define LOG_TAG_LIST \
   LOG_TAG(defaultmethods) \
   LOG_TAG(logging) \
+  LOG_TAG(modules) \
   LOG_TAG(safepoint)
 
 #define PREFIX_LOG_TAG(T) (LogTag::T)
--- a/src/share/vm/oops/instanceKlass.cpp	Thu Dec 03 03:55:20 2015 -0800
+++ b/src/share/vm/oops/instanceKlass.cpp	Tue Dec 08 10:45:38 2015 -0500
@@ -33,6 +33,7 @@
 #include "interpreter/oopMapCache.hpp"
 #include "interpreter/rewriter.hpp"
 #include "jvmtifiles/jvmti.h"
+#include "logging/log.hpp"
 #include "memory/heapInspection.hpp"
 #include "memory/iterator.inline.hpp"
 #include "memory/metadataFactory.hpp"
@@ -2405,23 +2406,21 @@
              name->as_C_string(), loader->loader_name());
     }
 
-    if (TraceModules) {
+    if (log_is_enabled(Debug, modules)) {
       ResourceMark rm;
       ModuleEntry* m = _package_entry->module();
-      tty->print_cr("[Setting package: class: %s, package: %s, loader: %s, module: %s]",
-                    external_name(),
-                    pkg_name->as_C_string(),
-                    loader->loader_name(),
-                    (m->is_named() ? m->name()->as_C_string() : UNNAMED_MODULE));
+      log_trace(modules)("Setting package: class: %s, package: %s, loader: %s, module: %s",
+                         external_name(),
+                         pkg_name->as_C_string(),
+                         loader->loader_name(),
+                         (m->is_named() ? m->name()->as_C_string() : UNNAMED_MODULE));
     }
   } else {
-    if (TraceModules) {
-      ResourceMark rm;
-      tty->print_cr("[Setting package: class: %s, package: unnamed, loader: %s, module: %s]",
-                    external_name(),
-                    (loader != NULL) ? loader->loader_name() : "NULL",
-                    UNNAMED_MODULE);
-    }
+    ResourceMark rm;
+    log_trace(modules)("Setting package: class: %s, package: unnamed, loader: %s, module: %s",
+                       external_name(),
+                       (loader != NULL) ? loader->loader_name() : "NULL",
+                       UNNAMED_MODULE);
   }
 }
 
--- a/src/share/vm/runtime/globals.hpp	Thu Dec 03 03:55:20 2015 -0800
+++ b/src/share/vm/runtime/globals.hpp	Tue Dec 08 10:45:38 2015 -0500
@@ -2486,9 +2486,6 @@
   develop(bool, TraceClassLoaderData, false,                                \
           "Trace class loader loader_data lifetime")                        \
                                                                             \
-  develop(bool, TraceModules, false,                                        \
-          "Trace module creation and lifetime")                             \
-                                                                            \
   product(size_t, InitialBootClassLoaderMetaspaceSize,                      \
           NOT_LP64(2200*K) LP64_ONLY(4*M),                                  \
           "Initial size of the boot class loader data metaspace")           \
--- /dev/null	Thu Jan 01 00:00:00 1970 +0000
+++ b/test/runtime/logging/ModulesTest.java	Tue Dec 08 10:45:38 2015 -0500
@@ -0,0 +1,51 @@
+/*
+ * Copyright (c) 2015, Oracle and/or its affiliates. All rights reserved.
+ * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
+ *
+ * This code is free software; you can redistribute it and/or modify it
+ * under the terms of the GNU General Public License version 2 only, as
+ * published by the Free Software Foundation.
+ *
+ * This code is distributed in the hope that it will be useful, but WITHOUT
+ * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
+ * FITNESS FOR A PARTICULAR PURPOSE.    See the GNU General Public License
+ * version 2 for more details (a copy is included in the LICENSE file that
+ * accompanied this code).
+ *
+ * You should have received a copy of the GNU General Public License version
+ * 2 along with this work; if not, write to the Free Software Foundation,
+ * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
+ *
+ * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
+ * or visit www.oracle.com if you need additional information or have any
+ * questions.
+ */
+
+/*
+ * @test
+ * @summary modules=debug should have logging from statements in the code
+ * @library /testlibrary
+ * @modules java.base/sun.misc
+ *          java.management
+ * @run main ModulesTest
+ */
+
+import jdk.test.lib.*;
+
+public class ModulesTest {
+    public static void main(String[] args) throws Exception {
+        ProcessBuilder pb = ProcessTools.createJavaProcessBuilder(
+            "-Xlog:modules=trace", "-version");
+        OutputAnalyzer output = new OutputAnalyzer(pb.start());
+        output.shouldContain("define_javabase_module(): Definition of module:");
+        output.shouldContain("define_javabase_module(): creation of package");
+        output.shouldContain("define_module(): creation of module");
+        output.shouldContain("define_module(): creation of package");
+        output.shouldContain("set_bootloader_unnamed_module(): recording unnamed");
+        output.shouldContain("add_module_exports(): package");
+        output.shouldContain("add_reads_module(): Adding read from module");
+        output.shouldContain("Setting package: class:");
+        output.shouldHaveExitValue(0);
+    }
+}
+