Hi Chris,
>
> On 6/11/13 1:05 AM, ruxing bao wrote:
> > Sorry,I can't get any more of the stack trace.
> >
> > We wrapped zookeepr client as a spring bean and invoked method
> > "close" of zookeeper in "destory-method" of bean,in that method
> > "close",zookeeper Send Thread was closed. When tomcat was shut
> > down, Spring closed it's container and bean was destroyed, then
> > "destroy-method" of bean was invoked. I'am confusing why is Send
> > Thread of Zookeeper seemed to exit slower than the
> > WebappClassLoader shedding its loaded classes.
>
>
> Threads don't always shut down immediately... let's see how you are
> telling the thread to shut down:
>
> > ps: details of zookeeper closing
>
> (Thanks!)
>
> > org.apache.zookeeper.Zookeeper public synchronized void close()
> > throws InterruptedException { if (!cnxn.getState().isAlive()) { if
> > (LOG.isDebugEnabled()) { LOG.debug("Close called on already closed
> > client"); } return; } if (LOG.isDebugEnabled()) {
> > LOG.debug("Closing session: 0x" +
> > Long.toHexString(getSessionId())); } try { cnxn.close(); } catch
> > (IOException e) { if (LOG.isDebugEnabled()) { LOG.debug("Ignoring
> > unexpected exception during close", e); } } LOG.info("Session: 0x"
> > + Long.toHexString(getSessionId()) + " closed"); }
>
> So, during webapp shutdown you should be getting the message "Closing
> session 0x[...]", right? No errors?
Yes, no errors.
> Is "cnxn" of type org.apache.zookeeped.ClientCnxn? That seems to be
> the case, but it's worth checking.
>
> > ----------------------------------------------------------------------------------------------------------------------
> >
> >
> org.apache.zookeeper.ClientCnxn
> > public void close() throws IOException { if (LOG.isDebugEnabled())
> > { LOG.debug("Closing client for session: 0x" +
> > Long.toHexString(getSessionId())); } try { RequestHeader h = new
> > RequestHeader(); h.setType(ZooDefs.OpCode.closeSession);
> > submitRequest(h, null, null, null); } catch (InterruptedException
> > e) { // ignore, close the send/event threads } finally {
> > disconnect(); } }
> >
> > public void disconnect() { if (LOG.isDebugEnabled()) {
> > LOG.debug("Disconnecting client for session: 0x" +
> > Long.toHexString(getSessionId())); } sendThread.close();
> > eventThread.queueEventOfDeath(); }
>
> Okay, so calling "close" asks the thread to stop (somewhat indirectly).
>
> > org.apache.zookeeper.ClientCnxn.SendThread void close() { state =
> > States.CLOSED; clientCnxnSocket.wakeupCnxn(); }
> >
> >
> > @Override public void run() {
> > clientCnxnSocket.introduce(this,sessionId);
> > clientCnxnSocket.updateNow();
> > clientCnxnSocket.updateLastSendAndHeard(); int to; long
> > lastPingRwServer = System.currentTimeMillis(); while
> > (state.isAlive()) { try { if (!clientCnxnSocket.isConnected()) {
> > if(!isFirstConnect){ try { Thread.sleep(r.nextInt(1000)); } catch
> > (InterruptedException e) { LOG.warn("Unexpected exception", e); }
> > } // don't re-establish connection if we are closing if (closing ||
> > !state.isAlive()) { break; } startConnect();
> > clientCnxnSocket.updateLastSendAndHeard(); } if
> > (state.isConnected()) { // determine whether we need to send an
> > AuthFailed event. if (zooKeeperSaslClient != null) { boolean
> > sendAuthEvent = false; if (zooKeeperSaslClient.getSaslState() ==
> > ZooKeeperSaslClient.SaslState.INITIAL) { try {
> > zooKeeperSaslClient.initialize(ClientCnxn.this); } catch
> > (SaslException e) { LOG.error("SASL authentication with Zookeeper
> > Quorum member failed: " + e); state = States.AUTH_FAILED;
> > sendAuthEvent = true; } } KeeperState authState =
> > zooKeeperSaslClient.getKeeperState(); if (authState != null) { if
> > (authState == KeeperState.AuthFailed) { // An authentication error
> > occurred during authentication with the Zookeeper Server. state =
> > States.AUTH_FAILED; sendAuthEvent = true; } else { if (authState ==
> > KeeperState.SaslAuthenticated) { sendAuthEvent = true; } } } if
> > (sendAuthEvent == true) { eventThread.queueEvent(new WatchedEvent(
> > Watcher.Event.EventType.None, authState,null)); } } to =
> > readTimeout - clientCnxnSocket.getIdleRecv(); } else { to =
> > connectTimeout - clientCnxnSocket.getIdleRecv(); }
> >
> > if (to <= 0) { throw new SessionTimeoutException( "Client session
> > timed out, have not heard from server in " +
> > clientCnxnSocket.getIdleRecv() + "ms" + " for sessionid 0x" +
> > Long.toHexString(sessionId)); } if (state.isConnected()) { int
> > timeToNextPing = readTimeout / 2 - clientCnxnSocket.getIdleSend();
> > if (timeToNextPing <= 0) { sendPing();
> > clientCnxnSocket.updateLastSend(); } else { if (timeToNextPing <
> > to) { to = timeToNextPing; } } } // If we are in read-only mode,
> > seek for read/write server if (state == States.CONNECTEDREADONLY)
> > { long now = System.currentTimeMillis(); int idlePingRwServer =
> > (int) (now - lastPingRwServer); if (idlePingRwServer >=
> > pingRwTimeout) { lastPingRwServer = now; idlePingRwServer = 0;
> > pingRwTimeout = Math.min(2*pingRwTimeout, maxPingRwTimeout);
> > pingRwServer(); } to = Math.min(to, pingRwTimeout -
> > idlePingRwServer); } clientCnxnSocket.doTransport(to, pendingQueue,
> > outgoingQueue, ClientCnxn.this); } catch (Throwable e) { if
> > (closing) { if (LOG.isDebugEnabled()) { // closing so this is
> > expected LOG.debug("An exception was thrown while closing send
> > thread for session 0x" + Long.toHexString(getSessionId()) + " : " +
> > e.getMessage()); } break; } else { // this is ugly, you have a
> > better way speak up if (e instanceof SessionExpiredException) {
> > LOG.info(e.getMessage() + ", closing socket connection"); } else if
> > (e instanceof SessionTimeoutException) { LOG.info(e.getMessage() +
> > RETRY_CONN_MSG); } else if (e instanceof EndOfStreamException) {
> > LOG.info(e.getMessage() + RETRY_CONN_MSG); } else if (e instanceof
> > RWServerFoundException) { LOG.info(e.getMessage()); } else {
> > LOG.warn( "Session 0x" + Long.toHexString(getSessionId()) + " for
> > server " + clientCnxnSocket.getRemoteSocketAddress() + ",
> > unexpected error" + RETRY_CONN_MSG, e); } cleanup(); if
> > (state.isAlive()) { eventThread.queueEvent(new WatchedEvent(
> > Event.EventType.None, Event.KeeperState.Disconnected, null)); }
> > clientCnxnSocket.updateNow();
> > clientCnxnSocket.updateLastSendAndHeard(); } } } cleanup();
> > clientCnxnSocket.close(); if (state.isAlive()) {
> > eventThread.queueEvent(new WatchedEvent(Event.EventType.None,
> > Event.KeeperState.Disconnected, null)); }
> > ZooTrace.logTraceMessage(LOG, ZooTrace.getTextTraceLevel(),
> > "SendThread exitedloop.");//at this line, error occurs. }
>
> It seems you have a race condition, here: you are asking the thread to
> stop (indirectly, by setting state=CLOSED). But, the thread requesting
> the close continues running without checking to see what happens with
> the SendThread. The SendThread has a Thread.sleep() call which means
> that it might be waiting for a while before exiting its run() method.
>
> Can you modify the code somewhere to:
>
> a) Call SendThread.interrupt()
>
> and
>
> b) Do a short loop waiting for SendThread.getState() == TERMINATED
>
> I think if you do these two things, you'll have a clean shutdown.
>
I would try this.
thanks,
Bob
