private async Task <HttpServiceRequest> ParseRequest(HttpListenerContext context)
{
var request = await _deserializationTime.Time(async() =>
{
using (var streamReader = new StreamReader(context.Request.InputStream))
{
var json = await streamReader.ReadToEndAsync();
return(JsonConvert.DeserializeObject <HttpServiceRequest>(json, JsonSettings));
}
});
// TODO: We have an issue when calling from Legacy:
// http://kibana.gigya.net/kibana3/#/dashboard/elasticsearch/logdog_dashboard?query=callID:8f74364e9cab4aa4954374b8064155a1&from=2019-07-23T10:29:15.218Z&to=2019-07-23T10:31:15.220Z
// var errors = new List<ValidationResult>();
//
// if ( !_validator.TryValidateObjectRecursive(request.Overrides, errors)
// || !_validator.TryValidateObjectRecursive(request.TracingData, errors)
// )
// {
// _failureCounter.Increment("InvalidRequestFormat");
// throw new RequestException("Invalid request format: " + string.Join("\n", errors.Select(a => a.MemberNames + ": " + a.ErrorMessage)));
// }
request.TracingData = request.TracingData ?? new TracingData();
request.TracingData.RequestID = request.TracingData.RequestID ?? Guid.NewGuid().ToString("N");
return(request);
}
private async Task HandleRequest(HttpListenerContext context, long ticks, long timeFromLastReq)
{
try
{
var deltaDelayTicks = DateTime.UtcNow.Ticks - ticks;
var sw = Stopwatch.StartNew();
RequestTimings.ClearCurrentTimings();
using (context.Response)
{
// Special endpoints should not be logged/measured/traced like regular endpoints
// Access is allowed without HTTPS verifications since they don't expose anything sensitive (e.g. config values are encrypted)
if (await TryHandleSpecialEndpoints(context))
{
return;
}
// Regular endpoint handling
using (_activeRequestsCounter.NewContext("Request"))
{
RequestTimings.GetOrCreate(); // initialize request timing context
string methodName = null;
// Initialize with empty object for protocol backwards-compatibility.
var requestData = new HttpServiceRequest {
TracingData = new TracingData()
};
object[] argumentsWithDefaults = null;
ServiceMethod serviceMethod = null;
ServiceCallEvent callEvent = _serverRequestPublisher.GetNewCallEvent();
try
{
try
{
await CheckSecureConnection(context);
ValidateRequest(context);
requestData = await ParseRequest(context);
//-----------------------------------------------------------------------------------------
// Don't move TracingContext writes main flow, IT have to be here, to avoid side changes
//-----------------------------------------------------------------------------------------
TracingContext.SetRequestID(requestData.TracingData.RequestID);
TracingContext.SpanStartTime = requestData.TracingData.SpanStartTime;
TracingContext.AbandonRequestBy = requestData.TracingData.AbandonRequestBy;
TracingContext.SetParentSpan(
requestData.TracingData.SpanID ?? Guid.NewGuid().ToString("N"));
TracingContext.SetOverrides(requestData.Overrides);
if (requestData.TracingData.Tags != null)
{
TracingContext.Tags = new ContextTags(requestData.TracingData.Tags);
}
TracingContext.AdditionalProperties = requestData.TracingData.AdditionalProperties;
callEvent.ServiceMethodSchema = context.Request.IsSecureConnection ? "HTTPS" : "HTTP";
SetCallEventRequestData(callEvent, requestData);
serviceMethod = ServiceEndPointDefinition.Resolve(requestData.Target);
callEvent.CalledServiceName = serviceMethod.GrainInterfaceType.Name;
methodName = serviceMethod.ServiceInterfaceMethod.Name;
var arguments = requestData.Target.IsWeaklyTyped
? GetParametersByName(serviceMethod, requestData.Arguments)
: requestData.Arguments.Values.Cast <object>().ToArray();
argumentsWithDefaults =
GetConvertedAndDefaultArguments(serviceMethod.ServiceInterfaceMethod, arguments);
if (_extendedDelayTimeLogging)
{
callEvent.RecvDateTicks = ticks;
callEvent.ReqStartupDeltaTicks = deltaDelayTicks;
callEvent.TimeFromLastReq = timeFromLastReq;
var outstandingReqs = Interlocked.Read(ref OutstandingRequests);
callEvent.OutstandingRequests = outstandingReqs;
if (deltaDelayTicks > 10_000_000)
{
callEvent.CollectionCountGen0 = GC.CollectionCount(0);
callEvent.CollectionCountGen1 = GC.CollectionCount(1);
callEvent.CollectionCountGen2 = GC.CollectionCount(2);
}
}
}
catch (Exception e)
{
callEvent.Exception = e;
if (e is RequestException)
{
throw;
}
throw new RequestException("Invalid request", e);
}
RejectRequestIfLateOrOverloaded();
var responseJson = await GetResponse(context, serviceMethod, requestData,
argumentsWithDefaults);
if (await TryWriteResponse(context, responseJson, serviceCallEvent: callEvent))
{
callEvent.ErrCode = 0;
_successCounter.Increment();
}
else
{
_failureCounter.Increment();
}
}
catch (Exception e)
{
callEvent.Exception = callEvent.Exception ?? e;
_failureCounter.Increment();
Exception ex = GetRelevantException(e);
string json = _serializationTime.Time(() => ExceptionSerializer.Serialize(ex));
await TryWriteResponse(context, json, GetExceptionStatusCode(ex),
serviceCallEvent : callEvent);
}
finally
{
sw.Stop();
callEvent.ActualTotalTime = sw.Elapsed.TotalMilliseconds;
_roundtripTime.Record((long)(sw.Elapsed.TotalMilliseconds * 1000000),
TimeUnit.Nanoseconds);
if (methodName != null)
{
_endpointContext.Timer(methodName, Unit.Requests)
.Record((long)(sw.Elapsed.TotalMilliseconds * 1000000), TimeUnit.Nanoseconds);
}
_serverRequestPublisher.TryPublish(callEvent, argumentsWithDefaults, serviceMethod);
}
}
}
}
finally
{
Interlocked.Decrement(ref OutstandingRequests);
}
}
private async Task <object> InvokeCore(HttpServiceRequest request, Type resultReturnType, JsonSerializerSettings jsonSettings)
{
if (request == null)
{
throw new ArgumentNullException(nameof(request));
}
request.TracingData = new TracingData
{
HostName = CurrentApplicationInfo.HostName?.ToUpperInvariant(),
ServiceName = CurrentApplicationInfo.Name,
RequestID = TracingContext.TryGetRequestID(),
SpanID = Guid.NewGuid().ToString("N"), //Each call is new span
ParentSpanID = TracingContext.TryGetSpanID(),
SpanStartTime = DateTimeOffset.UtcNow,
AbandonRequestBy = TracingContext.AbandonRequestBy
};
PrepareRequest?.Invoke(request);
while (true)
{
var config = GetConfig();
var clientCallEvent = EventPublisher.CreateEvent();
clientCallEvent.TargetService = ServiceName;
clientCallEvent.RequestId = request.TracingData?.RequestID;
clientCallEvent.TargetMethod = request.Target.MethodName;
clientCallEvent.SpanId = request.TracingData?.SpanID;
clientCallEvent.ParentSpanId = request.TracingData?.ParentSpanID;
string responseContent;
HttpResponseMessage response;
var nodeAndLoadBalancer = await ServiceDiscovery.GetNode().ConfigureAwait(false); // can throw
int?effectivePort = GetEffectivePort(nodeAndLoadBalancer.Node, config);
if (effectivePort == null)
{
throw new ConfigurationException("Cannot access service. Service Port not configured. See tags to find missing configuration", unencrypted: new Tags {
{ "ServiceName", ServiceName },
{ "Required configuration key", $"Discovery.{ServiceName}.DefaultPort" }
});
}
// The URL is only for a nice experience in Fiddler, it's never parsed/used for anything.
var uri = BuildUri(nodeAndLoadBalancer.Node.Hostname, effectivePort.Value, config) + ServiceName;
if (request.Target.MethodName != null)
{
uri += $".{request.Target.MethodName}";
}
if (request.Target.Endpoint != null)
{
uri += $"/{request.Target.Endpoint}";
}
try
{
Log.Debug(_ => _("ServiceProxy: Calling remote service. See tags for details.",
unencryptedTags: new
{
remoteEndpoint = nodeAndLoadBalancer.Node.Hostname,
remotePort = effectivePort,
remoteServiceName = ServiceName,
remoteMethodName = request.Target.MethodName
}));
clientCallEvent.TargetHostName = nodeAndLoadBalancer.Node.Hostname;
clientCallEvent.TargetPort = effectivePort.Value;
request.Overrides = TracingContext.TryGetOverrides()?.ShallowCloneWithDifferentPreferredEnvironment(nodeAndLoadBalancer.PreferredEnvironment)
?? new RequestOverrides {
PreferredEnvironment = nodeAndLoadBalancer.PreferredEnvironment
};
string requestContent = _serializationTime.Time(() => JsonConvert.SerializeObject(request, jsonSettings));
var httpContent = new StringContent(requestContent, Encoding.UTF8, "application/json");
httpContent.Headers.Add(GigyaHttpHeaders.ProtocolVersion, HttpServiceRequest.ProtocolVersion);
clientCallEvent.RequestStartTimestamp = Stopwatch.GetTimestamp();
try
{
response = await GetHttpClient(config).PostAsync(uri, httpContent).ConfigureAwait(false);
responseContent = await response.Content.ReadAsStringAsync().ConfigureAwait(false);
}
finally
{
clientCallEvent.ResponseEndTimestamp = Stopwatch.GetTimestamp();
}
if (response.Headers.TryGetValues(GigyaHttpHeaders.ExecutionTime, out IEnumerable <string> values))
{
var time = values.FirstOrDefault();
if (TimeSpan.TryParse(time, out TimeSpan executionTime))
{
clientCallEvent.ServerTimeMs = executionTime.TotalMilliseconds;
}
}
}
catch (HttpRequestException ex)
{
Log.Error("The remote service failed to return a valid HTTP response. Continuing to next " +
"host. See tags for URL and exception for details.",
exception: ex,
unencryptedTags: new { uri });
_hostFailureCounter.Increment("RequestFailure");
clientCallEvent.Exception = ex;
EventPublisher.TryPublish(clientCallEvent); // fire and forget!
if (nodeAndLoadBalancer.LoadBalancer != null)
{
nodeAndLoadBalancer.LoadBalancer.ReportUnreachable(nodeAndLoadBalancer.Node, ex);
continue;
}
throw;
}
catch (TaskCanceledException ex)
{
_failureCounter.Increment("RequestTimeout");
Exception rex = new RemoteServiceException("The request to the remote service exceeded the " +
"allotted timeout. See the 'RequestUri' property on this exception for the URL that was " +
"called and the tag 'requestTimeout' for the configured timeout.",
uri,
ex,
unencrypted: new Tags
{
{ "requestTimeout", LastHttpClient?.Timeout.ToString() },
{ "requestUri", uri }
});
clientCallEvent.Exception = rex;
EventPublisher.TryPublish(clientCallEvent); // fire and forget!
throw rex;
}
if (response.Headers.Contains(GigyaHttpHeaders.ServerHostname) || response.Headers.Contains(GigyaHttpHeaders.ProtocolVersion))
{
try
{
if (response.IsSuccessStatusCode)
{
var returnObj = _deserializationTime.Time(() => JsonConvert.DeserializeObject(responseContent, resultReturnType, jsonSettings));
clientCallEvent.ErrCode = 0;
EventPublisher.TryPublish(clientCallEvent); // fire and forget!
_successCounter.Increment();
return(returnObj);
}
else
{
Exception remoteException;
try
{
remoteException = _deserializationTime.Time(() => ExceptionSerializer.Deserialize(responseContent));
}
catch (Exception ex)
{
_applicationExceptionCounter.Increment("ExceptionDeserializationFailure");
throw new RemoteServiceException("The remote service returned a failure response " +
"that failed to deserialize. See the 'RequestUri' property on this exception " +
"for the URL that was called, the inner exception for the exact error and the " +
"'responseContent' encrypted tag for the original response content.",
uri,
ex,
unencrypted: new Tags {
{ "requestUri", uri }
},
encrypted: new Tags {
{ "responseContent", responseContent }
});
}
_applicationExceptionCounter.Increment();
clientCallEvent.Exception = remoteException;
EventPublisher.TryPublish(clientCallEvent); // fire and forget!
if (remoteException is RequestException || remoteException is EnvironmentException)
{
ExceptionDispatchInfo.Capture(remoteException).Throw();
}
if (remoteException is UnhandledException)
{
remoteException = remoteException.InnerException;
}
throw new RemoteServiceException("The remote service returned a failure response. See " +
"the 'RequestUri' property on this exception for the URL that was called, and the " +
"inner exception for details.",
uri,
remoteException,
unencrypted: new Tags {
{ "requestUri", uri }
});
}
}
catch (JsonException ex)
{
_failureCounter.Increment("Serialization");
Log.Error("The remote service returned a response with JSON that failed " +
"deserialization. See the 'uri' tag for the URL that was called, the exception for the " +
"exact error and the 'responseContent' encrypted tag for the original response content.",
exception: ex,
unencryptedTags: new { uri },
encryptedTags: new { responseContent });
clientCallEvent.Exception = ex;
EventPublisher.TryPublish(clientCallEvent); // fire and forget!
throw new RemoteServiceException("The remote service returned a response with JSON that " +
"failed deserialization. See the 'RequestUri' property on this exception for the URL " +
"that was called, the inner exception for the exact error and the 'responseContent' " +
"encrypted tag for the original response content.",
uri,
ex,
new Tags {
{ "responseContent", responseContent }
},
new Tags {
{ "requestUri", uri }
});
}
}
else
{
var exception = response.StatusCode == HttpStatusCode.ServiceUnavailable ?
new Exception($"The remote service is unavailable (503) and is not recognized as a Gigya host at uri: {uri}") :
new Exception($"The remote service returned a response but is not recognized as a Gigya host at uri: {uri}");
nodeAndLoadBalancer.LoadBalancer.ReportUnreachable(nodeAndLoadBalancer.Node, exception);
_hostFailureCounter.Increment("NotGigyaHost");
if (response.StatusCode == HttpStatusCode.ServiceUnavailable)
{
Log.Error("The remote service is unavailable (503) and is not recognized as a Gigya host. Continuing to next host.", unencryptedTags: new { uri });
}
else
{
Log.Error("The remote service returned a response but is not recognized as a Gigya host. Continuing to next host.", unencryptedTags: new { uri, statusCode = response.StatusCode }, encryptedTags: new { responseContent });
}
clientCallEvent.ErrCode = 500001; //(int)GSErrors.General_Server_Error;
EventPublisher.TryPublish(clientCallEvent); // fire and forget!
}
}
}