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. > 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
