RE: I'll buy you dinner if you can help me with strace/java ETIMEDOUT challenge :)

  • From: Timur Akhmadeev <Akhmadeev@xxxxxxxxxxxxxx>
  • To: "Christopher.Taylor2@xxxxxxxxxxxx" <Christopher.Taylor2@xxxxxxxxxxxx>, "oracle-l@xxxxxxxxxxxxx" <oracle-l@xxxxxxxxxxxxx>
  • Date: Fri, 12 Apr 2013 15:23:20 +0000

Hi

You most likely don't need strace with Java when you need to understand the 
basic idea of what's happening. You need to see a thread dump which will list 
all threads' stack traces several times. Then you can tell what's going on. Use 
kill -3 PID (this way thread dump will be in the standard output of the 
process) or $JDK_HOME/bin/jstack PID (this way output will be on your screen 
but a bit different) and post the results here.

Regards
Timur Akhmadeev
-----Original Message-----
From: oracle-l-bounce@xxxxxxxxxxxxx [mailto:oracle-l-bounce@xxxxxxxxxxxxx] On 
Behalf Of Christopher.Taylor2@xxxxxxxxxxxx
Sent: Thursday, April 11, 2013 10:29 PM
To: oracle-l@xxxxxxxxxxxxx
Subject: I'll buy you dinner if you can help me with strace/java ETIMEDOUT 
challenge :)

I'm getting a weird ETIMEDOUT error on a linux appserver connecting to my 
database server in the STRACE output and was curious if anyone has worked 
through anything like this?
This is a JDBC connection using SUN (Oracle) java 1.7

Googling this seems to be [maybe] related to:
a.) IPV6 enabled class where IPV6 is not enabled on the networks involved
b.) network subnets maybe diff between appserver and db server

appserver ifconfig:

bond0     Link encap:Ethernet  HWaddr 00:1B:21:34:C3:D0
          inet addr:10.26.97.67  Bcast:10.26.97.255  Mask:255.255.255.0
          inet6 addr: fe80::21b:21ff:fe34:c3d0/64 Scope:Link
          UP BROADCAST RUNNING MASTER MULTICAST  MTU:1500  Metric:1
          RX packets:3340492299 errors:0 dropped:0 overruns:0 frame:0
          TX packets:3648830057 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:0
          RX bytes:2879521470 (2.6 GiB)  TX bytes:3961401604 (3.6 GiB)

bond1     Link encap:Ethernet  HWaddr 00:22:19:C6:41:AD
          inet addr:10.27.109.22  Bcast:10.27.109.255  Mask:255.255.255.0
          inet6 addr: fe80::222:19ff:fec6:41ad/64 Scope:Link
          UP BROADCAST RUNNING MASTER MULTICAST  MTU:1500  Metric:1
          RX packets:72996 errors:0 dropped:0 overruns:0 frame:0
          TX packets:93 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:0
          RX bytes:17866672 (17.0 MiB)  TX bytes:10896 (10.6 KiB)

dbserver ifconfig:
bond0     Link encap:Ethernet  HWaddr 00:1B:21:34:E6:50
          inet addr:10.26.68.39  Bcast:10.26.68.127  Mask:255.255.255.128
          inet6 addr: fe80::21b:21ff:fe34:e650/64 Scope:Link
          UP BROADCAST RUNNING MASTER MULTICAST  MTU:1500  Metric:1
          RX packets:430735562 errors:0 dropped:0 overruns:0 frame:0
          TX packets:577589649 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:0
          RX bytes:107753963695 (100.3 GiB)  TX bytes:380819453716 (354.6 GiB)

bond0:1   Link encap:Ethernet  HWaddr 00:1B:21:34:E6:50
          inet addr:10.26.68.40  Bcast:10.26.68.127  Mask:255.255.255.128
          UP BROADCAST RUNNING MASTER MULTICAST  MTU:1500  Metric:1

bond1     Link encap:Ethernet  HWaddr 00:22:19:C5:E0:95
          inet addr:10.26.68.146  Bcast:10.26.68.255  Mask:255.255.255.128
          inet6 addr: fe80::222:19ff:fec5:e095/64 Scope:Link
          UP BROADCAST RUNNING MASTER MULTICAST  MTU:1500  Metric:1
          RX packets:3980676804 errors:15217 dropped:150060 overruns:0 
frame:15217
          TX packets:4250933594 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:0
          RX bytes:3531966654287 (3.2 TiB)  TX bytes:3877341563621 (3.5 TiB)

Here's a sample strace output:

17262 12:50:29 clock_gettime(CLOCK_REALTIME,  <unfinished ...>
14670 12:50:29 clock_gettime(CLOCK_REALTIME,  <unfinished ...>
12476 12:50:29 poll([{fd6, events=POLLIN|POLLERR}], 1, -1 <unfinished ...>
12475 12:50:29 clock_gettime(CLOCK_REALTIME,  <unfinished ...>
12474 12:50:29 clock_gettime(CLOCK_REALTIME,  <unfinished ...>
12473 12:50:29 clock_gettime(CLOCK_REALTIME,  <unfinished ...>
12472 12:50:29 clock_gettime(CLOCK_REALTIME,  <unfinished ...>
12468 12:50:29 clock_gettime(CLOCK_REALTIME,  <unfinished ...>
12467 12:50:29 clock_gettime(CLOCK_REALTIME,  <unfinished ...>
12466 12:50:29 futex(0x9699a44, FUTEX_WAIT_PRIVATE, 3, NULL <unfinished ...>
12465 12:50:29 futex(0x9697f44, FUTEX_WAIT_PRIVATE, 3023, NULL <unfinished ...>
12464 12:50:29 futex(0x968d944, FUTEX_WAIT_PRIVATE, 3003, NULL <unfinished ...>
12463 12:50:29 futex(0x12dac28, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
12462 12:50:29 futex(0x964e344, FUTEX_WAIT_PRIVATE, 7435, NULL <unfinished ...>
12461 12:50:29 futex(0x964c744, FUTEX_WAIT_PRIVATE, 2771, NULL <unfinished ...>
12460 12:50:29 clock_gettime(CLOCK_REALTIME,  <unfinished ...>
12459 12:50:29 clock_gettime(CLOCK_REALTIME,  <unfinished ...>
12457 12:50:29 futex(0xb7f59bd8, FUTEX_WAIT, 12459, NULL <unfinished ...>
17262 12:50:29 <... clock_gettime resumed> {1365702629, 722366764}) = 0
14670 12:50:29 <... clock_gettime resumed> {1365702629, 722397845}) = 0
12475 12:50:29 <... clock_gettime resumed> {1365702629, 722473766}) = 0
12474 12:50:29 <... clock_gettime resumed> {1365702629, 722496326}) = 0
12473 12:50:29 <... clock_gettime resumed> {1365702629, 722515323}) = 0
12472 12:50:29 <... clock_gettime resumed> {1365702629, 722530899}) = 0
12468 12:50:29 <... clock_gettime resumed> {1365702629, 722558487}) = 0
12467 12:50:29 <... clock_gettime resumed> {1365702629, 722580907}) = 0
12460 12:50:29 <... clock_gettime resumed> {1365702629, 722767741}) = 0
12459 12:50:29 <... clock_gettime resumed> {1365702629, 722794700}) = 0
17262 12:50:29 futex(0x99f2944, FUTEX_WAIT_PRIVATE, 1, {2, 301991236} 
<unfinished ...>
14670 12:50:29 futex(0x4f838044, FUTEX_WAIT_PRIVATE, 1, {5, 56155155} 
<unfinished ...>
12475 12:50:29 futex(0x4fb43d44, FUTEX_WAIT_PRIVATE, 1, {4, 676453234} 
<unfinished ...>
12474 12:50:29 futex(0x4fb4ad44, FUTEX_WAIT_PRIVATE, 1, {1, 945861674} 
<unfinished ...>
12473 12:50:29 futex(0x4fb17944, FUTEX_WAIT_PRIVATE, 1, {0, 42133677} 
<unfinished ...>
12472 12:50:29 futex(0x500f5344, FUTEX_WAIT_PRIVATE, 1, {0, 729113101} 
<unfinished ...>
12468 12:50:29 futex(0x500c1b44, FUTEX_WAIT_PRIVATE, 1, {5, 55977513} 
<unfinished ...>
12467 12:50:29 futex(0x969ba44, FUTEX_WAIT_PRIVATE, 1, {0, 36074093} 
<unfinished ...>
12460 12:50:29 futex(0x9646b44, FUTEX_WAIT_PRIVATE, 1, {0, 579873259} 
<unfinished ...>
12459 12:50:29 futex(0x95d1644, FUTEX_WAIT_PRIVATE, 1, {0, 572252300} 
<unfinished ...>
12467 12:50:29 <... futex resumed> )    = -1 ETIMEDOUT (Connection timed out)
12467 12:50:29 futex(0x969ba28, FUTEX_WAKE_PRIVATE, 1) = 0
12467 12:50:29 gettimeofday({1365702629, 760854}, NULL) = 0
12467 12:50:29 clock_gettime(CLOCK_MONOTONIC, {5867097, 90650189}) = 0
12467 12:50:29 gettimeofday({1365702629, 760941}, NULL) = 0
12467 12:50:29 clock_gettime(CLOCK_REALTIME, {1365702629, 760981923}) = 0
12467 12:50:29 futex(0x969ba44, FUTEX_WAIT_PRIVATE, 1, {0, 49959077} 
<unfinished ...>
12473 12:50:29 <... futex resumed> )    = -1 ETIMEDOUT (Connection timed out)
12473 12:50:29 futex(0x4fb17928, FUTEX_WAKE_PRIVATE, 1) = 0
12473 12:50:29 clock_gettime(CLOCK_MONOTONIC, {5867097, 96548969}) = 0
12473 12:50:29 clock_gettime(CLOCK_MONOTONIC, {5867097, 96595835}) = 0
12473 12:50:29 clock_gettime(CLOCK_MONOTONIC, {5867097, 96633830}) = 0
12473 12:50:29 gettimeofday({1365702629, 766923}, NULL) = 0
12473 12:50:29 clock_gettime(CLOCK_REALTIME, {1365702629, 766962002}) = 0
12473 12:50:29 futex(0x4fb17944, FUTEX_WAIT_PRIVATE, 1, {0, 960998}) = -1 
ETIMEDOUT (Connection timed out)
12473 12:50:29 futex(0x4fb17928, FUTEX_WAKE_PRIVATE, 1) = 0
12473 12:50:29 clock_gettime(CLOCK_MONOTONIC, {5867097, 98510968}) = 0
12473 12:50:29 clock_gettime(CLOCK_MONOTONIC, {5867097, 98585702}) = 0
12473 12:50:29 clock_gettime(CLOCK_MONOTONIC, {5867097, 98624885}) = 0
12473 12:50:29 gettimeofday({1365702629, 768913}, NULL) = 0
12473 12:50:29 clock_gettime(CLOCK_REALTIME, {1365702629, 768952428}) = 0
12473 12:50:29 futex(0x4fb17944, FUTEX_WAIT_PRIVATE, 1, {0, 99960572} 
<unfinished ...>
12467 12:50:29 <... futex resumed> )    = -1 ETIMEDOUT (Connection timed out)
12467 12:50:29 futex(0x969ba28, FUTEX_WAKE_PRIVATE, 1) = 0
12467 12:50:29 gettimeofday({1365702629, 811796}, NULL) = 0
12467 12:50:29 clock_gettime(CLOCK_MONOTONIC, {5867097, 141593727}) = 0
12467 12:50:29 gettimeofday({1365702629, 811883}, NULL) = 0
12467 12:50:29 clock_gettime(CLOCK_REALTIME, {1365702629, 811922807}) = 0
12467 12:50:29 futex(0x969ba44, FUTEX_WAIT_PRIVATE, 1, {0, 49960193}) = -1 
ETIMEDOUT (Connection timed out)
12467 12:50:29 futex(0x969ba28, FUTEX_WAKE_PRIVATE, 1) = 0
12467 12:50:29 gettimeofday({1365702629, 862767}, NULL) = 0
12467 12:50:29 clock_gettime(CLOCK_MONOTONIC, {5867097, 192576306}) = 0
12467 12:50:29 gettimeofday({1365702629, 862866}, NULL) = 0
12467 12:50:29 clock_gettime(CLOCK_REALTIME, {1365702629, 862905247}) = 0
12467 12:50:29 futex(0x969ba44, FUTEX_WAIT_PRIVATE, 1, {0, 49960753} 
<unfinished ...>
12473 12:50:29 <... futex resumed> )    = -1 ETIMEDOUT (Connection timed out)
12473 12:50:29 futex(0x4fb17928, FUTEX_WAKE_PRIVATE, 1) = 0
12473 12:50:29 clock_gettime(CLOCK_MONOTONIC, {5867097, 199533089}) = 0
12473 12:50:29 clock_gettime(CLOCK_MONOTONIC, {5867097, 199584983}) = 0
12473 12:50:29 clock_gettime(CLOCK_MONOTONIC, {5867097, 199622979}) = 0
12473 12:50:29 gettimeofday({1365702629, 869912}, NULL) = 0
12473 12:50:29 clock_gettime(CLOCK_REALTIME, {1365702629, 869950452}) = 0
12473 12:50:29 futex(0x4fb17944, FUTEX_WAIT_PRIVATE, 1, {0, 961548}) = -1 
ETIMEDOUT (Connection timed out)
12473 12:50:29 futex(0x4fb17928, FUTEX_WAKE_PRIVATE, 1) = 0
12473 12:50:29 clock_gettime(CLOCK_MONOTONIC, {5867097, 201507241}) = 0
12473 12:50:29 clock_gettime(CLOCK_MONOTONIC, {5867097, 201565561}) = 0
12473 12:50:29 clock_gettime(CLOCK_MONOTONIC, {5867097, 201603487}) = 0
12473 12:50:29 gettimeofday({1365702629, 871892}, NULL) = 0
12473 12:50:29 clock_gettime(CLOCK_REALTIME, {1365702629, 871931240}) = 0
12473 12:50:29 futex(0x4fb17944, FUTEX_WAIT_PRIVATE, 1, {0, 99960760} 
<unfinished ...>
12467 12:50:29 <... futex resumed> )    = -1 ETIMEDOUT (Connection timed out)
12467 12:50:29 futex(0x969ba28, FUTEX_WAKE_PRIVATE, 1) = 0
12467 12:50:29 gettimeofday({1365702629, 913790}, NULL) = 0
12467 12:50:29 clock_gettime(CLOCK_MONOTONIC, {5867097, 243595415}) = 0
12467 12:50:29 gettimeofday({1365702629, 913885}, NULL) = 0
12467 12:50:29 clock_gettime(CLOCK_REALTIME, {1365702629, 913924425}) = 0
12467 12:50:29 futex(0x969ba44, FUTEX_WAIT_PRIVATE, 1, {0, 49960575}) = -1 
ETIMEDOUT (Connection timed out)
12467 12:50:29 futex(0x969ba28, FUTEX_WAKE_PRIVATE, 1) = 0
12467 12:50:29 gettimeofday({1365702629, 964772}, NULL) = 0
12467 12:50:29 clock_gettime(CLOCK_MONOTONIC, {5867097, 294579741}) = 0
12467 12:50:29 gettimeofday({1365702629, 964869}, NULL) = 0
12467 12:50:29 clock_gettime(CLOCK_REALTIME, {1365702629, 964908611}) = 0

Disclaimer:  I am in no way a JDBC/java guy but I can probably work through the 
configuration files if there is any configuration question that might jump out 
to anyone?

Thanks!!!

Chris Taylor
Oracle DBA
Parallon IT&S


--
//www.freelists.org/webpage/oracle-l




________________________________
The information transmitted herein is intended only for the person or entity to 
which it is addressed and may contain confidential, proprietary and/or 
privileged material. Any review, retransmission, dissemination or other use of, 
or taking of any action in reliance upon, this information by persons or 
entities other than the intended recipient is prohibited. If you received this 
in error, please contact the sender and delete the material from any computer.
--
//www.freelists.org/webpage/oracle-l


Other related posts: