When performing regression testing on OpenJDK, the error "--Fail: waitForJdbMsg timed out after 40 seconds, looking for /]/, in 1 lines; exitting" occurred when testing a shell script with jdi-based debugging function through JTreg, and A timeout occurs, ultimately causing the test case to fail.
DeoptimizeWalk.sh（shell test script）：
#!/bin/sh
#
# Copyright (c) 2002, 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
# @bug 4525714
# @summary jtreg test PopAsynchronousTest fails in build 85 with -Xcomp
# @author Jim Holmlund/Swamy Venkataramanappa
# @run shell DeoptimizeWalk.sh
# This is another test of the same bug. The bug occurs when trying
# to walk the stack of a deoptimized thread. We can do this
# by running in -Xcomp mode and by doing a step which causes deopt,
# and then a 'where'. This will cause not all the frames to be shown.
compileOptions=-g
echo "*********** This test only fails with -Xcomp ***************"
createJavaFile()
{
cat <<EOF > $1.java.1
public class $1 {
static public void main(String[] args) {
$1 mine = new $1();
mine.a1(89);
}
public void a1(int p1) {
int v1 = 89;
System.out.println("a1" + v1);
a2(89);
}
public void a2(int pp) {
int v2 = 89;
System.out.println("a2" + v2);
a3(89);
}
public void a3(int pp) {
int v3 = 89;
System.out.println("a3"); //@ 1 breakpoint
a4(22); // it passes if this line is commented out
System.out.println("jj");
}
public void a4(int pp) {
int v4 = 90;
System.out.println("a4: @1 breakpoint here");
}
}
EOF
}
# This is called to feed cmds to jdb.
dojdbCmds()
{
setBkpts @1
runToBkpt @1
cmd where
#cmd next
cmd step
cmd where
cmd quit
jdbFailIfNotPresent "shtest\.main" 3
}
mysetup()
{
if [ -z "$TESTSRC" ] ; then
TESTSRC=.
fi
for ii in . $TESTSRC $TESTSRC/.. ; do
if [ -r "$ii/ShellScaffold.sh" ] ; then
. $ii/ShellScaffold.sh
break
fi
done
}
# You could replace this next line with the contents
# of ShellScaffold.sh and this script will run just the same.
mysetup
runit
debuggeeFailIfPresent "Internal exception:"
pass
jtr file of jtreg：
#Test Results (version 2)
#Mon Mar 25 18:22:47 CST 2024
#-----testdescription-----
$file=/path/to/kunzejdk/PrimetonKunZe-8/jdk/test/com/sun/jdi/DeoptimizeWalk.sh
$root=/path/to/kunzejdk/PrimetonKunZe-8/jdk/test
author=Jim Holmlund/Swamy Venkataramanappa
keywords=bug4525714 shell
run=USER_SPECIFIED shell DeoptimizeWalk.sh\n
source=DeoptimizeWalk.sh
title=jtreg test PopAsynchronousTest fails in build 85 with -Xcomp
#-----environment-----
#-----testresult-----
description=file\:/path/to/kunzejdk/PrimetonKunZe-8/jdk/test/com/sun/jdi/DeoptimizeWalk.sh
elapsed=480003 0\:08\:00.003
end=Mon Mar 25 18\:22\:47 CST 2024
environment=regtest
execStatus=Error. Program `sh' timed out (timeout set to 480000ms, elapsed time including timeout handling was 480002ms).
harnessLoaderMode=Classpath Loader
harnessVariety=Full Bundle
hostname=kylin-124
javatestOS=Linux 4.19.90-52.22.v2207.ky10.x86_64 (amd64)
javatestVersion=6.0-ea+b04-2024-03-25
jtregVersion=jtreg jtreg6 dev jtreg6
script=com.sun.javatest.regtest.exec.RegressionScript
sections=script_messages shell
start=Mon Mar 25 18\:14\:47 CST 2024
test=com/sun/jdi/DeoptimizeWalk.sh
testJDK=/path/to/kunzejdk/PrimetonKunZe-8/build/linux-x86_64-normal-server-release/images/j2sdk-image
totalTime=480004
user.name=root
work=/path/to/kunzejdk/PrimetonKunZe-8/build/linux-x86_64-normal-server-release/testoutput/jdk_tier1/JTwork/com/sun/jdi
#section:script_messages
----------messages:(4/255)----------
JDK under test: /path/to/kunzejdk/PrimetonKunZe-8/build/linux-x86_64-normal-server-release/images/j2sdk-image
openjdk version "1.8.0_402"
OpenJDK Runtime Environment Kunze (build 1.8.0_402-12)
OpenJDK 64-Bit Server VM Kunze (build 25.402-b12, mixed mode)
#section:shell
----------messages:(3/125)----------
command: shell DeoptimizeWalk.sh
reason: User specified action: run shell DeoptimizeWalk.sh
elapsed time (seconds): 480.003
----------System.out:(7/370)*----------
*********** This test only fails with -Xcomp ***************
--Compiling first version of /path/to/kunzejdk/PrimetonKunZe-8/build/linux-x86_64-normal-server-release/testoutput/jdk_tier1/JTwork/classes/0/com/sun/jdi/aa850509/shtest.java with options: -g
compiling shtest.java
--Starting jdb, address=
\u76d1\u542c\u5730\u5740: kylin-124:45527
Timeout refired 480 times
----------System.err:(87/5033)*----------
ShellScaffold.sh: Version
vv jdbOutFile vvvvvvvvvvvvvvvvvvvvvvvvvvvv
\u76d1\u542c\u5730\u5740: kylin-124:45527
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
-- jdb process info ----------------------
850604 TTY -Dapplication.home=/path/to/kunzejdk/PrimetonKunZe-8/build/linux-x86_64-normal-server-release/images/j2sdk-image -Xms8m -DHANGINGJAVA-850509_JDB
-- jdb threads: jstack 850604
2024-03-25 18:15:31
Full thread dump OpenJDK 64-Bit Server VM (25.402-b12 mixed mode):
"Attach Listener" #10 daemon prio=9 os_prio=0 cpu=0.44ms elapsed=0.20s tid=0x00007f5860001000 nid=0xd086a waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"Service Thread" #9 daemon prio=9 os_prio=0 cpu=0.04ms elapsed=43.15s tid=0x00007f58e40e1800 nid=0xcfad0 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"C1 CompilerThread3" #8 daemon prio=9 os_prio=0 cpu=35.19ms elapsed=43.15s tid=0x00007f58e40de800 nid=0xcfacf waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"C2 CompilerThread2" #7 daemon prio=9 os_prio=0 cpu=3.45ms elapsed=43.16s tid=0x00007f58e40dc800 nid=0xcface waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"C2 CompilerThread1" #6 daemon prio=9 os_prio=0 cpu=3.85ms elapsed=43.16s tid=0x00007f58e40db000 nid=0xcfacd waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"C2 CompilerThread0" #5 daemon prio=9 os_prio=0 cpu=4.98ms elapsed=43.16s tid=0x00007f58e40d8000 nid=0xcfacc waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"Signal Dispatcher" #4 daemon prio=9 os_prio=0 cpu=0.35ms elapsed=43.16s tid=0x00007f58e40d5000 nid=0xcfacb runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"Finalizer" #3 daemon prio=8 os_prio=0 cpu=0.36ms elapsed=43.18s tid=0x00007f58e40a2000 nid=0xcfaca in Object.wait() [0x00007f5889b69000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x0000000749481280> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:144)
- locked <0x0000000749481280> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:165)
at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:188)
"Reference Handler" #2 daemon prio=10 os_prio=0 cpu=0.57ms elapsed=43.18s tid=0x00007f58e409d800 nid=0xcfac9 in Object.wait() [0x00007f5889c6a000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x0000000749481448> (a java.lang.ref.Reference$Lock)
at java.lang.Object.wait(Object.java:502)
at java.lang.ref.Reference.tryHandlePending(Reference.java:191)
- locked <0x0000000749481448> (a java.lang.ref.Reference$Lock)
at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:153)
"main" #1 prio=5 os_prio=0 cpu=120.81ms elapsed=43.20s tid=0x00007f58e400b800 nid=0xcfab2 runnable [0x00007f58ea2eb000]
java.lang.Thread.State: RUNNABLE
at java.net.PlainSocketImpl.socketAccept(Native Method)
at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:409)
at java.net.ServerSocket.implAccept(ServerSocket.java:560)
at java.net.ServerSocket.accept(ServerSocket.java:528)
at com.sun.tools.jdi.SocketTransportService.accept(SocketTransportService.java:348)
at com.sun.tools.jdi.GenericListeningConnector.accept(GenericListeningConnector.java:151)
at com.sun.tools.example.debug.tty.VMConnection.listenTarget(VMConnection.java:536)
at com.sun.tools.example.debug.tty.VMConnection.open(VMConnection.java:330)
- locked <0x00000007493a60d8> (a com.sun.tools.example.debug.tty.VMConnection)
at com.sun.tools.example.debug.tty.Env.init(Env.java:63)
at com.sun.tools.example.debug.tty.TTY.main(TTY.java:1083)
"VM Thread" os_prio=0 cpu=2.52ms elapsed=43.18s tid=0x00007f58e4095800 nid=0xcfac7 runnable
"GC task thread#0 (ParallelGC)" os_prio=0 cpu=1.57ms elapsed=43.20s tid=0x00007f58e4021000 nid=0xcfab6 runnable
"GC task thread#1 (ParallelGC)" os_prio=0 cpu=0.99ms elapsed=43.20s tid=0x00007f58e4023000 nid=0xcfab7 runnable
"GC task thread#2 (ParallelGC)" os_prio=0 cpu=0.88ms elapsed=43.20s tid=0x00007f58e4025000 nid=0xcfab8 runnable
"GC task thread#3 (ParallelGC)" os_prio=0 cpu=0.08ms elapsed=43.20s tid=0x00007f58e4026800 nid=0xcfab9 runnable
"GC task thread#4 (ParallelGC)" os_prio=0 cpu=0.05ms elapsed=43.20s tid=0x00007f58e4028800 nid=0xcfaba runnable
"GC task thread#5 (ParallelGC)" os_prio=0 cpu=0.06ms elapsed=43.20s tid=0x00007f58e402a000 nid=0xcfabb runnable
"GC task thread#6 (ParallelGC)" os_prio=0 cpu=0.05ms elapsed=43.20s tid=0x00007f58e402c000 nid=0xcfabc runnable
"GC task thread#7 (ParallelGC)" os_prio=0 cpu=0.08ms elapsed=43.20s tid=0x00007f58e402d800 nid=0xcfabd runnable
"VM Periodic Task Thread" os_prio=0 cpu=17.44ms elapsed=43.15s tid=0x00007f58e40e4000 nid=0xcfad1 waiting on condition
JNI global references: 12
------------------------------------------
----------rerun:(21/1139)*----------
cd /path/to/kunzejdk/PrimetonKunZe-8/build/linux-x86_64-normal-server-release/testoutput/jdk_tier1/JTwork/scratch/2 && \\
HOME=/root \\
LANG=zh_CN.UTF-8 \\
PATH=/bin:/usr/bin:/usr/sbin \\
TESTSRC=/path/to/kunzejdk/PrimetonKunZe-8/jdk/test/com/sun/jdi \\
TESTSRCPATH=/path/to/kunzejdk/PrimetonKunZe-8/jdk/test/com/sun/jdi \\
TESTCLASSES=/path/to/kunzejdk/PrimetonKunZe-8/build/linux-x86_64-normal-server-release/testoutput/jdk_tier1/JTwork/classes/0/com/sun/jdi \\
TESTCLASSPATH=/path/to/kunzejdk/PrimetonKunZe-8/build/linux-x86_64-normal-server-release/testoutput/jdk_tier1/JTwork/classes/0/com/sun/jdi \\
COMPILEJAVA=/path/to/kunzejdk/PrimetonKunZe-8/build/linux-x86_64-normal-server-release/images/j2sdk-image \\
TESTJAVA=/path/to/kunzejdk/PrimetonKunZe-8/build/linux-x86_64-normal-server-release/images/j2sdk-image \\
TESTVMOPTS='-ea -esa -Xmx512m' \\
TESTTOOLVMOPTS='-J-ea -J-esa -J-Xmx512m' \\
TESTJAVACOPTS= \\
TESTJAVAOPTS= \\
TESTTIMEOUTFACTOR=4.0 \\
TESTROOT=/path/to/kunzejdk/PrimetonKunZe-8/jdk/test \\
FS=/ \\
PS=: \\
NULL=/dev/null \\
sh \\
/path/to/kunzejdk/PrimetonKunZe-8/jdk/test/com/sun/jdi/DeoptimizeWalk.sh
result: Error. Program `sh' timed out (timeout set to 480000ms, elapsed time including timeout handling was 480002ms).
test result: Error. Program `sh' timed out (timeout set to 480000ms, elapsed time including timeout handling was 480002ms).
test result:
test result: Error. Program `sh' timed out (timeout set to 480000ms, elapsed time including timeout handling was 480002ms).
The problem has been solved. It was caused by the local language environment of the operating system. Set the local language environment to en_US.UTF-8 and it will be fine.
- Check locale
echo $LANG - Set locale
export LANG=en_US.UTF-8
The problem has been solved. It was caused by the local language environment of the operating system. Set the local language environment to
en_US.UTF-8and it will be fine.echo $LANGexport LANG=en_US.UTF-8