JDK-4657238 : Reg-test DropPerformanceTest.html Failing
  • Type: Bug
  • Component: client-libs
  • Sub-Component: java.awt
  • Affected Version: 1.4.1
  • Priority: P4
  • Status: Closed
  • Resolution: Cannot Reproduce
  • OS: windows_xp
  • CPU: x86
  • Submitted: 2002-03-23
  • Updated: 2009-04-08
  • Resolved: 2002-06-13
Related Reports
Relates :  
JDK-4669873 - DnD on jdk1.4.x for Windows freezes app for couple of seconds.
Description
Name: as83306			Date: 03/22/2002

Regression test java/awt/dnd/DropPerformanceTest/DropPerformanceTest.html fails with Hopper build 05 on win_xp, host cwbybkr.  

 For test hardware config's, see http://sqesvr.eng/st3/jdk1.4/docs/Merlin-hw.html
#Test Results (version 2)
#Tue Mar 19 21:52:14 PST 2002
#checksum:2e7bfee8eae5d561
#-----testdescription-----
$file=C:\\Regression\\hopper\\jdk1.4.1Tests\\tests\\b06\\java\\awt\\dnd\\DropPerformanceTest\\DropPerformanceTest.html
$root=C:\\Regression\\hopper\\jdk1.4.1Tests\\tests\\b06
author=###@###.### area=dnd
keywords=bug4484996
run=USER_SPECIFIED applet DropPerformanceTest.html\r\n
source=DropPerformanceTest.html
title=Tests that drop doesn't take too much time on Win 95/98.

#-----environment-----

#-----testresult-----
description=file:///C:/Regression/hopper/jdk1.4.1Tests/tests/b06/java/awt/dnd/DropPerformanceTest/DropPerformanceTest.html
end=Tue Mar 19 21:52:14 PST 2002
environment=regtest
execStatus=Failed. Execution failed: Applet thread threw exception: java.lang.RuntimeException: The test failed: drop took too much time
javatestOS=Windows 2000 5.1 (x86)
javatestVersion=2.1.5
script=com.sun.javatest.regtest.RegressionScript 
sections=script_messages build compile applet
start=Tue Mar 19 21:50:57 PST 2002
status=Failed. Execution failed: Applet thread threw exception: java.lang.RuntimeException: The test failed: drop took too much time
test=java/awt/dnd/DropPerformanceTest/DropPerformanceTest.html
work=C:\\Results\\Regression\\hopper\\b06\\CWBYBKR-Windows_NT-jth13-jdk141b06.03-19.21-28-ALL\\java\\awt\\dnd\\DropPerformanceTest

#section:script_messages
----------messages:(4/200)----------
JDK under test: (C:/Java/jdk141b06)
java version "1.4.1-beta"
Java(TM) 2 Runtime Environment, Standard Edition (build 1.4.1-beta-b06)
Java HotSpot(TM) Client VM (build 1.4.1-beta-b06, mixed mode)

#section:build
----------messages:(3/108)----------
command: build DropPerformanceTest 
reason: Named class compiled on demand
elapsed time (seconds): 1.743
result: Passed. Compilation successful

#section:compile
----------messages:(3/214)*----------
command: compile C:\\Regression\\hopper\\jdk1.4.1Tests\\tests\\b06\\java\\awt\\dnd\\DropPerformanceTest\\DropPerformanceTest.java 
reason: .class file out of date or does not exist
elapsed time (seconds): 1.733
----------System.out:(0/0)----------
----------System.err:(0/0)----------
result: Passed. Compilation successful

#section:applet
----------messages:(3/143)----------
command: applet DropPerformanceTest.html
reason: User specified action: run applet DropPerformanceTest.html 
elapsed time (seconds): 75.248
----------System.out:(0/0)----------
----------System.err:(7/438)----------
Child VM: normal termination
Drop consumed 66726 milliseconds
java.lang.RuntimeException: The test failed: drop took too much time
	at DropPerformanceTest.start(DropPerformanceTest.java:190)
	at com.sun.javatest.regtest.AppletWrapper$AppletThread.run(AppletWrapper.java:145)
	at java.lang.Thread.run(Thread.java:536)
STATUS:Failed.Applet thread threw exception: java.lang.RuntimeException: The test failed: drop took too much time
result: Failed. Execution failed: Applet thread threw exception: java.lang.RuntimeException: The test failed: drop took too much time

test result: Failed. Execution failed: Applet thread threw exception: java.lang.RuntimeException: The test failed: drop took too much time
======================================================================

###@###.### 2002-04-16

no longer reproducible with b09.  please close as such.
Comments
EVALUATION Here is an evaluation by the responsible engineer, ###@###.### This bug documents the failure on WinXP. We don't have a machine with WinXP here. I was unable to reproduce it on WinNT and Win2000. I asked Peter to help me with the investigation. The results are as follows: 1)the bug is occasionally reproducible - sometimes fail on the first attempt, sometimes passes on 4-5 attempts and then fails 2)Peter reproduced the bug on WinXp with 1.4.1-b07 and b08. After the submitter updated the bug report with the note that it is no longer reproducible on b09, i asked Peter to rerun the test on b09. The test still fails occasionally. 3)The test fails because the drop takes too much time - the submitter reports 66726 milliseconds, in Peter's environment it sometimes takes even more - up to 351609 milliseconds. The full thread dump indicates that most of the time the test executes java.io.WinNTFileSystem.canonicalize() during deserialization of JButton on the drop target size. 4)I looked for references to the slowness of WinNTFileSystem.canonicalize() and found the bug #4379372. However it doesn't provide much information. While working on 4669873 i observed very slow execution of several WinNTFileSystem methods (including canonicalize()) on Win2000 - they can take up to 200 seconds. This is only reproducible when the file is accessed via network. This phenomenon doesn't manifest in my environment when all files are on the local drive. This probably explains why drops are so slow in Peter's environment. However the jtreg report pasted in the bug description documents that both the test case and the JDK build are on the local drive. On the next step i would ask Peter to patch WinNTFileSystem methods to collect execution time information. I expect that it will confirm my hypothesis that very slow execution of these methods is the cause of the failure. Then i will ask Peter to try to reproduce the failure when the JDK build and the test are on the local drive and if the failure doesn't manifest i would reassing this bug to classes_io. ###@###.### 2002-05-01 Further investigation indicates that occasional slowdowns of drop processing manifest only when the JDK being tested in on the remote drive accessed via network. In case of remote JDK the drop can easily take up to 300-400 seconds in our environment. In case of local JDK the drop is typically processed in less than 1 second. Only once it took 36 seconds. The bug is reproducible both with jtreg and with appletviewer. When running the test with appletviewer thread dumps indicates that most of the drop time is spent in WinNTFileSystem.canonicalize() The typical thread dump at the point of drop processing is attached to this bug report as nosec.fail.b08.log. ###@###.### 2002-05-08 Name: dsR10078 Date: 06/13/2002 Very slow drop processing might have the same cause as the drag freezes documented in the bug 4669873 - the toolkit threads executes a tight loop and consumes all processor time. Peter verified that after 4669873 is fixed, drop never takes more than 2 seconds and the test consistently passes on WinXP. ###@###.### 2002-05-08 ======================================================================
08-05-2002