United StatesChange Country, Oracle Worldwide Web Sites Communities I am a... I want to...
JDK-4987309 : NTLM authentication takes a long time (> 1000 seconds per request)

Details
Type:
Bug
Submit Date:
2004-02-03
Status:
Resolved
Updated Date:
2004-05-10
Project Name:
JDK
Resolved Date:
2004-04-06
Component:
core-libs
OS:
windows_xp
Sub-Component:
java.net
CPU:
x86
Priority:
P3
Resolution:
Fixed
Affected Versions:
1.4.2
Fixed Versions:
1.4.2_05 (05)

Related Reports
Backport:

Sub Tasks

Description
nt.WindowEvent;
import java.awt.event.WindowAdapter;
import javax.imageio.ImageIO;

public class ClassForNameTest extends Applet {
    private TextArea textArea;
    private Button button;

    private String buttonText;

    public ClassForNameTest() {
        setLayout(new BorderLayout());
    }

    public void init() {
        textArea = new TextArea();
        add(BorderLayout.CENTER, textArea);

        buttonText = "Check";
        button = new Button(buttonText);
        button.addActionListener(new ActionListener()
        {
            public void actionPerformed(ActionEvent e) {
                if (buttonText.equals(e.getActionCommand())) {
                    textArea.setText(null);
                    showContent();
                }
            }
        });
        add(BorderLayout.SOUTH, button);
    }

    public static final void main(String[] args) {
        final Frame f = new Frame();

        f.addWindowListener(new WindowAdapter()
        {
            public void windowClosing(WindowEvent e) {
                if (e.getSource() == f) {
                    f.dispose();
                    System.exit(0);
                }
            }
        });

        ClassForNameTest ct = new ClassForNameTest();

        f.add(ct);
        ct.init();

        f.pack();
        f.show();

        ct.start();
    }

    public void showContent() {
        Thread t = new Thread(new Runnable()
        {
            public void run() {
                try {
                    String[] imageIOReaderNames = ImageIO.getReaderFormatNames();
                    textArea.append("Succesfully loaded class\n");
                    if (imageIOReaderNames != null) {
                        for (int i = 0;  i < imageIOReaderNames.length;  i++) {
                            textArea.append(imageIOReaderNames[i]);
                            textArea.append("\n");
                        }
                    }
                } catch (Exception e) {
                    textArea.append("Exception trying to load class.");
                    textArea.append("\n");

                    textArea.append(e.toString());
                }
            }
        });
        t.start();
    }
}

---------- END SOURCE ----------

CUSTOMER SUBMITTED WORKAROUND :
Setting the system properties sun.net.client.defaultConnectTimeout and sun.net.client.defaultReadTimeout to a reasonably small value reduces the time taken.

For our application (which has many Class.forName() calls at startup) setting these to 200ms makes the loading time be approximately 30 seconds.  Setting them to 400ms makes the loading time be approx 50 seconds.

Doing this did seem to make me authenticate twice via the Plugin (in addition to the standard IE authentication dialog).
(Incident Review ID: 209537) 
======================================================================


Name: gm110360			Date: 02/02/2004


FULL PRODUCT VERSION :
java version "1.4.2"
Java(TM) 2 Runtime Environment, Standard Edition (build 1.4.2-b28)
Java HotSpot(TM) Client VM (build 1.4.2-b28, mixed mode)

FULL OS VERSION :
Microsoft Windows XP [Version 5.1.2600]


A DESCRIPTION OF THE PROBLEM :
When trying to run an applet from an NTLM protected web site, or a web site that supports multiple authentication schemes of which NTLM is one, the 1.4.2 Plugin can take an extraordinary amount of time to perform particular operations.

The operations that take a long time are trying to load (either directly or via reflection) the ImageIO (javax.imageio) classes or the Java Printing (javax.print) classes.  The description herein details loading the ImageIO classes.

Looking at a network trace, the following is observed for loading the applet itself shows the expected sequence of
GET -> Access Denied -> GET -> Access Denied -> GET -> OK:

GET /ntlm/test/ClassForNameTest.class HTTP/1.1
User-Agent: Mozilla/4.0 (Windows XP 5.1) Java/1.4.2
Host: canyon
Accept: text/html, image/gif, image/jpeg, *; q=.2, */*; q=.2
Connection: keep-alive

HTTP/1.1 401 Access Denied
Server: Microsoft-IIS/5.0
Date: Tue, 30 Sep 2003 13:24:46 GMT
WWW-Authenticate: Negotiate
WWW-Authenticate: NTLM
Connection: close
Content-Length: 4431
Content-Type: text/html

GET /ntlm/test/ClassForNameTest.class HTTP/1.1
User-Agent: Mozilla/4.0 (Windows XP 5.1) Java/1.4.2
Host: canyon
Accept: text/html, image/gif, image/jpeg, *; q=.2, */*; q=.2
Connection: keep-alive
Authorization: NTLM TlXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX=

HTTP/1.1 401 Access Denied
Server: Microsoft-IIS/5.0
Date: Tue, 30 Sep 2003 13:24:50 GMT
WWW-Authenticate: NTLM TlXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX=
Content-Length: 4033
Content-Type: text/html


GET /ntlm/test/ClassForNameTest.class HTTP/1.1
User-Agent: Mozilla/4.0 (Windows XP 5.1) Java/1.4.2
Host: canyon
Accept: text/html, image/gif, image/jpeg, *; q=.2, */*; q=.2
Connection: keep-alive
Authorization: NTLM TlXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX


HTTP/1.1 200 OK
Server: Microsoft-IIS/5.0
Date: Tue, 30 Sep 2003 13:24:50 GMT
Content-Type: application/octet-stream
Accept-Ranges: bytes
Last-Modified: Mon, 29 Sep 2003 15:42:02 GMT
ETag: "b45df39a086c31:848"
Content-Length: 2749


However, when attempting to load the ImageIO classes, a different sequence occurs - trying to download the javax.imageio.spi.ImageTranscoderSpi from the META-INF/services directory.  Note that this happens for a standalone applet, or for an applet in a jar file.  In this case, the sequence is
HEAD -> Access Denied -> HEAD -> Access Denied:

HEAD /ntlm/test/META-INF/services/javax.imageio.spi.ImageTranscoderSpi HTTP/1.1
User-Agent: Mozilla/4.0 (Windows.XP.5.1) Java/1.4.2
Host: canyon
Accept: text/html, image/gif, image/jpeg, *; q=.2, */*; q=.2
Connection:.keep-alive

HTTP/1.1 401 Access Denied
Server: Microsoft-IIS/5.0
Date: Mon, 29 Sep 2003 15:15:45 GMT
WWW-Authenticate: Negotiate
WWW-Authenticate: NTLM
Connection: close
Content-Length: 4431
Content-Type: text/html

HEAD /ntlm/test/META-INF/services/javax.imageio.spi.ImageTranscoderSpi HTTP/1.1
User-Agent: Mozilla/4.0 (Windows XP 5.1) Java/1.4.2
Host: canyon
Accept: text/html, image/gif, image/jpeg, *; q=.2, */*; q=.2
Connection: keep-alive
Authorization: NTLM TlXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX=

HTTP/1.1 401 Access Denied
Server: Microsoft-IIS/5.0
Date: Mon, 29 Sep 2003 15:15:45 GMT
WWW-Authenticate: NTLM TlXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX=
Content-Length: 4033
Content-Type: text/html


After the second "Access Denied" for the HEAD method, the Plugin does not send the required third stage of the NTLM authentication (thus it cannot know whether that file exists or not), nor does it close the connection.  The Plugin waits until the IIS web server times out the connection and sends a reset, after approximately 900-1000 seconds.

This problem does not happen with anything except NTLM, nor with earlier releases.  Indeed, this is more of a problem since deployments that worked fine with 1.4.1, by having NTLM and (say) Basic authentication, will now work very poorly indeed, by using NTLM.

The thread from which the Class.forName() call is made, or the first direct access of the ImageIO classes is made, does not appear to matter.  The applet lifecycle thread, the AWT event thread, or even a completely new thread, all exhibit the same problem.

STEPS TO FOLLOW TO REPRODUCE THE PROBLEM :
Attempt to load the ImageIO class itself via Class.forName().

-or-

Attempt to use the ImageIO class, by calling (for example) getReaderFormatNames().

-or-

Compile the attached test case (below).  Place on an IIS webserver on a server in an NT4-style domain (Windows 2000 was used for the server).  Select "Integrated Windows Authentication" to ensure NTLM authentication.  Create an appropriate HTML page - eg.
<!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.0 Transitional//EN">

<HTML>
<APPLET code=ClassForNameTest
        width=800 height=600>
</APPLET>
</HTML>

Point a web browser at the server, and load the web page.  Click on the button.

EXPECTED VERSUS ACTUAL BEHAVIOR :
EXPECTED -
Class loaded with no exceptions.

-or-

Method returns results.

-or-

TextArea is populated with names of available reader formats.
ACTUAL -
In all cases, a large amount of time passes before control returns to the code that attempts to load or use the ImageIO class.  On the order of 1000 seconds.

ERROR MESSAGES/STACK TRACES THAT OCCUR :
No error messages are produced.

Whilst the Plugin is taking the long amount of time to load the ImageIO class, the following Thread dump can be produced in the Java Console.  Thread-3 is the thread that is attempting to use the ImageIO class:

----------------------------------------------------
Dump thread stack ...
----------------------------------------------------
Full thread dump Java HotSpot(TM) Client VM (1.4.2-b28 mixed mode):

"Thread-3" prio=4 tid=0x0597cea8 nid=0x7dc runnable [716f000..716fd94]
	at java.net.SocketInputStream.socketRead0(Native Method)
	at java.net.SocketInputStream.read(Unknown Source)
	at java.io.BufferedInputStream.fill(Unknown Source)
	at java.io.BufferedInputStream.read1(Unknown Source)
	at java.io.BufferedInputStream.read(Unknown Source)
	- locked <0x100a0b10> (a java.io.BufferedInputStream)
	at sun.net.www.MeteredStream.read(Unknown Source)
	- locked <0x100a0bc0> (a sun.net.www.http.KeepAliveStream)
	at java.io.FilterInputStream.read(Unknown Source)
	at sun.net.www.protocol.http.HttpURLConnection.reset(Unknown Source)
	at sun.net.www.protocol.http.HttpURLConnection.getInputStream(Unknown Source)
	- locked <0x100a0bf0> (a sun.plugin.net.protocol.http.HttpURLConnection)
	at sun.plugin.net.protocol.http.HttpURLConnection.getInputStream(Unknown Source)
	- locked <0x100a0bf0> (a sun.plugin.net.protocol.http.HttpURLConnection)
	at java.net.HttpURLConnection.getResponseCode(Unknown Source)
	at sun.applet.AppletClassLoader.resourceExists(Unknown Source)
	at sun.applet.AppletClassLoader.findResources(Unknown Source)
	at sun.plugin.security.PluginClassLoader.findResourcesByURLPath(Unknown Source)
	at sun.plugin.security.PluginClassLoader.findResources(Unknown Source)
	at java.lang.ClassLoader.getResources(Unknown Source)
	at sun.misc.Service$LazyIterator.hasNext(Unknown Source)
	at javax.imageio.spi.IIORegistry.registerApplicationClasspathSpis(Unknown Source)
	at javax.imageio.spi.IIORegistry.<init>(Unknown Source)
	at javax.imageio.spi.IIORegistry.getDefaultInstance(Unknown Source)
	at javax.imageio.ImageIO.<clinit>(Unknown Source)
	at ClassForNameTest$2.run(ClassForNameTest.java:72)
	at java.lang.Thread.run(Unknown Source)

"AWT-EventQueue-2" prio=4 tid=0x0585acc0 nid=0xa44 in Object.wait() [7a8f000..7a8fd94]
	at java.lang.Object.wait(Native Method)
	- waiting on <0x107d18c0> (a java.awt.EventQueue)
	at java.lang.Object.wait(Unknown Source)
	at java.awt.EventQueue.getNextEvent(Unknown Source)
	- locked <0x107d18c0> (a java.awt.EventQueue)
	at java.awt.EventDispatchThread.pumpOneEventForHierarchy(Unknown Source)
	at java.awt.EventDispatchThread.pumpEventsForHierarchy(Unknown Source)
	at java.awt.EventDispatchThread.pumpEvents(Unknown Source)
	at java.awt.EventDispatchThread.pumpEvents(Unknown Source)
	at java.awt.EventDispatchThread.run(Unknown Source)

"TimerQueue" daemon prio=5 tid=0x05982ff8 nid=0xa7c in Object.wait() [780f000..780fd94]
	at java.lang.Object.wait(Native Method)
	- waiting on <0x107f8998> (a javax.swing.TimerQueue)
	at javax.swing.TimerQueue.run(Unknown Source)
	- locked <0x107f8998> (a javax.swing.TimerQueue)
	at java.lang.Thread.run(Unknown Source)

"AWT-EventQueue-1" prio=7 tid=0x0591bb58 nid=0xe80 waiting on condition [757f000..757fd94]
	at sun.plugin.JavaRunTime.dumpAllStacks(Native Method)
	at sun.plugin.ConsoleWindow$1.actionPerformed(Unknown Source)
	at javax.swing.JComponent$ActionStandin.actionPerformed(Unknown Source)
	at javax.swing.SwingUtilities.notifyAction(Unknown Source)
	at javax.swing.JComponent.processKeyBinding(Unknown Source)
	at javax.swing.KeyboardManager.fireBinding(Unknown Source)
	at javax.swing.KeyboardManager.fireKeyboardAction(Unknown Source)
	at javax.swing.JComponent.processKeyBindingsForAllComponents(Unknown Source)
	at javax.swing.JComponent.processKeyBindings(Unknown Source)
	at javax.swing.JComponent.processKeyEvent(Unknown Source)
	at java.awt.Component.processEvent(Unknown Source)
	at java.awt.Container.processEvent(Unknown Source)
	at java.awt.Component.dispatchEventImpl(Unknown Source)
	at java.awt.Container.dispatchEventImpl(Unknown Source)
	at java.awt.Component.dispatchEvent(Unknown Source)
	at java.awt.KeyboardFocusManager.redispatchEvent(Unknown Source)
	at java.awt.DefaultKeyboardFocusManager.dispatchKeyEvent(Unknown Source)
	at java.awt.DefaultKeyboardFocusManager.preDispatchKeyEvent(Unknown Source)
	at java.awt.DefaultKeyboardFocusManager.typeAheadAssertions(Unknown Source)
	at java.awt.DefaultKeyboardFocusManager.dispatchEvent(Unknown Source)
	at java.awt.Component.dispatchEventImpl(Unknown Source)
	at java.awt.Container.dispatchEventImpl(Unknown Source)
	at java.awt.Window.dispatchEventImpl(Unknown Source)
	at java.awt.Component.dispatchEvent(Unknown Source)
	at java.awt.EventQueue.dispatchEvent(Unknown Source)
	at java.awt.EventDispatchThread.pumpOneEventForHierarchy(Unknown Source)
	at java.awt.EventDispatchThread.pumpEventsForHierarchy(Unknown Source)
	at java.awt.EventDispatchThread.pumpEvents(Unknown Source)
	at java.awt.EventDispatchThread.pumpEvents(Unknown Source)
	at java.awt.EventDispatchThread.run(Unknown Source)

"thread applet-ClassForNameTest" prio=4 tid=0x0593aae0 nid=0xe04 in Object.wait() [737f000..737fd94]
	at java.lang.Object.wait(Native Method)
	- waiting on <0x107cf518> (a sun.plugin.AppletViewer)
	at java.lang.Object.wait(Unknown Source)
	at sun.applet.AppletPanel.getNextEvent(Unknown Source)
	- locked <0x107cf518> (a sun.plugin.AppletViewer)
	at sun.applet.AppletPanel.run(Unknown Source)
	at java.lang.Thread.run(Unknown Source)

"AWT-EventQueue-0" prio=7 tid=0x058545c0 nid=0xe18 in Object.wait() [706f000..706fd94]
	at java.lang.Object.wait(Native Method)
	- waiting on <0x107b2e20> (a java.awt.EventQueue)
	at java.lang.Object.wait(Unknown Source)
	at java.awt.EventQueue.getNextEvent(Unknown Source)
	- locked <0x107b2e20> (a java.awt.EventQueue)
	at java.awt.EventDispatchThread.pumpOneEventForHierarchy(Unknown Source)
	at java.awt.EventDispatchThread.pumpEventsForHierarchy(Unknown Source)
	at java.awt.EventDispatchThread.pumpEvents(Unknown Source)
	at java.awt.EventDispatchThread.pumpEvents(Unknown Source)
	at java.awt.EventDispatchThread.run(Unknown Source)

"Java2D Disposer" daemon prio=10 tid=0x05853f20 nid=0xe54 in Object.wait() [6f6f000..6f6fd94]
	at java.lang.Object.wait(Native Method)
	- waiting on <0x107cf818> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(Unknown Source)
	- locked <0x107cf818> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(Unknown Source)
	at sun.java2d.Disposer.run(Unknown Source)
	at java.lang.Thread.run(Unknown Source)

"Main Console Writer" prio=7 tid=0x0584ec58 nid=0xc3c in Object.wait() [6e6f000..6e6fd94]
	at java.lang.Object.wait(Native Method)
	- waiting on <0x107b5eb0> (a java.util.LinkedList)
	at java.lang.Object.wait(Unknown Source)
	at sun.plugin.MainConsoleWriter.run(Unknown Source)
	- locked <0x107b5eb0> (a java.util.LinkedList)
	at java.lang.Thread.run(Unknown Source)

"AWT-Windows" daemon prio=7 tid=0x05831978 nid=0xe70 runnable [6d6f000..6d6fd94]
	at sun.awt.windows.WToolkit.eventLoop(Native Method)
	at sun.awt.windows.WToolkit.run(Unknown Source)
	at java.lang.Thread.run(Unknown Source)

"AWT-Shutdown" prio=5 tid=0x05831678 nid=0xe4c in Object.wait() [6c6f000..6c6fd94]
	at java.lang.Object.wait(Native Method)
	- waiting on <0x10790070> (a java.lang.Object)
	at java.lang.Object.wait(Unknown Source)
	at sun.awt.AWTAutoShutdown.run(Unknown Source)
	- locked <0x10790070> (a java.lang.Object)
	at java.lang.Thread.run(Unknown Source)

"Signal Dispatcher" daemon prio=10 tid=0x0003f398 nid=0xbfc runnable [0..0]

"Finalizer" daemon prio=9 tid=0x02a44168 nid=0xd64 in Object.wait() [53df000..53dfd94]
	at java.lang.Object.wait(Native Method)
	- waiting on <0x10790170> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(Unknown Source)
	- locked <0x10790170> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(Unknown Source)
	at java.lang.ref.Finalizer$FinalizerThread.run(Unknown Source)

"Reference Handler" daemon prio=10 tid=0x02a42d38 nid=0xf9c in Object.wait() [52df000..52dfd94]
	at java.lang.Object.wait(Native Method)
	- waiting on <0x107901d8> (a java.lang.ref.Reference$Lock)
	at java.lang.Object.wait(Unknown Source)
	at java.lang.ref.Reference$ReferenceHandler.run(Unknown Source)
	- locked <0x107901d8> (a java.lang.ref.Reference$Lock)

"main" prio=5 tid=0x029f30a0 nid=0xc94 runnable [0..13e870]

"VM Thread" prio=5 tid=0x02a84698 nid=0xe28 runnable

"VM Periodic Task Thread" prio=10 tid=0x02a52ba0 nid=0xd10 waiting on condition
"Suspend Checker Thread" prio=10 tid=0x0003ea50 nid=0xdcc runnable
----------------------------------------------------
Done.



REPRODUCIBILITY :
This bug can be reproduced always.

---------- BEGIN SOURCE ----------
import java.applet.Applet;
import java.awt.BorderLayout;
import java.awt.Button;
import java.awt.Frame;
import java.awt.TextArea;
import java.awt.event.ActionListener;
import java.awt.event.ActionEvent;
import java.awt.eve

                                    

Comments
CONVERTED DATA

BugTraq+ Release Management Values

COMMIT TO FIX:
1.4.2_05
generic
tiger-beta2

FIXED IN:
1.4.2_05
tiger-beta2

INTEGRATED IN:
1.4.2_05
tiger-b46
tiger-beta2


                                     
2004-06-14
EVALUATION

Plugin does not handle NTLM negotiation. Re-assign to networking team for investigation.


###@###.### 2004-02-03

There is a problem in the HttpURLConnection.reset() function which
blocks until the server closes the connection, during HTTP HEAD requests
Need to fix this for tiger.

###@###.### 2004-03-22
                                     
2004-03-22



Hardware and Software, Engineered to Work Together