JPPF Issue Tracker ~ [CLOSED] JPPF-498 - Client reconnect to driver failure

<Apr 5, 2017, 11:29:36,582 AM MESZ> <Warning> <org.jppf.client.ClassServerDelegateImpl> <BEA-000000> <[jppf_discovery-1-4 - ClassServer] caught java.io.EOFException: could only read 0 bytes out of 4, will re-initialise ...> [client: jppf_discovery-1-4 - ClassServer] Attempting connection to the class server at FDAC8040.HR.LOCAL:11111 Apr 05, 2017 11:29:36 AM org.jppf.client.ClassServerDelegateImpl run WARNING: [jppf_discovery-1-1 - ClassServer] caught java.io.EOFException: could only read 0 bytes out of 4, will re-initialise ... Apr 05, 2017 11:29:36 AM org.jppf.client.ClassServerDelegateImpl init INFO: [client: jppf_discovery-1-1 - ClassServer] Attempting connection to the class server at FDAC8040.HR.LOCAL:11111 Apr 05, 2017 11:29:36 AM org.jppf.client.ClassServerDelegateImpl run WARNING: [jppf_discovery-1-5 - ClassServer] caught java.io.EOFException: could only read 0 bytes out of 4, will re-initialise ... Apr 05, 2017 11:29:36 AM org.jppf.client.ClassServerDelegateImpl init INFO: [client: jppf_discovery-1-5 - ClassServer] Attempting connection to the class server at FDAC8040.HR.LOCAL:11111 Apr 05, 2017 11:29:36 AM org.jppf.client.ClassServerDelegateImpl run WARNING: [jppf_discovery-1-2 - ClassServer] caught java.io.EOFException: could only read 0 bytes out of 4, will re-initialise ... Apr 05, 2017 11:29:36 AM org.jppf.client.ClassServerDelegateImpl init INFO: [client: jppf_discovery-1-2 - ClassServer] Attempting connection to the class server at FDAC8040.HR.LOCAL:11111 Apr 05, 2017 11:29:36 AM org.jppf.client.ClassServerDelegateImpl run WARNING: [jppf_discovery-1-3 - ClassServer] caught java.io.EOFException: could only read 0 bytes out of 4, will re-initialise ... Apr 05, 2017 11:29:36 AM org.jppf.client.ClassServerDelegateImpl init INFO: [client: jppf_discovery-1-3 - ClassServer] Attempting connection to the class server at FDAC8040.HR.LOCAL:11111 Apr 05, 2017 11:29:36 AM org.jppf.client.ClassServerDelegateImpl run WARNING: [jppf_discovery-1-4 - ClassServer] caught java.io.EOFException: could only read 0 bytes out of 4, will re-initialise ... Apr 05, 2017 11:29:36 AM org.jppf.client.ClassServerDelegateImpl init INFO: [client: jppf_discovery-1-4 - ClassServer] Attempting connection to the class server at FDAC8040.HR.LOCAL:11111 Attempting connection to the class server at 10.225.120.160:11111 process exited with code 0 Apr 05, 2017 11:29:39 AM GenericClientCommunicatorAdmin close INFO: java.io.IOException: The connection is not currently established. java.io.IOException: The connection is not currently established. at com.sun.jmx.remote.generic.ClientSynchroMessageConnectionImpl.checkState(ClientSynchroMessageConnectionImpl.java:514) at com.sun.jmx.remote.generic.ClientSynchroMessageConnectionImpl.sendOneWay(ClientSynchroMessageConnectionImpl.java:217) at javax.management.remote.generic.GenericConnector.close(GenericConnector.java:292) at javax.management.remote.generic.GenericConnector.close(GenericConnector.java:265) at javax.management.remote.generic.GenericClientCommunicatorAdmin.doStop(GenericClientCommunicatorAdmin.java:145) at com.sun.jmx.remote.opt.internal.ClientCommunicatorAdmin.restart(ClientCommunicatorAdmin.java:238) at com.sun.jmx.remote.opt.internal.ClientCommunicatorAdmin.gotIOException(ClientCommunicatorAdmin.java:133) at javax.management.remote.generic.GenericConnector$RequestHandler.execute(GenericConnector.java:372) at com.sun.jmx.remote.generic.ClientSynchroMessageConnectionImpl$RemoteJob.run(ClientSynchroMessageConnectionImpl.java:477) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) resetting with stopJmx=true node process id: 10724, uuid: A647D6AA-9961-27FF-7EB9-E7F7C8B5E311 Attempting connection to the class server at localhost:11111 resetting with stopJmx=true node process id: 10724, uuid: A647D6AA-9961-27FF-7EB9-E7F7C8B5E311 Attempting connection to the class server at localhost:11111 resetting with stopJmx=true node process id: 10724, uuid: A647D6AA-9961-27FF-7EB9-E7F7C8B5E311 Attempting connection to the class server at localhost:11111 resetting with stopJmx=true node process id: 10724, uuid: A647D6AA-9961-27FF-7EB9-E7F7C8B5E311 Attempting connection to the class server at localhost:11111 resetting with stopJmx=true node process id: 10724, uuid: A647D6AA-9961-27FF-7EB9-E7F7C8B5E311 Attempting connection to the class server at localhost:11111 resetting with stopJmx=true node process id: 10724, uuid: A647D6AA-9961-27FF-7EB9-E7F7C8B5E311 Attempting connection to the class server at localhost:11111 resetting with stopJmx=true node process id: 10724, uuid: A647D6AA-9961-27FF-7EB9-E7F7C8B5E311 Attempting connection to the class server at localhost:11111 resetting with stopJmx=true node process id: 10724, uuid: A647D6AA-9961-27FF-7EB9-E7F7C8B5E311 Attempting connection to the class server at localhost:11111 resetting with stopJmx=true node process id: 10724, uuid: A647D6AA-9961-27FF-7EB9-E7F7C8B5E311 Attempting connection to the class server at 10.225.120.160:11111 [client: jppf_discovery-1-1 - ClassServer] Reconnected to the class server [client: jppf_discovery-1-4 - ClassServer] Reconnected to the class server [client: jppf_discovery-1-3 - ClassServer] Reconnected to the class server [client: jppf_discovery-1-5 - ClassServer] Reconnected to the class server Apr 05, 2017 11:30:41 AM org.jppf.client.ClassServerDelegateImpl init INFO: [client: jppf_discovery-1-1 - ClassServer] Reconnected to the class server Apr 05, 2017 11:30:41 AM org.jppf.client.ClassServerDelegateImpl init INFO: [client: jppf_discovery-1-4 - ClassServer] Reconnected to the class server Apr 05, 2017 11:30:41 AM org.jppf.client.ClassServerDelegateImpl init INFO: [client: jppf_discovery-1-3 - ClassServer] Reconnected to the class server Apr 05, 2017 11:30:41 AM org.jppf.client.ClassServerDelegateImpl init INFO: [client: jppf_discovery-1-5 - ClassServer] Reconnected to the class server Apr 05, 2017 11:30:41 AM org.jppf.client.ClassServerDelegateImpl init INFO: [client: jppf_discovery-1-2 - ClassServer] Reconnected to the class server [client: jppf_discovery-1-2 - ClassServer] Reconnected to the class server RemoteClassLoaderConnection: Reconnected to the class server JPPF Node management initialized on port 12001 Attempting connection to the node server at 10.225.120.160:11111 Reconnected to the node server Node successfully initialized Apr 05, 2017 11:31:38 AM org.jppf.client.balancer.ChannelWrapperRemote$RemoteRunnable run WARNING: java.net.SocketException: Software caused connection abort: socket write error Apr 05, 2017 11:31:38 AM org.jppf.client.balancer.ChannelWrapperRemote$RemoteRunnable run SEVERE: future already removed java.lang.IllegalStateException: future already removed at org.jppf.client.balancer.ClientJob.taskCompleted(ClientJob.java:327) at org.jppf.client.balancer.ClientTaskBundle.taskCompleted(ClientTaskBundle.java:174) at org.jppf.client.balancer.ChannelWrapperRemote$RemoteRunnable.run(ChannelWrapperRemote.java:250) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) Apr 05, 2017 11:31:38 AM org.jppf.client.TaskServerConnectionHandler init INFO: [client: jppf_discovery-1-3 - TasksServer] Attempting connection to the task server at FDAC8040.HR.LOCAL:11111 Apr 05, 2017 11:31:38 AM org.jppf.client.TaskServerConnectionHandler init INFO: [client: jppf_discovery-1-3 - TasksServer] Reconnected to the JPPF task server <Apr 5, 2017, 11:31:38,371 AM MESZ> <Warning> <org.jppf.client.balancer.ChannelWrapperRemote> <BEA-000000> <java.net.SocketException: Software caused connection abort: socket write error> [client: jppf_discovery-1-3 - TasksServer] Attempting connection to the task server at FDAC8040.HR.LOCAL:11111 <Apr 5, 2017, 11:31:38,385 AM MESZ> <Error> <org.jppf.client.balancer.ChannelWrapperRemote> <BEA-000000> <future already removed java.lang.IllegalStateException: future already removed at org.jppf.client.balancer.ClientJob.taskCompleted(ClientJob.java:327) at org.jppf.client.balancer.ClientTaskBundle.taskCompleted(ClientTaskBundle.java:174) at org.jppf.client.balancer.ChannelWrapperRemote$RemoteRunnable.run(ChannelWrapperRemote.java:250) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) Truncated. see log file for complete stacktrace > [client: jppf_discovery-1-3 - TasksServer] Reconnected to the JPPF task server

I reproduced with Weblogic 12c, but also with a standalone client, using the following JUnit test:

public class TestJPPFDriverAdminMBean2 extends Setup1D1N1C {
  @Test(timeout = 10000)
  public void testRestartDriver() throws Exception {
    int nbTasks = 1;
    long duration = 1L;
    final JMXDriverConnectionWrapper driver = BaseSetup.getJMXConnection(client);
    print(false, false, "submitting job 1");
    List<Task<?>> results = client.submitJob(BaseTestHelper.createJob(ReflectionUtils.getCurrentMethodName() + "-1", true, false, nbTasks, LifeCycleTask.class, duration));
    assertNotNull(results);
    assertEquals(nbTasks, results.size());
    for (Task<?> task: results) {
      assertNotNull(task);
      assertNotNull(task.getResult());
      assertNull(task.getThrowable());
    }
    print(false, false, "restarting driver");
    new Thread(new Runnable() {
      @Override
      public void run() {
        try {
          driver.restartShutdown(1L, 1000L);
        } catch (Exception e) {
          e.printStackTrace();
        }
      }
    }).start();
    JPPFConnectionPool pool;
    print(false, false, "waiting for 0 connection");
    while (!client.findConnectionPools(JPPFClientConnectionStatus.ACTIVE, JPPFClientConnectionStatus.EXECUTING).isEmpty()) Thread.sleep(10L);
    print(false, false, "waiting for 1 connection");
    while ((pool = client.awaitWorkingConnectionPool()) == null) Thread.sleep(10L);
    print(false, false, "submitting job 2");
    results = client.submitJob(BaseTestHelper.createJob(ReflectionUtils.getCurrentMethodName() + "-2", true, false, nbTasks, LifeCycleTask.class, duration));
    assertNotNull(results);
    assertEquals(nbTasks, results.size());
    for (Task<?> task: results) {
      assertNotNull(task);
      assertNotNull(task.getResult());
      assertNull(task.getThrowable());
    }
  }
}

Show system-generated comments

Comment posted by

lolo4j

Apr 06, 09:27

Comment visibility (whether to hide this comment for "regular users")

Comment

I reproduced with Weblogic 12c, but also with a standalone client, using the following JUnit test:
<source lang="java5">public class TestJPPFDriverAdminMBean2 extends Setup1D1N1C {
  @Test(timeout = 10000)
  public void testRestartDriver() throws Exception {
    int nbTasks = 1;
    long duration = 1L;
    final JMXDriverConnectionWrapper driver = BaseSetup.getJMXConnection(client);
    print(false, false, "submitting job 1");
    List<Task<?>> results = client.submitJob(BaseTestHelper.createJob(ReflectionUtils.getCurrentMethodName() + "-1", true, false, nbTasks, LifeCycleTask.class, duration));
    assertNotNull(results);
    assertEquals(nbTasks, results.size());
    for (Task<?> task: results) {
      assertNotNull(task);
      assertNotNull(task.getResult());
      assertNull(task.getThrowable());
    }
    print(false, false, "restarting driver");
    new Thread(new Runnable() {
      @Override
      public void run() {
        try {
          driver.restartShutdown(1L, 1000L);
        } catch (Exception e) {
          e.printStackTrace();
        }
      }
    }).start();
    JPPFConnectionPool pool;
    print(false, false, "waiting for 0 connection");
    while (!client.findConnectionPools(JPPFClientConnectionStatus.ACTIVE, JPPFClientConnectionStatus.EXECUTING).isEmpty()) Thread.sleep(10L);
    print(false, false, "waiting for 1 connection");
    while ((pool = client.awaitWorkingConnectionPool()) == null) Thread.sleep(10L);
    print(false, false, "submitting job 2");
    results = client.submitJob(BaseTestHelper.createJob(ReflectionUtils.getCurrentMethodName() + "-2", true, false, nbTasks, LifeCycleTask.class, duration));
    assertNotNull(results);
    assertEquals(nbTasks, results.size());
    for (Task<?> task: results) {
      assertNotNull(task);
      assertNotNull(task.getResult());
      assertNull(task.getThrowable());
    }
  }
}</source>

or cancel

'''lolo4j wrote:'''
>I reproduced with Weblogic 12c, but also with a standalone client, using
>the following JUnit test: 
>public class TestJPPFDriverAdminMBean2 extends Setup1D1N1C {
>  @Test(timeout = 10000)
>  public void testRestartDriver() throws Exception {
>    int nbTasks = 1;
>    long duration = 1L;
>    final JMXDriverConnectionWrapper driver =
>BaseSetup.getJMXConnection(client);
>    print(false, false, "submitting job 1");
>    List<Task<?>> results =
>client.submitJob(BaseTestHelper.createJob(ReflectionUtils.getCurrentMethodName()
>+ "-1", true, false, nbTasks, LifeCycleTask.class, duration));
>    assertNotNull(results);
>    assertEquals(nbTasks, results.size());
>    for (Task<?> task: results) {
>      assertNotNull(task);
>      assertNotNull(task.getResult());
>      assertNull(task.getThrowable());
>    }
>    print(false, false, "restarting driver");
>    new Thread(new Runnable() {
>      @Override
>      public void run() {
>        try {
>          driver.restartShutdown(1L, 1000L);
>        } catch (Exception e) {
>          e.printStackTrace();
>        }
>      }
>    }).start();
>    JPPFConnectionPool pool;
>    print(false, false, "waiting for 0 connection");
>    while (!client.findConnectionPools(JPPFClientConnectionStatus.ACTIVE,
>JPPFClientConnectionStatus.EXECUTING).isEmpty()) Thread.sleep(10L);
>    print(false, false, "waiting for 1 connection");
>    while ((pool = client.awaitWorkingConnectionPool()) == null)
>Thread.sleep(10L);
>    print(false, false, "submitting job 2");
>    results =
>client.submitJob(BaseTestHelper.createJob(ReflectionUtils.getCurrentMethodName()
>+ "-2", true, false, nbTasks, LifeCycleTask.class, duration));
>    assertNotNull(results);
>    assertEquals(nbTasks, results.size());
>    for (Task<?> task: results) {
>      assertNotNull(task);
>      assertNotNull(task.getResult());
>      assertNull(task.getThrowable());
>    }
>  }
>} 
>

Apr 06, 09:38

A file was uploaded. Generated logs from TestJPPFDriverAdminMBean2 test

This comment was attached:

Attached full set of logs generated by the TestJPPFDriverAdminMBean2 test JUnit test

Apr 07, 07:30

Fixed in:

trunk revision 4496
branch b5.2 revision 4497

Apr 07, 08:00

Released the fix in patch 01 for jPPF 5.2.6

Really delete this comment?

Really delete this comment?

Really delete this comment?

Really delete this comment?

Really delete this comment?

Really delete this comment?

Really delete this comment?

Really delete this comment?