Author: breed
Date: Thu Jan 15 15:48:24 2009
New Revision: 734857
URL: http://svn.apache.org/viewvc?rev=734857&view=rev
Log:
ZOOKEEPER-259. cleanup the logging levels used (use the correct level)
and messages generated. (phunt via breed)
Modified:
hadoop/zookeeper/trunk/CHANGES.txt
hadoop/zookeeper/trunk/src/c/src/zk_adaptor.h
hadoop/zookeeper/trunk/src/c/src/zookeeper.c
hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/ClientCnxn.java
hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/ZooKeeper.java
hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/DataTree.java
hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/FinalRequestProcessor.java
hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/LogFormatter.java
hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/NIOServerCnxn.java
hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/PrepRequestProcessor.java
hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/SessionTrackerImpl.java
hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/SyncRequestProcessor.java
hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/ZooKeeperServer.java
hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/AuthFastLeaderElection.java
hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/CommitProcessor.java
hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/FastLeaderElection.java
hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/Follower.java
hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/FollowerHandler.java
hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/FollowerRequestProcessor.java
hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/FollowerZooKeeperServer.java
hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/Leader.java
hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/LeaderElection.java
hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/QuorumCnxManager.java
hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/QuorumPeerConfig.java
hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/SendAckRequestProcessor.java
hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/upgrade/DataTreeV1.java
hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/upgrade/UpgradeSnapShotV1.java
hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/util/Profiler.java
Modified: hadoop/zookeeper/trunk/CHANGES.txt
URL: http://svn.apache.org/viewvc/hadoop/zookeeper/trunk/CHANGES.txt?rev=734857&r1=734856&r2=734857&view=diff
==============================================================================
--- hadoop/zookeeper/trunk/CHANGES.txt (original)
+++ hadoop/zookeeper/trunk/CHANGES.txt Thu Jan 15 15:48:24 2009
@@ -105,6 +105,8 @@
ZOOKEEPER-234. Eliminate using statics to initialize the sever. Should
allow server to be more embeddable in OSGi enviorments. (phunt)
+ ZOOKEEPER-259. cleanup the logging levels used (use the correct level)
+ and messages generated. (phunt via breed)
Release 3.0.0 - 2008-10-21
Modified: hadoop/zookeeper/trunk/src/c/src/zk_adaptor.h
URL: http://svn.apache.org/viewvc/hadoop/zookeeper/trunk/src/c/src/zk_adaptor.h?rev=734857&r1=734856&r2=734857&view=diff
==============================================================================
--- hadoop/zookeeper/trunk/src/c/src/zk_adaptor.h (original)
+++ hadoop/zookeeper/trunk/src/c/src/zk_adaptor.h Thu Jan 15 15:48:24 2009
@@ -166,6 +166,7 @@
watcher_fn watcher; /* the registered watcher */
struct timeval last_recv; /* The time that the last message was received */
struct timeval last_send; /* The time that the last message was sent */
+ struct timeval last_ping; /* The time that the last PING was sent */
struct timeval next_deadline; /* The time of the next deadline */
int recv_timeout; /* The maximum amount of time that can go by without
receiving anything from the zookeeper server */
Modified: hadoop/zookeeper/trunk/src/c/src/zookeeper.c
URL: http://svn.apache.org/viewvc/hadoop/zookeeper/trunk/src/c/src/zookeeper.c?rev=734857&r1=734856&r2=734857&view=diff
==============================================================================
--- hadoop/zookeeper/trunk/src/c/src/zookeeper.c (original)
+++ hadoop/zookeeper/trunk/src/c/src/zookeeper.c Thu Jan 15 15:48:24 2009
@@ -1060,6 +1060,7 @@
rc = serialize_RequestHeader(oa, "header", &h);
enter_critical(zh);
+ gettimeofday(&zh->last_ping, 0);
rc = rc < 0 ? rc : add_void_completion(zh, h.xid, 0, 0);
rc = rc < 0 ? rc : queue_buffer_bytes(&zh->to_send, get_buffer(oa),
get_buffer_len(oa));
@@ -1118,6 +1119,7 @@
*tv = get_timeval(zh->recv_timeout/3);
zh->last_recv = now;
zh->last_send = now;
+ zh->last_ping = now;
}
if (zh->fd != -1) {
int idle_recv = calculate_interval(&zh->last_recv, &now);
@@ -1495,8 +1497,9 @@
// fprintf(stderr, "Got %llx for %x\n", hdr.zxid, hdr.xid);
}
- LOG_DEBUG(("Got response xid=%x", hdr.xid));
if (hdr.xid == WATCHER_EVENT_XID) {
+ LOG_DEBUG(("Processing WATCHER_EVENT"));
+
struct WatcherEvent evt;
int type;
char *path;
@@ -1514,8 +1517,11 @@
deallocate_WatcherEvent(&evt);
queue_completion(&zh->completions_to_process, c, 0);
} else if (hdr.xid == SET_WATCHES_XID) {
+ LOG_DEBUG(("Processing SET_WATCHES"));
free_buffer(bptr);
} else if (hdr.xid == AUTH_XID){
+ LOG_DEBUG(("Processing AUTH_XID"));
+
/* special handling for the AUTH response as it may come back
* out-of-band */
auth_completion_func(hdr.err,zh);
@@ -1534,6 +1540,8 @@
assert(cptr);
/* The requests are going to come back in order */
if (cptr->xid != hdr.xid) {
+ LOG_DEBUG(("Processing unexpected or out-of-order response!"));
+
// received unexpected (or out-of-order) response
close_buffer_iarchive(&ia);
free_buffer(bptr);
@@ -1549,10 +1557,17 @@
if (cptr->c.void_result != SYNCHRONOUS_MARKER) {
if(hdr.xid == PING_XID){
+ struct timeval now;
+ gettimeofday(&now, 0);
+ int elapsed = calculate_interval(&zh->last_ping, &now);
+ LOG_DEBUG(("Got ping response in %d ms", elapsed));
+
// Nothing to do with a ping response
free_buffer(bptr);
destroy_completion_entry(cptr);
} else {
+ LOG_DEBUG(("Queueing asynchronous response"));
+
cptr->buffer = bptr;
queue_completion(&zh->completions_to_process, cptr, 0);
}
@@ -1562,7 +1577,8 @@
sc->rc = rc;
switch(cptr->completion_type) {
case COMPLETION_DATA:
- LOG_DEBUG(("Calling COMPLETION_DATA for xid=%x rc=%d",cptr->xid,rc));
+ LOG_DEBUG(("Calling COMPLETION_DATA for xid=%x rc=%d",
+ cptr->xid, rc));
if (rc==0) {
struct GetDataResponse res;
int len;
@@ -1579,7 +1595,8 @@
}
break;
case COMPLETION_STAT:
- LOG_DEBUG(("Calling COMPLETION_STAT for xid=%x rc=%d",cptr->xid,rc));
+ LOG_DEBUG(("Calling COMPLETION_STAT for xid=%x rc=%d",
+ cptr->xid, rc));
if (rc == 0) {
struct SetDataResponse res;
deserialize_SetDataResponse(ia, "reply", &res);
@@ -1588,7 +1605,8 @@
}
break;
case COMPLETION_STRINGLIST:
- LOG_DEBUG(("Calling COMPLETION_STRINGLIST for xid=%x rc=%d",cptr->xid,rc));
+ LOG_DEBUG(("Calling COMPLETION_STRINGLIST for xid=%x rc=%d",
+ cptr->xid, rc));
if (rc == 0) {
struct GetChildrenResponse res;
deserialize_GetChildrenResponse(ia, "reply", &res);
@@ -1598,7 +1616,8 @@
}
break;
case COMPLETION_STRING:
- LOG_DEBUG(("Calling COMPLETION_STRING for xid=%x rc=%d",cptr->xid,rc));
+ LOG_DEBUG(("Calling COMPLETION_STRING for xid=%x rc=%d",
+ cptr->xid, rc));
if (rc == 0) {
struct CreateResponse res;
int len;
@@ -1616,7 +1635,8 @@
}
break;
case COMPLETION_ACLLIST:
- LOG_DEBUG(("Calling COMPLETION_ACLLIST for xid=%x rc=%d",cptr->xid,rc));
+ LOG_DEBUG(("Calling COMPLETION_ACLLIST for xid=%x rc=%d",
+ cptr->xid, rc));
if (rc == 0) {
struct GetACLResponse res;
deserialize_GetACLResponse(ia, "reply", &res);
@@ -1628,7 +1648,12 @@
}
break;
case COMPLETION_VOID:
- LOG_DEBUG(("Calling COMPLETION_VOID for xid=%x rc=%d",cptr->xid,rc));
+ LOG_DEBUG(("Calling COMPLETION_VOID for xid=%x rc=%d",
+ cptr->xid, rc));
+ break;
+ default:
+ LOG_DEBUG(("UNKNOWN response type xid=%x rc=%d",
+ cptr->xid, rc));
break;
}
notify_sync_completion(sc);
Modified: hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/ClientCnxn.java
URL: http://svn.apache.org/viewvc/hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/ClientCnxn.java?rev=734857&r1=734856&r2=734857&view=diff
==============================================================================
--- hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/ClientCnxn.java (original)
+++ hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/ClientCnxn.java Thu Jan 15 15:48:24 2009
@@ -211,7 +211,7 @@
this.bb.putInt(this.bb.capacity() - 4);
this.bb.rewind();
} catch (IOException e) {
- LOG.warn("Unexpected exception",e);
+ LOG.warn("Ignoring unexpected exception", e);
}
}
this.watchRegistration = watchRegistration;
@@ -429,7 +429,7 @@
}
}
} catch (InterruptedException e) {
- LOG.warn("Event thread exiting due to interruption", e);
+ LOG.error("Event thread exiting due to interruption", e);
}
LOG.info("EventThread shut down");
@@ -484,6 +484,8 @@
boolean initialized;
+ private long lastPingSentNs;
+
void readLength() throws IOException {
int len = incomingBuffer.getInt();
if (len < 0 || len >= 4096 * 1024) {
@@ -524,16 +526,19 @@
replyHdr.deserialize(bbia, "header");
if (replyHdr.getXid() == -2) {
// -2 is the xid for pings
- LOG
- .debug("Got ping sessionid:0x"
- + Long.toHexString(sessionId));
+ if (LOG.isDebugEnabled()) {
+ LOG.debug("Got ping response for sessionid:0x"
+ + Long.toHexString(sessionId)
+ + " after "
+ + ((System.nanoTime() - lastPingSentNs) / 1000000)
+ + "ms");
+ }
return;
}
if (replyHdr.getXid() == -4) {
// -2 is the xid for AuthPacket
// TODO: process AuthPacket here
- LOG
- .debug("Got auth sessionid:0x"
+ LOG.debug("Got auth sessionid:0x"
+ Long.toHexString(sessionId));
return;
}
@@ -732,6 +737,7 @@
}
private void sendPing() {
+ lastPingSentNs = System.nanoTime();
RequestHeader h = new RequestHeader(-2, OpCode.ping);
queuePacket(h, null, null, null, null, null, null, null);
}
Modified: hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/ZooKeeper.java
URL: http://svn.apache.org/viewvc/hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/ZooKeeper.java?rev=734857&r1=734856&r2=734857&view=diff
==============================================================================
--- hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/ZooKeeper.java (original)
+++ hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/ZooKeeper.java Thu Jan 15 15:48:24 2009
@@ -420,7 +420,7 @@
try {
cnxn.close();
} catch (IOException e) {
- LOG.warn("Unexpected exception", e);
+ LOG.warn("Ignoring unexpected exception", e);
}
LOG.info("Session: 0x" + Long.toHexString(getSessionId()) + " closed");
Modified: hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/DataTree.java
URL: http://svn.apache.org/viewvc/hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/DataTree.java?rev=734857&r1=734856&r2=734857&view=diff
==============================================================================
--- hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/DataTree.java (original)
+++ hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/DataTree.java Thu Jan 15 15:48:24 2009
@@ -37,6 +37,7 @@
import org.apache.zookeeper.WatchedEvent;
import org.apache.zookeeper.Watcher;
import org.apache.zookeeper.KeeperException.Code;
+import org.apache.zookeeper.KeeperException.NoNodeException;
import org.apache.zookeeper.Watcher.Event;
import org.apache.zookeeper.Watcher.Event.EventType;
import org.apache.zookeeper.Watcher.Event.KeeperState;
@@ -44,6 +45,7 @@
import org.apache.zookeeper.data.ACL;
import org.apache.zookeeper.data.Stat;
import org.apache.zookeeper.data.StatPersisted;
+import org.apache.zookeeper.proto.WatcherEvent;
import org.apache.zookeeper.txn.CreateTxn;
import org.apache.zookeeper.txn.DeleteTxn;
import org.apache.zookeeper.txn.ErrorTxn;
@@ -98,9 +100,6 @@
*/
protected long aclIndex = 0;
- /** A debug string * */
- private String debug = "debug";
-
@SuppressWarnings("unchecked")
public HashSet<String> getEphemerals(long sessionId) {
HashSet<String> retv = ephemerals.get(sessionId);
@@ -521,10 +520,10 @@
public volatile long lastProcessedZxid = 0;
- @SuppressWarnings("unchecked")
public ProcessTxnResult processTxn(TxnHeader header, Record txn) {
ProcessTxnResult rc = new ProcessTxnResult();
+ String debug = "";
try {
rc.clientId = header.getClientId();
rc.cxid = header.getCxid();
@@ -557,6 +556,7 @@
break;
case OpCode.setACL:
SetACLTxn setACLTxn = (SetACLTxn) txn;
+ debug = "Set ACL for transaction for " + setACLTxn.getPath();
rc.stat = setACL(setACLTxn.getPath(), setACLTxn.getAcl(),
setACLTxn.getVersion());
break;
@@ -573,8 +573,7 @@
if (initialized
|| (e.code() != Code.NONODE
&& e.code() != Code.NODEEXISTS)) {
- LOG.warn(debug);
- LOG.error("FIXMSG",e);
+ LOG.warn("Failed:" + debug, e);
}
}
return rc;
@@ -582,9 +581,9 @@
void killSession(long session, long zxid) {
// the list is already removed from the ephemerals
- // so we do not have to worry about synchronyzing on
+ // so we do not have to worry about synchronizing on
// the list. This is only called from FinalRequestProcessor
- // so there is no need for synchornization. The list is not
+ // so there is no need for synchronization. The list is not
// changed here. Only create and delete change the list which
// are again called from FinalRequestProcessor in sequence.
HashSet<String> list = ephemerals.remove(session);
@@ -592,13 +591,15 @@
for (String path : list) {
try {
deleteNode(path, zxid);
- ZooTrace.logTraceMessage(LOG,
- ZooTrace.SESSION_TRACE_MASK,
- "Deleting ephemeral node "
- + path + " for session 0x"
- + Long.toHexString(session));
- } catch (KeeperException e) {
- LOG.error("FIXMSG",e);
+ if (LOG.isDebugEnabled()) {
+ LOG.debug("Deleting ephemeral node " + path
+ + " for session 0x"
+ + Long.toHexString(session));
+ }
+ } catch (NoNodeException e) {
+ LOG.warn("Ignoring NoNodeException for path " + path
+ + " while removing ephemeral for dead session 0x"
+ + Long.toHexString(session));
}
}
}
Modified: hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/FinalRequestProcessor.java
URL: http://svn.apache.org/viewvc/hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/FinalRequestProcessor.java?rev=734857&r1=734856&r2=734857&view=diff
==============================================================================
--- hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/FinalRequestProcessor.java (original)
+++ hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/FinalRequestProcessor.java Thu Jan 15 15:48:24 2009
@@ -238,15 +238,16 @@
} catch (KeeperException e) {
err = e.code();
} catch (Exception e) {
- LOG.warn("****************************** " + request);
+ // log at error level as we are returning a marshalling
+ // error to the user
+ LOG.error("Failed to process " + request, e);
StringBuffer sb = new StringBuffer();
ByteBuffer bb = request.request;
bb.rewind();
while (bb.hasRemaining()) {
sb.append(Integer.toHexString(bb.get() & 0xff));
}
- LOG.warn(sb.toString());
- LOG.error("FIXMSG",e);
+ LOG.error("Dumping request buffer: 0x" + sb.toString());
err = Code.MARSHALLINGERROR;
}
ReplyHeader hdr =
Modified: hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/LogFormatter.java
URL: http://svn.apache.org/viewvc/hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/LogFormatter.java?rev=734857&r1=734856&r2=734857&view=diff
==============================================================================
--- hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/LogFormatter.java (original)
+++ hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/LogFormatter.java Thu Jan 15 15:48:24 2009
@@ -65,7 +65,7 @@
+ " " + TraceFormatter.op2String(hdr.getType()));
if (logStream.readByte("EOR") != 'B') {
LOG.error("Last transaction was partial.");
- throw new EOFException();
+ throw new EOFException("Last transaction was partial.");
}
}
}
Modified: hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/NIOServerCnxn.java
URL: http://svn.apache.org/viewvc/hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/NIOServerCnxn.java?rev=734857&r1=734856&r2=734857&view=diff
==============================================================================
--- hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/NIOServerCnxn.java (original)
+++ hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/NIOServerCnxn.java Thu Jan 15 15:48:24 2009
@@ -164,14 +164,11 @@
}
selected.clear();
} catch (Exception e) {
- LOG.error("FIXMSG",e);
+ LOG.warn("Ignoring exception", e);
}
}
- ZooTrace.logTraceMessage(LOG, ZooTrace.getTextTraceLevel(),
- "NIOServerCnxn factory exitedloop.");
clear();
- LOG.error("=====> Goodbye cruel world <======");
- // System.exit(0);
+ LOG.info("NIOServerCnxn factory exited run method");
}
/**
@@ -189,7 +186,8 @@
try {
cnxn.close();
} catch (Exception e) {
- // Do nothing.
+ LOG.warn("Ignoring exception closing cnxn sessionid 0x"
+ + Long.toHexString(cnxn.sessionId), e);
}
}
}
@@ -203,9 +201,9 @@
this.interrupt();
this.join();
} catch (InterruptedException e) {
- LOG.warn("Interrupted",e);
+ LOG.warn("Ignoring interrupted exception during shutdown", e);
} catch (Exception e) {
- LOG.error("Unexpected exception", e);
+ LOG.warn("Ignoring unexpected exception during shutdown", e);
}
if (zks != null) {
zks.shutdown();
@@ -261,22 +259,14 @@
void sendBuffer(ByteBuffer bb) {
synchronized (factory) {
- try {
- sk.selector().wakeup();
- // ZooLog.logTraceMessage(LOG,
- // ZooLog.CLIENT_DATA_PACKET_TRACE_MASK,
- // "Add a buffer to outgoingBuffers");
- // ZooLog.logTraceMessage(LOG,
- // ZooLog.CLIENT_DATA_PACKET_TRACE_MASK,
- //"sk " + sk + " is valid: " +
- // sk.isValid(), );
- outgoingBuffers.add(bb);
- if (sk.isValid()) {
- sk.interestOps(sk.interestOps() | SelectionKey.OP_WRITE);
- }
- } catch (RuntimeException e) {
- LOG.error("FIXMSG",e);
- throw e;
+ sk.selector().wakeup();
+ if (LOG.isTraceEnabled()) {
+ LOG.trace("Add a buffer to outgoingBuffers, sk " + sk
+ + " is valid: " + sk.isValid());
+ }
+ outgoingBuffers.add(bb);
+ if (sk.isValid()) {
+ sk.interestOps(sk.interestOps() | SelectionKey.OP_WRITE);
}
}
}
@@ -403,9 +393,16 @@
}
}
} catch (CancelledKeyException e) {
+ LOG.warn("Exception causing close of session 0x"
+ + Long.toHexString(sessionId)
+ + " due to " + e);
+ LOG.debug("CancelledKeyException stack trace", e);
close();
} catch (IOException e) {
- // LOG.error("FIXMSG",e);
+ LOG.warn("Exception causing close of session 0x"
+ + Long.toHexString(sessionId)
+ + " due to " + e);
+ LOG.debug("IOException stack trace", e);
close();
}
}
@@ -428,12 +425,13 @@
if (ap == null
|| (ap.handleAuthentication(this, authPacket.getAuth())
!= KeeperException.Code.OK)) {
- if (ap == null)
- LOG.error("No authentication provider for scheme: "
- + scheme + " has " + ProviderRegistry.listProviders());
- else
- LOG.debug("Authentication failed for scheme: "
- + scheme);
+ if (ap == null) {
+ LOG.warn("No authentication provider for scheme: "
+ + scheme + " has "
+ + ProviderRegistry.listProviders());
+ } else {
+ LOG.warn("Authentication failed for scheme: " + scheme);
+ }
// send a response...
ReplyHeader rh = new ReplyHeader(h.getXid(), 0,
KeeperException.Code.AUTHFAILED.intValue());
@@ -487,17 +485,19 @@
.getArchive(new ByteBufferInputStream(incomingBuffer));
ConnectRequest connReq = new ConnectRequest();
connReq.deserialize(bia, "connect");
- LOG.warn("Connected to " + sock.socket().getRemoteSocketAddress()
+ LOG.info("Connected to " + sock.socket().getRemoteSocketAddress()
+ " lastZxid " + connReq.getLastZxidSeen());
if (zk == null) {
throw new IOException("ZooKeeperServer not running");
}
if (connReq.getLastZxidSeen() > zk.dataTree.lastProcessedZxid) {
- LOG.error("Client has seen zxid 0x"
- + Long.toHexString(connReq.getLastZxidSeen())
- + " our last zxid is 0x"
- + Long.toHexString(zk.dataTree.lastProcessedZxid));
- throw new IOException("We are out of date");
+ String msg = "Client has seen zxid 0x"
+ + Long.toHexString(connReq.getLastZxidSeen())
+ + " our last zxid is 0x"
+ + Long.toHexString(zk.dataTree.lastProcessedZxid);
+
+ LOG.error(msg);
+ throw new IOException(msg);
}
sessionTimeout = connReq.getTimeOut();
byte passwd[] = connReq.getPasswd();
@@ -513,11 +513,10 @@
if (connReq.getSessionId() != 0) {
setSessionId(connReq.getSessionId());
zk.reopenSession(this, sessionId, passwd, sessionTimeout);
- LOG.warn("Renewing session 0x" + Long.toHexString(sessionId));
+ LOG.info("Renewing session 0x" + Long.toHexString(sessionId));
} else {
zk.createSession(this, passwd, sessionTimeout);
- LOG.warn("Creating new session 0x"
- + Long.toHexString(sessionId));
+ LOG.info("Creating new session 0x" + Long.toHexString(sessionId));
}
initialized = true;
}
@@ -730,8 +729,8 @@
zk.removeCnxn(this);
}
- ZooTrace.logTraceMessage(LOG, ZooTrace.SESSION_TRACE_MASK,
- "close NIOServerCnxn: " + sock);
+ LOG.info("closing session:0x" + Long.toHexString(sessionId)
+ + " NIOServerCnxn: " + sock);
try {
/*
* The following sequence of code is stupid! You would think that
@@ -742,11 +741,13 @@
sock.socket().shutdownOutput();
} catch (IOException e) {
// This is a relatively common exception that we can't avoid
+ LOG.debug("ignoring exception during output shutdown", e);
}
try {
sock.socket().shutdownInput();
} catch (IOException e) {
- LOG.warn("ignoring exception during input shutdown", e);
+ // This is a relatively common exception that we can't avoid
+ LOG.debug("ignoring exception during input shutdown", e);
}
try {
sock.socket().close();
@@ -855,8 +856,10 @@
ByteBuffer bb = ByteBuffer.wrap(baos.toByteArray());
bb.putInt(bb.remaining() - 4).rewind();
sendBuffer(bb);
- LOG.warn("Finished init of 0x" + Long.toHexString(sessionId)
- + ": " + valid);
+
+ LOG.info("Finished init of 0x" + Long.toHexString(sessionId)
+ + " valid:" + valid);
+
if (!valid) {
sendBuffer(closeConn);
}
@@ -866,7 +869,7 @@
enableRecv();
}
} catch (Exception e) {
- LOG.error("FIXMSG",e);
+ LOG.warn("Exception while establishing session, closing", e);
close();
}
}
Modified: hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/PrepRequestProcessor.java
URL: http://svn.apache.org/viewvc/hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/PrepRequestProcessor.java?rev=734857&r1=734856&r2=734857&view=diff
==============================================================================
--- hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/PrepRequestProcessor.java (original)
+++ hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/PrepRequestProcessor.java Thu Jan 15 15:48:24 2009
@@ -99,10 +99,9 @@
pRequest(request);
}
} catch (InterruptedException e) {
- LOG.error("FIXMSG",e);
+ LOG.error("Unexpected interruption", e);
}
- ZooTrace.logTraceMessage(LOG, ZooTrace.getTextTraceLevel(),
- "PrepRequestProcessor exited loop!");
+ LOG.info("PrepRequestProcessor exited loop!");
}
ChangeRecord getRecordForPath(String path) throws KeeperException.NoNodeException {
@@ -360,18 +359,22 @@
txn = new ErrorTxn(e.code().intValue());
}
} catch (Exception e) {
- LOG.error("*********************************" + request);
+ // log at error level as we are returning a marshalling
+ // error to the user
+ LOG.error("Failed to process " + request, e);
+
StringBuffer sb = new StringBuffer();
ByteBuffer bb = request.request;
- if(bb!=null){
+ if(bb != null){
bb.rewind();
while (bb.hasRemaining()) {
sb.append(Integer.toHexString(bb.get() & 0xff));
}
- }else
+ } else {
sb.append("request buffer is null");
- LOG.error(sb.toString());
- LOG.error("Unexpected exception", e);
+ }
+
+ LOG.error("Dumping request buffer: 0x" + sb.toString());
if (txnHeader != null) {
txnHeader.setType(OpCode.error);
txn = new ErrorTxn(Code.MARSHALLINGERROR.intValue());
Modified: hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/SessionTrackerImpl.java
URL: http://svn.apache.org/viewvc/hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/SessionTrackerImpl.java?rev=734857&r1=734856&r2=734857&view=diff
==============================================================================
--- hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/SessionTrackerImpl.java (original)
+++ hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/SessionTrackerImpl.java Thu Jan 15 15:48:24 2009
@@ -129,7 +129,7 @@
if (set != null) {
for (Session s : set.sessions) {
sessionsById.remove(s.sessionId);
- LOG.warn("Expiring session 0x"
+ LOG.info("Expiring session 0x"
+ Long.toHexString(s.sessionId));
expirer.expire(s.sessionId);
}
@@ -137,10 +137,9 @@
nextExpirationTime += expirationInterval;
}
} catch (InterruptedException e) {
- LOG.error("FIXMSG",e);
+ LOG.error("Unexpected interruption", e);
}
- ZooTrace.logTraceMessage(LOG, ZooTrace.getTextTraceLevel(),
- "SessionTrackerImpl exited loop!");
+ LOG.info("SessionTrackerImpl exited loop!");
}
synchronized public boolean touchSession(long sessionId, int timeout) {
Modified: hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/SyncRequestProcessor.java
URL: http://svn.apache.org/viewvc/hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/SyncRequestProcessor.java?rev=734857&r1=734856&r2=734857&view=diff
==============================================================================
--- hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/SyncRequestProcessor.java (original)
+++ hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/SyncRequestProcessor.java Thu Jan 15 15:48:24 2009
@@ -110,15 +110,13 @@
}
}
}
- } catch (Exception e) {
- LOG.error("Severe error, exiting",e);
+ } catch (Throwable t) {
+ LOG.fatal("Severe unrecoverable error, exiting", t);
System.exit(11);
}
- ZooTrace.logTraceMessage(LOG, ZooTrace.getTextTraceLevel(),
- "SyncRequestProcessor exited!");
+ LOG.info("SyncRequestProcessor exited!");
}
- @SuppressWarnings("unchecked")
private void flush(LinkedList<Request> toFlush) throws IOException {
if (toFlush.size() == 0)
return;
Modified: hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/ZooKeeperServer.java
URL: http://svn.apache.org/viewvc/hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/ZooKeeperServer.java?rev=734857&r1=734856&r2=734857&view=diff
==============================================================================
--- hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/ZooKeeperServer.java (original)
+++ hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/ZooKeeperServer.java Thu Jan 15 15:48:24 2009
@@ -242,8 +242,7 @@
}
baos.close();
} catch (IOException e) {
- // This really should be impossible
- LOG.error("FIXMSG",e);
+ LOG.error("This really should be impossible", e);
}
QuorumPacket pp = new QuorumPacket(Leader.PROPOSAL, request.zxid,
baos.toByteArray(), null);
@@ -259,7 +258,7 @@
try {
txnLogFactory.save(dataTree, sessionsWithTimeouts);
} catch (IOException e) {
- LOG.error("Severe error, exiting",e);
+ LOG.fatal("Severe unrecoverable error, exiting", e);
// This is a severe error that we cannot recover from,
// so we need to exit
System.exit(10);
@@ -293,13 +292,16 @@
return System.currentTimeMillis();
}
- public void closeSession(long sessionId) throws InterruptedException {
- ZooTrace.logTraceMessage(LOG, ZooTrace.SESSION_TRACE_MASK,
- "ZooKeeperServer --- Session to be closed: 0x"
- + Long.toHexString(sessionId));
+ private void close(long sessionId) {
+ submitRequest(null, sessionId, OpCode.closeSession, 0, null, null);
+ }
+
+ public void closeSession(long sessionId) {
+ LOG.info("Closing session 0x" + Long.toHexString(sessionId));
+
// we do not want to wait for a session close. send it as soon as we
// detect it!
- submitRequest(null, sessionId, OpCode.closeSession, 0, null, null);
+ close(sessionId);
}
protected void killSession(long sessionId, long zxid) {
@@ -313,15 +315,8 @@
}
public void expire(long sessionId) {
- try {
- ZooTrace.logTraceMessage(LOG,
- ZooTrace.SESSION_TRACE_MASK,
- "ZooKeeperServer --- Session to expire: 0x"
- + Long.toHexString(sessionId));
- closeSession(sessionId);
- } catch (Exception e) {
- LOG.error("FIXMSG",e);
- }
+ LOG.info("Expiring session 0x" + Long.toHexString(sessionId));
+ close(sessionId);
}
void touch(ServerCnxn cnxn) throws IOException {
@@ -502,8 +497,7 @@
}
}
- public void closeSession(ServerCnxn cnxn, RequestHeader requestHeader)
- throws InterruptedException {
+ public void closeSession(ServerCnxn cnxn, RequestHeader requestHeader) {
closeSession(cnxn.getSessionId());
}
@@ -531,7 +525,7 @@
wait(1000);
}
} catch (InterruptedException e) {
- LOG.error("FIXMSG",e);
+ LOG.warn("Unexpected interruption", e);
}
if (firstProcessor == null) {
throw new RuntimeException("Not started");
@@ -548,10 +542,10 @@
}
} else {
LOG.warn("Dropping packet at server of type " + si.type);
- // if unvalid packet drop the packet.
+ // if invalid packet drop the packet.
}
} catch (IOException e) {
- LOG.error("FIXMSG",e);
+ LOG.warn("Ignoring unexpected exception", e);
}
}
Modified: hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/AuthFastLeaderElection.java
URL: http://svn.apache.org/viewvc/hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/AuthFastLeaderElection.java?rev=734857&r1=734856&r2=734857&view=diff
==============================================================================
--- hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/AuthFastLeaderElection.java (original)
+++ hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/AuthFastLeaderElection.java Thu Jan 15 15:48:24 2009
@@ -234,7 +234,7 @@
responseBuffer.clear();
mySocket.receive(responsePacket);
} catch (IOException e) {
- LOG.warn("Exception receiving: " + e.toString());
+ LOG.warn("Ignoring exception receiving", e);
}
// Receive new message
if (responsePacket.getLength() != responseBytes.length) {
@@ -370,7 +370,7 @@
break;
// Default case
default:
- LOG.warn("Received message of incorrect type");
+ LOG.warn("Received message of incorrect type " + type);
break;
}
}
@@ -459,8 +459,7 @@
mySocket.send(requestPacket);
}
} catch (IOException e) {
- LOG.warn("Exception while sending challenge: "
- + e.toString());
+ LOG.warn("Exception while sending challenge: ", e);
}
break;
@@ -492,8 +491,7 @@
try {
mySocket.send(requestPacket);
} catch (IOException e) {
- LOG.warn("Exception while sending challenge: "
- + e.toString());
+ LOG.warn("Exception while sending challenge: ", e);
}
break;
@@ -545,8 +543,7 @@
.containsKey(m.tag);
}
} catch (InterruptedException e) {
- LOG.warn("Challenge request exception: "
- + e.toString());
+ LOG.warn("Challenge request exception: ", e);
}
}
@@ -574,8 +571,7 @@
l.wait((int) timeout);
}
} catch (InterruptedException e) {
- LOG.warn("Ack exception: "
- + e.toString());
+ LOG.warn("Ack exception: ", e);
}
synchronized (acksqueue) {
for (int i = 0; i < acksqueue.size(); ++i) {
@@ -598,8 +594,7 @@
}
}
} catch (IOException e) {
- LOG.warn("Sending exception: "
- + e.toString());
+ LOG.warn("Sending exception: ", e);
/*
* Do nothing, just try again
*/
@@ -639,8 +634,7 @@
try {
mySocket.send(requestPacket);
} catch (IOException e) {
- LOG.warn("Exception while sending ack: "
- + e.toString());
+ LOG.warn("Exception while sending ack: ", e);
}
break;
}
@@ -781,7 +775,7 @@
proposedLeader = self.getId();
proposedZxid = self.getLastLoggedZxid();
- LOG.warn("Election tally");
+ LOG.info("Election tally");
sendNotifications();
/*
@@ -838,7 +832,7 @@
} else if (termPredicate(recvset, proposedLeader,
proposedZxid)) {
// Otherwise, wait for a fixed amount of time
- LOG.warn("Passed predicate");
+ LOG.info("Passed predicate");
Thread.sleep(finalizeWait);
// Notification probe = recvqueue.peek();
Modified: hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/CommitProcessor.java
URL: http://svn.apache.org/viewvc/hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/CommitProcessor.java?rev=734857&r1=734856&r2=734857&view=diff
==============================================================================
--- hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/CommitProcessor.java (original)
+++ hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/CommitProcessor.java Thu Jan 15 15:48:24 2009
@@ -144,10 +144,9 @@
}
}
} catch (Exception e) {
- LOG.error("FIXMSG",e);
+ LOG.error("Unexpected exception causing exit", e);
}
- ZooTrace.logTraceMessage(LOG, ZooTrace.getTextTraceLevel(),
- "CommitProcessor exited loop!");
+ LOG.info("CommitProcessor exited loop!");
}
synchronized public void commit(Request request) {
Modified: hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/FastLeaderElection.java
URL: http://svn.apache.org/viewvc/hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/FastLeaderElection.java?rev=734857&r1=734856&r2=734857&view=diff
==============================================================================
--- hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/FastLeaderElection.java (original)
+++ hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/FastLeaderElection.java Thu Jan 15 15:48:24 2009
@@ -514,7 +514,7 @@
updateProposal(self.getId(), self.getLastLoggedZxid());
}
- LOG.warn("New election: " + proposedZxid);
+ LOG.info("New election: " + proposedZxid);
sendNotifications();
/*
Modified: hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/Follower.java
URL: http://svn.apache.org/viewvc/hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/Follower.java?rev=734857&r1=734856&r2=734857&view=diff
==============================================================================
--- hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/Follower.java (original)
+++ hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/Follower.java Thu Jan 15 15:48:24 2009
@@ -154,7 +154,7 @@
LOG.error("Unexpected exception",e);
throw e;
} else {
- LOG.warn("Unexpected exception",e);
+ LOG.warn("Unexpected exception, tries="+tries,e);
sock = new Socket();
sock.setSoTimeout(self.tickTime * self.initLimit);
}
@@ -199,7 +199,7 @@
boolean truncated=zk.getLogWriter().truncateLog(qp.getZxid());
if (!truncated) {
// not able to truncate the log
- LOG.error("Not able to truncate the log "
+ LOG.fatal("Not able to truncate the log "
+ Long.toHexString(qp.getZxid()));
System.exit(13);
}
@@ -207,7 +207,7 @@
zk.loadData();
}
else {
- LOG.error("Got unexpected packet from leader "
+ LOG.fatal("Got unexpected packet from leader "
+ qp.getType() + " exiting ... " );
System.exit(13);
}
@@ -398,6 +398,6 @@
zk.shutdown();
}
- LOG.error("FIXMSG",new Exception("shutdown Follower"));
+ LOG.info("shutdown called", new Exception("shutdown Follower"));
}
}
Modified: hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/FollowerHandler.java
URL: http://svn.apache.org/viewvc/hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/FollowerHandler.java?rev=734857&r1=734856&r2=734857&view=diff
==============================================================================
--- hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/FollowerHandler.java (original)
+++ hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/FollowerHandler.java Thu Jan 15 15:48:24 2009
@@ -280,7 +280,7 @@
try {
sendPackets();
} catch (InterruptedException e) {
- LOG.warn("Interrupted",e);
+ LOG.warn("Unexpected interruption",e);
}
}
}.start();
@@ -353,10 +353,11 @@
}
} catch (IOException e) {
if (sock != null && !sock.isClosed()) {
- LOG.error("FIXMSG",e);
+ LOG.error("Unexpected exception causing shutdown while sock "
+ + "still open", e);
}
} catch (InterruptedException e) {
- LOG.error("FIXMSG",e);
+ LOG.error("Unexpected exception causing shutdown", e);
} finally {
LOG.warn("******* GOODBYE "
+ (sock != null ? sock.getRemoteSocketAddress() : "<null>")
@@ -365,7 +366,7 @@
try {
queuedPackets.put(proposalOfDeath);
} catch (InterruptedException e) {
- LOG.error("FIXMSG",e);
+ LOG.warn("Ignoring unexpected exception", e);
}
shutdown();
}
@@ -377,7 +378,7 @@
sock.close();
}
} catch (IOException e) {
- LOG.error("FIXMSG",e);
+ LOG.warn("Ignoring unexpected exception during socket close", e);
}
leader.removeFollowerHandler(this);
}
Modified: hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/FollowerRequestProcessor.java
URL: http://svn.apache.org/viewvc/hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/FollowerRequestProcessor.java?rev=734857&r1=734856&r2=734857&view=diff
==============================================================================
--- hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/FollowerRequestProcessor.java (original)
+++ hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/FollowerRequestProcessor.java Thu Jan 15 15:48:24 2009
@@ -85,10 +85,9 @@
}
}
} catch (Exception e) {
- LOG.error("FIXMSG",e);
+ LOG.error("Unexpected exception causing exit", e);
}
- ZooTrace.logTraceMessage(LOG, ZooTrace.getTextTraceLevel(),
- "FollowerRequestProcessor exited loop!");
+ LOG.info("FollowerRequestProcessor exited loop!");
}
public void processRequest(Request request) {
Modified: hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/FollowerZooKeeperServer.java
URL: http://svn.apache.org/viewvc/hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/FollowerZooKeeperServer.java?rev=734857&r1=734856&r2=734857&view=diff
==============================================================================
--- hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/FollowerZooKeeperServer.java (original)
+++ hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/FollowerZooKeeperServer.java Thu Jan 15 15:48:24 2009
@@ -129,7 +129,7 @@
}
long firstElementZxid = pendingTxns.element().zxid;
if (firstElementZxid != zxid) {
- LOG.error("Committing zxid 0x" + Long.toHexString(zxid)
+ LOG.fatal("Committing zxid 0x" + Long.toHexString(zxid)
+ " but next pending txn 0x"
+ Long.toHexString(firstElementZxid));
System.exit(12);
@@ -166,14 +166,15 @@
try {
super.shutdown();
} catch (Exception e) {
- LOG.error("FIXMSG",e);
+ LOG.warn("Ignoring unexpected exception during shutdown", e);
}
try {
if (syncProcessor != null) {
syncProcessor.shutdown();
}
} catch (Exception e) {
- LOG.error("FIXMSG",e);
+ LOG.warn("Ignoring unexpected exception in syncprocessor shutdown",
+ e);
}
}
Modified: hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/Leader.java
URL: http://svn.apache.org/viewvc/hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/Leader.java?rev=734857&r1=734856&r2=734857&view=diff
==============================================================================
--- hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/Leader.java (original)
+++ hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/Leader.java Thu Jan 15 15:48:24 2009
@@ -113,7 +113,7 @@
ss = new ServerSocket(self.getQuorumAddress().getPort());
} catch (BindException e) {
LOG.error("Couldn't bind to port "
- + self.getQuorumAddress().getPort());
+ + self.getQuorumAddress().getPort(), e);
throw e;
}
this.zk=zk;
@@ -254,8 +254,8 @@
newLeaderProposal.packet = new QuorumPacket(NEWLEADER, zk.getZxid(),
null, null);
if ((newLeaderProposal.packet.getZxid() & 0xffffffffL) != 0) {
- LOG.warn("NEWLEADER proposal has Zxid of "
- + newLeaderProposal.packet.getZxid());
+ LOG.info("NEWLEADER proposal has Zxid of "
+ + Long.toHexString(newLeaderProposal.packet.getZxid()));
}
outstandingProposals.add(newLeaderProposal);
@@ -354,7 +354,7 @@
try {
ss.close();
} catch (IOException e) {
- LOG.error("FIXMSG",e);
+ LOG.warn("Ignoring unexpected exception during close",e);
}
synchronized (followers) {
for (Iterator<FollowerHandler> it = followers.iterator(); it
Modified: hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/LeaderElection.java
URL: http://svn.apache.org/viewvc/hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/LeaderElection.java?rev=734857&r1=734856&r2=734857&view=diff
==============================================================================
--- hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/LeaderElection.java (original)
+++ hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/LeaderElection.java Thu Jan 15 15:48:24 2009
@@ -97,13 +97,13 @@
}
}
result.winningCount = 0;
- LOG.warn("Election tally: ");
+ LOG.info("Election tally: ");
for (Entry<Vote, Integer> entry : countTable.entrySet()) {
if (entry.getValue() > result.winningCount) {
result.winningCount = entry.getValue();
result.winner = entry.getKey();
}
- LOG.warn(entry.getKey().id + "\t-> " + entry.getValue());
+ LOG.info(entry.getKey().id + "\t-> " + entry.getValue());
}
return result;
}
@@ -139,7 +139,7 @@
HashSet<Long> heardFrom = new HashSet<Long>();
for (QuorumServer server : self.quorumPeers.values()) {
requestPacket.setSocketAddress(server.addr);
- LOG.warn("Server address: " + server.addr);
+ LOG.info("Server address: " + server.addr);
try {
s.send(requestPacket);
responsePacket.setLength(responseBytes.length);
@@ -166,10 +166,9 @@
votes.put(addr, vote);
//}
} catch (IOException e) {
- LOG.error("Error in looking for leader", e);
+ LOG.warn("Ignoring exception while looking for leader", e);
// Errors are okay, since hosts may be
// down
- // ZooKeeperServer.logException(e);
}
}
ElectionResult result = countVotes(votes, heardFrom);
Modified: hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/QuorumCnxManager.java
URL: http://svn.apache.org/viewvc/hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/QuorumCnxManager.java?rev=734857&r1=734856&r2=734857&view=diff
==============================================================================
--- hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/QuorumCnxManager.java (original)
+++ hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/QuorumCnxManager.java Thu Jan 15 15:48:24 2009
@@ -21,14 +21,15 @@
import java.io.IOException;
import java.net.InetAddress;
import java.net.InetSocketAddress;
+import java.net.Socket;
import java.net.UnknownHostException;
import java.nio.ByteBuffer;
import java.nio.channels.ServerSocketChannel;
import java.nio.channels.SocketChannel;
+import java.util.Enumeration;
import java.util.Random;
import java.util.concurrent.ArrayBlockingQueue;
import java.util.concurrent.ConcurrentHashMap;
-import java.util.Enumeration;
import org.apache.log4j.Logger;
@@ -160,8 +161,7 @@
msgBuffer.position(0);
s.write(msgBuffer);
} catch (IOException e) {
- LOG.warn("Exception reading or writing challenge: "
- + e.toString());
+ LOG.warn("Exception reading or writing challenge: ", e);
return false;
}
@@ -172,9 +172,8 @@
sid + ", " + self.getId() + ")");
s.socket().close();
} catch (IOException e) {
- LOG.error("Error when closing socket or trying to reopen connection: "
- + e.toString());
-
+ LOG.warn("Ignoring exception when closing socket or trying to "
+ + "reopen connection: ", e);
}
// Otherwise proceed with the connection
} else {
@@ -294,7 +293,7 @@
b.position(0);
recvQueue.put(new Message(b.duplicate(), sid));
} catch (InterruptedException e) {
- LOG.warn("Exception when loopbacking");
+ LOG.warn("Exception when loopbacking", e);
}
/*
* Otherwise send to the corresponding thread to send.
@@ -319,8 +318,8 @@
connectOne(sid);
} catch (InterruptedException e) {
- LOG.warn("Interrupted while waiting to put message in queue."
- + e.toString());
+ LOG.warn("Interrupted while waiting to put message in queue.",
+ e);
}
}
@@ -339,9 +338,7 @@
channel.socket().setTcpNoDelay(true);
initiateConnection(channel, sid);
} catch (IOException e) {
- LOG.warn("Cannot open channel to "
- + sid + "( " + e.toString()
- + ")");
+ LOG.warn("Cannot open channel to " + sid, e);
}
}
}
@@ -379,11 +376,11 @@
*/
public void halt() {
shutdown = true;
- LOG.warn("Halting listener");
+ LOG.info("Halting listener");
listener.halt();
for(SendWorker sw: senderWorkerMap.values()){
- LOG.warn("Halting sender: " + sw);
+ LOG.info("Halting sender: " + sw);
sw.finish();
}
}
@@ -403,17 +400,17 @@
try {
ss = ServerSocketChannel.open();
int port = self.quorumPeers.get(self.getId()).electionAddr.getPort();
- LOG.warn("My election bind port: " + port);
+ LOG.info("My election bind port: " + port);
ss.socket().bind(new InetSocketAddress(port));
while (!shutdown) {
SocketChannel client = ss.accept();
- client.socket().setTcpNoDelay(true);
+ Socket sock = client.socket();
+ sock.setTcpNoDelay(true);
- //synchronized(senderWorkerMap){
- LOG.warn("Connection request");
+ LOG.info("Connection request "
+ + sock.getRemoteSocketAddress());
receiveConnection(client);
- //}
}
} catch (IOException e) {
System.err.println("Listener.run: " + e.getMessage());
@@ -434,7 +431,6 @@
* soon as there is one available. If connection breaks, then opens a new
* one.
*/
-
class SendWorker extends Thread {
// Send msgs to peer
Long sid;
@@ -473,8 +469,8 @@
try {
b = queueSendMap.get(sid).take();
} catch (InterruptedException e) {
- LOG.warn("Interrupted while waiting for message on queue ("
- + e.toString() + ")");
+ LOG.warn("Interrupted while waiting for message on queue",
+ e);
continue;
}
@@ -493,8 +489,7 @@
* If reconnection doesn't work, then put the
* message back to the beginning of the queue and leave.
*/
- LOG.warn("Exception when using channel: " + sid
- + ")" + e.toString());
+ LOG.warn("Exception when using channel: " + sid, e);
running = false;
synchronized (senderWorkerMap) {
recvWorker.finish();
@@ -509,7 +504,7 @@
}
}
}
- LOG.warn("Leaving thread");
+ LOG.warn("Send worker leaving thread");
}
}
@@ -569,12 +564,11 @@
}
} catch (IOException e) {
- LOG.warn("Connection broken: " + e.toString());
+ LOG.warn("Connection broken: ", e);
} catch (InterruptedException e) {
LOG.warn("Interrupted while trying to add new "
- + "message to the reception queue (" + e.toString()
- + ")");
+ + "message to the reception queue", e);
}
}
}
Modified: hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/QuorumPeerConfig.java
URL: http://svn.apache.org/viewvc/hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/QuorumPeerConfig.java?rev=734857&r1=734856&r2=734857&view=diff
==============================================================================
--- hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/QuorumPeerConfig.java (original)
+++ hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/QuorumPeerConfig.java Thu Jan 15 15:48:24 2009
@@ -96,9 +96,8 @@
long sid = Long.parseLong(key.substring(dot + 1));
String parts[] = value.split(":");
if ((parts.length != 2) && (parts.length != 3)) {
- LOG
- .error(value
- + " does not have the form host:port or host:port:port");
+ LOG.error(value
+ + " does not have the form host:port or host:port:port");
}
InetSocketAddress addr = new InetSocketAddress(parts[0],
Integer.parseInt(parts[1]));
Modified: hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/SendAckRequestProcessor.java
URL: http://svn.apache.org/viewvc/hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/SendAckRequestProcessor.java?rev=734857&r1=734856&r2=734857&view=diff
==============================================================================
--- hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/SendAckRequestProcessor.java (original)
+++ hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/quorum/SendAckRequestProcessor.java Thu Jan 15 15:48:24 2009
@@ -42,7 +42,7 @@
try {
follower.writePacket(qp);
} catch (IOException e) {
- LOG.error("FIXMSG",e);
+ LOG.warn("Ignoring unexpected exception during packet send", e);
}
}
}
Modified: hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/upgrade/DataTreeV1.java
URL: http://svn.apache.org/viewvc/hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/upgrade/DataTreeV1.java?rev=734857&r1=734856&r2=734857&view=diff
==============================================================================
--- hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/upgrade/DataTreeV1.java (original)
+++ hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/upgrade/DataTreeV1.java Thu Jan 15 15:48:24 2009
@@ -33,15 +33,15 @@
import org.apache.log4j.Logger;
import org.apache.zookeeper.KeeperException;
import org.apache.zookeeper.Watcher;
-import org.apache.zookeeper.Watcher.Event.EventType;
import org.apache.zookeeper.KeeperException.Code;
+import org.apache.zookeeper.KeeperException.NoNodeException;
import org.apache.zookeeper.Watcher.Event;
+import org.apache.zookeeper.Watcher.Event.EventType;
import org.apache.zookeeper.ZooDefs.OpCode;
import org.apache.zookeeper.data.ACL;
import org.apache.zookeeper.data.Stat;
import org.apache.zookeeper.data.StatPersistedV1;
import org.apache.zookeeper.server.WatchManager;
-import org.apache.zookeeper.server.ZooTrace;
import org.apache.zookeeper.txn.CreateTxn;
import org.apache.zookeeper.txn.DeleteTxn;
import org.apache.zookeeper.txn.ErrorTxn;
@@ -76,9 +76,6 @@
*/
private Map<Long, HashSet<String>> ephemerals = new ConcurrentHashMap<Long, HashSet<String>>();
- /** A debug string * */
- private String debug = "debug";
-
/**
* return the ephemerals for this tree
* @return the ephemerals for this tree
@@ -391,6 +388,7 @@
public ProcessTxnResult processTxn(TxnHeader header, Record txn) {
ProcessTxnResult rc = new ProcessTxnResult();
+ String debug = "";
try {
rc.clientId = header.getClientId();
rc.cxid = header.getCxid();
@@ -423,6 +421,7 @@
break;
case OpCode.setACL:
SetACLTxn setACLTxn = (SetACLTxn) txn;
+ debug = "Set ACL for transaction for " + setACLTxn.getPath();
rc.stat = setACL(setACLTxn.getPath(), setACLTxn.getAcl(),
setACLTxn.getVersion());
break;
@@ -439,8 +438,7 @@
if (initialized
|| (e.code() != Code.NONODE
&& e.code() != Code.NODEEXISTS)) {
- LOG.warn(debug);
- LOG.error("FIXMSG",e);
+ LOG.warn("Failed:" + debug, e);
}
}
return rc;
@@ -458,13 +456,15 @@
for (String path : list) {
try {
deleteNode(path);
- ZooTrace.logTraceMessage(LOG,
- ZooTrace.SESSION_TRACE_MASK,
- "Deleting ephemeral node "
- + path + " for session 0x"
- + Long.toHexString(session));
- } catch (KeeperException e) {
- LOG.error("FIXMSG",e);
+ if (LOG.isDebugEnabled()) {
+ LOG.debug("Deleting ephemeral node " + path
+ + " for session 0x"
+ + Long.toHexString(session));
+ }
+ } catch (NoNodeException e) {
+ LOG.warn("Ignoring NoNodeException for path " + path
+ + " while removing ephemeral for dead session 0x"
+ + Long.toHexString(session));
}
}
}
Modified: hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/upgrade/UpgradeSnapShotV1.java
URL: http://svn.apache.org/viewvc/hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/upgrade/UpgradeSnapShotV1.java?rev=734857&r1=734856&r2=734857&view=diff
==============================================================================
--- hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/upgrade/UpgradeSnapShotV1.java (original)
+++ hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/upgrade/UpgradeSnapShotV1.java Thu Jan 15 15:48:24 2009
@@ -118,7 +118,7 @@
Record txn = SerializeUtils.deserializeTxn(ia, hdr);
if (logStream.readByte("EOR") != 'B') {
LOG.warn("Last transaction was partial.");
- throw new EOFException();
+ throw new EOFException("Last transaction was partial.");
}
if (hdr.getZxid() <= highestZxid && highestZxid != 0) {
LOG.error(highestZxid + "(higestZxid) >= "
@@ -175,7 +175,7 @@
File[] logFiles) throws IOException {
long zxid = 0;
for (File f: logFiles) {
- LOG.warn("Processing log file: " + f);
+ LOG.info("Processing log file: " + f);
InputStream logIs =
new BufferedInputStream(new FileInputStream(f));
zxid = playLog(BinaryInputArchive.getArchive(logIs));
Modified: hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/util/Profiler.java
URL: http://svn.apache.org/viewvc/hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/util/Profiler.java?rev=734857&r1=734856&r2=734857&view=diff
==============================================================================
--- hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/util/Profiler.java (original)
+++ hadoop/zookeeper/trunk/src/java/main/org/apache/zookeeper/server/util/Profiler.java Thu Jan 15 15:48:24 2009
@@ -33,7 +33,7 @@
T res = op.execute();
long end = System.currentTimeMillis();
if (end - start > timeout) {
- LOG.warn("Elapsed "+(end - start) + " ms: " + message);
+ LOG.info("Elapsed "+(end - start) + " ms: " + message);
}
return res;
}
|