Revamp Log interface to eliminate boilerplate and reduce Log-induced exceptions.
This commit is contained in:
Родитель
b3597d0e27
Коммит
371e1facf7
|
@ -242,21 +242,19 @@ namespace Bond.Comm.Epoxy
|
|||
|
||||
if (layerError != null)
|
||||
{
|
||||
Log.Error("{0}.{1}: Sending request {2}/{3} failed due to layer error (Code: {4}, Message: {5}).",
|
||||
this, nameof(SendRequestAsync), conversationId, methodName, layerError.error_code,
|
||||
layerError.message);
|
||||
Log.Site().Error("{0} Sending request {1}/{2} failed due to layer error (Code: {3}, Message: {4}).",
|
||||
this, conversationId, methodName, layerError.error_code, layerError.message);
|
||||
return Message.FromError(layerError);
|
||||
}
|
||||
|
||||
var frame = MessageToFrame(conversationId, methodName, PayloadType.Request, request, layerData);
|
||||
|
||||
Log.Debug("{0}.{1}: Sending request {2}/{3}.", this, nameof(SendRequestAsync), conversationId, methodName);
|
||||
Log.Site().Debug("{0} Sending request {1}/{2}.", this, conversationId, methodName);
|
||||
var responseTask = responseMap.Add(conversationId);
|
||||
|
||||
bool wasSent = await SendFrameAsync(frame);
|
||||
Log.Debug(
|
||||
"{0}.{1}: Sending request {2}/{3} {4}.",
|
||||
this, nameof(SendRequestAsync), conversationId, methodName, wasSent ? "succeded" : "failed");
|
||||
Log.Site().Debug("{0} Sending request {1}/{2} {3}.",
|
||||
this, conversationId, methodName, wasSent ? "succeeded" : "failed");
|
||||
|
||||
if (!wasSent)
|
||||
{
|
||||
|
@ -270,9 +268,8 @@ namespace Bond.Comm.Epoxy
|
|||
|
||||
if (!wasCompleted)
|
||||
{
|
||||
Log.Information(
|
||||
"{0}.{1} Unsuccessfully sent request {2}/{3} still received response.",
|
||||
this, nameof(SendRequestAsync), conversationId, methodName);
|
||||
Log.Site().Information("{0} Unsuccessfully sent request {1}/{2} still received response.",
|
||||
this, conversationId, methodName);
|
||||
}
|
||||
}
|
||||
|
||||
|
@ -288,18 +285,17 @@ namespace Bond.Comm.Epoxy
|
|||
// If there was a layer error, replace the response with the layer error
|
||||
if (layerError != null)
|
||||
{
|
||||
Log.Error("{0}.{1}: Sending reply for conversation ID {2} failed due to layer error (Code: {3}, Message: {4}).",
|
||||
this, nameof(SendReplyAsync), conversationId, layerError.error_code, layerError.message);
|
||||
Log.Site().Error("{0} Sending reply for conversation ID {1} failed due to layer error (Code: {2}, Message: {3}).",
|
||||
this, conversationId, layerError.error_code, layerError.message);
|
||||
response = Message.FromError(layerError);
|
||||
}
|
||||
|
||||
var frame = MessageToFrame(conversationId, null, PayloadType.Response, response, layerData);
|
||||
Log.Debug("{0}.{1}: Sending reply for conversation ID {2}.", this, nameof(SendReplyAsync), conversationId);
|
||||
Log.Site().Debug("{0} Sending reply for conversation ID {1}.", this, conversationId);
|
||||
|
||||
bool wasSent = await SendFrameAsync(frame);
|
||||
Log.Debug(
|
||||
"{0}.{1}: Sending reply for conversation ID {2} {3}.",
|
||||
this, nameof(SendReplyAsync), conversationId, wasSent ? "succeded" : "failed");
|
||||
Log.Site().Debug("{0} Sending reply for conversation ID {1} {2}.",
|
||||
this, conversationId, wasSent ? "succeedeed" : "failed");
|
||||
}
|
||||
|
||||
private async Task<bool> SendFrameAsync(Frame frame)
|
||||
|
@ -323,8 +319,7 @@ namespace Bond.Comm.Epoxy
|
|||
}
|
||||
catch (Exception ex) when (ex is IOException || ex is ObjectDisposedException || ex is SocketException)
|
||||
{
|
||||
Log.Error(ex, "{0}.{1}: While writing a Frame to the network: {2}", this, nameof(SendFrameAsync),
|
||||
ex.Message);
|
||||
Log.Site().Error(ex, "{0} While writing a Frame to the network: {1}", this, ex.Message);
|
||||
return false;
|
||||
}
|
||||
}
|
||||
|
@ -339,19 +334,18 @@ namespace Bond.Comm.Epoxy
|
|||
|
||||
if (layerError != null)
|
||||
{
|
||||
Log.Error("{0}.{1}: Sending event {2}/{3} failed due to layer error (Code: {4}, Message: {5}).",
|
||||
this, nameof(SendEventAsync), conversationId, methodName, layerError.error_code, layerError.message);
|
||||
Log.Site().Error("{0} Sending event {1}/{2} failed due to layer error (Code: {3}, Message: {4}).",
|
||||
this, conversationId, methodName, layerError.error_code, layerError.message);
|
||||
return;
|
||||
}
|
||||
|
||||
var frame = MessageToFrame(conversationId, methodName, PayloadType.Event, message, layerData);
|
||||
|
||||
Log.Debug("{0}.{1}: Sending event {2}/{3}.", this, nameof(SendEventAsync), conversationId, methodName);
|
||||
Log.Site().Debug("{0} Sending event {1}/{2}.", this, conversationId, methodName);
|
||||
|
||||
bool wasSent = await SendFrameAsync(frame);
|
||||
Log.Debug(
|
||||
"{0}.{1}: Sending event {2}/{3} {4}.",
|
||||
this, nameof(SendEventAsync), conversationId, methodName, wasSent ? "succeded" : "failed");
|
||||
Log.Site().Debug("{0} Sending event {1}/{2} {3}.",
|
||||
this, conversationId, methodName, wasSent ? "succeeded" : "failed");
|
||||
}
|
||||
|
||||
internal Task StartAsync()
|
||||
|
@ -428,7 +422,7 @@ namespace Bond.Comm.Epoxy
|
|||
|
||||
case State.Disconnected: // we should never enter this switch in the Disconnected state
|
||||
default:
|
||||
Log.Error("Unexpected connection state: {0}", state);
|
||||
Log.Site().Error("{0} Unexpected connection state: {1}", this, state);
|
||||
protocolError = ProtocolErrorCode.INTERNAL_ERROR;
|
||||
nextState = State.SendProtocolError;
|
||||
break;
|
||||
|
@ -436,8 +430,7 @@ namespace Bond.Comm.Epoxy
|
|||
}
|
||||
catch (Exception ex) when (state != State.Disconnecting && state != State.Disconnected)
|
||||
{
|
||||
Log.Error(ex, "{0}.{1} Unhandled exception. Current state: {2}",
|
||||
this, nameof(ConnectionLoop), state);
|
||||
Log.Site().Error(ex, "{0} Unhandled exception. Current state: {1}", this, state);
|
||||
|
||||
// we're in a state where we can attempt to disconnect
|
||||
protocolError = ProtocolErrorCode.INTERNAL_ERROR;
|
||||
|
@ -445,8 +438,8 @@ namespace Bond.Comm.Epoxy
|
|||
}
|
||||
catch (Exception ex)
|
||||
{
|
||||
Log.Error(ex, "{0}.{1} Unhandled exception during shutdown. Abandoning connection. Current state: {2}",
|
||||
this, nameof(ConnectionLoop), state);
|
||||
Log.Site().Error(ex, "{0} Unhandled exception during shutdown. Abandoning connection. Current state: {1}",
|
||||
this, state);
|
||||
break; // the while loop
|
||||
}
|
||||
|
||||
|
@ -455,8 +448,7 @@ namespace Bond.Comm.Epoxy
|
|||
|
||||
if (state != State.Disconnected)
|
||||
{
|
||||
Log.Information("{0}.{1} Abandoning connection. Current state: {2}",
|
||||
this, nameof(ConnectionLoop), state);
|
||||
Log.Site().Information("{0} Abandoning connection. Current state: {1}", this, state);
|
||||
}
|
||||
|
||||
DoDisconnected();
|
||||
|
@ -477,7 +469,7 @@ namespace Bond.Comm.Epoxy
|
|||
}
|
||||
else
|
||||
{
|
||||
Log.Information("Rejecting connection {0} because {1}:{2}",
|
||||
Log.Site().Information("{0} Rejecting connection because {1}:{2}",
|
||||
this, disconnectError.error_code, disconnectError.message);
|
||||
|
||||
protocolError = ProtocolErrorCode.CONNECTION_REJECTED;
|
||||
|
@ -506,8 +498,7 @@ namespace Bond.Comm.Epoxy
|
|||
Frame frame = await Frame.ReadAsync(networkStream, shutdownTokenSource.Token);
|
||||
if (frame == null)
|
||||
{
|
||||
Log.Information("{0}.{1} EOS encountered while waiting for config, so disconnecting.",
|
||||
this, nameof(DoExpectConfigAsync));
|
||||
Log.Site().Information("{0} EOS encountered while waiting for config, so disconnecting.", this);
|
||||
return State.Disconnecting;
|
||||
}
|
||||
|
||||
|
@ -528,8 +519,8 @@ namespace Bond.Comm.Epoxy
|
|||
|
||||
default:
|
||||
protocolError = result.ErrorCode ?? ProtocolErrorCode.PROTOCOL_VIOLATED;
|
||||
Log.Error("{0}.{1}: Unsupported FrameDisposition {2} when waiting for config. ErrorCode: {3})",
|
||||
this, nameof(DoExpectConfigAsync), result.Disposition, protocolError);
|
||||
Log.Site().Error("{0} Unsupported FrameDisposition {1} when waiting for config. ErrorCode: {2})",
|
||||
this, result.Disposition, protocolError);
|
||||
return State.SendProtocolError;
|
||||
}
|
||||
}
|
||||
|
@ -546,21 +537,19 @@ namespace Bond.Comm.Epoxy
|
|||
frame = await Frame.ReadAsync(networkStream, shutdownTokenSource.Token);
|
||||
if (frame == null)
|
||||
{
|
||||
Log.Information("{0}.{1} EOS encountered, so disconnecting.", this,
|
||||
nameof(DoConnectedAsync));
|
||||
Log.Site().Information("{0} EOS encountered, so disconnecting.", this);
|
||||
return State.Disconnecting;
|
||||
}
|
||||
}
|
||||
catch (EpoxyProtocolErrorException pex)
|
||||
{
|
||||
Log.Error(pex, "{0}.{1} Protocol error encountered.", this,
|
||||
nameof(DoConnectedAsync));
|
||||
Log.Site().Error(pex, "{0} Protocol error encountered.", this);
|
||||
protocolError = ProtocolErrorCode.PROTOCOL_VIOLATED;
|
||||
return State.SendProtocolError;
|
||||
}
|
||||
catch (Exception ex) when (ex is IOException || ex is ObjectDisposedException || ex is SocketException)
|
||||
{
|
||||
Log.Error(ex, "{0}.{1} IO error encountered.", this, nameof(DoConnectedAsync));
|
||||
Log.Site().Error(ex, "{0} IO error encountered.", this);
|
||||
return State.Disconnecting;
|
||||
}
|
||||
|
||||
|
@ -599,7 +588,7 @@ namespace Bond.Comm.Epoxy
|
|||
return State.Disconnecting;
|
||||
|
||||
default:
|
||||
Log.Error("{0}.{1}: Unsupported FrameDisposition {2}", this, nameof(DoConnectedAsync), result.Disposition);
|
||||
Log.Site().Error("{0} Unsupported FrameDisposition {1}", this, result.Disposition);
|
||||
protocolError = ProtocolErrorCode.INTERNAL_ERROR;
|
||||
return State.SendProtocolError;
|
||||
}
|
||||
|
@ -615,20 +604,20 @@ namespace Bond.Comm.Epoxy
|
|||
Error details = errorDetails;
|
||||
|
||||
var frame = MakeProtocolErrorFrame(errorCode, details);
|
||||
Log.Debug("{0}.{1}: Sending protocol error with code {2} and details {3}.",
|
||||
this, nameof(DoSendProtocolErrorAsync), errorCode, details == null ? "<null>" : details.error_code + details.message);
|
||||
Log.Site().Debug("{0} Sending protocol error with code {1} and details {2}.",
|
||||
this, errorCode, details == null ? "<null>" : details.error_code + details.message);
|
||||
|
||||
bool wasSent = await SendFrameAsync(frame);
|
||||
Log.Debug(
|
||||
"{0}.{1}: Sending protocol error with code {2} {3}.",
|
||||
this, nameof(DoSendProtocolErrorAsync), errorCode, wasSent ? "succeded" : "failed");
|
||||
Log.Site().Debug(
|
||||
"{0} Sending protocol error with code {1} {2}.",
|
||||
this, errorCode, wasSent ? "succeeded" : "failed");
|
||||
|
||||
return State.Disconnecting;
|
||||
}
|
||||
|
||||
private State DoDisconnect()
|
||||
{
|
||||
Log.Debug("{0}.{1}: Shutting down.", this, nameof(DoDisconnect));
|
||||
Log.Site().Debug("{0} Shutting down.", this);
|
||||
|
||||
netSocket.Shutdown();
|
||||
|
||||
|
@ -673,8 +662,8 @@ namespace Bond.Comm.Epoxy
|
|||
{
|
||||
if (headers.error_code != (int)ErrorCode.OK)
|
||||
{
|
||||
Log.Error("{0}.{1}: Received request with a non-zero error code. Conversation ID: {2}",
|
||||
this, nameof(DispatchRequest), headers.conversation_id);
|
||||
Log.Site().Error("{0} Received request with a non-zero error code. Conversation ID: {1}",
|
||||
this, headers.conversation_id);
|
||||
protocolError = ProtocolErrorCode.PROTOCOL_VIOLATED;
|
||||
return State.SendProtocolError;
|
||||
}
|
||||
|
@ -698,9 +687,9 @@ namespace Bond.Comm.Epoxy
|
|||
}
|
||||
else
|
||||
{
|
||||
Log.Error("{0}.{1}: Receiving request {2}/{3} failed due to layer error (Code: {4}, Message: {5}).",
|
||||
this, nameof(DispatchRequest), headers.conversation_id, headers.method_name,
|
||||
layerError.error_code, layerError.message);
|
||||
Log.Site().Error("{0} Receiving request {1}/{2} failed due to layer error (Code: {3}, Message: {4}).",
|
||||
this, headers.conversation_id, headers.method_name,
|
||||
layerError.error_code, layerError.message);
|
||||
result = Message.FromError(layerError);
|
||||
}
|
||||
|
||||
|
@ -731,16 +720,16 @@ namespace Bond.Comm.Epoxy
|
|||
|
||||
if (layerError != null)
|
||||
{
|
||||
Log.Error("{0}.{1}: Receiving response {2}/{3} failed due to layer error (Code: {4}, Message: {5}).",
|
||||
this, nameof(DispatchResponse), headers.conversation_id, headers.method_name,
|
||||
Log.Site().Error("{0} Receiving response {1}/{2} failed due to layer error (Code: {3}, Message: {4}).",
|
||||
this, headers.conversation_id, headers.method_name,
|
||||
layerError.error_code, layerError.message);
|
||||
response = Message.FromError(layerError);
|
||||
}
|
||||
|
||||
if (!responseMap.Complete(headers.conversation_id, response))
|
||||
{
|
||||
Log.Error("{0}.{1}: Response for unmatched request. Conversation ID: {2}",
|
||||
this, nameof(DispatchResponse), headers.conversation_id);
|
||||
Log.Site().Error("{0} Response for unmatched request. Conversation ID: {1}",
|
||||
this, headers.conversation_id);
|
||||
}
|
||||
}
|
||||
|
||||
|
@ -748,8 +737,8 @@ namespace Bond.Comm.Epoxy
|
|||
{
|
||||
if (headers.error_code != (int)ErrorCode.OK)
|
||||
{
|
||||
Log.Error("{0}.{1}: Received event with a non-zero error code. Conversation ID: {2}",
|
||||
this, nameof(DispatchEvent), headers.conversation_id);
|
||||
Log.Site().Error("{0} Received event with a non-zero error code. Conversation ID: {1}",
|
||||
this, headers.conversation_id);
|
||||
return;
|
||||
}
|
||||
|
||||
|
@ -763,8 +752,8 @@ namespace Bond.Comm.Epoxy
|
|||
|
||||
if (layerError != null)
|
||||
{
|
||||
Log.Error("{0}.{1}: Receiving event {2}/{3} failed due to layer error (Code: {4}, Message: {5}).",
|
||||
this, nameof(DispatchEvent), headers.conversation_id, headers.method_name,
|
||||
Log.Site().Error("{0}: Receiving event {1}/{2} failed due to layer error (Code: {3}, Message: {4}).",
|
||||
this, headers.conversation_id, headers.method_name,
|
||||
layerError.error_code, layerError.message);
|
||||
return;
|
||||
}
|
||||
|
@ -864,7 +853,7 @@ namespace Bond.Comm.Epoxy
|
|||
}
|
||||
catch (Exception ex) when (ex is IOException || ex is SocketException)
|
||||
{
|
||||
Log.Error(ex, "Exception during connection shutdown");
|
||||
Log.Site().Error(ex, "Exception during connection shutdown");
|
||||
}
|
||||
|
||||
stream = null;
|
||||
|
|
|
@ -53,7 +53,7 @@ namespace Bond.Comm.Epoxy
|
|||
|
||||
public override void AddService<T>(T service)
|
||||
{
|
||||
Log.Information("{0}.{1}: Adding {2}.", this, nameof(AddService), typeof(T).Name);
|
||||
Log.Site().Information("Listener on {0} adding {1}.", ListenEndpoint, typeof(T).Name);
|
||||
serviceHost.Register(service);
|
||||
}
|
||||
|
||||
|
@ -89,7 +89,7 @@ namespace Bond.Comm.Epoxy
|
|||
|
||||
private async Task AcceptAsync(CancellationToken t)
|
||||
{
|
||||
Log.Information("{0}.{1}: Accepting connections...", this, nameof(AcceptAsync));
|
||||
Log.Site().Information("Accepting connections on {0}", ListenEndpoint);
|
||||
while (!t.IsCancellationRequested)
|
||||
{
|
||||
Socket socket = null;
|
||||
|
@ -110,13 +110,11 @@ namespace Bond.Comm.Epoxy
|
|||
}
|
||||
|
||||
await connection.StartAsync();
|
||||
Log.Debug("{0}.{1}: Accepted connection from {2}.",
|
||||
this, nameof(AcceptAsync), connection.RemoteEndPoint);
|
||||
Log.Site().Debug("Accepted connection from {0}.", connection.RemoteEndPoint);
|
||||
}
|
||||
catch (SocketException ex)
|
||||
{
|
||||
Log.Fatal(ex, "{0}.{1}: Accept failed with error {2}.",
|
||||
this, nameof(AcceptAsync), ex.SocketErrorCode);
|
||||
Log.Site().Fatal(ex, "Accept failed with error {0}.", ex.SocketErrorCode);
|
||||
|
||||
ShutdownSocketSafe(socket);
|
||||
}
|
||||
|
@ -130,7 +128,7 @@ namespace Bond.Comm.Epoxy
|
|||
// connection.
|
||||
}
|
||||
}
|
||||
Log.Information("{0}.{1}: Shutting down.", this, nameof(AcceptAsync));
|
||||
Log.Site().Information("Shutting down connection on {0}", ListenEndpoint);
|
||||
}
|
||||
|
||||
private static void ShutdownSocketSafe(Socket socket)
|
||||
|
@ -143,7 +141,7 @@ namespace Bond.Comm.Epoxy
|
|||
catch (SocketException ex)
|
||||
{
|
||||
// We tried to cleanly shutdown the socket, oh well.
|
||||
Log.Debug(ex, "Exception encountered when shutting down a socket.");
|
||||
Log.Site().Debug(ex, "Exception encountered when shutting down a socket.");
|
||||
}
|
||||
}
|
||||
}
|
||||
|
|
|
@ -179,7 +179,7 @@ namespace Bond.Comm.Epoxy
|
|||
};
|
||||
}
|
||||
|
||||
Log.Debug("{0}.{1}: Processing {2} framelets.", nameof(EpoxyProtocol), nameof(Classify), frame.Count);
|
||||
Log.Site().Debug("Processing {0} framelets.", frame.Count);
|
||||
|
||||
var state = ClassifyState.ExpectFirstFramelet;
|
||||
EpoxyHeaders headers = null;
|
||||
|
@ -284,8 +284,7 @@ namespace Bond.Comm.Epoxy
|
|||
};
|
||||
|
||||
default:
|
||||
Log.Error("{0}.{1}: Unhandled state {2}. Dropping frame.",
|
||||
nameof(EpoxyProtocol), nameof(Classify), state);
|
||||
Log.Site().Error("Unhandled state {0}. Dropping frame.", state);
|
||||
return new ClassifyResult
|
||||
{
|
||||
Disposition = FrameDisposition.Indeterminate
|
||||
|
@ -302,7 +301,7 @@ namespace Bond.Comm.Epoxy
|
|||
|
||||
if (frame.Framelets.Count == 0)
|
||||
{
|
||||
Log.Error("{0}.{1}: Frame was empty.", nameof(EpoxyProtocol), nameof(TransitionExpectFirstFramelet));
|
||||
Log.Site().Error("Frame was empty.");
|
||||
errorCode = ProtocolErrorCode.MALFORMED_DATA;
|
||||
return ClassifyState.MalformedFrame;
|
||||
}
|
||||
|
@ -319,8 +318,7 @@ namespace Bond.Comm.Epoxy
|
|||
return ClassifyState.ExpectProtocolError;
|
||||
|
||||
default:
|
||||
Log.Error("{0}.{1}: Frame began with invalid FrameletType {2}.",
|
||||
nameof(EpoxyProtocol), nameof(TransitionExpectEpoxyHeaders), frame.Framelets[0].Type);
|
||||
Log.Site().Error("Frame began with invalid FrameletType {0}.", frame.Framelets[0].Type);
|
||||
errorCode = ProtocolErrorCode.MALFORMED_DATA;
|
||||
return ClassifyState.MalformedFrame;
|
||||
}
|
||||
|
@ -347,15 +345,13 @@ namespace Bond.Comm.Epoxy
|
|||
break;
|
||||
|
||||
default:
|
||||
Log.Error("{0}.{1}: Didn't get a valid {2}.",
|
||||
nameof(EpoxyProtocol), nameof(TransitionExpectEpoxyHeaders), nameof(EpoxyHeaders));
|
||||
Log.Site().Error("Didn't get a valid {0}.", nameof(EpoxyHeaders));
|
||||
errorCode = ProtocolErrorCode.MALFORMED_DATA;
|
||||
return ClassifyState.MalformedFrame;
|
||||
}
|
||||
|
||||
Log.Debug("{0}.{1}: Deserialized {2} with conversation ID {3} and payload type {4}.",
|
||||
nameof(EpoxyProtocol), nameof(TransitionExpectEpoxyHeaders), nameof(EpoxyHeaders),
|
||||
headers.conversation_id, headers.payload_type);
|
||||
Log.Site().Debug("Deserialized {0} with conversation ID {1} and payload type {2}.",
|
||||
nameof(EpoxyHeaders), headers.conversation_id, headers.payload_type);
|
||||
return ClassifyState.ExpectOptionalLayerData;
|
||||
}
|
||||
|
||||
|
@ -373,8 +369,7 @@ namespace Bond.Comm.Epoxy
|
|||
|
||||
if (frame.Count < 2)
|
||||
{
|
||||
Log.Error("{0}.{1}: Frame did not continue with LayerData or PayloadData.",
|
||||
nameof(EpoxyProtocol), nameof(TransitionExpectEpoxyHeaders));
|
||||
Log.Site().Error("Frame did not continue with LayerData or PayloadData.");
|
||||
errorCode = ProtocolErrorCode.MALFORMED_DATA;
|
||||
return ClassifyState.MalformedFrame;
|
||||
}
|
||||
|
@ -388,15 +383,14 @@ namespace Bond.Comm.Epoxy
|
|||
|
||||
if (framelet.Type != FrameletType.LayerData)
|
||||
{
|
||||
Log.Error("{0}.{1}: Frame did not continue with LayerData or PayloadData.",
|
||||
nameof(EpoxyProtocol), nameof(TransitionExpectOptionalLayerData));
|
||||
Log.Site().Error("Frame did not continue with LayerData or PayloadData.");
|
||||
errorCode = ProtocolErrorCode.MALFORMED_DATA;
|
||||
return ClassifyState.MalformedFrame;
|
||||
}
|
||||
|
||||
layerData = framelet.Contents;
|
||||
Log.Debug("{0}.{1}: Extracted {2}-byte layer data in conversation ID {3}.",
|
||||
nameof(EpoxyProtocol), nameof(TransitionExpectOptionalLayerData), layerData.Count, headers.conversation_id);
|
||||
Log.Site().Debug("Extracted {0}-byte layer data in conversation ID {1}.",
|
||||
layerData.Count, headers.conversation_id);
|
||||
return ClassifyState.ExpectPayload;
|
||||
}
|
||||
|
||||
|
@ -416,8 +410,7 @@ namespace Bond.Comm.Epoxy
|
|||
|
||||
if (payloadDataIndex >= frame.Count)
|
||||
{
|
||||
Log.Error("{0}.{1}: Frame did not continue with PayloadData.",
|
||||
nameof(EpoxyProtocol), nameof(TransitionExpectEpoxyHeaders));
|
||||
Log.Site().Error("Frame did not continue with PayloadData.");
|
||||
errorCode = ProtocolErrorCode.MALFORMED_DATA;
|
||||
return ClassifyState.MalformedFrame;
|
||||
}
|
||||
|
@ -425,15 +418,14 @@ namespace Bond.Comm.Epoxy
|
|||
var framelet = frame.Framelets[payloadDataIndex];
|
||||
if (framelet.Type != FrameletType.PayloadData)
|
||||
{
|
||||
Log.Error("{0}.{1}: Frame did not continue with PayloadData.",
|
||||
nameof(EpoxyProtocol), nameof(TransitionExpectEpoxyHeaders));
|
||||
Log.Site().Error("Frame did not continue with PayloadData.");
|
||||
errorCode = ProtocolErrorCode.MALFORMED_DATA;
|
||||
return ClassifyState.MalformedFrame;
|
||||
}
|
||||
|
||||
payload = framelet.Contents;
|
||||
Log.Debug("{0}.{1}: Extracted {2}-byte payload in conversation ID {3}.",
|
||||
nameof(EpoxyProtocol), nameof(TransitionExpectPayload), payload.Count, headers.conversation_id);
|
||||
Log.Site().Debug("Extracted {0}-byte payload in conversation ID {1}.",
|
||||
payload.Count, headers.conversation_id);
|
||||
return ClassifyState.ExpectEndOfFrame;
|
||||
}
|
||||
|
||||
|
@ -453,8 +445,7 @@ namespace Bond.Comm.Epoxy
|
|||
}
|
||||
else
|
||||
{
|
||||
Log.Error("{0}.{1}: Frame had trailing framelets.",
|
||||
nameof(EpoxyProtocol), nameof(TransitionExpectEndOfFrame));
|
||||
Log.Site().Error("Frame had trailing framelets.");
|
||||
errorCode = ProtocolErrorCode.MALFORMED_DATA;
|
||||
return ClassifyState.MalformedFrame;
|
||||
}
|
||||
|
@ -475,8 +466,7 @@ namespace Bond.Comm.Epoxy
|
|||
case PayloadType.Event:
|
||||
return ClassifyState.ValidFrame;
|
||||
default:
|
||||
Log.Warning("{0}.{1}: Received unrecognized payload type {2}.",
|
||||
nameof(EpoxyProtocol), nameof(TransitionFrameComplete), headers.payload_type);
|
||||
Log.Site().Warning("Received unrecognized payload type {0}.", headers.payload_type);
|
||||
errorCode = ProtocolErrorCode.NOT_SUPPORTED;
|
||||
return ClassifyState.MalformedFrame;
|
||||
}
|
||||
|
@ -522,8 +512,7 @@ namespace Bond.Comm.Epoxy
|
|||
|
||||
if (frame.Count != 1)
|
||||
{
|
||||
Log.Error("{0}.{1}: Config frame had trailing framelets.",
|
||||
nameof(EpoxyProtocol), nameof(TransitionExpectConfig));
|
||||
Log.Site().Error("Config frame had trailing framelets.");
|
||||
errorCode = ProtocolErrorCode.MALFORMED_DATA;
|
||||
return ClassifyState.MalformedFrame;
|
||||
}
|
||||
|
@ -541,8 +530,7 @@ namespace Bond.Comm.Epoxy
|
|||
break;
|
||||
|
||||
default:
|
||||
Log.Error("{0}.{1}: Didn't get a valid {2}.",
|
||||
nameof(EpoxyProtocol), nameof(TransitionExpectConfig), nameof(EpoxyConfig));
|
||||
Log.Site().Error("Didn't get a valid {0}.", nameof(EpoxyConfig));
|
||||
errorCode = ProtocolErrorCode.MALFORMED_DATA;
|
||||
return ClassifyState.MalformedFrame;
|
||||
}
|
||||
|
@ -570,19 +558,15 @@ namespace Bond.Comm.Epoxy
|
|||
break;
|
||||
|
||||
default:
|
||||
Log.Error("{0}.{1}: Didn't get a valid {2}.",
|
||||
nameof(EpoxyProtocol), nameof(TransitionExpectProtocolError), nameof(ProtocolError));
|
||||
Log.Site().Error("Didn't get a valid {0}.", nameof(ProtocolError));
|
||||
return ClassifyState.ErrorInErrorFrame;
|
||||
}
|
||||
|
||||
Log.Debug("{0}.{1}: Deserialized {2} with code {3}.",
|
||||
nameof(EpoxyProtocol), nameof(TransitionExpectProtocolError), nameof(ProtocolError),
|
||||
error.error_code);
|
||||
Log.Site().Debug("Deserialized {0} with code {1}.", nameof(ProtocolError), error.error_code);
|
||||
|
||||
if (frame.Count > 1)
|
||||
{
|
||||
Log.Error("{0}.{1}: Frame had trailing framelets.",
|
||||
nameof(EpoxyProtocol), nameof(TransitionExpectProtocolError));
|
||||
Log.Site().Error("Frame had trailing framelets.");
|
||||
return ClassifyState.ErrorInErrorFrame;
|
||||
}
|
||||
|
||||
|
|
|
@ -49,7 +49,7 @@ namespace Bond.Comm.Epoxy
|
|||
|
||||
public async Task<EpoxyConnection> ConnectToAsync(IPEndPoint endpoint, CancellationToken ct)
|
||||
{
|
||||
Log.Information("{0}.{1}: Connecting to {2}.", nameof(EpoxyTransport), nameof(ConnectToAsync), endpoint);
|
||||
Log.Site().Information("Connecting to {0}.", endpoint);
|
||||
|
||||
Socket socket = MakeClientSocket();
|
||||
await Task.Factory.FromAsync(socket.BeginConnect, socket.EndConnect, endpoint, state: null);
|
||||
|
|
|
@ -86,8 +86,7 @@ namespace Bond.Comm.Epoxy
|
|||
{
|
||||
if (framelets.Count == UInt16.MaxValue)
|
||||
{
|
||||
var message = LogUtil.ErrorAndReturnFormatted("{0}.{1}: Exceeded maximum allowed count of framelets.",
|
||||
nameof(Frame), nameof(Add));
|
||||
var message = Log.Site().ErrorAndReturnFormatted("Exceeded maximum allowed count of framelets.");
|
||||
throw new InvalidOperationException(message);
|
||||
}
|
||||
|
||||
|
@ -99,8 +98,7 @@ namespace Bond.Comm.Epoxy
|
|||
}
|
||||
catch (OverflowException oex)
|
||||
{
|
||||
var message = LogUtil.ErrorAndReturnFormatted("{0}.{1}: Exceeded maximum size of frame.",
|
||||
nameof(Frame), nameof(Add));
|
||||
var message = Log.Site().ErrorAndReturnFormatted("Exceeded maximum size of frame.");
|
||||
throw new InvalidOperationException(message, oex);
|
||||
}
|
||||
}
|
||||
|
@ -152,7 +150,7 @@ namespace Bond.Comm.Epoxy
|
|||
}
|
||||
catch (Exception ex) when (ex is IOException || ex is ObjectDisposedException)
|
||||
{
|
||||
Log.Error(ex, "{0}.{1}: Failed to write entire frame", nameof(Frame), nameof(WriteAsync));
|
||||
Log.Site().Error(ex, "Failed to write entire frame.");
|
||||
throw;
|
||||
}
|
||||
}
|
||||
|
|
|
@ -189,8 +189,7 @@ namespace Bond.Comm
|
|||
}
|
||||
catch (Exception ex)
|
||||
{
|
||||
Log.Error(ex, "{0}.{1}: Exception in handler for connection {2}: {3}",
|
||||
nameof(Listener), nameof(OnDisconnected), args.Connection, ex.Message);
|
||||
Log.Site().Error(ex, "Exception in handler for connection {0}: {1}", args.Connection, ex.Message);
|
||||
args.DisconnectError = Transport.MakeInternalServerError(ex);
|
||||
}
|
||||
|
||||
|
@ -221,8 +220,7 @@ namespace Bond.Comm
|
|||
}
|
||||
catch (Exception ex)
|
||||
{
|
||||
Log.Error(ex, "{0}.{1}: Exception in handler for connection {2}: {3}",
|
||||
nameof(Listener), nameof(OnDisconnected), args.Connection, ex.Message);
|
||||
Log.Site().Error(ex, "Exception in handler for connection {0}: {1}", args.Connection, ex.Message);
|
||||
}
|
||||
}
|
||||
}
|
||||
|
|
|
@ -4,6 +4,7 @@
|
|||
namespace Bond.Comm
|
||||
{
|
||||
using System;
|
||||
using System.Runtime.CompilerServices;
|
||||
|
||||
/// <summary>
|
||||
/// Represents the severity of a log message. Severities compare with <
|
||||
|
@ -22,40 +23,44 @@ namespace Bond.Comm
|
|||
/// Once passed to <see cref="Log.SetHandler"/>, will receive callbacks for
|
||||
/// messages logged by Bond.
|
||||
/// </summary>
|
||||
public interface LogHandler
|
||||
public interface ILogHandler
|
||||
{
|
||||
/// <summary>
|
||||
/// Invoked for each log message that Bond wants to log.
|
||||
/// Invoked for each log message that Bond generates. Messages below
|
||||
/// Bond's <see cref="Log.DropBelow"/> will not result in calls to this
|
||||
/// function.
|
||||
/// </summary>
|
||||
/// <param name="severity">The severity of the log message.</param>
|
||||
/// <param name="message">Bond's log message, including the location in
|
||||
/// the code that generated it.</param>
|
||||
/// <param name="severity">The level the message was logged at.</param>
|
||||
/// <param name="exception">
|
||||
/// The exception that is associated with the log message. May be
|
||||
/// <c>null</c>.
|
||||
/// </param>
|
||||
/// <param name="format">The format string.</param>
|
||||
/// <param name="args">The format string arguments.</param>
|
||||
/// <remarks>
|
||||
/// It is the responsibility of the LogHandler to format the message.
|
||||
/// </remarks>
|
||||
void Handle(LogSeverity severity, Exception exception, string format, object[] args);
|
||||
void Handle(string message, LogSeverity severity, Exception exception);
|
||||
}
|
||||
|
||||
/// <summary>
|
||||
/// Implement a <see cref="LogHandler"/> and pass it to
|
||||
/// Implement a <see cref="ILogHandler"/> and pass it to
|
||||
/// <see cref="SetHandler"/> to receive log messages.
|
||||
/// </summary>
|
||||
public static class Log
|
||||
public class Log
|
||||
{
|
||||
private static LogHandler handler;
|
||||
/// <summary>
|
||||
/// Messages below DropBelow will not be passed to the <see cref="ILogHandler"/>.
|
||||
/// </summary>
|
||||
public static LogSeverity DropBelow { get; set; } = LogSeverity.Information;
|
||||
|
||||
private static ILogHandler handler;
|
||||
|
||||
/// <summary>
|
||||
/// Sets a <see cref="LogHandler"/> to receive Bond log messages.
|
||||
/// Sets a <see cref="ILogHandler"/> to receive Bond log messages.
|
||||
/// </summary>
|
||||
/// <param name="newHandler">The handler to add.</param>
|
||||
/// <exception cref="InvalidOperationException">
|
||||
/// Thrown when there is another handler registered.
|
||||
/// </exception>
|
||||
public static void SetHandler(LogHandler newHandler)
|
||||
public static void SetHandler(ILogHandler newHandler)
|
||||
{
|
||||
if (newHandler == null)
|
||||
{
|
||||
|
@ -64,13 +69,13 @@ namespace Bond.Comm
|
|||
if (handler != null)
|
||||
{
|
||||
throw new InvalidOperationException(
|
||||
$"Attempted to add a {nameof(LogHandler)} when there already was one");
|
||||
$"Attempted to add a {nameof(ILogHandler)} when there already was one");
|
||||
}
|
||||
handler = newHandler;
|
||||
}
|
||||
|
||||
/// <summary>
|
||||
/// Removes the existing <see cref="LogHandler"/>.
|
||||
/// Removes the existing <see cref="ILogHandler"/>.
|
||||
/// </summary>
|
||||
/// <remarks>
|
||||
/// May be called even if there is no existing handler.
|
||||
|
@ -80,86 +85,154 @@ namespace Bond.Comm
|
|||
handler = null;
|
||||
}
|
||||
|
||||
public static void Fatal(Exception exception, string format, params object[] args)
|
||||
internal static string Format(
|
||||
string fileName, int lineNumber, string methodName,
|
||||
string format, object[] args)
|
||||
{
|
||||
return string.Concat(
|
||||
fileName, ":", lineNumber, " - ", methodName, " - ",
|
||||
string.Format(format, args));
|
||||
|
||||
}
|
||||
|
||||
const string Unknown = "<unknown>";
|
||||
string filePath;
|
||||
int lineNumber;
|
||||
string memberName;
|
||||
bool used;
|
||||
|
||||
/// <summary>
|
||||
/// The only correct way to log is to call Log.Site().{Debug, Information, ...}. Site() returns an object that
|
||||
/// captures your callsite and exposes the different log levels. Do not use the object returned by Site() to log
|
||||
/// twice. (We detect this and throw an exception.) Do not call Site() anywhere but the line you want to log from.
|
||||
/// (We cannot detect this, so you will just get incorrect callsite information.)
|
||||
/// </summary>
|
||||
/// <returns>A Log instance that will let you log exactly one message.</returns>
|
||||
public static Log Site(
|
||||
[CallerFilePath] string filePath = Unknown,
|
||||
[CallerLineNumber] int lineNumber = 0,
|
||||
[CallerMemberName] string memberName = Unknown)
|
||||
{
|
||||
return new Log
|
||||
{
|
||||
filePath = filePath,
|
||||
lineNumber = lineNumber,
|
||||
memberName = memberName
|
||||
};
|
||||
}
|
||||
|
||||
private void LogMessage(
|
||||
LogSeverity severity, Exception exception,
|
||||
string format, object[] args)
|
||||
{
|
||||
CheckReuse();
|
||||
if (severity < DropBelow) { return; }
|
||||
|
||||
// It's relatively easy to make mistakes in the variadic logging functions that will throw a FormatException
|
||||
// inside Format(). This is not a good reason to interrupt normal control flow or kill a service.
|
||||
// If that happens, catch the exception, log the message format and params that caused the exception, and
|
||||
// log at high severity regardless.
|
||||
string message;
|
||||
try
|
||||
{
|
||||
message = Format(filePath, lineNumber, memberName, format, args);
|
||||
}
|
||||
catch (FormatException fe)
|
||||
{
|
||||
severity = severity < LogSeverity.Error ? LogSeverity.Error : severity;
|
||||
// nulls in args will be logged as empty strings.
|
||||
var argsStr = "[" + string.Join(", ", args) + "]";
|
||||
const string formatExceptionFormat = "Log call threw {0}({1}) with format \"{2}\" and args {3}";
|
||||
message = Format(filePath, lineNumber, memberName, formatExceptionFormat,
|
||||
new object[] {nameof(FormatException), fe.Message, format, argsStr});
|
||||
}
|
||||
handler?.Handle(message, severity, exception);
|
||||
}
|
||||
|
||||
private void CheckReuse()
|
||||
{
|
||||
if (!used)
|
||||
{
|
||||
used = true;
|
||||
}
|
||||
else
|
||||
{
|
||||
var message =
|
||||
$"An instance of {nameof(Log)} was used twice. First use: {filePath}:{lineNumber} - {memberName}";
|
||||
throw new InvalidOperationException(message);
|
||||
}
|
||||
}
|
||||
|
||||
public void Fatal(Exception exception, string format, params object[] args)
|
||||
{
|
||||
LogMessage(LogSeverity.Fatal, exception, format, args);
|
||||
}
|
||||
|
||||
public static void Fatal(string format, params object[] args)
|
||||
public void Fatal(string format, params object[] args)
|
||||
{
|
||||
LogMessage(LogSeverity.Fatal, null, format, args);
|
||||
Fatal(null, format, args);
|
||||
}
|
||||
|
||||
public static void Error(Exception exception, string format, params object[] args)
|
||||
public void Error(Exception exception, string format, params object[] args)
|
||||
{
|
||||
LogMessage(LogSeverity.Error, exception, format, args);
|
||||
}
|
||||
|
||||
public static void Error(string format, params object[] args)
|
||||
public void Error(string format, params object[] args)
|
||||
{
|
||||
LogMessage(LogSeverity.Error, null, format, args);
|
||||
Error(null, format, args);
|
||||
}
|
||||
|
||||
public static void Warning(Exception exception, string format, params object[] args)
|
||||
public void Warning(Exception exception, string format, params object[] args)
|
||||
{
|
||||
LogMessage(LogSeverity.Warning, exception, format, args);
|
||||
}
|
||||
|
||||
public static void Warning(string format, params object[] args)
|
||||
public void Warning(string format, params object[] args)
|
||||
{
|
||||
LogMessage(LogSeverity.Warning, null, format, args);
|
||||
Warning(null, format, args);
|
||||
}
|
||||
|
||||
public static void Information(Exception exception, string format, params object[] args)
|
||||
public void Information(Exception exception, string format, params object[] args)
|
||||
{
|
||||
LogMessage(LogSeverity.Information, exception, format, args);
|
||||
}
|
||||
|
||||
public static void Information(string format, params object[] args)
|
||||
public void Information(string format, params object[] args)
|
||||
{
|
||||
LogMessage(LogSeverity.Information, null, format, args);
|
||||
Information(null, format, args);
|
||||
}
|
||||
|
||||
public static void Debug(Exception exception, string format, params object[] args)
|
||||
public void Debug(Exception exception, string format, params object[] args)
|
||||
{
|
||||
LogMessage(LogSeverity.Debug, exception, format, args);
|
||||
}
|
||||
|
||||
public static void Debug(string format, params object[] args)
|
||||
public void Debug(string format, params object[] args)
|
||||
{
|
||||
LogMessage(LogSeverity.Debug, null, format, args);
|
||||
Debug(null, format, args);
|
||||
}
|
||||
|
||||
private static void LogMessage(LogSeverity severity, Exception exception, string format, object[] args)
|
||||
public string FatalAndReturnFormatted(Exception exception, string format, params object[] args)
|
||||
{
|
||||
handler?.Handle(severity, exception, format, args);
|
||||
}
|
||||
}
|
||||
|
||||
public class LogUtil
|
||||
{
|
||||
public static string FatalAndReturnFormatted(Exception exception, string format, params object[] args)
|
||||
{
|
||||
Log.Fatal(exception, format, args);
|
||||
Fatal(exception, format, args);
|
||||
return string.Format(format, args);
|
||||
}
|
||||
|
||||
public static string FatalAndReturnFormatted(string format, params object[] args)
|
||||
public string FatalAndReturnFormatted(string format, params object[] args)
|
||||
{
|
||||
Log.Fatal(null, format, args);
|
||||
return FatalAndReturnFormatted(null, format, args);
|
||||
}
|
||||
|
||||
public string ErrorAndReturnFormatted(Exception exception, string format, params object[] args)
|
||||
{
|
||||
Error(exception, format, args);
|
||||
return string.Format(format, args);
|
||||
}
|
||||
|
||||
public static string ErrorAndReturnFormatted(Exception exception, string format, params object[] args)
|
||||
public string ErrorAndReturnFormatted(string format, params object[] args)
|
||||
{
|
||||
Log.Error(exception, format, args);
|
||||
return string.Format(format, args);
|
||||
}
|
||||
|
||||
public static string ErrorAndReturnFormatted(string format, params object[] args)
|
||||
{
|
||||
Log.Error(null, format, args);
|
||||
return string.Format(format, args);
|
||||
return ErrorAndReturnFormatted(null, format, args);
|
||||
}
|
||||
}
|
||||
}
|
||||
|
|
|
@ -6,7 +6,7 @@ namespace Bond.Comm
|
|||
/// Once passed to <see cref="Metrics.SetHandler"/>, will receive callbacks
|
||||
/// when new metrics are emitted by Bond.
|
||||
/// </summary>
|
||||
public interface MetricsHandler
|
||||
public interface IMetricsHandler
|
||||
{
|
||||
/// <summary>
|
||||
/// Will be called once at the end of each connection.
|
||||
|
@ -20,38 +20,38 @@ namespace Bond.Comm
|
|||
}
|
||||
|
||||
/// <summary>
|
||||
/// Implement a <see cref="MetricsHandler"/> and pass it to
|
||||
/// Implement a <see cref="IMetricsHandler"/> and pass it to
|
||||
/// <see cref="Metrics.SetHandler"/> to receive metrics objects showing
|
||||
/// what Bond is doing and where it's spending time.
|
||||
/// </summary>
|
||||
public static class Metrics
|
||||
{
|
||||
private static MetricsHandler handler;
|
||||
private static IMetricsHandler handler;
|
||||
|
||||
/// <summary>
|
||||
/// Sets a <see cref="MetricsHandler"/> to receive Bond metrics.
|
||||
/// Sets a <see cref="IMetricsHandler"/> to receive Bond metrics.
|
||||
/// </summary>
|
||||
/// <param name="newHandler">The handler to add.</param>
|
||||
/// <exception cref="InvalidOperationException">
|
||||
/// Thrown when there is another handler registered.
|
||||
/// </exception>
|
||||
public static void SetHandler(MetricsHandler newHandler)
|
||||
public static void SetHandler(IMetricsHandler newHandler)
|
||||
{
|
||||
if (newHandler == null)
|
||||
{
|
||||
throw new ArgumentException($"Attempted to set a null {nameof(MetricsHandler)}");
|
||||
throw new ArgumentException($"Attempted to set a null {nameof(IMetricsHandler)}");
|
||||
}
|
||||
|
||||
if (handler != null)
|
||||
{
|
||||
throw new InvalidOperationException($"Attempted to set a {nameof(MetricsHandler)} when there already was one");
|
||||
throw new InvalidOperationException($"Attempted to set a {nameof(IMetricsHandler)} when there already was one");
|
||||
}
|
||||
|
||||
handler = newHandler;
|
||||
}
|
||||
|
||||
/// <summary>
|
||||
/// Removes the existing <see cref="MetricsHandler"/>.
|
||||
/// Removes the existing <see cref="IMetricsHandler"/>.
|
||||
/// </summary>
|
||||
/// <remarks>
|
||||
/// May be called even if there is no existing handler.
|
||||
|
|
|
@ -87,8 +87,7 @@ namespace Bond.Comm.Layers
|
|||
{
|
||||
error_code = (int)ErrorCode.UnhandledLayerError,
|
||||
};
|
||||
Log.Error(ex, "{0}.{1}: While handling layer {2}: {3}",
|
||||
nameof(LayerStack<TLayerData>), nameof(OnSendImpl), layerIndex, ex.Message);
|
||||
Log.Site().Error(ex, "While handling layer {0}: {1}", layerIndex, ex.Message);
|
||||
}
|
||||
}
|
||||
|
||||
|
@ -113,8 +112,7 @@ namespace Bond.Comm.Layers
|
|||
error_code = (int)ErrorCode.UnhandledLayerError
|
||||
};
|
||||
|
||||
Log.Error(ex, "{0}.{1}: While handling layer {2}: {3}",
|
||||
nameof(LayerStack<TLayerData>), nameof(OnReceiveImpl), layerIndex, ex.Message);
|
||||
Log.Site().Error(ex, "While handling layer {0}: {1}", layerIndex, ex.Message);
|
||||
}
|
||||
}
|
||||
|
||||
|
@ -141,8 +139,7 @@ namespace Bond.Comm.Layers
|
|||
error_code = (int)ErrorCode.UnhandledLayerError
|
||||
};
|
||||
|
||||
Log.Error(ex, "{0}.{1}: While unmarshaling layer data: {2}",
|
||||
nameof(LayerStack<TLayerData>), nameof(DeserializeLayerData), ex.Message);
|
||||
Log.Site().Error(ex, "While unmarshaling layer data: {0}", ex.Message);
|
||||
|
||||
realLayerData = new TLayerData();
|
||||
}
|
||||
|
|
|
@ -16,8 +16,8 @@ namespace Bond.Comm.Layers
|
|||
error = layerStack.OnSend(messageType, sendContext, out layerData);
|
||||
if (error != null)
|
||||
{
|
||||
Log.Warning("{0}.{1}: Layer error occurred sending message of type {2} (Code: {3} Message: {4}).",
|
||||
nameof(LayerStackUtils), nameof(ProcessOnSend), messageType, error.error_code, error.message);
|
||||
Log.Site().Warning("Layer error occurred sending message of type {0} (Code: {1} Message: {2}).",
|
||||
messageType, error.error_code, error.message);
|
||||
}
|
||||
}
|
||||
|
||||
|
@ -32,15 +32,15 @@ namespace Bond.Comm.Layers
|
|||
{
|
||||
if (layerData == null)
|
||||
{
|
||||
Log.Warning("{0}.{1}: Layer stack present but no layer data received.", nameof(LayerStackUtils), nameof(ProcessOnReceive));
|
||||
Log.Site().Warning("Layer stack present but no layer data received.");
|
||||
}
|
||||
|
||||
error = layerStack.OnReceive(messageType, receiveContext, layerData);
|
||||
|
||||
if (error != null)
|
||||
{
|
||||
Log.Warning("{0}.{1}: Layer error occurred receiving message of type {2} (Code: {3} Message: {4}).",
|
||||
nameof(LayerStackUtils), nameof(ProcessOnReceive), messageType, error.error_code, error.message);
|
||||
Log.Site().Warning("Layer error occurred receiving message of type {0} (Code: {1} Message: {2}).",
|
||||
messageType, error.error_code, error.message);
|
||||
}
|
||||
}
|
||||
return error;
|
||||
|
|
|
@ -64,7 +64,7 @@ namespace Bond.Comm.Service
|
|||
}
|
||||
}
|
||||
|
||||
public void Register(IService service)
|
||||
public void Register<T>(T service) where T : IService
|
||||
{
|
||||
var methodNames = new SortedSet<string>();
|
||||
|
||||
|
@ -93,8 +93,7 @@ namespace Bond.Comm.Service
|
|||
}
|
||||
}
|
||||
|
||||
Log.Information("{0}.{1}: Registered {2} with methods: {3}",
|
||||
nameof(ServiceHost), nameof(Register), nameof(service), string.Join(", ", methodNames));
|
||||
Log.Site().Information("Registered {0} with methods: {1}", typeof(T).Name, string.Join(", ", methodNames));
|
||||
}
|
||||
|
||||
public void Deregister<T>(T service) where T : IService
|
||||
|
@ -106,8 +105,7 @@ namespace Bond.Comm.Service
|
|||
dispatchTable.Remove(serviceMethod.MethodName);
|
||||
}
|
||||
}
|
||||
Log.Information("{0}.{1}: Deregistered {2} with methods: {3}",
|
||||
nameof(ServiceHost), nameof(Deregister), typeof (T).Name);
|
||||
Log.Site().Information("Deregistered {0}.", typeof(T).Name);
|
||||
}
|
||||
|
||||
public async Task<IMessage> DispatchRequest(
|
||||
|
@ -116,8 +114,7 @@ namespace Bond.Comm.Service
|
|||
var totalTime = Stopwatch.StartNew();
|
||||
Stopwatch serviceTime = null;
|
||||
var requestMetrics = StartRequestMetrics(methodName, connectionMetrics);
|
||||
Log.Information("{0}.{1}: Got request [{2}] from {3}.",
|
||||
nameof(ServiceHost), nameof(DispatchRequest), methodName, context.Connection);
|
||||
Log.Site().Information("Got request [{0}] from {1}.", methodName, context.Connection);
|
||||
|
||||
ServiceMethodInfo methodInfo;
|
||||
|
||||
|
@ -127,7 +124,7 @@ namespace Bond.Comm.Service
|
|||
{
|
||||
var errorMessage = "Got request for unknown method [" + methodName + "].";
|
||||
|
||||
Log.Error("{0}.{1}: {2}", nameof(ServiceHost), nameof(DispatchRequest), errorMessage);
|
||||
Log.Site().Error(errorMessage);
|
||||
var error = new Error
|
||||
{
|
||||
message = errorMessage,
|
||||
|
@ -143,7 +140,7 @@ namespace Bond.Comm.Service
|
|||
ServiceCallbackType.RequestResponse + ", but it was registered as " +
|
||||
methodInfo.CallbackType + ".";
|
||||
|
||||
Log.Error("{0}.{1}: {2}", nameof(ServiceHost), nameof(DispatchRequest), errorMessage);
|
||||
Log.Site().Error(errorMessage);
|
||||
var error = new Error
|
||||
{
|
||||
message = errorMessage,
|
||||
|
@ -152,7 +149,7 @@ namespace Bond.Comm.Service
|
|||
return Message.FromError(error);
|
||||
}
|
||||
|
||||
IMessage result = null;
|
||||
IMessage result;
|
||||
|
||||
try
|
||||
{
|
||||
|
@ -163,8 +160,7 @@ namespace Bond.Comm.Service
|
|||
}
|
||||
catch (Exception ex)
|
||||
{
|
||||
Log.Error(ex, "{0}.{1}: Failed to complete method [{2}]. With exception: {3}",
|
||||
nameof(ServiceHost), nameof(DispatchRequest), methodName, ex.Message);
|
||||
Log.Site().Error(ex, "Failed to complete method [{0}]. With exception: {1}", methodName, ex.Message);
|
||||
result = Message.FromError(Transport.MakeInternalServerError(ex));
|
||||
}
|
||||
|
||||
|
@ -180,25 +176,22 @@ namespace Bond.Comm.Service
|
|||
var totalTime = Stopwatch.StartNew();
|
||||
Stopwatch serviceTime = null;
|
||||
var requestMetrics = StartRequestMetrics(methodName, connectionMetrics);
|
||||
Log.Information("{0}.{1}: Got event [{2}] from {3}.",
|
||||
nameof(ServiceHost), nameof(DispatchEvent), methodName, context.Connection);
|
||||
Log.Site().Information("Got event [{0}] from {1}.", methodName, context.Connection);
|
||||
ServiceMethodInfo methodInfo;
|
||||
|
||||
lock (dispatchTableLock)
|
||||
{
|
||||
if (!dispatchTable.TryGetValue(methodName, out methodInfo))
|
||||
{
|
||||
Log.Error("{0}.{1}: Got request for unknown method [{2}].",
|
||||
nameof(ServiceHost), nameof(DispatchEvent), methodName);
|
||||
Log.Site().Error("Got request for unknown method [{0}].", methodName);
|
||||
return;
|
||||
}
|
||||
}
|
||||
|
||||
if (methodInfo.CallbackType != ServiceCallbackType.Event)
|
||||
{
|
||||
Log.Error("{0}.{1}: Method [{2}] invoked as if it were {3}, but it was registered as {4}.",
|
||||
nameof(ServiceHost), nameof(DispatchEvent), methodName, ServiceCallbackType.Event,
|
||||
methodInfo.CallbackType);
|
||||
Log.Site().Error("Method [{0}] invoked as if it were {1}, but it was registered as {2}.",
|
||||
methodName, ServiceCallbackType.Event, methodInfo.CallbackType);
|
||||
return;
|
||||
}
|
||||
|
||||
|
@ -209,8 +202,7 @@ namespace Bond.Comm.Service
|
|||
}
|
||||
catch (Exception ex)
|
||||
{
|
||||
Log.Error(ex, "{0}.{1}: Failed to complete method [{2}]. With exception: {3}",
|
||||
nameof(ServiceHost), nameof(DispatchEvent), methodName, ex.Message);
|
||||
Log.Site().Error(ex, "Failed to complete method [{0}]. With exception: {1}", methodName, ex.Message);
|
||||
}
|
||||
|
||||
FinishRequestMetrics(requestMetrics, totalTime, serviceTime);
|
||||
|
|
|
@ -5,6 +5,7 @@ namespace UnitTest.Interfaces
|
|||
{
|
||||
using System;
|
||||
using System.Collections.Generic;
|
||||
using System.Diagnostics;
|
||||
using System.Linq;
|
||||
using Bond.Comm;
|
||||
using NUnit.Framework;
|
||||
|
@ -12,17 +13,17 @@ namespace UnitTest.Interfaces
|
|||
[TestFixture]
|
||||
public class LogTests
|
||||
{
|
||||
private class TestLogHandler : LogHandler
|
||||
private class TestLogHandler : ILogHandler
|
||||
{
|
||||
public LogSeverity? LastMessageSeverity;
|
||||
public string LastMessage;
|
||||
public Exception LastException;
|
||||
public int MessagesHandled;
|
||||
|
||||
public void Handle(LogSeverity severity, Exception exception, string format, params object[] args)
|
||||
public void Handle(string message, LogSeverity severity, Exception exception)
|
||||
{
|
||||
LastMessageSeverity = severity;
|
||||
LastMessage = string.Format(format, args);
|
||||
LastMessage = message;
|
||||
LastException = exception;
|
||||
MessagesHandled++;
|
||||
}
|
||||
|
@ -49,26 +50,26 @@ namespace UnitTest.Interfaces
|
|||
}
|
||||
}
|
||||
|
||||
private readonly List<LogSeverity> allSeverities = Enum.GetValues(typeof(LogSeverity)).Cast<LogSeverity>().ToList();
|
||||
private readonly List<LogSeverity> allSeverities = Enum.GetValues(typeof(LogSeverity)).Cast<LogSeverity>().OrderBy(x => x).ToList();
|
||||
|
||||
private readonly Dictionary<LogSeverity, Action<string, object[]>> levelLoggers =
|
||||
new Dictionary<LogSeverity, Action<string, object[]>>
|
||||
{
|
||||
{ LogSeverity.Debug, Log.Debug },
|
||||
{ LogSeverity.Information, Log.Information },
|
||||
{ LogSeverity.Warning, Log.Warning },
|
||||
{ LogSeverity.Error, Log.Error },
|
||||
{ LogSeverity.Fatal, Log.Fatal },
|
||||
{ LogSeverity.Debug, (message, args) => Log.Site().Debug(message, args) },
|
||||
{ LogSeverity.Information, (message, args) => Log.Site().Information(message, args) },
|
||||
{ LogSeverity.Warning, (message, args) => Log.Site().Warning(message, args) },
|
||||
{ LogSeverity.Error, (message, args) => Log.Site().Error(message, args) },
|
||||
{ LogSeverity.Fatal, (message, args) => Log.Site().Fatal(message, args) },
|
||||
};
|
||||
|
||||
private readonly Dictionary<LogSeverity, Action<Exception, string, object[]>> exceptionLevelLoggers =
|
||||
new Dictionary<LogSeverity, Action<Exception, string, object[]>>
|
||||
{
|
||||
{ LogSeverity.Debug, Log.Debug },
|
||||
{ LogSeverity.Information, Log.Information },
|
||||
{ LogSeverity.Warning, Log.Warning },
|
||||
{ LogSeverity.Error, Log.Error },
|
||||
{ LogSeverity.Fatal, Log.Fatal },
|
||||
{ LogSeverity.Debug, (ex, message, args) => Log.Site().Debug(ex, message, args) },
|
||||
{ LogSeverity.Information, (ex, message, args) => Log.Site().Information(ex, message, args) },
|
||||
{ LogSeverity.Warning, (ex, message, args) => Log.Site().Warning(ex, message, args) },
|
||||
{ LogSeverity.Error, (ex, message, args) => Log.Site().Error(ex, message, args) },
|
||||
{ LogSeverity.Fatal, (ex, message, args) => Log.Site().Fatal(ex, message, args) },
|
||||
};
|
||||
|
||||
private static Tuple<string, object[]> MakeMessage(LogSeverity severity, bool withException)
|
||||
|
@ -80,6 +81,8 @@ namespace UnitTest.Interfaces
|
|||
[SetUp]
|
||||
public void SetUp()
|
||||
{
|
||||
// Tests that exercise filtering enable it themselves.
|
||||
Log.DropBelow = LogSeverity.Debug;
|
||||
handler = new TestLogHandler();
|
||||
Log.SetHandler(handler);
|
||||
}
|
||||
|
@ -93,20 +96,10 @@ namespace UnitTest.Interfaces
|
|||
[Test]
|
||||
public void SeveritiesAreSorted()
|
||||
{
|
||||
var severitiesAscending = new List<LogSeverity>(new[]
|
||||
{
|
||||
LogSeverity.Debug,
|
||||
LogSeverity.Information,
|
||||
LogSeverity.Warning,
|
||||
LogSeverity.Error,
|
||||
LogSeverity.Fatal
|
||||
});
|
||||
var numSeverities = severitiesAscending.Count;
|
||||
// Make sure this list is complete.
|
||||
CollectionAssert.AreEquivalent(allSeverities, severitiesAscending);
|
||||
|
||||
var lower = severitiesAscending.GetRange(0, numSeverities - 1);
|
||||
var higher = severitiesAscending.GetRange(1, numSeverities - 1);
|
||||
// Assumes allSeverities is sorted.
|
||||
var numSeverities = allSeverities.Count;
|
||||
var lower = allSeverities.GetRange(0, numSeverities - 1);
|
||||
var higher = allSeverities.GetRange(1, numSeverities - 1);
|
||||
var pairs = lower.Zip(higher, (l, h) => new Tuple<LogSeverity, LogSeverity>(l, h));
|
||||
foreach (var pair in pairs)
|
||||
{
|
||||
|
@ -131,7 +124,7 @@ namespace UnitTest.Interfaces
|
|||
{
|
||||
// Clear the handler registered by SetUp().
|
||||
Log.RemoveHandler();
|
||||
Log.Information("no-op");
|
||||
Log.Site().Information("no-op");
|
||||
}
|
||||
|
||||
[Test]
|
||||
|
@ -152,10 +145,10 @@ namespace UnitTest.Interfaces
|
|||
var formatArgs = MakeMessage(severity, withException: false);
|
||||
var format = formatArgs.Item1;
|
||||
var args = formatArgs.Item2;
|
||||
var formatted = string.Format(format, args);
|
||||
var message = string.Format(format, args);
|
||||
logger(format, args);
|
||||
Assert.AreEqual(severity, handler.LastMessageSeverity);
|
||||
Assert.AreEqual(formatted, handler.LastMessage);
|
||||
StringAssert.Contains(message, handler.LastMessage);
|
||||
Assert.IsNull(handler.LastException);
|
||||
Assert.AreEqual(messagesLogged + 1, handler.MessagesHandled);
|
||||
messagesLogged++;
|
||||
|
@ -164,10 +157,10 @@ namespace UnitTest.Interfaces
|
|||
formatArgs = MakeMessage(severity, withException: true);
|
||||
format = formatArgs.Item1;
|
||||
args = formatArgs.Item2;
|
||||
formatted = string.Format(format, args);
|
||||
message = string.Format(format, args);
|
||||
exceptionLogger(exception, format, args);
|
||||
Assert.AreEqual(severity, handler.LastMessageSeverity);
|
||||
Assert.AreEqual(formatted, handler.LastMessage);
|
||||
StringAssert.Contains(message, handler.LastMessage);
|
||||
Assert.NotNull(handler.LastException);
|
||||
Assert.AreEqual(severity, ((TestException) handler.LastException).Severity);
|
||||
Assert.AreEqual(messagesLogged + 1, handler.MessagesHandled);
|
||||
|
@ -176,6 +169,43 @@ namespace UnitTest.Interfaces
|
|||
}
|
||||
}
|
||||
|
||||
[Test]
|
||||
public void DropBelow()
|
||||
{
|
||||
const LogSeverity dropBelow = LogSeverity.Warning;
|
||||
Log.DropBelow = dropBelow;
|
||||
|
||||
var messagesHandled = handler.MessagesHandled;
|
||||
// Assumes allSeverities is sorted.
|
||||
foreach (var severity in allSeverities)
|
||||
{
|
||||
var message = "level " + severity;
|
||||
levelLoggers[severity](message, new object[0]);
|
||||
if (severity < dropBelow)
|
||||
{
|
||||
Assert.Null(handler.LastMessage);
|
||||
Assert.Null(handler.LastMessageSeverity);
|
||||
Assert.AreEqual(messagesHandled, handler.MessagesHandled);
|
||||
}
|
||||
else
|
||||
{
|
||||
StringAssert.Contains(message, handler.LastMessage);
|
||||
Assert.AreEqual(severity, handler.LastMessageSeverity);
|
||||
Assert.AreEqual(messagesHandled + 1, handler.MessagesHandled);
|
||||
messagesHandled = handler.MessagesHandled;
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
[Test]
|
||||
public void LogContext()
|
||||
{
|
||||
// There are two statements on this line so that expectedLineNumber will be correct for the Warning().
|
||||
Log.Site().Warning("context"); var expectedLineNumber = new StackFrame(0, true).GetFileLineNumber();
|
||||
StringAssert.Contains(nameof(LogTests) + ".cs:" + expectedLineNumber, handler.LastMessage);
|
||||
StringAssert.Contains(nameof(LogContext), handler.LastMessage);
|
||||
}
|
||||
|
||||
[Test]
|
||||
public void FatalWithFormatted()
|
||||
{
|
||||
|
@ -186,10 +216,10 @@ namespace UnitTest.Interfaces
|
|||
var format = formatArgs.Item1;
|
||||
var args = formatArgs.Item2;
|
||||
var formatted = string.Format(format, args);
|
||||
var messageReturned = LogUtil.FatalAndReturnFormatted(format, args);
|
||||
var messageReturned = Log.Site().FatalAndReturnFormatted(format, args);
|
||||
Assert.AreEqual(LogSeverity.Fatal, handler.LastMessageSeverity);
|
||||
Assert.AreEqual(formatted, handler.LastMessage);
|
||||
Assert.AreEqual(messageReturned, handler.LastMessage);
|
||||
StringAssert.Contains(formatted, handler.LastMessage);
|
||||
StringAssert.Contains(messageReturned, handler.LastMessage);
|
||||
Assert.IsNull(handler.LastException);
|
||||
Assert.AreEqual(messagesLogged + 1, handler.MessagesHandled);
|
||||
messagesLogged++;
|
||||
|
@ -199,13 +229,46 @@ namespace UnitTest.Interfaces
|
|||
format = formatArgs.Item1;
|
||||
args = formatArgs.Item2;
|
||||
formatted = string.Format(format, args);
|
||||
messageReturned = LogUtil.FatalAndReturnFormatted(exception, format, args);
|
||||
messageReturned = Log.Site().FatalAndReturnFormatted(exception, format, args);
|
||||
Assert.AreEqual(LogSeverity.Fatal, handler.LastMessageSeverity);
|
||||
Assert.AreEqual(formatted, handler.LastMessage);
|
||||
Assert.AreEqual(messageReturned, handler.LastMessage);
|
||||
StringAssert.Contains(formatted, handler.LastMessage);
|
||||
StringAssert.Contains(messageReturned, handler.LastMessage);
|
||||
Assert.NotNull(handler.LastException);
|
||||
Assert.AreEqual(LogSeverity.Fatal, ((TestException)handler.LastException).Severity);
|
||||
Assert.AreEqual(messagesLogged + 1, handler.MessagesHandled);
|
||||
}
|
||||
|
||||
[Test]
|
||||
public void FormatExceptionIsSuppressedAndLogged()
|
||||
{
|
||||
const string format = "{0}, but there's nothing to put here: {1}";
|
||||
const string somestr = "any string goes here";
|
||||
|
||||
// Messages below Error should be raised to Error.
|
||||
Log.Site().Debug(format, somestr);
|
||||
|
||||
Assert.AreEqual(LogSeverity.Error, handler.LastMessageSeverity);
|
||||
Assert.Null(handler.LastException);
|
||||
StringAssert.Contains(format, handler.LastMessage);
|
||||
StringAssert.Contains(somestr, handler.LastMessage);
|
||||
StringAssert.Contains("Log call threw", handler.LastMessage);
|
||||
|
||||
// Messages above Error should be left at their original severity.
|
||||
Log.Site().Fatal(format, somestr);
|
||||
|
||||
Assert.AreEqual(LogSeverity.Fatal, handler.LastMessageSeverity);
|
||||
Assert.Null(handler.LastException);
|
||||
StringAssert.Contains(format, handler.LastMessage);
|
||||
StringAssert.Contains(somestr, handler.LastMessage);
|
||||
StringAssert.Contains("Log call threw", handler.LastMessage);
|
||||
}
|
||||
|
||||
[Test]
|
||||
public void LogInstanceReuseThrows()
|
||||
{
|
||||
var logInstance = Log.Site();
|
||||
logInstance.Warning("This should be fine.");
|
||||
Assert.Throws<InvalidOperationException>(() => logInstance.Warning("This should throw."));
|
||||
}
|
||||
}
|
||||
}
|
||||
|
|
|
@ -7,13 +7,10 @@ namespace Bond.Examples.Logging
|
|||
|
||||
using Bond.Comm;
|
||||
|
||||
public class ConsoleLogger : LogHandler
|
||||
public class ConsoleLogger : ILogHandler
|
||||
{
|
||||
public void Handle(LogSeverity severity, Exception exception, String format, params object[] args)
|
||||
public void Handle(string message, LogSeverity severity, Exception exception)
|
||||
{
|
||||
if (severity < LogSeverity.Information) { return; }
|
||||
|
||||
var message = string.Format(format, args);
|
||||
Console.WriteLine($"[bond] {severity.ToString().ToUpper()}: {message}");
|
||||
if (exception != null)
|
||||
{
|
||||
|
|
|
@ -7,7 +7,7 @@
|
|||
<ProjectGuid>{5C8132A8-C4B1-45E0-BCA6-379DA23B86D3}</ProjectGuid>
|
||||
<OutputType>Library</OutputType>
|
||||
<AppDesignerFolder>Properties</AppDesignerFolder>
|
||||
<RootNamespace>logging</RootNamespace>
|
||||
<RootNamespace>Bond.Examples.Logging</RootNamespace>
|
||||
<AssemblyName>logging</AssemblyName>
|
||||
<TargetFrameworkVersion>v4.5</TargetFrameworkVersion>
|
||||
<FileAlignment>512</FileAlignment>
|
||||
|
@ -54,4 +54,4 @@
|
|||
</ProjectReference>
|
||||
</ItemGroup>
|
||||
<Import Project="$(MSBuildToolsPath)\Microsoft.CSharp.targets" />
|
||||
</Project>
|
||||
</Project>
|
|
@ -1,14 +1,11 @@
|
|||
using System;
|
||||
using System.Collections.Generic;
|
||||
using System.Linq;
|
||||
using System.Text;
|
||||
using System.Threading.Tasks;
|
||||
|
||||
namespace Bond.Examples.Metrics
|
||||
{
|
||||
using Bond.Comm;
|
||||
|
||||
public class ConsoleMetricsHandler : MetricsHandler
|
||||
public class ConsoleMetricsHandler : IMetricsHandler
|
||||
{
|
||||
public void Handle(ConnectionMetrics metrics)
|
||||
{
|
||||
|
|
|
@ -7,7 +7,7 @@
|
|||
<ProjectGuid>{72ECA320-121F-4F3A-B455-B9EDE3364D9D}</ProjectGuid>
|
||||
<OutputType>Library</OutputType>
|
||||
<AppDesignerFolder>Properties</AppDesignerFolder>
|
||||
<RootNamespace>metrics</RootNamespace>
|
||||
<RootNamespace>Bond.Examples.Metrics</RootNamespace>
|
||||
<AssemblyName>metrics</AssemblyName>
|
||||
<TargetFrameworkVersion>v4.5</TargetFrameworkVersion>
|
||||
<FileAlignment>512</FileAlignment>
|
||||
|
@ -45,4 +45,4 @@
|
|||
<Reference Include="System" />
|
||||
</ItemGroup>
|
||||
<Import Project="$(MSBuildToolsPath)\Microsoft.CSharp.targets" />
|
||||
</Project>
|
||||
</Project>
|
Загрузка…
Ссылка в новой задаче