oracle / oracle/visualvm

[Sporadic] CPU Profiler ArrayIndexOutOfBoundsException

Open
#285 2 comments 0 reactions 1 assignee View on GitHub

@thurka is already working on this.

Since Mar 23, 2021.

bug
Dominant language
Java
Stars
3.3k
Forks
334
No merged PRs in 30d

Description

Describe the bug

Relevant stack trace snippet:

Caused by: java.lang.ArrayIndexOutOfBoundsException: Index 6200 out of bounds for length 6200
	at org.graalvm.visualvm.lib.jfluid.server.ProfilerRuntimeCPUFullInstr.methodEntry(ProfilerRuntimeCPUFullInstr.java:180)
	at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:662)

Observed when connecting to local Spring Boot application.

When profiling is stopped there is no exception.

CPU Profiler configuration contains only part of all application classes. (app.package.root.service.something**)

Can't reproduce.

Expected behavior
No exception coming from profiler code.

Desktop:

  • OS: Linux debian-desktop 5.10.0-4-amd64 #1 SMP Debian 5.10.19-1 (2021-03-02) x86_64 GNU/Linux
  • JDK version: openjdk version "11.0.11-ea" 2021-04-20
  • Version: 2.0.6

Additional context

This is seems to be the offending line:
https://github.com/oracle/visualvm/blob/master/visualvm/libs.profiler/lib.profiler/src/org/graalvm/visualvm/lib/jfluid/server/ProfilerRuntimeCPUFullInstr.java#L180

            if (ti.stackDepth <= stackDepthLimit) {
                // See comment marked with (***)
                int methodIdInt = methodId&0xff;
                methodIdInt |= methodId&0xff00;

                // Now check if it's the first invocation of this method, and if so, perform instrumentation of nearest callees
                if (!instrMethodInvoked[methodIdInt]) { // <-- thrown from here
                    instrMethodInvoked[methodIdInt] = true; // Mark this method as invoked
                    firstTimeMethodInvoke(ti, methodId);
                }

Bit manipulation here looks correct, so I've quickly checked where instrMethodInvoked comes from, and it may be the case that it's size calculation is slightly wrong at:

https://github.com/oracle/visualvm/blob/fce6d08e92fdafd9d4fb0f0bf35d9b8f1afc60b1/visualvm/libs.profiler/lib.profiler/src/org/graalvm/visualvm/lib/jfluid/global/ProfilingSessionStatus.java#L377

or some other problem with concurrency.

Since I'm no JVM internals expert, I'm not sure about it and how to narrow it down more.

Visual VM Log

-------------------------------------------------------------------------------
>Log Session: Monday, March 22, 2021 at 12:33:22 PM Eastern European Standard Time
>System Info: 
  Product Version         = VisualVM 2.0.6
  Operating System        = Linux version 5.10.0-4-amd64 running on amd64
  Java; VM; Vendor        = 11.0.11-ea; OpenJDK 64-Bit Server VM 11.0.11-ea+4-post-Debian-1; Debian
  Runtime                 = OpenJDK Runtime Environment 11.0.11-ea+4-post-Debian-1
  Java Home               = /usr/lib/jvm/java-11-openjdk-amd64
  System Locale; Encoding = en_US (visualvm); UTF-8
  Home Directory          = /home/pavel
  Current Directory       = /home/pavel
  User Directory          = /home/pavel/.visualvm/2.0.6
  Cache Directory         = /home/pavel/.cache/visualvm/2.0.6
  Installation            = /usr/share/visualvm/visualvm
                            /usr/share/visualvm/platform
  Boot & Ext. Classpath   = 
  Application Classpath   = /usr/share/visualvm/platform/lib/boot.jar:/usr/share/visualvm/platform/lib/org-openide-modules.jar:/usr/share/visualvm/platform/lib/org-openide-util.jar:/usr/share/visualvm/platform/lib/org-openide-util-lookup.jar:/usr/share/visualvm/platform/lib/org-openide-util-ui.jar
  Startup Classpath       = /usr/share/visualvm/platform/core/asm-8.0.1.jar:/usr/share/visualvm/platform/core/asm-commons-8.0.1.jar:/usr/share/visualvm/platform/core/asm-tree-8.0.1.jar:/usr/share/visualvm/platform/core/core-base.jar:/usr/share/visualvm/platform/core/core.jar:/usr/share/visualvm/platform/core/org-netbeans-libs-asm.jar:/usr/share/visualvm/platform/core/org-openide-filesystems-compat8.jar:/usr/share/visualvm/platform/core/org-openide-filesystems.jar:/usr/share/visualvm/visualvm/core/org-graalvm-visualvm-modules-startup.jar:/usr/share/visualvm/visualvm/core/locale/core_visualvm.jar
-------------------------------------------------------------------------------
WARNING [org.netbeans.core.projects.cache]: layer jar:file:/usr/share/visualvm/visualvm/modules/org-graalvm-visualvm-jfr.jar!/org/graalvm/visualvm/jfr/resources/layer.xml contains duplicate folders named Actions/Other
INFO [org.netbeans.core.startup.NbEvents]: Turning on modules:
	org.openide.util.lookup [8.43 20201005-debian-12.1]
	org.openide.util [9.16 20201005-debian-12.1]
	org.openide.util.ui [9.17 20201005-debian-12.1]
	org.openide.modules [7.57 20201005-debian-12.1]
	org.netbeans.api.annotations.common/1 [1.36 20201005-debian-12.1]
	org.openide.filesystems [9.19 20201005-debian-12.1]
	org.openide.awt [7.77 20201005-debian-12.1]
	org.netbeans.api.progress/1 [1.56 20201005-debian-12.1]
	org.netbeans.api.progress.nb [1.56 20201005-debian-12.1]
	org.openide.dialogs [7.51 20201005-debian-12.1]
	org.openide.nodes [7.54 20201005-debian-12.1]
	org.openide.windows [6.86 20201005-debian-12.1]
	org.netbeans.modules.editor.mimelookup/1 [1.49 20201005-debian-12.1]
	org.openide.text [6.76 20201005-debian-12.1]
	org.netbeans.api.scripting [1.6 20201005-debian-12.1]
	org.netbeans.swing.tabcontrol [1.65 20201005-debian-12.1]
	org.netbeans.swing.outline [1.43 20201005-debian-12.1]
	org.openide.explorer [6.71 20201005-debian-12.1]
	org.openide.actions [6.48 20201005-debian-12.1]
	org.netbeans.modules.queries/1 [1.52 20201005-debian-12.1]
	org.netbeans.api.templates [1.17 20201005-debian-12.1]
	org.openide.filesystems.nb [9.19 20201005-debian-12.1]
	org.openide.loaders [7.77 20201005-debian-12.1]
	org.netbeans.api.intent [1.11 20201005-debian-12.1]
	org.netbeans.api.io [1.12 20201005-debian-12.1]
	org.openide.io [1.58 20201005-debian-12.1]
	org.openide.filesystems.compat8 [9.18 20201005-debian-12.1]
	org.netbeans.swing.plaf [1.51 20201005-debian-12.1]
	org.netbeans.spi.quicksearch [1.36 20201005-debian-12.1]
	org.netbeans.libs.asm [5.12 20201005-debian-12.1]
	org.netbeans.bootstrap/1 [2.87 20201005-debian-12.1]
	org.netbeans.core.startup.base [1.71.0.1 1 20201005-debian-12.1]
	org.netbeans.core.startup/1 [1.71.0.1 20201005-debian-12.1]
	org.netbeans.modules.settings/1 [1.58 20201005-debian-12.1]
	org.netbeans.modules.sendopts/2 [2.45 20201005-debian-12.1]
	org.netbeans.modules.sampler [1.23 20201005-debian-12.1]
	org.netbeans.modules.progress.ui [1.42 20201005-debian-12.1]
	org.netbeans.modules.keyring [1.33 20201005-debian-12.1]
	org.netbeans.core/2 [3.60 20201005-debian-12.1]
	org.netbeans.modules.options.api/1 [1.54 20201005-debian-12.1]
	org.netbeans.modules.options.keymap [1.46 20201005-debian-12.1]
	org.netbeans.modules.masterfs/2 [2.64.0.2 2 20201005-debian-12.1]
	org.netbeans.modules.masterfs.ui [2.12.0.2 20201005-debian-12.1]
	org.netbeans.modules.masterfs.nio2 [1.24 20201005-debian-12.1]
	org.netbeans.libs.jna/2 [2.4 20201005-debian-12.1]
	org.netbeans.modules.masterfs.linux [1.22 20201005-debian-12.1]
	org.netbeans.modules.keyring.fallback [1.17 20201005-debian-12.1]
	org.netbeans.modules.keyring.impl [1.33 20201005-debian-12.1]
	org.netbeans.modules.editor.mimelookup.impl/1 [1.41 20201005-debian-12.1]
	org.netbeans.modules.autoupdate.services [1.64 20201005-debian-12.1]
	org.netbeans.modules.autoupdate.ui [1.55 20201005-debian-12.1]
	org.netbeans.modules.autoupdate.cli [1.22 20201005-debian-12.1]
	org.netbeans.libs.jna.platform/2 [2.4 20201005-debian-12.1]
	org.netbeans.core.windows/2 [2.94 20201005-debian-12.1]
	org.netbeans.core.ui/1 [1.54 20201005-debian-12.1]
	org.netbeans.core.network [1.21 20201005-debian-12.1]
	org.netbeans.core.nativeaccess/1 [1.40 20201005-debian-12.1]
	org.netbeans.core.multitabs/1 [1.21.0.1 1 20201005-debian-12.1]
	org.netbeans.core.io.ui/1 [1.39 20201005-debian-12.1]
	org.graalvm.visualvm.lib.jfluid/2 [2.5 691217]
	org.graalvm.visualvm.lib.charts/2 [2.0 691217]
	org.graalvm.visualvm.lib.common/2 [2.2 691217]
	org.graalvm.visualvm.lib.profiler.api/2 [2.1 691217]
	org.graalvm.visualvm.lib.ui/2 [2.2 691217]
	org.graalvm.visualvm.uisupport/2 [2.0 691217]
	org.graalvm.visualvm.core/2 [2.2 691217]
	org.graalvm.visualvm.host/2 [2.0 691217]
	org.graalvm.visualvm.application/2 [2.0 691217]
	org.graalvm.visualvm.tools/2 [2.0 691217]
	org.graalvm.visualvm.coredump/2 [2.0 691217]
	org.graalvm.visualvm.threaddump/2 [2.0 691217]
	org.graalvm.visualvm.lib.profiler.utilities/2 [2.0 691217]
	org.graalvm.visualvm.lib.profiler.attach/2 [2.0 691217]
	org.graalvm.visualvm.lib.profiler/2 [2.2 691217]
	org.graalvm.visualvm.lib.profiler.snaptracer/2 [2.0 691217]
	org.graalvm.visualvm.profiling/2 [2.2 691217]
	org.graalvm.visualvm.lib.profiler.oql/2 [2.0 691217]
	org.graalvm.visualvm.lib.profiler.heapwalker/2 [2.0 691217]
	org.graalvm.visualvm.heapviewer/2 [2.3 691217]
	org.graalvm.visualvm.heapdump/2 [2.0 691217]
	org.graalvm.visualvm.sampler.truffle/2 [2.0 691217]
	org.graalvm.visualvm.sampler/2 [2.0 691217]
	org.graalvm.visualvm.sa/2 [2.0 691217]
	org.graalvm.visualvm.modules.startup/2 [2.1 691217]
	org.graalvm.visualvm.profiler/2 [2.0 691217]
	org.graalvm.visualvm.charts/2 [2.0 691217]
	org.graalvm.visualvm.application.views/2 [2.0 691217]
	org.graalvm.visualvm.modules.graalvm/2 [2.0 691217]
	org.graalvm.visualvm.modules.appui/2 [2.1 691217]
	org.graalvm.visualvm.jvmstat/2 [2.0 691217]
	org.graalvm.visualvm.jvm/2 [2.0 691217]
	org.graalvm.visualvm.jmx/2 [2.1 691217]
	org.graalvm.visualvm.jfr/2 [2.1 691217]
	org.graalvm.visualvm.host.views/2 [2.0 691217]
	org.graalvm.visualvm.host.remote/2 [2.0 691217]
	org.graalvm.visualvm.heapviewer.truffle/2 [2.0 691217]
	org.graalvm.visualvm.heapviewer.console/2 [2.0 691217]
	org.graalvm.visualvm.attach/2 [2.0 691217]
INFO [org.netbeans.core.network.proxy.NetworkProxyReloader]: System network proxy resolver: no suitable found, using fallback.
INFO [org.netbeans.core.network.proxy.fallback.FallbackNetworkProxy]: Fallback system proxy resolver: no http_proxy variable found
INFO [org.netbeans.core.network.proxy.NetworkProxyReloader]: System network proxy reloading succeeded.
INFO [org.netbeans.core.network.proxy.NetworkProxyReloader]: System network proxy - mode: direct
INFO [org.netbeans.core.network.proxy.NetworkProxyReloader]: System network proxy: fell to default (correct if direct mode went before)
INFO [org.netbeans.ui.metrics.laf]: USG_LOOK_AND_FEEL
Exception "java.lang.ClassNotFoundException: com/intellij/codeInsight/editorActions/FoldingData"while constructing DataFlavor for: application/x-java-jvm-local-objectref; class=com.intellij.codeInsight.editorActions.FoldingData
INFO [null]: Last record repeated again.
Exception "java.lang.ClassNotFoundException: com/intellij/codeInsight/editorActions/ReferenceData"while constructing DataFlavor for: application/x-java-jvm-local-objectref; class=com.intellij.codeInsight.editorActions.ReferenceData
INFO [null]: Last record repeated again.
Diagnostic information
Input arguments:
	-Djdk.home=/usr/lib/jvm/java-11-openjdk-amd64
	-Dnetbeans.default_userdir_root=/home/pavel/.visualvm
	-Dnetbeans.dirs=/usr/share/visualvm/visualvm:
	-Dnetbeans.home=/usr/share/visualvm/platform
	-Xms24m
	-Xmx768m
	-Dnetbeans.accept_license_class=org.graalvm.visualvm.modules.startup.AcceptLicense
	-Dnetbeans.importclass=org.graalvm.visualvm.modules.startup.ImportSettings
	-Dsun.jvmstat.perdata.syncWaitMs=10000
	-Dsun.java2d.noddraw=true
	-Dsun.java2d.d3d=false
	-Dorg.netbeans.core.TimeableEventQueue.quantum=360000
	-Dpolyglot.js.nashorn-compat=true
	-Dsun.misc.URLClassPath.disableJarChecking=true
	--add-exports=java.desktop/sun.awt=ALL-UNNAMED
	--add-exports=jdk.internal.jvmstat/sun.jvmstat.monitor.event=ALL-UNNAMED
	--add-exports=jdk.internal.jvmstat/sun.jvmstat.monitor=ALL-UNNAMED
	--add-exports=java.desktop/sun.swing=ALL-UNNAMED
	--add-exports=jdk.attach/sun.tools.attach=ALL-UNNAMED
	--add-opens=java.base/java.net=ALL-UNNAMED
	--add-opens=java.base/java.lang.ref=ALL-UNNAMED
	--add-opens=java.base/java.lang=ALL-UNNAMED
	--add-opens=java.desktop/javax.swing=ALL-UNNAMED
	--add-opens=java.desktop/javax.swing.plaf.basic=ALL-UNNAMED
	-XX:+IgnoreUnrecognizedVMOptions
	-XX:+HeapDumpOnOutOfMemoryError
	-XX:HeapDumpPath=/home/pavel/.visualvm/2.0.6/var/log/heapdump.hprof
Compiler: HotSpot 64-Bit Tiered Compilers
Heap memory usage: initial 24.0MB maximum 768.0MB
Non heap memory usage: initial 7.3MB maximum -1b
Garbage collector: G1 Young Generation (Collections=19 Total time spent=0s)
Garbage collector: G1 Old Generation (Collections=0 Total time spent=0s)
Classes: loaded=6870 total loaded=6879 unloaded 9
INFO [org.netbeans.core.ui.warmup.DiagnosticTask]: Total memory 67,410,419,712
INFO [null]: Total physical memory 67,410,419,712
WARNING [org.openide.filesystems.Ordering]: Found same position 1,500 for both VisualVM/ExplorerPopupSelection/org-graalvm-visualvm-application-RemoveFinishedApplicationsAction-selectionAware.instance and VisualVM/ExplorerPopupSelection/org-graalvm-visualvm-application-snapshot-ApplicationSnapshotAction.shadow
INFO [org.netbeans.modules.autoupdate.updateprovider.AutoupdateCatalogParser]: Unpaired license 36ED1425 without any module.
WARNING [org.netbeans.modules.keyring.fallback.MasterPasswordEncryption]: Falling back to master password encryption; add -J-Dorg.netbeans.modules.keyring.level=0 to netbeans.conf to see why native keyrings could not be loaded

Contributor guide

Open the contributing guide

First steps

  1. Read the whole issue, then the project's contributing guide.
  2. Comment on the issue to say you are picking it up — it saves two people doing the same work.
  3. Fork the repository and make your change on a branch.
  4. Open a pull request that references the issue number.

Assessment

This issue has not been assessed yet.

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.