0 Replies Latest reply on Mar 23, 2015 4:52 PM by Vanessa Cañete

    Connection is not released - Lock owned during cleanup - Using Java Callables

    Vanessa Cañete Newbie

      Using jdbc driver: pgjdbc-ng 0.3 -- impossibl/pgjdbc-ng · GitHub

      Using Threads.

      I'm using threads because i need to call 3 store procedures at the same time.

      I cannot wait the process and do it sequentially because it will cost to much time.

      ## How I got my connection?

      The param jndi is parametrized and is correct.

      DataSource dataSource = InitialContext.doLookup(jndi);
      


      This datasource is stored in memory during the application life, it means all the time.

      When I need a connection I do:

      Connection conn = dataSource.getConnection();
      conn.setTypeMap(map);
      

       

      ## How I used the connection?

      I have a class ConciliadorCallable that implements Callable interface, it is like a thread but it can return something.

      I override the call() method like this:


      public RetornoType call() {
        String ident = "[Thread:" + routine + " : " + id + " : " + msisdn + "]";
        log.info(ident);
        CallableStatement cs = null;
        Connection unwrapedConnection = null;
        RetornoType r = null;
        try {
        unwrapedConnection = controller.getConnection();
        String sql = "{ call " + routine + "(?,???) }";
        log.info(ident + ": Ejecutando: " + sql);
        cs = unwrapedConnection.prepareCall(sql);
        cs.setInt(1, id);
        cs.setString(2, msisdn);
        cs.registerOutParameter(3, Types.VARCHAR);
        cs.registerOutParameter(4, Types.VARCHAR);
        cs.execute();
        String codigo = cs.getString(3);
        String mensaje = cs.getString(4);
        r = new RetornoType(codigo, mensaje);
        log.info(ident + ": Executed ok: " + codigo);
        } catch (MiddlewareCallException ex) {
        answer = new RetornoType("-1", ident + ex.getMessage());
        log.error(ident + "\n" + answer, ex);
        } catch (ParseException ex) {
        answer = new RetornoType("-2", ident + ex.getMessage());
        log.error(ident + "\n" + answer, ex);
        } catch (DatabaseConnectionException ex) {
        answer = new RetornoType("-3", ident + ex.getMessage());
        log.error(ident + "\n" + answer, ex);
        } catch (IllegalArgumentException ex) {
        answer = new RetornoType("-4", ident + ex.getMessage());
        log.error(ident + "\n" + answer, ex);
        } catch (IllegalAccessException ex) {
        answer = new RetornoType("-5", ident + ex.getMessage());
        log.error(ident + "\n" + answer, ex);
        } catch (SQLException ex) {
        answer = new RetornoType("-6", ident + ex.getMessage());
        log.error(ident + "\n" + answer, ex);
        log.info(ex.getSQLState() + " : " + ex.getMessage());
        } catch (Exception ex) {
        answer = new RetornoType("-7", ident + ex.getMessage());
        log.error(ident + "\n" + answer, ex);
        } finally {
        try {
        log.info(ident + ": Finally.");
      
        if (cs != null && !cs.isClosed()) {
        cs.close();
        log.info(ident + ": Callable statement closed.");
        }
        if (unwrapedConnection != null && !unwrapedConnection.isClosed()) {
        unwrapedConnection.close();
        log.info(ident + ": Connection closed.");
        }
        } catch (SQLException ex) {
        log.info("Error closing connections.");
        log.error(ident, ex);
        }
        }
        return answer == null ? r : answer;
      }
      

       

      And I use the "thread" like this:

       

      ArrayList<ConciliadorCallable> tasks = new ArrayList<>();
      tasks.add(new ConciliadorCallable("HLR", "conciliar", id, msisdn));
      tasks.add(new ConciliadorCallable("HSS", "conciliar_hss", id, msisdn));
      tasks.add(new ConciliadorCallable("PCRF", "conciliar_pcrf", id, msisdn));
      
      
      ExecutorService pool = Executors.newFixedThreadPool(tasks.size());
      HashMap<String, Future> set = new HashMap<>();
      ArrayList<RespuestaConciliador> respuestas = new ArrayList<>();
      
      
      for (ConciliadorCallable task : tasks) {
        Future<RetornoType> future = pool.submit(task);
        set.put(task.plataforma, future);
      }
      
      
      for (Entry<String, Future> future : set.entrySet()) {
        try {
        log.info("Obtaining answer from FutureTask: " + future.getKey());
        respuestas.add(new RespuestaConciliador((RetornoType) future.getValue().get(), future.getKey()));
        } catch (InterruptedException | ExecutionException ex) {
        log.error("ERROR:", ex);
        respuestas.add(new RespuestaConciliador(new RetornoType("-9", ex.getMessage()), future.getKey()));
        }
      }
      pool.shutdown(); 
      


      What's the problem?

      When I call the service for the first time it works. But later in the second time it seems like the connections are never released. And I can't make it work.

      I have to disable the datasource in the Jboss and enable it again.. But as is imaginable it works just one time again..

      My connection pool had a max of 3 to prove my point that the connections are never "closed".

       

      This is the warning I have when disable the datasource in Jboss..

      12:14:03,953 INFO  [org.jboss.as.connector.subsystems.datasources] (MSC service thread 1-1) JBAS010409: Fuente de datos desenlazados [java:jboss/datasources/PROVISIONING-POSTGRES]

      12:14:03,959 WARN  [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (ServerService Thread Pool -- 251) IJ000615: Destroying active connection in pool: PROVISIONING-POSTGRES (org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@19ac2b9b)

      12:14:03,960 WARN  [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (ServerService Thread Pool -- 251) IJ000615: Destroying active connection in pool: PROVISIONING-POSTGRES (org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@7662da47)

      12:14:03,960 WARN  [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (ServerService Thread Pool -- 251) IJ000615: Destroying active connection in pool: PROVISIONING-POSTGRES (org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@53e8a809)

      12:14:03,960 WARN  [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (ServerService Thread Pool -- 251) IJ000615: Destroying active connection in pool: PROVISIONING-POSTGRES (org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@4f7011e8)

      12:14:03,960 WARN  [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (ServerService Thread Pool -- 251) IJ000615: Destroying active connection in pool: PROVISIONING-POSTGRES (org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@46a7bf16)

      12:14:03,960 WARN  [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (ServerService Thread Pool -- 251) Lock owned during cleanup: pool-92-thread-1: java.lang.Throwable: Lock owned during cleanup: pool-92-thread-1

              at java.lang.Object.wait(Native Method) [rt.jar:1.7.0_45]

              at com.impossibl.postgres.protocol.v30.CommandImpl.waitFor(CommandImpl.java:119)

              at com.impossibl.postgres.protocol.v30.BindExecCommandImpl.execute(BindExecCommandImpl.java:346)

              at com.impossibl.postgres.protocol.v30.ProtocolImpl.execute(ProtocolImpl.java:369)

              at com.impossibl.postgres.jdbc.PGConnectionImpl.execute(PGConnectionImpl.java:428)

              at com.impossibl.postgres.jdbc.PGStatement.executeStatement(PGStatement.java:372)

              at com.impossibl.postgres.jdbc.PGPreparedStatement.execute(PGPreparedStatement.java:233)

              at com.impossibl.postgres.jdbc.PGCallableStatement.execute(PGCallableStatement.java:145)

              at org.jboss.jca.adapters.jdbc.WrappedPreparedStatement.execute(WrappedPreparedStatement.java:404) [ironjacamar-jdbc-1.0.26.Final-redhat-1.jar:1.0.26.Final-redhat-1]

              at py.com.personal.is.provisioning.postgres.rest.conciliacion.ConciliadorCallable.llamar(ConciliadorCallable.java:86)

              at py.com.personal.is.provisioning.postgres.rest.conciliacion.ConciliadorCallable.call(ConciliadorCallable.java:66)

              at py.com.personal.is.provisioning.postgres.rest.conciliacion.ConciliadorCallable.call(ConciliadorCallable.java:31)

              at java.util.concurrent.FutureTask.run(FutureTask.java:262) [rt.jar:1.7.0_45]

              at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [rt.jar:1.7.0_45]

              at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [rt.jar:1.7.0_45]

              at java.lang.Thread.run(Thread.java:744) [rt.jar:1.7.0_45]