public void Debug(string logType, string message, IDictionary <string, string> userFields = null)
{
if (isInitialized == false)
{
GamebaseLog.Error("InstanceLogger not initialized", this);
return;
}
logger.Debug(logType, message, MakeFields(userFields));
}
private async Task LogBody(string fmtText, HttpContent content)
{
// This buffers the body content within the HttpContent if required.
var bodyBytes = content != null ? await content.ReadAsByteArrayAsync().ConfigureAwait(false) : new byte[0];
char[] bodyChars = new char[bodyBytes.Length];
for (int i = 0; i < bodyBytes.Length; i++)
{
var b = bodyBytes[i];
bodyChars[i] = b >= 32 && b <= 126 ? (char)b : '.';
}
InstanceLogger.Debug(fmtText, new string(bodyChars));
}
private void LogHeaders(string initialText, HttpHeaders headers1, HttpHeaders headers2)
{
var headers = (headers1 ?? Enumerable.Empty <KeyValuePair <string, IEnumerable <string> > >())
.Concat(headers2 ?? Enumerable.Empty <KeyValuePair <string, IEnumerable <string> > >()).ToList();
var args = new object[headers.Count * 2];
var fmt = new StringBuilder(headers.Count * 32);
fmt.Append(initialText);
var argBuilder = new StringBuilder();
for (int i = 0; i < headers.Count; i++)
{
fmt.Append($"\n [{{{i * 2}}}] '{{{1 + i * 2}}}'");
args[i * 2] = headers[i].Key;
argBuilder.Clear();
args[1 + i * 2] = string.Join("; ", headers[i].Value);
}
InstanceLogger.Debug(fmt.ToString(), args);
}
/// <summary>
/// The main logic of sending a request to the server. This send method adds the User-Agent header to a request
/// with <see cref="ApplicationName"/> and the library version. It also calls interceptors before each attempt,
/// and unsuccessful response handler or exception handlers when abnormal response or exception occurred.
/// </summary>
protected override async Task <HttpResponseMessage> SendAsync(HttpRequestMessage request,
CancellationToken cancellationToken)
{
var loggable = IsLoggingEnabled && InstanceLogger.IsDebugEnabled;
string loggingRequestId = "";
if (loggable)
{
loggingRequestId = Interlocked.Increment(ref _loggingRequestId).ToString("X8");
}
int triesRemaining = NumTries;
int redirectRemaining = NumRedirects;
Exception lastException = null;
// Set User-Agent header.
var userAgent = (ApplicationName == null ? "" : ApplicationName + " ") + UserAgentSuffix;
// TODO: setting the User-Agent won't work on Silverlight. We may need to create a special callback here to
// set it correctly.
request.Headers.Add("User-Agent", userAgent);
HttpResponseMessage response = null;
do // While (triesRemaining > 0)
{
response?.Dispose();
response = null;
lastException = null;
// Check after previous response (if any) has been disposed of.
cancellationToken.ThrowIfCancellationRequested();
// We keep a local list of the interceptors, since we can't call await inside lock.
List <IHttpExecuteInterceptor> interceptors;
lock (executeInterceptorsLock)
{
interceptors = executeInterceptors.ToList();
}
if (request.Properties.TryGetValue(ExecuteInterceptorKey, out var interceptorsValue) &&
interceptorsValue is List <IHttpExecuteInterceptor> perCallinterceptors)
{
interceptors.AddRange(perCallinterceptors);
}
// Intercept the request.
foreach (var interceptor in interceptors)
{
await interceptor.InterceptAsync(request, cancellationToken).ConfigureAwait(false);
}
if (loggable)
{
if ((LogEvents & LogEventType.RequestUri) != 0)
{
InstanceLogger.Debug("Request[{0}] (triesRemaining={1}) URI: '{2}'", loggingRequestId, triesRemaining, request.RequestUri);
}
if ((LogEvents & LogEventType.RequestHeaders) != 0)
{
LogHeaders($"Request[{loggingRequestId}] Headers:", request.Headers, request.Content?.Headers);
}
if ((LogEvents & LogEventType.RequestBody) != 0)
{
await LogBody($"Request[{loggingRequestId}] Body: '{{0}}'", request.Content).ConfigureAwait(false);
}
}
try
{
// Send the request!
response = await base.SendAsync(request, cancellationToken).ConfigureAwait(false);
}
catch (Exception ex)
{
lastException = ex;
}
// Decrease the number of retries.
if (response == null || ((int)response.StatusCode >= 400 || (int)response.StatusCode < 200))
{
triesRemaining--;
}
// Exception was thrown, try to handle it.
if (response == null)
{
var exceptionHandled = false;
// We keep a local list of the handlers, since we can't call await inside lock.
List <IHttpExceptionHandler> handlers;
lock (exceptionHandlersLock)
{
handlers = exceptionHandlers.ToList();
}
if (request.Properties.TryGetValue(ExceptionHandlerKey, out var handlersValue) &&
handlersValue is List <IHttpExceptionHandler> perCallHandlers)
{
handlers.AddRange(perCallHandlers);
}
// Try to handle the exception with each handler.
foreach (var handler in handlers)
{
exceptionHandled |= await handler.HandleExceptionAsync(new HandleExceptionArgs
{
Request = request,
Exception = lastException,
TotalTries = NumTries,
CurrentFailedTry = NumTries - triesRemaining,
CancellationToken = cancellationToken
}).ConfigureAwait(false);
}
if (!exceptionHandled)
{
InstanceLogger.Error(lastException,
"Response[{0}] Exception was thrown while executing a HTTP request and it wasn't handled", loggingRequestId);
throw lastException;
}
else if (loggable && (LogEvents & LogEventType.ResponseAbnormal) != 0)
{
InstanceLogger.Debug("Response[{0}] Exception {1} was thrown, but it was handled by an exception handler",
loggingRequestId, lastException.Message);
}
}
else
{
if (loggable)
{
if ((LogEvents & LogEventType.ResponseStatus) != 0)
{
InstanceLogger.Debug("Response[{0}] Response status: {1} '{2}'", loggingRequestId, response.StatusCode, response.ReasonPhrase);
}
if ((LogEvents & LogEventType.ResponseHeaders) != 0)
{
LogHeaders($"Response[{loggingRequestId}] Headers:", response.Headers, response.Content?.Headers);
}
if ((LogEvents & LogEventType.ResponseBody) != 0)
{
await LogBody($"Response[{loggingRequestId}] Body: '{{0}}'", response.Content).ConfigureAwait(false);
}
}
if (response.IsSuccessStatusCode)
{
// No need to retry, the response was successful.
triesRemaining = 0;
}
else
{
bool errorHandled = false;
// We keep a local list of the handlers, since we can't call await inside lock.
List <IHttpUnsuccessfulResponseHandler> handlers;
lock (unsuccessfulResponseHandlersLock)
{
handlers = unsuccessfulResponseHandlers.ToList();
}
if (request.Properties.TryGetValue(UnsuccessfulResponseHandlerKey, out var handlersValue) &&
handlersValue is List <IHttpUnsuccessfulResponseHandler> perCallHandlers)
{
handlers.AddRange(perCallHandlers);
}
// Try to handle the abnormal HTTP response with each handler.
foreach (var handler in handlers)
{
try
{
errorHandled |= await handler.HandleResponseAsync(new HandleUnsuccessfulResponseArgs
{
Request = request,
Response = response,
TotalTries = NumTries,
CurrentFailedTry = NumTries - triesRemaining,
CancellationToken = cancellationToken
}).ConfigureAwait(false);
}
catch when(DisposeAndReturnFalse(response))
{
}
bool DisposeAndReturnFalse(IDisposable disposable)
{
disposable.Dispose();
return(false);
}
}
if (!errorHandled)
{
if (FollowRedirect && HandleRedirect(response))
{
if (redirectRemaining-- == 0)
{
triesRemaining = 0;
}
errorHandled = true;
if (loggable && (LogEvents & LogEventType.ResponseAbnormal) != 0)
{
InstanceLogger.Debug("Response[{0}] Redirect response was handled successfully. Redirect to {1}",
loggingRequestId, response.Headers.Location);
}
}
else
{
if (loggable && (LogEvents & LogEventType.ResponseAbnormal) != 0)
{
InstanceLogger.Debug("Response[{0}] An abnormal response wasn't handled. Status code is {1}",
loggingRequestId, response.StatusCode);
}
// No need to retry, because no handler handled the abnormal response.
triesRemaining = 0;
}
}
else if (loggable && (LogEvents & LogEventType.ResponseAbnormal) != 0)
{
InstanceLogger.Debug("Response[{0}] An abnormal response was handled by an unsuccessful response handler. " +
"Status Code is {1}", loggingRequestId, response.StatusCode);
}
}
}
} while (triesRemaining > 0); // Not a successful status code but it was handled.
// If the response is null, we should throw the last exception.
if (response == null)
{
InstanceLogger.Error(lastException, "Request[{0}] Exception was thrown while executing a HTTP request", loggingRequestId);
throw lastException;
}
else if (!response.IsSuccessStatusCode && loggable && (LogEvents & LogEventType.ResponseAbnormal) != 0)
{
InstanceLogger.Debug("Response[{0}] Abnormal response is being returned. Status Code is {1}", loggingRequestId, response.StatusCode);
}
return(response);
}