Debugtypes

[adinn]

No description provided.

[adinn]

This PR implements issue #2986.

Note that the debug info model relies on the use of data_location attributes on class, array, interface and header info record types to ensure gdb translates oop references to memory addresses. There is a bug in printing of objects which employ data_location attributes in gdb releases 7.x, 8.x and 9.x. This means that attempts to print objects field by field fail with an internal error.

This problem has been fixed in gdb 10.1. I am currently negotiating with the Red Hat gdb team to try to get the relevant patch back-ported to gdb 9.x and 8.x. Meanwhile, anyone wanting to use this upgrade to the debuginfo feature on Linux will need to ensure that they employ gdb 10.

This also means that the debuginfo gate test probably needs to be updated so it is skipped when the gdb release is less that 10. Unless the machines used to run the gate tests can be configuerd to use gdb 10.

[adinn]

@olpaw I have fixed all the outstanding style issues and corrected the debuginfo script so that it only tests printing of objects field by field when gdb10+ is available. So, this PR is now complete and ready for review.

[adinn]

@olpaw I forgot to mention that this version works whether or not the build employs isolates.

[olpaw]

Hi @adinn looking forward to go through your PR!
ATM I'm still busy with the aftermath of merging serialization support.
I hope I will be able to have a look somewhere in the second half of next week.

[adinn]

@olpaw Thanks. There is no rush. I am officially on holiday for all of December (official return Jan 4th). However, I will be around up to Christmas week keeping tabs on a few things, the most important being this PR and the patch backport I requested from our gdb team. I'll do my best to respond to any feedback you can give in a timely fashion so this doesn't go cold and require you to effectively restart the review in January.

[olpaw]

Hi @adinn Unfortunately I was not able to look into your PR. Looking closer into serialization more & more work was/is needed to get serialization support into some form that will allow us to support all possible serialization usage patterns. I will be off from next week on till Jan 6th. Debuginfo will have to wait till then. Happy holidays & best wishes for the new year!

[adinn]

@olpaw Sure, no problem. Have a good holiday and new year!

[zakkak]

Great work @adinn :)

I have left a few minor comments

[adinn]

@olpaw Hi Paul, any chance of a review for this PR soon?
n.b. the failures in the gate checks don't appear to relate to the PR.

[olpaw]

Hi @adinn, I have a bit more backlog to go through this week but I should be able to take a look sometime next week.

[adinn]

Hi @olpaw. Great. Thanks for the update.

[olpaw]

Hi @adinn, I get a NPE when I build the native-image image with debuginfo on this PR. It only happens when I build with -O0.

graal/substratevm> mx native-image -g -O0 -jar svmbuild/vm/lib/graalvm/svm-driver.jar svmbuild/vm/bin/native-image.x 
[svmbuild/vm/bin/native-image.x:30713]    classlist:   2,031.39 ms,  0.96 GB
[svmbuild/vm/bin/native-image.x:30713]        (cap):     573.40 ms,  0.96 GB
[svmbuild/vm/bin/native-image.x:30713]        setup:   2,096.21 ms,  0.96 GB
[svmbuild/vm/bin/native-image.x:30713]     (clinit):     334.90 ms,  1.73 GB
[svmbuild/vm/bin/native-image.x:30713]   (typeflow):   7,818.12 ms,  1.73 GB
[svmbuild/vm/bin/native-image.x:30713]    (objects):   9,248.56 ms,  1.73 GB
[svmbuild/vm/bin/native-image.x:30713]   (features):     485.46 ms,  1.73 GB
[svmbuild/vm/bin/native-image.x:30713]     analysis:  18,440.54 ms,  1.73 GB
[svmbuild/vm/bin/native-image.x:30713]     universe:     699.39 ms,  1.73 GB
[svmbuild/vm/bin/native-image.x:30713]      (parse):   2,450.42 ms,  2.26 GB
[svmbuild/vm/bin/native-image.x:30713]    (compile):  11,985.25 ms,  3.19 GB
[svmbuild/vm/bin/native-image.x:30713]      compile:  15,374.42 ms,  3.19 GB
[svmbuild/vm/bin/native-image.x:30713]        image:   2,908.11 ms,  3.19 GB
Fatal error:com.oracle.svm.core.util.VMError$HostedError: java.lang.NullPointerException
	at com.oracle.svm.core.util.VMError.shouldNotReachHere(VMError.java:72)
	at com.oracle.svm.hosted.NativeImageGenerator.doRun(NativeImageGenerator.java:667)
	at com.oracle.svm.hosted.NativeImageGenerator.lambda$run$0(NativeImageGenerator.java:474)
	at java.base/java.util.concurrent.ForkJoinTask$AdaptedRunnableAction.exec(ForkJoinTask.java:1407)
	at java.base/java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:290)
	at java.base/java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1020)
	at java.base/java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1656)
	at java.base/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1594)
	at java.base/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:183)
Caused by: java.lang.NullPointerException
	at com.oracle.objectfile.debugentry.DebugInfoBase.lambda$installDebugInfo$5(DebugInfoBase.java:216)
	at com.oracle.svm.hosted.image.NativeImageDebugInfoProvider$NativeImageDebugCodeInfo.debugContext(NativeImageDebugInfoProvider.java:836)
	at com.oracle.objectfile.debugentry.DebugInfoBase.lambda$installDebugInfo$6(DebugInfoBase.java:195)
	at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:183)
	at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:195)
	at java.base/java.util.TreeMap$EntrySpliterator.forEachRemaining(TreeMap.java:2962)
	at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:484)
	at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:474)
	at java.base/java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:150)
	at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:173)
	at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)
	at java.base/java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:497)
	at com.oracle.objectfile.debugentry.DebugInfoBase.installDebugInfo(DebugInfoBase.java:195)
	at com.oracle.objectfile.elf.ELFObjectFile.installDebugInfo(ELFObjectFile.java:1203)
	at com.oracle.svm.hosted.image.NativeBootImage.build(NativeBootImage.java:455)
	at com.oracle.svm.hosted.NativeImageGenerator.doRun(NativeImageGenerator.java:656)
	... 7 more
Error: Image build request failed with exit status 1

[adinn]

Hmm, thanks for letting me know. I'll take a look and see what I can find.

[adinn]

@olpaw Hi Paul. I am confused by the error you got because it happens on line 216 where there is this code

214     ClassEntry classEntry = ensureClassEntry(className);
215     FileEntry fileEntry = ensureFileEntry(fileName, filePath, cachePath);
216     Range primaryRange = classEntry.makePrimaryRange(methodName, symbolName, paramSignature, returnTypeName, stringTable, fileEntry, lo, hi, primaryLine, modifiers, isDeoptTarget);

So, an NPE at that line can only imply that classEntry == null. However, ensureClassEntry never returns a null value:

private ClassEntry ensureClassEntry(String className) {
    /*
     * See if we already have an entry.
     */
    ClassEntry classEntry = primaryClassesIndex.get(className);
    if (classEntry == null) {
        TypeEntry typeEntry = typesIndex.get(className);
        assert (typeEntry != null && typeEntry.isClass());
        classEntry = (ClassEntry) typeEntry;
        primaryClasses.add(classEntry);
        primaryClassesIndex.put(className, classEntry);
    }
    assert (classEntry.getTypeName().equals(className));
    return classEntry;
}

So, this is a bit of an odd result. Perhaps you could check your build and also that you have the right code for the patch? Also, are you running with -J-ea -J-esa If all that passes then perhaps yo ucan give me th eful lcommand line and test code.

However, before doing that ... yes, wait, there's more!

I ran native-image on Hello.java with -O0 and got an assertion rather than an NPE. I rebased my PR over the latest upstream repo and it was still there. So, there is a bug but not the one you mentioned:

The problem I encountered was that with -O0 I end up seeing two compilation ranges for what is essentially the same source method. There are two distinct code ranges for code compiled from method

com.oracle.svm.jni.nativeapi.JNIObjectHandle
com.oracle.svm.jni.functions.JNIFunctions::NewStringUTF(com.oracle.svm.jni.nativeapi.JNIEnvironment,
                                                        org.graalvm.nativeimage.c.type.CCharPointer)

One of these code ranges appears to be a generated stub. It is associated with file com/oracle/svm/core/code/IsolateLeaveStub.java and its symbol name includes a numeric hash. The other is appears ot be a compield version of the original method. It is associated with file com/oracle/svm/jni/functions/JNIFunctions.java and it's symbol name is the standard 'package qualified method name with sig derived from arg types'. The assert happens because that the code that tracks method declaration locations for reuse at method definition time uses the standard name to index the offset. So, that means we see two entries which should have two different locations but they have the same key. The sanity check when I add the index for the second one finds a different, existing index installed for the first one and trips an assert.

If -O0 is omitted I only see the compiled range for the Isolates stub so the problem does not arise.

[adinn]

n.b. I have pushed a fix for the assert that happens when -O0 is specified.

[olpaw]

I'm on e745c48.

To reproduce you have to use a Java11 JVMCI JDK.
(e.g. https://github.com/graalvm/labs-openjdk-11/releases/tag/jvmci-20.3-b09)

It happens when className equals "com.oracle.svm.core.jdk.Target_java_lang_Module". Then typesIndex.get(className) returns null. Which also makes classEntry null. If I build with assertions then the assert

assert (typeEntry != null && typeEntry.isClass());

fails (as expected).

...
Caused by: java.lang.AssertionError
	at com.oracle.objectfile.debugentry.DebugInfoBase.ensureClassEntry(DebugInfoBase.java:327)
	at com.oracle.objectfile.debugentry.DebugInfoBase.lambda$installDebugInfo$5(DebugInfoBase.java:214)
	at com.oracle.svm.hosted.image.NativeImageDebugInfoProvider$NativeImageDebugCodeInfo.debugContext(NativeImageDebugInfoProvider.java:836)
	at com.oracle.objectfile.debugentry.DebugInfoBase.lambda$installDebugInfo$6(DebugInfoBase.java:195)
...

[Jsn2win]

Good

[adinn]

I'm on e745c48.

Ok, thanks.

To reproduce you have to use a Java11 JVMCI JDK.
(e.g. https://github.com/graalvm/labs-openjdk-11/releases/tag/jvmci-20.3-b09)

Well, I have been using jvmci-20.3-b05. I'll switch to b09 and see if that reproduces the problem.

It happens when className equals "com.oracle.svm.core.jdk.Target_java_lang_Module". Then typesIndex.get(className) returns null. Which also makes classEntry null. If I build with assertions then the assert

assert (typeEntry != null && typeEntry.isClass());

fails (as expected).

Ok, good. Glad to see I had the foresight to plant a correct sanity check even if I didn't get the code right! I'll see if I can catch that specific case and work out what is happening. Is there a specific app you are compiling that causes this error?

I suspect that what is happening is that there is a disparity in the determination of the class name between the point where the ClassEntry is created and this point where it is looked up. The difficulty here is that there are two classes in play (Module and Target_java_lang_Module) contributing code elements to what must appear as a single class in the debug view of the native image. The general policy adopted in my implementation is to use the originating class (i.e Module) to group any such original and susbtituted elements (n.b. the methods that identify the relevant class by name is in the NativeImageDebugInfo suite of classes). It looks like this is a case where a substituted method or a newly introduced method is being reported as belonging to the original class at one point and to the substituted (Target) class at another point.

[olpaw]

Ok, good. Glad to see I had the foresight to plant a correct sanity check even if I didn't get the code right! I'll see if I can catch that specific case and work out what is happening. Is there a specific app you are compiling that causes this error?

Yes. The native-image image (the image that gets built out of the native-image driver). Build it with

mx native-image -g -O0 -jar svmbuild/vm/lib/graalvm/svm-driver.jar svmbuild/vm/bin/native-image.x 

If you are building this with JAVA_HOME set to a Java 11 JVMCI JDK you should have no problem replicating the issue.

[adinn]

@olpaw I found the problem with resolving the type name -- the lookup of the original class name for a method was being sidetracked into using the Target class when the method came from the Target. The same problem was present for fields. Constructor name substitutuion (class name to replace for init) was also being done wrong. I have pushed a fix for all of them.

[olpaw]

@olpaw Hi Paul, thanks for clarifying, especially the rules for compressed references. I'll meld the appropriate oop conversion rules into the next patch.

I have now also added this information as JavaDoc. See a36a825

[adinn]

@olpaw Thanks for the javadoc, Paul. I now have a patch implemented and tested that should work for CE and EE. I'm working on a minor re-organization to make the array length field an element of each array layout type rather than bring it in from a special array header. I'll push them both together 'real soon'.

[adinn]

@olpaw I have pushed all the changes needed to 1) correct indirect oop conversion and 2) make arrays inherit a normal object header with the length field overlaid in each array implementation layout.

I also updated the gdb test script used by mx debuginfotest to 1) expect the new layouts and 2) bypass testing of value printing for all gdb versions (including gdb 10.1). This is temporary until I can get the fedora/RHEL gdb bug fixed. If you have a local gdb built without the fedora/RHEL bug you can override to use that gdb and to enable printing by setting two env vars:

$ GDB_BIN=~/path/to/local/gdb \
   GDB_CAN_PRINT=True \
   mx debuginfotest
. . .

So this version ought to be complete and to address all review comments.

[olpaw]

If you have a local gdb built without the fedora/RHEL bug you can override to use that gdb and to enable printing by setting two env vars:

Thanks for the hint. I will re-review and test your PR today.

[olpaw]

Looks much better now. Only a few more changes required (see prev comments).
In addition please

• Rebase to latest master
• Squash commits where it makes sense and make messages start uppercase

Btw, I have tested a bit locally and also -H:+SpawnIsolates seems to work as expected (running debuginfotest fails though).
If you rebase to master I can easily test some more locally with the other reference access modes.

[adinn]

Hi @olpaw,

Sorry for the delay in pushing the remaining fixes -- a meeting got in the way.

In addition please

Rebase to latest master
Squash commits where it makes sense and make messages start uppercase

Now done.

Btw, I have tested a bit locally and also -H:+SpawnIsolates seems to work as expected (running debuginfotest fails though).

I'm not sure what you are saying is failing here, the test in any circumstances or when using -H:+SpawnIsolates.

Testing with mx debuginfotest only ever tests the -H:-SpawnIsolates case. It works for me when I have a vanilla gdb in the path or specified using GDB_BIN and I also set env var GDB_CAN_PRINT=True. It should work with any gdb if GDB_CAN_PRINT is unset or set to another value. Can you explain precisely how you are testing and how it is failing?

The python driver script (mx_substratevm.py) only builds the native image for Hello using command line option -H:-SpawnIsolates. That's because the gdb script (testhello.py) is written to expect output in the format you would see for that mode. That includes details of both printed objects and printed types.

Testing an image built with -H:+SpawnIsolates will require either 1) providing a new gdb script which looks for print object/type output in a different format or 2) modifying the existing script to check the output for a format determined by a config setting supplied when the script is run. I plan to implement such a change. Does that need to be done as part of this commit or provided as a follow-up?

If you rebase to master I can easily test some more locally with the other reference access modes.

Should be possible now.

[olpaw]

I'm not sure what you are saying is failing here, the test in any circumstances or when using -H:+SpawnIsolates.

Only when I run with -H:+SpawnIsolates. Otherwise GDB_BIN=/home/pwoegere/.local/gdb-10.1/bin/gdb GDB_CAN_PRINT=True mx -v debuginfotest passes fine when I run it locally with the GDB I built from http://ftp.gnu.org/gnu/gdb/gdb-10.1.tar.xz

Testing with mx debuginfotest only ever tests the -H:-SpawnIsolates case. It works for me when I have a vanilla gdb in the path or specified using GDB_BIN and I also set env var GDB_CAN_PRINT=True. It should work with any gdb if GDB_CAN_PRINT is unset or set to another value. Can you explain precisely how you are testing and how it is failing?

With

--- a/substratevm/mx.substratevm/mx_substratevm.py
+++ b/substratevm/mx.substratevm/mx_substratevm.py
@@ -734,7 +734,7 @@ def _debuginfotest(native_image, path, build_only, args):
                          '-cp', classpath('com.oracle.svm.test'),
                          '-Dgraal.LogFile=graal.log',
                          '-g',
-                         '-H:-SpawnIsolates',
+                         '-H:+SpawnIsolates',
                          '-H:DebugInfoSourceSearchPath=' + sourcepath,
                          '-H:DebugInfoSourceCacheRoot=' + join(path, 'sources'),
                          'hello.Hello'] + args

I get

...
(gdb) print /x *(('java.lang.String[]' *)$rdi)->hub
Checker print String[] hub: insufficient matching lines 8 for regular expressions 9
Checker print String[] hub {
  re.compile('.* = {')
  re.compile('[ \t]+<java.lang.Object> = {')
  re.compile('[ \t]+<_objhdr> = {')
  re.compile('[ \t]+hub = 0x[0-9a-f]+,')
  re.compile('[ \t]+idHash = 0x[0-9a-f]+')
  re.compile('[ \t]+}, <No data fields>},')
  re.compile('[ \t]+members of java\\.lang\\.Class:')
  re.compile('[ \t]+name = 0x[0-9a-f]+,')
  re.compile('}')
}

$2 = {
  <java.lang.Class> = {
    <java.lang.Object> = {
      <_objhdr> = {
        hub = 0x1c3768,
        idHash = 0x7e6ef134
      }, <No data fields>}, 
    members of java.lang.Class:
    name = 0x18e078,
    isAnonymousClass = 0x3b9480,
    superHub = 0x1c6168,
    componentHub = 0x19ea60,
    arrayHub = 0x1c89a8,
    enclosingClass = 0x0,
    interfacesEncoding = 0x39cb60,
    enumConstantsReference = 0x0,
    sourceFileName = 0x0,
    annotationsEncoding = 0x0,
    classInitializationInfo = 0x2a7bf0,
    classLoader = 0x0,
    module = 0x2e6948,
    nestHost = 0x1c2ce8,
    packageNameReference = 0x39ae38,
    rd = 0x2836e0,
    hubType = 0x5,
    layoutEncoding = 0x80001003,
    monitorOffset = 0x0,
    modifiers = 0x411,
    referenceMapIndex = 0x0,
    typeCheckStart = 0x823,
    typeCheckRange = 0x1,
    typeCheckSlot = 0x0,
    isLocalClass = 0x0,
    isInstantiated = 0x1,
    hasDefaultMethods = 0x0,
    declaresDefaultMethods = 0x0
  }, <No data fields>}

[exit code: 1]
  File "/home/pwoegere/OLabs/git/mx/mx.py", line 17265, in <module>
    main()
  File "/home/pwoegere/OLabs/git/mx/mx.py", line 17246, in main
    retcode = c(command_args)
  File "/home/pwoegere/OLabs/git/mx/mx_commands.py", line 147, in __call__
    return self.command_function(*args, **kwargs)
  File "/home/pwoegere/OLabs/issues/GR-28867/graal/substratevm/mx.substratevm/mx_substratevm.py", line 1066, in debuginfotest
    build_if_missing=True
  File "/home/pwoegere/OLabs/issues/GR-28867/graal/substratevm/mx.substratevm/mx_substratevm.py", line 776, in native_image_context_run
    func(native_image, func_args)
  File "/home/pwoegere/OLabs/issues/GR-28867/graal/substratevm/mx.substratevm/mx_substratevm.py", line 1064, in <lambda>
    _debuginfotest(native_image, output_path, build_only, a), unmask(parsed.image_args),
  File "/home/pwoegere/OLabs/issues/GR-28867/graal/substratevm/mx.substratevm/mx_substratevm.py", line 745, in _debuginfotest
    mx.run([os.environ.get('GDB_BIN', 'gdb'), '-x', join(parent, 'mx.substratevm/testhello.py'), join(path, 'hello.hello')])
  File "/home/pwoegere/OLabs/git/mx/mx.py", line 12835, in run
    abort(retcode)
  File "/home/pwoegere/OLabs/git/mx/mx.py", line 3952, in abort
    traceback.print_stack()

Testing an image built with -H:+SpawnIsolates will require either 1) providing a new gdb script which looks for print object/type output in a different format or 2) modifying the existing script to check the output for a format determined by a config setting supplied when the script is run. I plan to implement such a change. Does that need to be done as part of this commit or provided as a follow-up?

I figured that this needs tweaking of the checking script. It's fine if this will be added in a follow up PR.

[olpaw]

Alright. Looks good now. I will create the internal PR and run it through our gates.

Thanks a lot for your great contribution!

[adinn]

All right. Looks good now. I will create the internal PR and run it through our gates.

Excellent. Let's hope it all just sails through :-) Of course, I'll be happy to help when it turns out there is more rework :-p

Thanks a lot for your great contribution!

Thanks for your patience and very careful reviewing. Your help in getting this right (and right for all cases) is very much appreciated.

[olpaw]

@adinn your PR is on master. Our gates found one small issue. See 912d73e
There a HostedOption was accessed via static initializer. This is unsafe because it is not guaranteed that our option processing has already completed at that point in time. As you can see, the fix was simple enough.

I also tested your implementation against our third reference access usecase were we have:

3. -H:+SpawnIsolates and -H:+UseCompressedReferences (EE default)

• Regular reference: address64 = (val32 << compressShift) + r14
• Reference to hub: address64 = ((val32 >>> num_GC_bits) << compressShift) + r14
• where compressShift is defined by CompressEncoding.getShift()

Unfortunately that did not work. But I found the reason and have already fixed it locally.
I will create a PR with the fix and add you as reviewer.

[adinn]

@olpaw Hurrah! Thanks very much for providing the requisite patch-ups. I'll keep an eye out for the patch.

I have a patch ready for the debuginfotypes test script and driver code that tests both settings for SpawnIsolates. I'll create a new PR for that asap.

[olpaw]

@olpaw Hurrah! Thanks very much for providing the requisite patch-ups. I'll keep an eye out for the patch.

It's this one: #3205