Add --basic-ops-log-rewrite to debug why inlined operations are rewritten

Author: eregon

src/main/java/org/truffleruby/core/inlined/InlinedOperationNode.java

@@ -10,10 +10,13 @@
 package org.truffleruby.core.inlined;
 
 import com.oracle.truffle.api.Assumption;
+import com.oracle.truffle.api.CompilerDirectives;
 import com.oracle.truffle.api.frame.VirtualFrame;
 
 import org.truffleruby.RubyLanguage;
+import org.truffleruby.core.array.ArrayUtils;
 import org.truffleruby.language.dispatch.RubyCallNodeParameters;
+import org.truffleruby.language.methods.TranslateExceptionNode;
 
 public abstract class InlinedOperationNode extends InlinedReplaceableNode {
 
@@ -30,6 +33,12 @@ protected Object rewriteAndCall(VirtualFrame frame, Object receiver, Object... a
 
     protected Object rewriteAndCallWithBlock(VirtualFrame frame, Object receiver, Object block,
             Object... arguments) {
+        CompilerDirectives.transferToInterpreterAndInvalidate();
+        if (getContext().getOptions().BASICOPS_LOG_REWRITE) {
+            RubyLanguage.LOGGER.info(
+                    "Rewrite " + this + " with arguments" + TranslateExceptionNode
+                            .argumentsToString(new StringBuilder(), ArrayUtils.unshift(arguments, receiver)));
+        }
         return rewriteToCallNode().executeWithArgumentsEvaluated(frame, receiver, block, arguments);
     }
 

src/main/java/org/truffleruby/language/methods/TranslateExceptionNode.java

@@ -190,8 +190,15 @@ private RubyException translateUnsupportedSpecialization(RubyContext context,
         builder.append("TruffleRuby doesn't have a case for the ");
         builder.append(exception.getNode().getClass().getName());
         builder.append(" node with values of type");
+        argumentsToString(builder, exception.getSuppliedValues());
+        builder.append('\n');
+        appendJavaStackTrace(exception, builder);
+        String message = builder.toString().trim();
+        return context.getCoreExceptions().typeError(message, this, exception);
+    }
 
-        for (Object value : exception.getSuppliedValues()) {
+    public static StringBuilder argumentsToString(StringBuilder builder, Object[] arguments) {
+        for (Object value : arguments) {
             builder.append(" ");
 
             if (value == null) {
@@ -232,11 +239,7 @@ private RubyException translateUnsupportedSpecialization(RubyContext context,
                 builder.append(value.toString());
             }
         }
-
-        builder.append('\n');
-        appendJavaStackTrace(exception, builder);
-        String message = builder.toString().trim();
-        return context.getCoreExceptions().typeError(message, this, exception);
+        return builder;
     }
 
     @TruffleBoundary

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

@@ -161,6 +161,8 @@ public class Options {
     public final boolean ROPE_PRINT_INTERN_STATS;
     /** --cexts-to-native-stats=false */
     public final boolean CEXTS_TO_NATIVE_STATS;
+    /** --basic-ops-log-rewrite=false */
+    public final boolean BASICOPS_LOG_REWRITE;
     /** --array-small=3 */
     public final int ARRAY_SMALL;
     /** --cexts-marking-cache=100 */
@@ -270,6 +272,7 @@ public Options(Env env, OptionValues options, LanguageOptions languageOptions) {
         LOG_PENDING_INTERRUPTS = options.get(OptionsCatalog.LOG_PENDING_INTERRUPTS_KEY);
         ROPE_PRINT_INTERN_STATS = options.get(OptionsCatalog.ROPE_PRINT_INTERN_STATS_KEY);
         CEXTS_TO_NATIVE_STATS = options.get(OptionsCatalog.CEXTS_TO_NATIVE_STATS_KEY);
+        BASICOPS_LOG_REWRITE = options.get(OptionsCatalog.BASICOPS_LOG_REWRITE_KEY);
         ARRAY_SMALL = options.get(OptionsCatalog.ARRAY_SMALL_KEY);
         CEXTS_MARKING_CACHE = options.get(OptionsCatalog.CEXTS_MARKING_CACHE_KEY);
         GLOBAL_VARIABLE_MAX_INVALIDATIONS = options.get(OptionsCatalog.GLOBAL_VARIABLE_MAX_INVALIDATIONS_KEY);
@@ -431,6 +434,8 @@ public Object fromDescriptor(OptionDescriptor descriptor) {
                 return ROPE_PRINT_INTERN_STATS;
             case "ruby.cexts-to-native-stats":
                 return CEXTS_TO_NATIVE_STATS;
+            case "ruby.basic-ops-log-rewrite":
+                return BASICOPS_LOG_REWRITE;
             case "ruby.array-small":
                 return ARRAY_SMALL;
             case "ruby.cexts-marking-cache":

src/options.yml

@@ -180,6 +180,7 @@ INTERNAL: # Options for debugging the TruffleRuby implementation
 
     # Options to help debugging the implementation performance
     BASICOPS_INLINE: [basic-ops-inline, boolean, true, Inline basic operations (like Fixnum operators) in the AST without a call]
+    BASICOPS_LOG_REWRITE: [basic-ops-log-rewrite, boolean, false, Log the receiver and arguments when basic operations like Fixnum operators cannot be handled inline]
     PROFILE_ARGUMENTS: [profile-arguments, boolean, true, Profile the value and class of the receiver and arguments]
 
     # Inline cache sizes

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

@@ -105,6 +105,7 @@ public class OptionsCatalog {
     public static final OptionKey<Boolean> LAZY_TRANSLATION_CORE_KEY = new OptionKey<>(LAZY_CALLTARGETS_KEY.getDefaultValue());
     public static final OptionKey<Boolean> CHAOS_DATA_KEY = new OptionKey<>(false);
     public static final OptionKey<Boolean> BASICOPS_INLINE_KEY = new OptionKey<>(true);
+    public static final OptionKey<Boolean> BASICOPS_LOG_REWRITE_KEY = new OptionKey<>(false);
     public static final OptionKey<Boolean> PROFILE_ARGUMENTS_KEY = new OptionKey<>(true);
     public static final OptionKey<Integer> DEFAULT_CACHE_KEY = new OptionKey<>(8);
     public static final OptionKey<Integer> METHOD_LOOKUP_CACHE_KEY = new OptionKey<>(DEFAULT_CACHE_KEY.getDefaultValue());
@@ -756,6 +757,13 @@ public class OptionsCatalog {
             .stability(OptionStability.EXPERIMENTAL)
             .build();
 
+    public static final OptionDescriptor BASICOPS_LOG_REWRITE = OptionDescriptor
+            .newBuilder(BASICOPS_LOG_REWRITE_KEY, "ruby.basic-ops-log-rewrite")
+            .help("Log the receiver and arguments when basic operations like Fixnum operators cannot be handled inline")
+            .category(OptionCategory.INTERNAL)
+            .stability(OptionStability.EXPERIMENTAL)
+            .build();
+
     public static final OptionDescriptor PROFILE_ARGUMENTS = OptionDescriptor
             .newBuilder(PROFILE_ARGUMENTS_KEY, "ruby.profile-arguments")
             .help("Profile the value and class of the receiver and arguments")
@@ -1313,6 +1321,8 @@ public static OptionDescriptor fromName(String name) {
                 return CHAOS_DATA;
             case "ruby.basic-ops-inline":
                 return BASICOPS_INLINE;
+            case "ruby.basic-ops-log-rewrite":
+                return BASICOPS_LOG_REWRITE;
             case "ruby.profile-arguments":
                 return PROFILE_ARGUMENTS;
             case "ruby.default-cache":
@@ -1515,6 +1525,7 @@ public static OptionDescriptor[] allDescriptors() {
             LAZY_TRANSLATION_CORE,
             CHAOS_DATA,
             BASICOPS_INLINE,
+            BASICOPS_LOG_REWRITE,
             PROFILE_ARGUMENTS,
             DEFAULT_CACHE,
             METHOD_LOOKUP_CACHE,