commons-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From sebb <seb...@gmail.com>
Subject Re: [dbcp] multipleThreads test
Date Tue, 12 Jan 2010 12:51:07 GMT
On 12/01/2010, Phil Steitz <phil.steitz@gmail.com> wrote:
> sebb wrote:
>  > On 12/01/2010, Phil Steitz <phil.steitz@gmail.com> wrote:
>  >> sebb wrote:
>  >>  > On 11/01/2010, Phil Steitz <phil.steitz@gmail.com> wrote:
>  >>  >> Phil Steitz wrote:
>  >>  >>  > Posting the last failed build output while it is, um....still
available:
>  >>  >
>  >>  > I assume this is from:
>  >>  >
>  >>  > http://vmbuild.apache.org/continuum/buildResult.action?buildId=267625&projectId=22
>  >>  >
>  >>  >>  >
>  >>  >>  > Multithread test time = 489 ms. Threads: 20. Loops: 20. Hold
time:
>  >>  >>  > 200. Maxwait: 100. Done: 11. Did not run: 0. Failed: 9. expectError:
>  >>  >>  > true
>  >>  >>  > StartupDelay: 0. ConnectTime: 3. Runtime: 203. Loops: 1. State:
>  >>  >>  > Done. thrown: null. (using nanoTime)
>  >>  >>  > StartupDelay: 0. ConnectTime: 132. Runtime: 333. Loops: 1.
State:
>  >>  >>  > Done. thrown: null. (using nanoTime)
>  >>  >>  > StartupDelay: 42. ConnectTime: 90. Runtime: 290. Loops: 1.
State:
>  >>  >>  > Done. thrown: null. (using nanoTime)
>  >>  >>  > StartupDelay: 0. ConnectTime: 90. Runtime: 291. Loops: 1. State:
>  >>  >>  > Done. thrown: null. (using nanoTime)
>  >>  >>  > StartupDelay: 76. ConnectTime: 14. Runtime: 215. Loops: 1.
State:
>  >>  >>  > Done. thrown: null. (using nanoTime)
>  >>  >>  > StartupDelay: 13. ConnectTime: 1. Runtime: 202. Loops: 1. State:
>  >>  >>  > Done. thrown: null. (using nanoTime)
>  >>  >>  > StartupDelay: 16. ConnectTime: 0. Runtime: 200. Loops: 1. State:
>  >>  >>  > Done. thrown: null. (using nanoTime)
>  >>  >>  > StartupDelay: 1. ConnectTime: 0. Runtime: 200. Loops: 1. State:
>  >>  >>  > Done. thrown: null. (using nanoTime)
>  >>  >>  > StartupDelay: 11. ConnectTime: 0. Runtime: 200. Loops: 1. State:
>  >>  >>  > Done. thrown: null. (using nanoTime)
>  >>  >>  > StartupDelay: 18. ConnectTime: 0. Runtime: 201. Loops: 1. State:
>  >>  >>  > Done. thrown: null. (using nanoTime)
>  >>  >>  > StartupDelay: 7. ConnectTime: 17. Runtime: 218. Loops: 1. State:
>  >>  >>  > Done. thrown: null. (using nanoTime)
>  >>  >>  > StartupDelay: 0. ConnectTime: -. Runtime: 100. Loops: 1. State:
>  >>  >>  > Getting Connection. thrown:
>  >>  >>  > org.apache.commons.dbcp.SQLNestedException: Could not retrieve
>  >>  >>  > connection info from pool. (using nanoTime)
>  >>  >>  > StartupDelay: 0. ConnectTime: -. Runtime: 101. Loops: 1. State:
>  >>  >>  > Getting Connection. thrown:
>  >>  >>  > org.apache.commons.dbcp.SQLNestedException: Could not retrieve
>  >>  >>  > connection info from pool. (using nanoTime)
>  >>  >>  > StartupDelay: 1. ConnectTime: -. Runtime: 100. Loops: 1. State:
>  >>  >>  > Getting Connection. thrown:
>  >>  >>  > org.apache.commons.dbcp.SQLNestedException: Could not retrieve
>  >>  >>  > connection info from pool. (using nanoTime)
>  >>  >>  > StartupDelay: 0. ConnectTime: -. Runtime: 100. Loops: 1. State:
>  >>  >>  > Getting Connection. thrown:
>  >>  >>  > org.apache.commons.dbcp.SQLNestedException: Could not retrieve
>  >>  >>  > connection info from pool. (using nanoTime)
>  >>  >>  > StartupDelay: 0. ConnectTime: -. Runtime: 100. Loops: 1. State:
>  >>  >>  > Getting Connection. thrown:
>  >>  >>  > org.apache.commons.dbcp.SQLNestedException: Could not retrieve
>  >>  >>  > connection info from pool. (using nanoTime)
>  >>  >>  > StartupDelay: 0. ConnectTime: -. Runtime: 100. Loops: 1. State:
>  >>  >>  > Getting Connection. thrown:
>  >>  >>  > org.apache.commons.dbcp.SQLNestedException: Could not retrieve
>  >>  >>  > connection info from pool. (using nanoTime)
>  >>  >>  > StartupDelay: 0. ConnectTime: -. Runtime: 101. Loops: 1. State:
>  >>  >>  > Getting Connection. thrown:
>  >>  >>  > org.apache.commons.dbcp.SQLNestedException: Could not retrieve
>  >>  >>  > connection info from pool. (using nanoTime)
>  >>  >>  > StartupDelay: 1. ConnectTime: -. Runtime: 100. Loops: 1. State:
>  >>  >>  > Getting Connection. thrown:
>  >>  >>  > org.apache.commons.dbcp.SQLNestedException: Could not retrieve
>  >>  >>  > connection info from pool. (using nanoTime)
>  >>  >>  > StartupDelay: 0. ConnectTime: -. Runtime: 100. Loops: 1. State:
>  >>  >>  > Getting Connection. thrown:
>  >>  >>  > org.apache.commons.dbcp.SQLNestedException: Could not retrieve
>  >>  >>  > connection info from pool. (using nanoTime)
>  >>  >>  >
>  >>  >>  > There are three things that look odd here.  First is that the
second
>  >>  >>  > successful thread should have failed with a timeout.  That
may be
>  >>  >>  > explainable by "wakeup delay."  The second is that unless
>  >>  >>  > startupDelay is not reliable, the allocation looks unfair and
pool
>  >>  >>  > 1.5 is supposed to implement fairness - i.e., it should be
the
>  >>  >>  > threads with lower startupDelays that are served first.
>  >>  >>
>  >>  >>
>  >>  >> Scratch that.  pooledConnectionAndInfo has a synch block before the
>  >>  >>  call to borrowObject to create or acquire the pool.  All threads
are
>  >>  >>  going after the same pool.  The first one in has to create the pool.
>  >>  >>
>  >>  >
>  >>  > It's rather odd.
>  >>  >
>  >>  > The successful threads all took 200+ms to complete, during which time
>  >>  > there should be no spare connections available.
>  >>  >
>  >>  > Yet the second thread only appears to have waited 132ms to get the connection.
>  >>  > [Which should have caused a timeout error, but perhaps that's excusable.]
>  >>  > However, it should not be possible to aquire the 11th connection in
>  >>  > less than 200ms.
>  >>  > What happened to that thread?
>  >>  > Did it somehow stall before waiting for the connection?
>  >>  > If so, why is the overall runtime for the thread only 333ms?
>  >>  >
>  >>  > I will add some more info to the debug output.
>  >>
>  >>
>  >> Still no failures.  This weekend, NTP was re-enabled on vmbuild. It
>  >>  had been disabled for some time.
>  >
>  > I think at least one build failed after the time was corrected:
>  >
>  > http://vmbuild.apache.org/continuum/buildResult.action?projectId=22&projectGroupId=22&projectName=&buildId=267564
>  >
>  > Anyway, the test depends on relative time, rather than absolute time,
>  > so the true time is surely irrelevant?
>
>
> The true time, yes; but if any of this affects measures of elapsed
>  time differentially across threads, that would cause problems.

Indeed, but I don't think this is very likely.

> >
>  > Perhaps if the clock was running extremely slowly or very fast it
>  > might cause JVM scheduling issues, but otherwise I don't see how it
>  > could affect the test.
>  >
>  >>  As I said above, loaded guests running under Vmware are known to
>  >>  lose clock accuracy.  See [1], [2].
>  >
>  > BTW, both URLs are the same.
>  >
>  >>  [1]
>  >>  http://kb.vmware.com/selfservice/microsites/search.do?language=en_US&cmd=displayKC&externalId=1006072
>  >>  [2]
>  >>  http://kb.vmware.com/selfservice/microsites/search.do?language=en_US&cmd=displayKC&externalId=1006072
>
>
> I meant
>  http://www.vmware.com/pdf/vmware_timekeeping.pdf

Thanks, that's very interesting and exhaustive (not finished reading it yet!)

> >>
>  >>
>  >>  Phil
>  >>
>  >>
>  >>
>  >>  >
>  >>  >>  Phil
>  >>  >>
>  >>  >>
>  >>  >>
>  >>  >>   This could
>  >>  >>  > point to a pool bug. Finally, the connectTimes for some of
the
>  >>  >>  > successful threads are way too long.
>  >>  >>  >
>  >>  >>  > Phil
>  >>  >>
>  >>  >>
>  >>  >>  ---------------------------------------------------------------------
>  >>  >>  To unsubscribe, e-mail: dev-unsubscribe@commons.apache.org
>  >>  >>  For additional commands, e-mail: dev-help@commons.apache.org
>  >>  >>
>  >>  >>
>  >>  >
>  >>  > ---------------------------------------------------------------------
>  >>  > To unsubscribe, e-mail: dev-unsubscribe@commons.apache.org
>  >>  > For additional commands, e-mail: dev-help@commons.apache.org
>  >>  >
>  >>
>  >>
>  >>  ---------------------------------------------------------------------
>  >>  To unsubscribe, e-mail: dev-unsubscribe@commons.apache.org
>  >>  For additional commands, e-mail: dev-help@commons.apache.org
>  >>
>  >>
>  >
>  > ---------------------------------------------------------------------
>  > To unsubscribe, e-mail: dev-unsubscribe@commons.apache.org
>  > For additional commands, e-mail: dev-help@commons.apache.org
>  >
>
>
>  ---------------------------------------------------------------------
>  To unsubscribe, e-mail: dev-unsubscribe@commons.apache.org
>  For additional commands, e-mail: dev-help@commons.apache.org
>
>

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@commons.apache.org
For additional commands, e-mail: dev-help@commons.apache.org


Mime
View raw message