[GR-14450] Work around autoloading bugs

PullRequest: truffleruby/698

Author: chrisseaton

CHANGELOG.md

@@ -11,6 +11,7 @@ Bug fixes:
 * Combining multiple `**` arguments containing duplicate keys produced
   an incorrect hash. This has now been fixed (#1469).
 * `IO#read_nonblock` now returns the passed buffer object, if one is supplied.
+* Worked out autoloading issue (#1614).
 
 New features:
 

lib/mri/net/http.rb

@@ -22,7 +22,13 @@
 
 require_relative 'protocol'
 require 'uri'
-autoload :OpenSSL, 'openssl'
+
+if RUBY_ENGINE == 'truffleruby'
+  # See tagged specs around autoload
+  require 'openssl'
+else
+  autoload :OpenSSL, 'openssl'
+end
 
 module Net   #:nodoc:
 

src/main/java/org/truffleruby/core/module/ModuleFields.java

@@ -320,6 +320,11 @@ public RubyConstant setConstant(RubyContext context, Node currentNode, String na
     @TruffleBoundary
     public void setAutoloadConstant(RubyContext context, Node currentNode, String name, DynamicObject filename) {
         assert RubyGuards.isRubyString(filename);
+        if (context.getOptions().LOG_AUTOLOAD) {
+            RubyLanguage.LOGGER.info(() -> String.format("%s: setting up autoload %s::%s with %s",
+                    context.fileLine(context.getCallStack().getTopMostUserSourceSection()),
+                    getName(), name, filename));
+        }
         setConstantInternal(context, currentNode, name, filename, true);
     }
 

src/main/java/org/truffleruby/core/module/ModuleNodes.java

@@ -879,6 +879,7 @@ public RubyNode coerceToBoolean(RubyNode inherit) {
         }
 
         // Symbol
+
         @Specialization(guards = { "inherit", "isRubySymbol(name)" })
         public Object getConstant(DynamicObject module, DynamicObject name, boolean inherit) {
             return getConstant(module, Layouts.SYMBOL.getString(name));
@@ -890,6 +891,7 @@ public Object getConstantNoInherit(DynamicObject module, DynamicObject name, boo
         }
 
         // String
+
         @Specialization(guards = { "inherit", "isRubyString(name)", "equalNode.execute(rope(name), cachedRope)", "!scoped" }, limit = "getLimit()")
         public Object getConstantStringCached(DynamicObject module, DynamicObject name, boolean inherit,
                 @Cached("privatizeRope(name)") Rope cachedRope,

src/main/java/org/truffleruby/language/constants/GetConstantNode.java

@@ -17,6 +17,7 @@
 import com.oracle.truffle.api.profiles.ConditionProfile;
 
 import org.truffleruby.Layouts;
+import org.truffleruby.RubyLanguage;
 import org.truffleruby.core.module.ModuleFields;
 import org.truffleruby.core.module.ModuleOperations;
 import org.truffleruby.core.string.StringOperations;
@@ -76,10 +77,22 @@ protected Object autoloadConstant(LexicalScope lexicalScope, DynamicObject modul
             // We found an autoload constant while we are already require-ing the autoload file,
             // consider it missing to avoid circular require warnings and calling #require twice.
             // For instance, autoload :RbConfig, "rbconfig"; require "rbconfig" causes this.
+            if (getContext().getOptions().LOG_AUTOLOAD) {
+                RubyLanguage.LOGGER.info(() -> String.format("%s: %s::%s is being treated as missing while loading %s",
+                        getContext().fileLine(getContext().getCallStack().getTopMostUserSourceSection()),
+                        Layouts.MODULE.getFields(module).getName(), name, expandedPath));
+            }
             return doMissingConstant(module, name, getSymbol(name));
         }
 
         autoloadConstant.startAutoLoad();
+
+        if (getContext().getOptions().LOG_AUTOLOAD) {
+            RubyLanguage.LOGGER.info(() -> String.format("%s: autoloading %s::%s with %s",
+                    getContext().fileLine(getContext().getCallStack().getTopMostUserSourceSection()),
+                    Layouts.MODULE.getFields(autoloadConstantModule).getName(), name, autoloadConstant.getAutoloadPath()));
+        }
+
         try {
 
             // We need to notify cached lookup that we are autoloading the constant, as constant

src/main/java/org/truffleruby/options/Options.java

@@ -76,6 +76,7 @@ public class Options {
     public final String[] CEXTS_LIBRARY_REMAP;
     public final boolean OPTIONS_LOG;
     public final boolean LOG_LOAD;
+    public final boolean LOG_AUTOLOAD;
     public final boolean LOG_FEATURE_LOCATION;
     public final boolean CEXTS_LOG_LOAD;
     public final boolean CEXTS_LOG_WARNINGS;
@@ -208,6 +209,7 @@ public Options(Env env, OptionValues options) {
         CEXTS_LIBRARY_REMAP = options.get(OptionsCatalog.CEXTS_LIBRARY_REMAP_KEY);
         OPTIONS_LOG = options.get(OptionsCatalog.OPTIONS_LOG_KEY);
         LOG_LOAD = options.get(OptionsCatalog.LOG_LOAD_KEY);
+        LOG_AUTOLOAD = options.get(OptionsCatalog.LOG_AUTOLOAD_KEY);
         LOG_FEATURE_LOCATION = options.get(OptionsCatalog.LOG_FEATURE_LOCATION_KEY);
         CEXTS_LOG_LOAD = options.get(OptionsCatalog.CEXTS_LOG_LOAD_KEY);
         CEXTS_LOG_WARNINGS = options.get(OptionsCatalog.CEXTS_LOG_WARNINGS_KEY);
@@ -392,6 +394,8 @@ public Object fromDescriptor(OptionDescriptor descriptor) {
                 return OPTIONS_LOG;
             case "ruby.log.load":
                 return LOG_LOAD;
+            case "ruby.log.autoload":
+                return LOG_AUTOLOAD;
             case "ruby.log.feature_location":
                 return LOG_FEATURE_LOCATION;
             case "ruby.cexts.log.load":

src/options.yml

@@ -72,6 +72,7 @@ EXPERT:
 
     # Tracing loading of Ruby files and C extensions
     LOG_LOAD: [log.load, boolean, false, Log loading files]
+    LOG_AUTOLOAD: [log.autoload, boolean, false, Log autoloading]
     LOG_FEATURE_LOCATION: [log.feature_location, boolean, false, Log the process of finding features]
     CEXTS_LOG_LOAD: [cexts.log.load, boolean, false, Log loading of cexts]
     CEXTS_LOG_WARNINGS: [cexts.log.warnings, boolean, false, Log cexts warnings]

src/shared/java/org/truffleruby/shared/options/OptionsCatalog.java

@@ -71,6 +71,7 @@ public class OptionsCatalog {
     public static final OptionKey<String[]> CEXTS_LIBRARY_REMAP_KEY = new OptionKey<>(new String[]{}, StringArrayOptionType.INSTANCE);
     public static final OptionKey<Boolean> OPTIONS_LOG_KEY = new OptionKey<>(false);
     public static final OptionKey<Boolean> LOG_LOAD_KEY = new OptionKey<>(false);
+    public static final OptionKey<Boolean> LOG_AUTOLOAD_KEY = new OptionKey<>(false);
     public static final OptionKey<Boolean> LOG_FEATURE_LOCATION_KEY = new OptionKey<>(false);
     public static final OptionKey<Boolean> CEXTS_LOG_LOAD_KEY = new OptionKey<>(false);
     public static final OptionKey<Boolean> CEXTS_LOG_WARNINGS_KEY = new OptionKey<>(false);
@@ -502,6 +503,13 @@ public class OptionsCatalog {
             .stability(OptionStability.EXPERIMENTAL)
             .build();
 
+    public static final OptionDescriptor LOG_AUTOLOAD = OptionDescriptor
+            .newBuilder(LOG_AUTOLOAD_KEY, "ruby.log.autoload")
+            .help("Log autoloading")
+            .category(OptionCategory.EXPERT)
+            .stability(OptionStability.EXPERIMENTAL)
+            .build();
+
     public static final OptionDescriptor LOG_FEATURE_LOCATION = OptionDescriptor
             .newBuilder(LOG_FEATURE_LOCATION_KEY, "ruby.log.feature_location")
             .help("Log the process of finding features")
@@ -1164,6 +1172,8 @@ public static OptionDescriptor fromName(String name) {
                 return OPTIONS_LOG;
             case "ruby.log.load":
                 return LOG_LOAD;
+            case "ruby.log.autoload":
+                return LOG_AUTOLOAD;
             case "ruby.log.feature_location":
                 return LOG_FEATURE_LOCATION;
             case "ruby.cexts.log.load":
@@ -1409,6 +1419,7 @@ public static OptionDescriptor[] allDescriptors() {
             LAZY_TRANSLATION_LOG,
             LAZY_TRANSLATION_USER,
             LOAD_PATHS,
+            LOG_AUTOLOAD,
             LOG_FEATURE_LOCATION,
             LOG_LOAD,
             METHOD_LOOKUP_CACHE,