Menu
AIX 64bit, 7G RAM
$ uname -a
AIX server3 1 7 00036073D600
$ java -version
java version "1.6.0"
Java(TM) SE Runtime Environment (build pap6460_26sr1-20111114_01(SR1))
IBM J9 VM (build 2.6, JRE 1.6.0 AIX ppc64-64 20111113_94967 (JIT enabled, AOT enabled)
J9VM - R26_Java626_SR1_20111113_1649_B94967
JIT - r11_20111028_21230
GC - R26_Java626_SR1_20111113_1649_B94967
J9CL - 20111113_94967)
JCL - 20111112_01
$ time /opt/IBM/WebSphere/AppServer/java/bin/java
...
real 0m40.62s
user 0m0.43s
sys 0m0.04s
It takes 40s to start java command without any application. The JRE(64bit) is part of WebSphere V8, and need 20 min. to start Application Server.
In the same AIX, there is another JRE(32bit), it works very well.
$ /usr/java6/bin/java -version
java version "1.6.0"
Java(TM) SE Runtime Environment (build pap3260sr9fp2-20110627_03(SR9 FP2))
IBM J9 VM (build 2.4, JRE 1.6.0 IBM J9 2.4 AIX ppc-32 jvmap3260sr9-20110624_85526 (JIT enabled, AOT enabled)
J9VM - 20110624_085526
JIT - r9_20101028_17488ifx17
GC - 20101027_AA)
JCL - 20110530_01
$ time /usr/java6/bin/java
real 0m0.70s
user 0m0.64s
sys 0m0.05s
I found some thing using truss.When java is going to startup, it is blocked at thread_tsleep() for a long time. Why? How to correct it?
kopen("/etc/irs.conf", O_RDONLY) Err#2 ENOENT
_thread_self() = 26738737
getdomainname(0x09001000A00E44F8, 1024) = 0
_thread_self() = 26738737
_thread_self() = 26738737
_thread_self() = 26738737
getdomainname(0x09001000A00E44F8, 1024) = 0
_thread_self() = 26738737
_thread_self() = 26738737
_thread_self() = 26738737
kopen("/etc/hesiod.conf", O_RDONLY) Err#2 ENOENT
_thread_self() = 26738737
getdomainname(0x09001000A00E44F8, 1024) = 0
_thread_self() = 26738737
_thread_self() = 26738737
_thread_self() = 26738737
getdomainname(0x09001000A00E44F8, 1024) = 0
_thread_self() = 26738737
_thread_self() = 26738737
_thread_self() = 26738737
getdomainname(0x09001000A00E44F8, 1024) = 0
_thread_self() = 26738737
_thread_self() = 26738737
socket(2, 2, 0) = 4
getsockopt(4, 65535, 4104, 0x000001001012A934, 0x000001001012A930) = 0
connext(4, 0x00000100103F37B8, 16) = 0
_esend(4, 0x000001001012B860, 40, 0, 0x0000000000000000) = 40
_poll(0x000001001012AA00, 1, 5000) = 1
_enrecvfrom(4, 0x000001001012CBB0, 1024, 0, 0x000001001012B1C0, 0x000001001012A9E8, 0x0000000000000000) = 56
close(4) = 0
socket(2, 2, 0) = 4
getsockopt(4, 65535, 4104, 0x000001001012A934, 0x000001001012A930) = 0
connext(4, 0x00000100103F37B8, 16) = 0
_esend(4, 0x000001001012B860, 40, 0, 0x0000000000000000) = 40
_poll(0x000001001012AA00, 1, 5000) = 1
_enrecvfrom(4, 0x000001001012CBB0, 1024, 0, 0x000001001012B1C0, 0x000001001012A9E8, 0x0000000000000000) = 94
_esend(4, 0x000001001012B860, 25, 0, 0x0000000000000000) = 25
_poll(0x000001001012AA00, 1, 5000) = 1
_enrecvfrom(4, 0x000001001012CBB0, 1024, 0, 0x000001001012B1C0, 0x000001001012A9E8, 0x0000000000000000) = 25
close(4) = 0
socket(2, 2, 0) = 4
_esendto(4, 0x000001001012B860, 25, 0, 0x00000100103F37C8, 16, 0x0000000000000000) = 25
thread_tsleep(0, 0x09001000A030F400, 0x0000000000000000, 0x0000000000000000) (sleeping...)
_poll(0x000001001012AA00, 1, 5000) = 0
close(4) = 0
socket(2, 2, 0) = 4
_esendto(4, 0x000001001012B860, 25, 0, 0x00000100103F37C8, 16, 0x0000000000000000) = 25
thread_tsleep(0, 0x09001000A030F400, 0x0000000000000000, 0x0000000000000000) (sleeping...)
_poll(0x000001001012AA00, 1, 5000) = 0
close(4) = 0
socket(2, 2, 0) = 4
_esendto(4, 0x000001001012B860, 25, 0, 0x00000100103F37C8, 16, 0x0000000000000000) = 25
thread_tsleep(0, 0x09001000A030F400, 0x0000000000000000, 0x0000000000000000) (sleeping...)
_poll(0x000001001012AA00, 1, 10000) = 0
close(4) = 0
socket(2, 2, 0) = 4
_esendto(4, 0x000001001012B860, 25, 0, 0x00000100103F37C8, 16, 0x0000000000000000) = 25
thread_tsleep(0, 0x09001000A030F400, 0x0000000000000000, 0x0000000000000000) (sleeping...)
_poll(0x000001001012AA00, 1, 20000) = 0
close(4) = 0
getdomainname(0x000001001012CD10, 256) = 0
kopen("/etc/hosts", O_RDONLY) = 4
kioctl(4, 22528, 0x0000000000000000, 0x0000000000000000) Err#25 ENOTTY
kfcntl(4, F_SETFD, 0x0000000000000001) = 0
kioctl(4, 22528, 0x0000000000000000, 0x0000000000000000) Err#25 ENOTTY
kread(0x0000000000000004, 0x0000010010416538, 0x0000000000001000) = 0x00000000000007B0
0x00000000: " # = = = = = = = = = ="..
kread(0x0000000000000004, 0x0000010010416538, 0x0000000000001000) = 0x0000000000000000
0x00000000: " # = = = = = = = = = ="..
close(4) = 0
__libc_sbrk(0x0000000000020020) = 0x0000010010421C20
with timestamp
1.8662: socket(2, 2, 0) = 4
1.8666: _esendto(4, 0x000001001012B860, 25, 0, 0x00000100103F38A8, 16, 0x0000000000000000) = 25
3.8671: thread_tsleep(0, 0x09001000A030F400, 0x0000000000000000, 0x0000000000000000) (sleeping...)
1.8669: _poll(0x000001001012AA00, 1, 5000) = 0
6.8705: close(4) = 0
6.8710: socket(2, 2, 0) = 4
6.8715: _esendto(4, 0x000001001012B860, 25, 0, 0x00000100103F38A8, 16, 0x0000000000000000) = 25
8.8723: thread_tsleep(0, 0x09001000A030F400, 0x0000000000000000, 0x0000000000000000) (sleeping...)
6.8720: _poll(0x000001001012AA00, 1, 5000) = 0
11.8726: close(4) = 0
11.8729: socket(2, 2, 0) = 4
11.8732: _esendto(4, 0x000001001012B860, 25, 0, 0x00000100103F38A8, 16, 0x0000000000000000) = 25
13.8738: thread_tsleep(0, 0x09001000A030F400, 0x0000000000000000, 0x0000000000000000) (sleeping...)
11.8736: _poll(0x000001001012AA00, 1, 10000) = 0
21.8741: close(4) = 0
21.8744: socket(2, 2, 0) = 4
21.8748: _esendto(4, 0x000001001012B860, 25, 0, 0x00000100103F38A8, 16, 0x0000000000000000) = 25
23.8754: thread_tsleep(0, 0x09001000A030F400, 0x0000000000000000, 0x0000000000000000) (sleeping...)
21.8752: _poll(0x000001001012AA00, 1, 20000) = 0
41.8756: close(4) = 0
41.8760: getdomainname(0x000001001012CD10, 256) = 0
41.8763: kopen("/etc/hosts", O_RDONLY) = 4
41.8767: kioctl(4, 22528, 0x0000000000000000, 0x0000000000000000) Err#25 ENOTTY
41.8770: kfcntl(4, F_SETFD, 0x0000000000000001) = 0
41.8773: kioctl(4, 22528, 0x0000000000000000, 0x0000000000000000) Err#25 ENOTTY
kread(0x0000000000000004, 0x0000010010416618, 0x0000000000001000) = 0x00000000000007B0
0x00000000: " # = = = = = = = = = ="..
kread(0x0000000000000004, 0x0000010010416618, 0x0000000000001000) = 0x0000000000000000
0x00000000: " # = = = = = = = = = ="..
41.8782: close(4) = 0
tp
Quit in sem_wait at 0x9000000002632d8 ($t3)
0x9000000002632d8 (sem_wait+0x98) e8410028 ld r2,0x28(r1)
thread state-k wchan state-u k-tid mode held scope function
>$t1 run blocked 31391751 u no sys _event_sleep
_event_sleep(??, ??, ??, ??, ??, ??) at 0x9000000008365c4
_event_wait(??, ??) at 0x900000000837064
_cond_wait_local(??, ??, ??) at 0x90000000084521c
_cond_wait(??, ??, ??) at 0x900000000845808
pthread_join(??, ??) at 0x90000000082d2b0
unnamed block in ContinueInNewThread(continuation = 0x6c6f636b6c002e66, stack_size = 7310577395057127012, args = 0x5f6f72002e666574), line 2286 in "java_md.c"
ContinueInNewThread(continuation = 0x6c6f636b6c002e66, stack_size = 7310577395057127012, args = 0x5f6f72002e666574), line 2286 in "java_md.c"
unnamed block in main(argc = 0, argv = 0x000001001000c178), line 532 in "java.c"
main(argc = 0, argv = 0x000001001000c178), line 532 in "java.c"
thread state-k wchan state-u k-tid mode held scope function
>$t2 run running 54329549 u no sys __fd_poll
__fd_poll(??, ??, ??) at 0x90000000012c0d4
res_send.poll(??, ??, ??) at 0x9000000001021ac
res_nsend(0x100103f37a8, 0x1001012b860, 0x1900000019, 0x1001012cbb0, 0x40000000400) at 0x9000000001011d4
res_nquery(??, ??, ??, ??, ??, ??) at 0x90000000012b5d8
res_nquerydomain(??, ??, ??, ??, ??, ??, ??) at 0x90000000012ab14
res_nsearch(??, ??, ??, ??, ??, ??) at 0x90000000012af08
res_search(??, ??, ??, ??, ??) at 0x900000000107b50
dns_ho.ho_byname2(??, ??, ??) at 0x90000000013a384
gen_ho.ho_byname2(??, ??, ??) at 0x900000000163888
gethostbyname2(??, ??) at 0x9000000001060ec
getaddrinfo2(??, ??, ??, ??, ??) at 0x900000000102ba0
getaddrinfo(??, ??, ??, ??) at 0x900000000104d34
j9sock_getaddrinfo() at 0x9000000053caad8
populateRASNetData() at 0x900000005347fc0
VMInitStages() at 0x9000000053086b0
runJ9VMDllMain() at 0x90000000530bb9c
pool.pool_do() at 0x9000000052f29c8
runInitializationStage() at 0x90000000530b890
protectedInitializeJavaVM() at 0x900000005306478
j9sig_protect() at 0x9000000053a2b9c
initializeJavaVM() at 0x90000000530585c
jniinv.JNI_CreateJavaVM() at 0x90000000530ea14
jvm.JNI_CreateJavaVM() at 0x900000000ccc510
redirector.JNI_CreateJavaVM() at 0x900000000cb5574
InitializeJVM(pvm = (nil), penv = (nil), ifn = (nil)), line 1801 in "java.c"
main(argc = 0, argv = (nil)), line 810 in "java.c"
thread state-k wchan state-u k-tid mode held scope function
>$t3 run running 52887625 k no sys sem_wait
sem_wait(??) at 0x9000000002632d8
asynchSignalReporter() at 0x9000000053a3dcc
thread_wrapper() at 0x900000000d00ad0
!!!! ThreadDump Completed- detached from debugger !!!!
Update
I found this topic, and test the program on my AIX. When using hostname, it delayed for about 40s for DNS query. IP Address is normal.
Java cannot resolve DNS address from AIX: UnknownHostException
By the way, the hostname shows server3, when I ping the name, it shows : PING server3.cf1.xx.xxxx.com ..... I run the program using server3.cf1.xx.xxxx.com, there is no delay.
Update2:
It is IPV6 problem. If I add -Djava.net.preferIPv4Stack=true, the java application runs well. But java command still uses IPV6 to query DNS. So java command has 40s delay, and java application has no deley on DNS query.
Can I set the default protocol to IPV4 in AIX, not java parameter?
486
I'm not 100% sure on this, but it's at least worth a try:
On AIX, the 32 bit Java VM uses IPv4 as the default IP protocol, while the 64 bit VM uses IPv6. If IPv6 is enabled in the operating system, but incorrectly configured, the 64 bit VM may seem to hang at different points, where it actually is waiting for network timeouts. This seem to match your analysis with truss.
You can try to start the 64 bit VM with IPv4 as the preferred network stack by adding the following option to the java command:
-Djava.net.preferIPv4Stack=true
147
If you love us? You can donate to us via Paypal or buy me a coffee so we can maintain and grow! Thank you!
Donate Us With
