Author: david.lloyd(a)jboss.com
Date: 2008-11-18 13:52:09 -0500 (Tue, 18 Nov 2008)
New Revision: 4697
Modified:
remoting3/trunk/protocol/multiplex/src/main/java/org/jboss/remoting/protocol/multiplex/FutureRemoteRequestHandlerSource.java
remoting3/trunk/protocol/multiplex/src/main/java/org/jboss/remoting/protocol/multiplex/MultiplexConnection.java
remoting3/trunk/protocol/multiplex/src/main/java/org/jboss/remoting/protocol/multiplex/MultiplexReadHandler.java
remoting3/trunk/protocol/multiplex/src/main/java/org/jboss/remoting/protocol/multiplex/MultiplexReplyHandler.java
remoting3/trunk/protocol/multiplex/src/main/java/org/jboss/remoting/protocol/multiplex/MultiplexRequestHandler.java
remoting3/trunk/protocol/multiplex/src/main/java/org/jboss/remoting/protocol/multiplex/MultiplexRequestHandlerSource.java
Log:
More logging updates
Modified:
remoting3/trunk/protocol/multiplex/src/main/java/org/jboss/remoting/protocol/multiplex/FutureRemoteRequestHandlerSource.java
===================================================================
---
remoting3/trunk/protocol/multiplex/src/main/java/org/jboss/remoting/protocol/multiplex/FutureRemoteRequestHandlerSource.java 2008-11-15
02:11:16 UTC (rev 4696)
+++
remoting3/trunk/protocol/multiplex/src/main/java/org/jboss/remoting/protocol/multiplex/FutureRemoteRequestHandlerSource.java 2008-11-18
18:52:09 UTC (rev 4697)
@@ -43,4 +43,8 @@
protected boolean setResult(final RequestHandlerSource result) {
return super.setResult(result);
}
+
+ public String toString() {
+ return "future remote request handler source <" +
Integer.toHexString(hashCode()) + ">";
+ }
}
Modified:
remoting3/trunk/protocol/multiplex/src/main/java/org/jboss/remoting/protocol/multiplex/MultiplexConnection.java
===================================================================
---
remoting3/trunk/protocol/multiplex/src/main/java/org/jboss/remoting/protocol/multiplex/MultiplexConnection.java 2008-11-15
02:11:16 UTC (rev 4696)
+++
remoting3/trunk/protocol/multiplex/src/main/java/org/jboss/remoting/protocol/multiplex/MultiplexConnection.java 2008-11-18
18:52:09 UTC (rev 4697)
@@ -141,6 +141,7 @@
}
void doBlockingWrite(ByteBuffer... buffers) throws IOException {
+ log.trace("Sending message:\n%s", new MultiDumper(buffers));
if (buffers.length == 1) doBlockingWrite(buffers[0]); else for (;;) {
if (channel.send(buffers)) {
return;
@@ -149,6 +150,30 @@
}
}
+ private static final class MultiDumper {
+ private final ByteBuffer[] buffers;
+
+ public MultiDumper(final ByteBuffer[] buffers) {
+ this.buffers = buffers;
+ }
+
+ public String toString() {
+ StringBuilder builder = new StringBuilder();
+ for (int i = 0; i < buffers.length; i++) {
+ ByteBuffer buffer = buffers[i];
+ builder.append("Buffer ");
+ builder.append(i);
+ builder.append(":\n");
+ try {
+ Buffers.dump(buffer, builder, 8, 1);
+ } catch (IOException e) {
+ // ignore
+ }
+ }
+ return builder.toString();
+ }
+ }
+
void doBlockingWrite(ByteBuffer buffer) throws IOException {
log.trace("Sending message:\n%s", Buffers.createDumper(buffer, 8, 1));
for (;;) {
@@ -256,6 +281,7 @@
}
public Handle<RequestHandlerSource> openRemoteService(final QualifiedName name)
throws IOException {
+ log.trace("Sending request to open remote service \"%s\"",
name);
final FutureRemoteRequestHandlerSource future = new
FutureRemoteRequestHandlerSource();
int id;
for (;;) {
@@ -272,7 +298,7 @@
doBlockingWrite(buffer);
try {
final Handle<RequestHandlerSource> handle =
future.getInterruptibly().getHandle();
- log.trace("Opened %s to %s", handle, this);
+ log.trace("Opened %s", handle);
return handle;
} catch (InterruptedException e) {
Thread.currentThread().interrupt();
@@ -426,7 +452,7 @@
}
public String toString() {
- return "multiplex connection <" + Integer.toHexString(hashCode()) +
"> on " + channel;
+ return "multiplex connection <" + Integer.toHexString(hashCode()) +
"> via " + channel;
}
@SuppressWarnings({ "unchecked" })
Modified:
remoting3/trunk/protocol/multiplex/src/main/java/org/jboss/remoting/protocol/multiplex/MultiplexReadHandler.java
===================================================================
---
remoting3/trunk/protocol/multiplex/src/main/java/org/jboss/remoting/protocol/multiplex/MultiplexReadHandler.java 2008-11-15
02:11:16 UTC (rev 4696)
+++
remoting3/trunk/protocol/multiplex/src/main/java/org/jboss/remoting/protocol/multiplex/MultiplexReadHandler.java 2008-11-18
18:52:09 UTC (rev 4697)
@@ -84,7 +84,7 @@
channel.resumeReads();
return;
}
- log.trace("Received message:\n%s", Buffers.createDumper(buffer, 8,
1));
+ log.trace("Received raw message:\n%s", Buffers.createDumper(buffer,
8, 1));
final MessageType msgType;
try {
msgType = MessageType.getMessageType(buffer.get() & 0xff);
@@ -92,7 +92,6 @@
log.trace("Received invalid message type");
return;
}
- log.trace("Decoded message type %s", msgType);
switch (msgType) {
case REQUEST: {
final int clientId = buffer.getInt();
@@ -109,6 +108,7 @@
unmarshaller.start(Marshalling.createByteInput(buffer));
payload = unmarshaller.readObject();
unmarshaller.finish();
+ log.trace("Received inbound request (client id = %d,
request id = %d) (type is %s)", Integer.valueOf(clientId),
Integer.valueOf(requestId), payload == null ? "null" : payload.getClass());
} finally {
IoUtils.safeClose(unmarshaller);
}
@@ -155,6 +155,7 @@
unmarshaller.start(Marshalling.createByteInput(buffer));
payload = unmarshaller.readObject();
unmarshaller.finish();
+ log.trace("Received inbound reply (id = %d) (type is
%s)", Integer.valueOf(requestId), payload == null ? "null" :
payload.getClass());
} finally {
IoUtils.safeClose(unmarshaller);
}
@@ -171,6 +172,7 @@
final int requestId = buffer.getInt();
final RemoteRequestContext context =
connection.getLocalRequest(requestId);
if (context != null) {
+ log.trace("Received inbound cancel request (request id = %d)
to %s", Integer.valueOf(requestId), context);
context.cancel();
}
break;
@@ -179,6 +181,7 @@
final int requestId = buffer.getInt();
final ReplyHandler replyHandler =
connection.getRemoteRequest(requestId);
if (replyHandler != null) {
+ log.trace("Received inbound cancel acknowledge (request id =
%d) to ", Integer.valueOf(requestId), replyHandler);
SpiUtils.safeHandleCancellation(replyHandler);
}
break;
@@ -187,7 +190,7 @@
final int requestId = buffer.getInt();
final ReplyHandler replyHandler =
connection.removeRemoteRequest(requestId);
if (replyHandler == null) {
- log.trace("Got reply to unknown request %d",
Integer.valueOf(requestId));
+ log.trace("Got a failure reply to unknown request %d to
%s", Integer.valueOf(requestId), replyHandler);
break;
}
final IOException cause;
@@ -197,13 +200,16 @@
unmarshaller.start(Marshalling.createByteInput(buffer));
cause = (IOException) unmarshaller.readObject();
unmarshaller.finish();
+ log.trace("Received inbound request receive failure
notification to %s: %s", replyHandler, cause);
} finally {
IoUtils.safeClose(unmarshaller);
}
} catch (IOException e) {
+ log.trace("Received inbound request receive failure
notification; the remote exception could not be read: %s", e);
SpiUtils.safeHandleException(replyHandler, new
RemoteExecutionException("Remote operation failed; the remote exception could not be
read", e));
break;
} catch (ClassNotFoundException e) {
+ log.trace("Received inbound request receive failure
notification; the remote exception could not be read: %s", e);
SpiUtils.safeHandleException(replyHandler, new
RemoteExecutionException("Remote operation failed; the remote exception could not be
read", e));
break;
}
@@ -224,11 +230,14 @@
unmarshaller.start(Marshalling.createByteInput(buffer));
try {
cause = (IOException) unmarshaller.readObject();
+ log.trace("Received inbound request failure
notification: %s", cause);
} catch (ClassNotFoundException e) {
+ log.trace("Received inbound request failure
notification; the remote exception could not be read: %s", e);
SpiUtils.safeHandleException(replyHandler, new
RemoteExecutionException("Remote request failed (and an ClassNotFoundException
occurred when attempting to unmarshal the cause)"));
log.trace(e, "Class not found in exception reply to
request ID %d", Integer.valueOf(requestId));
break;
} catch (ClassCastException e) {
+ log.trace("Received inbound request failure
notification; the remote exception could not be read: %s", e);
SpiUtils.safeHandleException(replyHandler, new
RemoteExecutionException("Remote request failed (and an ClassCastException occurred
when attempting to unmarshal the cause)"));
log.trace(e, "Class cast exception in exception
reply to request ID %d", Integer.valueOf(requestId));
break;
@@ -237,7 +246,7 @@
IoUtils.safeClose(unmarshaller);
}
} catch (IOException ex) {
- log.trace("Failed to unmarshal an exception reply (%s),
sending a generic execution exception");
+ log.trace("Received inbound request failure notification;
the remote exception could not be read: %s", ex);
SpiUtils.safeHandleException(replyHandler, new
RemoteExecutionException("Remote request failed (and an unexpected I/O error occurred
when attempting to read the cause)"));
break;
}
@@ -251,6 +260,7 @@
log.warn("Got client close message for unknown client
%d", Integer.valueOf(clientId));
break;
}
+ log.trace("Received inbound client close for %s", handle);
IoUtils.safeClose(handle);
break;
}
@@ -278,6 +288,7 @@
case SERVICE_OPEN_REQUEST: {
final int serviceId = buffer.getInt();
final QualifiedName qualifiedName =
MultiplexConnection.getQualifiedName(buffer);
+ log.trace("Received a service open request for service %d on
path \"%s\"", Integer.valueOf(serviceId), qualifiedName);
final Handle<RequestHandlerSource> service =
connection.getService(qualifiedName);
if (service == null) {
ByteBuffer replyBuffer = ByteBuffer.allocate(5);
@@ -285,6 +296,7 @@
replyBuffer.putInt(serviceId);
replyBuffer.flip();
try {
+ log.trace("Sending a service-open-not-found message for
request for service %d on path \"%s\"", Integer.valueOf(serviceId),
qualifiedName);
connection.doBlockingWrite(replyBuffer);
} catch (IOException e) {
log.error(e, "Failed to send an error reply to an
invalid service open request");
@@ -301,6 +313,7 @@
replyBuffer.putInt(serviceId);
replyBuffer.flip();
try {
+ log.trace("Sending a service-open-failed message for
request for service %d on path \"%s\"", Integer.valueOf(serviceId),
qualifiedName);
connection.doBlockingWrite(replyBuffer);
} catch (IOException e2) {
log.trace(e, "Failed to send an exception reply to a
service open request");
@@ -313,6 +326,7 @@
replyBuffer.putInt(serviceId);
replyBuffer.flip();
try {
+ log.trace("Sending a service open reply message for request
for service %d on path \"%s\"", Integer.valueOf(serviceId),
qualifiedName);
connection.doBlockingWrite(replyBuffer);
} catch (IOException e) {
log.trace(e, "Failed to send a reply to a service open
request");
@@ -323,6 +337,7 @@
case SERVICE_OPEN_NOT_FOUND:
case SERVICE_OPEN_FORBIDDEN: {
final int serviceId = buffer.getInt();
+ log.trace("Received a service open failure (%s) message for
service %d", msgType, Integer.valueOf(serviceId));
final FutureRemoteRequestHandlerSource future =
connection.removeFutureRemoteService(serviceId);
if (future == null) {
log.trace("Service open failure reply received for unknown
service ID %d", Integer.valueOf(serviceId));
@@ -342,6 +357,7 @@
log.trace("Service open reply received for unknown service
ID %d", Integer.valueOf(serviceId));
break;
}
+ log.trace("Received a service open reply message for service %d
for %s", Integer.valueOf(serviceId), future);
final MultiplexRequestHandlerSource requestHandlerSource = new
MultiplexRequestHandlerSource(serviceId, connection);
future.setResult(requestHandlerSource);
break;
@@ -349,6 +365,7 @@
case SERVICE_CLOSE_NOTIFY: {
final int serviceId = buffer.getInt();
final FutureRemoteRequestHandlerSource future =
connection.removeFutureRemoteService(serviceId);
+ log.trace("Received a service close notify message for service
%d for %s", Integer.valueOf(serviceId), future);
future.addNotifier(new
IoFuture.HandlingNotifier<RequestHandlerSource>() {
public void handleDone(final RequestHandlerSource result) {
IoUtils.safeClose(result);
Modified:
remoting3/trunk/protocol/multiplex/src/main/java/org/jboss/remoting/protocol/multiplex/MultiplexReplyHandler.java
===================================================================
---
remoting3/trunk/protocol/multiplex/src/main/java/org/jboss/remoting/protocol/multiplex/MultiplexReplyHandler.java 2008-11-15
02:11:16 UTC (rev 4696)
+++
remoting3/trunk/protocol/multiplex/src/main/java/org/jboss/remoting/protocol/multiplex/MultiplexReplyHandler.java 2008-11-18
18:52:09 UTC (rev 4697)
@@ -24,6 +24,7 @@
import org.jboss.remoting.spi.ReplyHandler;
import org.jboss.xnio.IoUtils;
+import org.jboss.xnio.log.Logger;
import org.jboss.marshalling.Marshaller;
import org.jboss.marshalling.ByteOutput;
import java.nio.ByteBuffer;
@@ -35,6 +36,7 @@
*
*/
final class MultiplexReplyHandler implements ReplyHandler {
+ private static final Logger log =
Logger.getLogger("org.jboss.remoting.multiplex.reply-handler");
private final int requestId;
private final MultiplexConnection connection;
@@ -45,6 +47,7 @@
}
public void handleReply(final Object reply) throws IOException {
+ log.trace("Sending outbound reply (request id = %d) (type is %s)",
Integer.valueOf(requestId), reply == null ? "null" : reply.getClass());
final MultiplexConnection connection = this.connection;
final Marshaller marshaller =
connection.getMarshallerFactory().createMarshaller(connection.getMarshallingConfiguration());
try {
@@ -58,6 +61,7 @@
marshaller.close();
output.close();
connection.doBlockingWrite(bufferList);
+ log.trace("Sent reply %s", reply);
} finally {
IoUtils.safeClose(output);
}
@@ -95,4 +99,8 @@
buffer.flip();
connection.doBlockingWrite(buffer);
}
+
+ public String toString() {
+ return "forwarding reply handler <" + Integer.toString(hashCode(),
16) + "> (request id = " + requestId + ") for " + connection;
+ }
}
Modified:
remoting3/trunk/protocol/multiplex/src/main/java/org/jboss/remoting/protocol/multiplex/MultiplexRequestHandler.java
===================================================================
---
remoting3/trunk/protocol/multiplex/src/main/java/org/jboss/remoting/protocol/multiplex/MultiplexRequestHandler.java 2008-11-15
02:11:16 UTC (rev 4696)
+++
remoting3/trunk/protocol/multiplex/src/main/java/org/jboss/remoting/protocol/multiplex/MultiplexRequestHandler.java 2008-11-18
18:52:09 UTC (rev 4697)
@@ -66,7 +66,7 @@
}
public RemoteRequestContext receiveRequest(final Object request, final ReplyHandler
handler) {
- log.trace("Sending outbound request of type %s", request == null ?
"null" : request.getClass());
+ log.trace("Sending outbound request (request id = %d) (type is %s)",
request == null ? "null" : request.getClass());
final List<ByteBuffer> bufferList;
final MultiplexConnection connection = this.connection;
try {
@@ -85,7 +85,6 @@
marshaller.close();
output.close();
connection.doBlockingWrite(bufferList);
- log.trace("Sent request %s", request);
return new RemoteRequestContextImpl(id, connection);
} finally {
IoUtils.safeClose(output);
@@ -101,7 +100,7 @@
}
public String toString() {
- return "forwarding request handler <" + Integer.toString(hashCode(),
16) + "> (id = " + identifier + ")";
+ return "forwarding request handler <" + Integer.toString(hashCode(),
16) + "> (id = " + identifier + ") for " + connection;
}
}
@@ -120,6 +119,7 @@
public void cancel() {
if (! cancelSent.getAndSet(true)) try {
+ log.trace("Sending cancel request from %s", this);
final ByteBuffer buffer = ByteBuffer.allocate(5);
buffer.put((byte) MessageType.CANCEL_REQUEST.getId());
buffer.putInt(id);
@@ -131,6 +131,6 @@
}
public String toString() {
- return "remote request context (multiplex) <" +
Integer.toString(hashCode(), 16) + "> (id = " + id + ")";
+ return "remote request context <" + Integer.toString(hashCode(), 16)
+ "> (request id = " + id + ") for " + connection;
}
}
Modified:
remoting3/trunk/protocol/multiplex/src/main/java/org/jboss/remoting/protocol/multiplex/MultiplexRequestHandlerSource.java
===================================================================
---
remoting3/trunk/protocol/multiplex/src/main/java/org/jboss/remoting/protocol/multiplex/MultiplexRequestHandlerSource.java 2008-11-15
02:11:16 UTC (rev 4696)
+++
remoting3/trunk/protocol/multiplex/src/main/java/org/jboss/remoting/protocol/multiplex/MultiplexRequestHandlerSource.java 2008-11-18
18:52:09 UTC (rev 4697)
@@ -57,6 +57,7 @@
}
public Handle<RequestHandler> createRequestHandler() throws IOException {
+ log.trace("Creating new request handler from %s", this);
final int id = connection.nextRemoteClient();
final RequestHandler requestHandler = new MultiplexRequestHandler(id,
connection);
boolean ok = false;
@@ -70,6 +71,7 @@
buffer.flip();
connection.doBlockingWrite(buffer);
final Handle<RequestHandler> handlerHandle = new
MultiplexRequestHandler(id, connection).getHandle();
+ log.trace("Created new request handler with a handle of %s",
handlerHandle);
ok = true;
return handlerHandle;
} finally {
@@ -85,6 +87,6 @@
}
public String toString() {
- return "forwarding request handler source <" +
Integer.toString(hashCode(), 16) + "> (id = " + identifier + ")";
+ return "forwarding request handler source <" +
Integer.toString(hashCode(), 16) + "> (id = " + identifier + ") for
" + connection;
}
}