Board index » jbuilder » Re: much slower out of the IDE

Re: much slower out of the IDE


2005-07-13 06:06:41 AM
jbuilder13
dingfelder wrote:
Quote
I look forward to your thoughts...
How sure are you that you're using the same Java VM version each time?
Make a simple class that prints the value of the java.version property.
Something like this:
package junk;
public class Junk {
public static void main(String args[]) {
System.out.println("java.version = " +
System.getProperty("java.version"));
}
}
Then run that class each of the three ways and see if you get the same
information each time.
--
Gillmer J. Derge [TeamB]
 
 

Re:Re: much slower out of the IDE

dingfelder wrote:
Quote
while it was creating a connection, I killed it and got:

Full thread dump Java HotSpot(TM) Client VM (1.5.0_03-b07 mixed mode, sharing):

"Thread-2" prio=7 tid=0x03a7ec10 nid=0x8a4 runnable [0x03e3f000..0x03e3f9e4]
at java.net.Inet4AddressImpl.getHostByAddr(Native Method)
at java.net.InetAddress$1.getHostByAddr(InetAddress.java:842)
at java.net.InetAddress.getHostFromNameService(InetAddress.java:532)

Does anything stand out as unusual?
Oooo. Lots of questions now...
On what machine does this database reside? The localhost, or a
different machine? If it is localhost, are you addressing by
"localhost" or "127.0.0.1" or by sctual name? If it is a different
machine, how is your machine resolving names? WINS? DNS?
--
Regards,
Lori Olson [TeamB]
------------
Save yourself, and everyone else, some time and search the
newsgroups and the FAQ-O-Matic before posting your next
question.
Google Advanced Newsgroup Search
www.google.ca/advanced_group_search
Other Newsgroup Searches:
www.borland.com/newsgroups/ngsearch.html
Joi Ellis's FAQ-O-Matic:
www.visi.com/~gyles19/fom-serve/cache/1.html
 

Re:Re: much slower out of the IDE

dingfelder wrote:
Quote
while it was creating a connection, I killed it and got:

Full thread dump Java HotSpot(TM) Client VM (1.5.0_03-b07 mixed mode, sharing):

"Thread-2" prio=7 tid=0x03a7ec10 nid=0x8a4 runnable [0x03e3f000..0x03e3f9e4]
at java.net.Inet4AddressImpl.getHostByAddr(Native Method)
at java.net.InetAddress$1.getHostByAddr(InetAddress.java:842)
at java.net.InetAddress.getHostFromNameService(InetAddress.java:532)
at java.net.InetAddress.getHostName(InetAddress.java:475)
at java.net.InetAddress.getHostName(InetAddress.java:447)
at java.net.InetSocketAddress.getHostName(InetSocketAddress.java:210)
[snip]
at com.sirtrack.kiwipicadmin.KiwiPicDBMgr.connectSDB(KiwiPicDBMgr.java:352)
[snip]
"AWT-EventQueue-0" prio=7 tid=0x00e76c68 nid=0x9f4 runnable [0x03a3e000..0x03a3fae4]
at java.awt.FontMetrics.initIDs(Native Method)
[snip]
at com.sirtrack.kiwipicadmin.KiwiPicAdminUI.<init>(KiwiPicAdminUI.java:311)
[snip]

Does anything stand out as unusual?
As Lori already pointed out, the hostname lookup seems to be the
problem. Check how your machine (and Java VM) is resolving names.
To me it seems that the socket implementation is trying to do a
reverse lookup to obtain the hostname of the IP address. This is
causing the delay, because the name resolving entity might not
know your IP address and then is forwarding the request to some
remote entity (DNS). In the end this lookup could be failing
silently.
The difference is probably that in the IDE some other socket
factory or other system property tells the VM to not to do the
hostname lookup. Follow Gillmer's suggestion to check wheather
in each case you are using the same VM installation.
As a second point, please ensure with another thread dump a few
seconds later, that the AWT-EventQueue-0 is done with the setup
and is waiting for your JDBC connection.
Cheers,
Christoph
 

{smallsort}

Re:Re: much slower out of the IDE

RE the second point, I did another thread dump a few seconds later...
I still see AWT-EventQueue-0...
I should maybe detail the process so you have some idea what is happening at the moment:
1. As the app starts, the first thing that happens is a "manager" object is created.
2. This mgr fires off a thread to connect to the DB.
3. The gui then does it's jbinit
4. When done, the gui fires off a second thread to "wait" until the DB is ready, and displays a "connecting" message until the mgr says it is connected.
(So, the DB connection is in a different thread from the AWT stuff)
Here is the thread dump:
Full thread dump Java HotSpot(TM) Client VM (1.5.0_03-b07 mixed mode, sharing):
"Thread-3" prio=7 tid=0x03afada8 nid=0x9f4 waiting on condition [0x046bf000..0x046bfce4]
at java.lang.Thread.sleep(Native Method)
at com.sirtrack.common.thread.SirtrackThread.Sleep(SirtrackThread.java:33)
at com.sirtrack.kiwipicadmin.KiwiPicAdminUI$UpdateDBStatusThread.run(KiwiPicAdminUI.java:3242)
"TimerQueue" daemon prio=5 tid=0x03aa5df0 nid=0x938 in Object.wait() [0x0447f000..0x0447fd64]
at java.lang.Object.wait(Native Method)
- waiting on <0x2308a228>(a javax.swing.TimerQueue)
at javax.swing.TimerQueue.run(TimerQueue.java:233)
- locked <0x2308a228>(a javax.swing.TimerQueue)
at java.lang.Thread.run(Thread.java:595)
"Thread-2" prio=7 tid=0x03a48278 nid=0x914 runnable [0x03e3f000..0x03e3f9e4]
at java.net.Inet4AddressImpl.getHostByAddr(Native Method)
at java.net.InetAddress$1.getHostByAddr(InetAddress.java:842)
at java.net.InetAddress.getHostFromNameService(InetAddress.java:532)
at java.net.InetAddress.getHostName(InetAddress.java:475)
at java.net.InetAddress.getHostName(InetAddress.java:447)
at java.net.InetSocketAddress.getHostName(InetSocketAddress.java:210)
at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:341)
at java.net.Socket.connect(Socket.java:507)
at java.net.Socket.connect(Socket.java:457)
at java.net.Socket.<init>(Socket.java:365)
at java.net.Socket.<init>(Socket.java:207)
at com.mysql.jdbc.StandardSocketFactory.connect(StandardSocketFactory.java:142)
at com.mysql.jdbc.MysqlIO.<init>(MysqlIO.java:280)
at com.mysql.jdbc.Connection.createNewIO(Connection.java:1774)
at com.mysql.jdbc.Connection.<init>(Connection.java:437)
at com.mysql.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:268)
at java.sql.DriverManager.getConnection(DriverManager.java:525)
- locked <0x26b6c288>(a java.lang.Class)
at java.sql.DriverManager.getConnection(DriverManager.java:171)
- locked <0x26b6c288>(a java.lang.Class)
at com.sirtrack.common.db.DBConn.createConn(DBConn.java:101)
at com.sirtrack.kiwipicadmin.KiwiPicDBMgr.connectEXO(KiwiPicDBMgr.java:372)
at com.sirtrack.kiwipicadmin.KiwiPicDBMgr.<init>(KiwiPicDBMgr.java:53)
at com.sirtrack.kiwipicadmin.KiwiPicDBMgr.<clinit>(KiwiPicDBMgr.java:41)
at com.sirtrack.kiwipicadmin.KiwiPicAdminMgr$StartDBThread.run(KiwiPicAdminMgr.java:823)
"Java2D Disposer" daemon prio=10 tid=0x00ea70f0 nid=0x9b4 in Object.wait() [0x03d3f000..0x03d3fa64]
at java.lang.Object.wait(Native Method)
- waiting on <0x22fe55b0>(a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:116)
- locked <0x22fe55b0>(a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:132)
at sun.java2d.Disposer.run(Disposer.java:107)
at java.lang.Thread.run(Thread.java:595)
"DestroyJavaVM" prio=5 tid=0x002f7120 nid=0x6cc waiting on condition [0x00000000..0x0012fcf4]
"AWT-EventQueue-0" prio=7 tid=0x00e7a620 nid=0x698 in Object.wait() [0x03a3f000..0x03a3fae4]
at java.lang.Object.wait(Native Method)
- waiting on <0x22fc0528>(a java.awt.EventQueue)
at java.lang.Object.wait(Object.java:474)
at java.awt.EventQueue.getNextEvent(EventQueue.java:345)
- locked <0x22fc0528>(a java.awt.EventQueue)
at java.awt.EventDispatchThread.pumpOneEventForHierarchy(EventDispatchThread.java:189)
at java.awt.EventDispatchThread.pumpEventsForHierarchy(EventDispatchThread.java:163)
at java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:157)
at java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:149)
at java.awt.EventDispatchThread.run(EventDispatchThread.java:110)
"AWT-Windows" daemon prio=7 tid=0x00e797a0 nid=0x9cc runnable [0x0392f000..0x0392fb64]
at sun.awt.windows.WToolkit.eventLoop(Native Method)
at sun.awt.windows.WToolkit.run(WToolkit.java:269)
at java.lang.Thread.run(Thread.java:595)
"AWT-Shutdown" prio=5 tid=0x00e792d0 nid=0x6b8 in Object.wait() [0x0382f000..0x0382fbe4]
at java.lang.Object.wait(Native Method)
- waiting on <0x22fc0630>(a java.lang.Object)
at java.lang.Object.wait(Object.java:474)
at sun.awt.AWTAutoShutdown.run(AWTAutoShutdown.java:259)
- locked <0x22fc0630>(a java.lang.Object)
at java.lang.Thread.run(Thread.java:595)
"Low Memory Detector" daemon prio=5 tid=0x00e4dfd8 nid=0x9dc runnable [0x00000000..0x00000000]
"CompilerThread0" daemon prio=10 tid=0x00e4c990 nid=0x95c waiting on condition [0x00000000..0x034ef748]
"Signal Dispatcher" daemon prio=10 tid=0x00e4bb98 nid=0x9ac waiting on condition [0x00000000..0x00000000]
"Finalizer" daemon prio=9 tid=0x00e27818 nid=0x9f0 in Object.wait() [0x032ef000..0x032ef9e4]
at java.lang.Object.wait(Native Method)
- waiting on <0x22fc07d8>(a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:116)
- locked <0x22fc07d8>(a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:132)
at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)
"Reference Handler" daemon prio=10 tid=0x00e48af0 nid=0x9e4 in Object.wait() [0x031ef000..0x031efae4]
at java.lang.Object.wait(Native Method)
- waiting on <0x22fc0430>(a java.lang.ref.Reference$Lock)
at java.lang.Object.wait(Object.java:474)
at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116)
- locked <0x22fc0430>(a java.lang.ref.Reference$Lock)
"VM Thread" prio=10 tid=0x00e19f80 nid=0x7c8 runnable
"VM Periodic Task Thread" prio=10 tid=0x00e4f570 nid=0x898 waiting on condition
Quote

As a second point, please ensure with another thread dump a few
seconds later, that the AWT-EventQueue-0 is done with the setup
and is waiting for your JDBC connection.

Cheers,
Christoph
 

Re:Re: much slower out of the IDE

Interesting.
I specified to use 1.4.2_04 in the project settings and the IDE does this correctly.
I also specifically set a JAVA_HOME environment variable to 1.4.2_04 and this is the first dir in the path as well
I added that line to my code and determined that it is using 1.5.0_03 in the jar and exe.
How can you make the jar file use a particular JVM if it does not use the path of JAVA home variable?
"Gillmer J. Derge [TeamB]" < XXXX@XXXXX.COM >wrote:
Quote
dingfelder wrote:
>I look forward to your thoughts...

How sure are you that you're using the same Java VM version each time?

Make a simple class that prints the value of the java.version property.
Something like this:

package junk;
public class Junk {
public static void main(String args[]) {
System.out.println("java.version = " +
System.getProperty("java.version"));
}
}

Then run that class each of the three ways and see if you get the same
information each time.

--
Gillmer J. Derge [TeamB]
 

Re:Re: much slower out of the IDE

Quote
Oooo. Lots of questions now...

On what machine does this database reside? The localhost, or a
different machine? If it is localhost, are you addressing by
"localhost" or "127.0.0.1" or by sctual name? If it is a different
machine, how is your machine resolving names? WINS? DNS?

--

Regards,

Lori Olson [TeamB]
The DB is on a seperate box (in the same LAN)
It is referred to by IP address.
I am checking with the Sys-Admins to see what they think about the LAN settings
 

Re:Re: much slower out of the IDE

dingfelder wrote:
Quote
Interesting.

I specified to use 1.4.2_04 in the project settings and the IDE does
this correctly.

I also specifically set a JAVA_HOME environment variable to 1.4.2_04
and this is the first dir in the path as well

I added that line to my code and determined that it is using 1.5.0_03
in the jar and exe.

How can you make the jar file use a particular JVM if it does not use
the path of JAVA home variable?

This is one of my pet peeves. On Windows, the "last JDK/JRE in" wins!
There is this bizarre combination of the "stub" java.exe and javaw.exe
in C:\windows\system32 which look up in the registry which actual
version to use. In this case, the last JDK you installed was 1.5.0_03,
so it "wins".
I always perform the following actions:
1. After every JDK/JRE install, I rename/move the java.exe and
javaw.exe in C:\windows\system32
2. I always set JAVA_HOME to the JDK I actually want to be using.
3. I always set my PATH to include %JAVA_HOME%\bin at the front.
Some of that may be redundant, but it is the safest way I have found.
--
Regards,
Lori Olson [TeamB]
------------
Save yourself, and everyone else, some time and search the
newsgroups and the FAQ-O-Matic before posting your next
question.
Google Advanced Newsgroup Search
www.google.ca/advanced_group_search
Other Newsgroup Searches:
www.borland.com/newsgroups/ngsearch.html
Joi Ellis's FAQ-O-Matic:
www.visi.com/~gyles19/fom-serve/cache/1.html
 

Re:Re: much slower out of the IDE

OK, I agree 100% with what you said and I also do most of what you listed... I just didn't previously rename the exes in the windows dir.
I went ahead and did that, but i still get the 1.5 jdk from the jar file.
I know java 1.4 the only java in the path and JAVA_HOME is set to 1.4, additionally, java -version on the command line gives:
C:\>java -version
java version "1.4.2_04"
Playing around with windows settings, I see that the windows "association" for java jar files is set to "C:\Program Files\Java\jdk1.5.0_03\bin\javaw.exe" -jar "%1" %*
If I manually change this to the older 1.4 java, I verified that it does indeed make jar files use 1.4
However, native exe's made from JBuilder still use 1.5
Is there something in the registry or somewhere else that controls this?
(I have no idea what is "in" the exe file so I dont know it's jvm launching logic.)
I realize this is getting way off topic from the original discussion of the slow db connection but I would like to be clear on how this works.
"Lori M Olson [TeamB]" < XXXX@XXXXX.COM >wrote:
Quote
dingfelder wrote:
>Interesting.
>
>I specified to use 1.4.2_04 in the project settings and the IDE does
>this correctly.
>
>I also specifically set a JAVA_HOME environment variable to 1.4.2_04
>and this is the first dir in the path as well
>
>I added that line to my code and determined that it is using 1.5.0_03
>in the jar and exe.
>
>How can you make the jar file use a particular JVM if it does not use
>the path of JAVA home variable?
>

This is one of my pet peeves. On Windows, the "last JDK/JRE in" wins!
There is this bizarre combination of the "stub" java.exe and javaw.exe
in C:\windows\system32 which look up in the registry which actual
version to use. In this case, the last JDK you installed was 1.5.0_03,
so it "wins".

I always perform the following actions:

1. After every JDK/JRE install, I rename/move the java.exe and
javaw.exe in C:\windows\system32

2. I always set JAVA_HOME to the JDK I actually want to be using.

3. I always set my PATH to include %JAVA_HOME%\bin at the front.

Some of that may be redundant, but it is the safest way I have found.

--

Regards,

Lori Olson [TeamB]

------------

Save yourself, and everyone else, some time and search the
newsgroups and the FAQ-O-Matic before posting your next
question.

Google Advanced Newsgroup Search
www.google.ca/advanced_group_search
Other Newsgroup Searches:
www.borland.com/newsgroups/ngsearch.html
Joi Ellis's FAQ-O-Matic:
www.visi.com/~gyles19/fom-serve/cache/1.html
 

Re:Re: much slower out of the IDE

Well, guess what... the issue WAS indeed the DNS / name resolution, or something therein...
I had the sys admin add our server to the name server so a reverse lookup would work
After this, the db connection went from 7 seconds to 2 seconds for the 1st connection, and from 7 to 200ms for the second connection.
The question I wonder though is, why did this help?
I realise that a DNS server entry is needed if you are using a host name, since the dns server has to translate it to an IP address. BUT, since I was already using a ip address, why did it need a dns server at all? *confused*
"C.Reck" < XXXX@XXXXX.COM >wrote:
Quote
dingfelder wrote:
>while it was creating a connection, I killed it and got:
>
>Full thread dump Java HotSpot(TM) Client VM (1.5.0_03-b07 mixed mode, sharing):
>
>"Thread-2" prio=7 tid=0x03a7ec10 nid=0x8a4 runnable [0x03e3f000..0x03e3f9e4]
>at java.net.Inet4AddressImpl.getHostByAddr(Native Method)
>at java.net.InetAddress$1.getHostByAddr(InetAddress.java:842)
>at java.net.InetAddress.getHostFromNameService(InetAddress.java:532)
>at java.net.InetAddress.getHostName(InetAddress.java:475)
>at java.net.InetAddress.getHostName(InetAddress.java:447)
>at java.net.InetSocketAddress.getHostName(InetSocketAddress.java:210)
[snip]
>at com.sirtrack.kiwipicadmin.KiwiPicDBMgr.connectSDB(KiwiPicDBMgr.java:352)
[snip]
>"AWT-EventQueue-0" prio=7 tid=0x00e76c68 nid=0x9f4 runnable [0x03a3e000..0x03a3fae4]
>at java.awt.FontMetrics.initIDs(Native Method)
[snip]
>at com.sirtrack.kiwipicadmin.KiwiPicAdminUI.<init>(KiwiPicAdminUI.java:311)
[snip]
>
>Does anything stand out as unusual?

As Lori already pointed out, the hostname lookup seems to be the
problem. Check how your machine (and Java VM) is resolving names.

To me it seems that the socket implementation is trying to do a
reverse lookup to obtain the hostname of the IP address. This is
causing the delay, because the name resolving entity might not
know your IP address and then is forwarding the request to some
remote entity (DNS). In the end this lookup could be failing
silently.

The difference is probably that in the IDE some other socket
factory or other system property tells the VM to not to do the
hostname lookup. Follow Gillmer's suggestion to check wheather
in each case you are using the same VM installation.


As a second point, please ensure with another thread dump a few
seconds later, that the AWT-EventQueue-0 is done with the setup
and is waiting for your JDBC connection.

Cheers,
Christoph
 

Re:Re: much slower out of the IDE

dingfelder wrote:
Quote
Well, guess what... the issue WAS indeed the DNS / name resolution,
or something therein...

I had the sys admin add our server to the name server so a reverse
lookup would work

After this, the db connection went from 7 seconds to 2 seconds for
the 1st connection, and from 7 to 200ms for the second connection.

The question I wonder though is, why did this help?

I realise that a DNS server entry is needed if you are using a host
name, since the dns server has to translate it to an IP address.
BUT, since I was already using a ip address, why did it need a dns
server at all? *confused*

Sometimes you get reverse-name-lookup stuff happening. Then it has to
translate that IP to a name, and then back again.
I get confused about this name resolution stuff, too. Thankfully, I can
usually just throw up my hands and give up and let my husband (a Unix
sysadmin) figure it out for me ;-)
--
Regards,
Lori Olson [TeamB]
------------
Save yourself, and everyone else, some time and search the
newsgroups and the FAQ-O-Matic before posting your next
question.
Google Advanced Newsgroup Search
www.google.ca/advanced_group_search
Other Newsgroup Searches:
www.borland.com/newsgroups/ngsearch.html
Joi Ellis's FAQ-O-Matic:
www.visi.com/~gyles19/fom-serve/cache/1.html
 

Re:Re: much slower out of the IDE

dingfelder wrote:
Quote
OK, I agree 100% with what you said and I also do most of what you
listed... I just didn't previously rename the exes in the windows
dir.

I went ahead and did that, but i still get the 1.5 jdk from the jar
file.

I know java 1.4 the only java in the path and JAVA_HOME is set to
1.4, additionally, java -version on the command line gives: C:\>java
-version java version "1.4.2_04"

Playing around with windows settings, I see that the windows
"association" for java jar files is set to "C:\Program
Files\Java\jdk1.5.0_03\bin\javaw.exe" -jar "%1" %*

If I manually change this to the older 1.4 java, I verified that it
does indeed make jar files use 1.4

However, native exe's made from JBuilder still use 1.5

Is there something in the registry or somewhere else that controls
this? (I have no idea what is "in" the exe file so I dont know it's
jvm launching logic.)

I realize this is getting way off topic from the original discussion
of the slow db connection but I would like to be clear on how this
works.

Ok, then we get to next step in my paranoid little list.
4. Always make sure that the JDK you want to use is the last one
installed. Even if it means re-installing it (over and over).
--
Regards,
Lori Olson [TeamB]
------------
Save yourself, and everyone else, some time and search the
newsgroups and the FAQ-O-Matic before posting your next
question.
Google Advanced Newsgroup Search
www.google.ca/advanced_group_search
Other Newsgroup Searches:
www.borland.com/newsgroups/ngsearch.html
Joi Ellis's FAQ-O-Matic:
www.visi.com/~gyles19/fom-serve/cache/1.html