sebb wrote: > On 12/01/2010, Phil Steitz <phil.ste...@gmail.com> wrote: >> sebb wrote: >> > On 11/01/2010, Phil Steitz <phil.ste...@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. > > 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 >> >> >> 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-unsubscr...@commons.apache.org >> >> For additional commands, e-mail: dev-h...@commons.apache.org >> >> >> >> >> > >> > --------------------------------------------------------------------- >> > To unsubscribe, e-mail: dev-unsubscr...@commons.apache.org >> > For additional commands, e-mail: dev-h...@commons.apache.org >> > >> >> >> --------------------------------------------------------------------- >> To unsubscribe, e-mail: dev-unsubscr...@commons.apache.org >> For additional commands, e-mail: dev-h...@commons.apache.org >> >> > > --------------------------------------------------------------------- > To unsubscribe, e-mail: dev-unsubscr...@commons.apache.org > For additional commands, e-mail: dev-h...@commons.apache.org > --------------------------------------------------------------------- To unsubscribe, e-mail: dev-unsubscr...@commons.apache.org For additional commands, e-mail: dev-h...@commons.apache.org
