Skip to content

Commit c7aa3fb

Browse files
pragnagopapragnagopa
authored
Log request/response between host and custom handler when running in core tools (#6396)
1 parent 2324bfa commit c7aa3fb

File tree

5 files changed

+75
-33
lines changed

5 files changed

+75
-33
lines changed

‎src/WebJobs.Script/Extensions/HttpRequestExtensions.cs‎

Lines changed: 1 addition & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -117,8 +117,7 @@ public static bool IsMediaTypeOctetOrMultipart(this HttpRequest request)
117117
{
118118
if (MediaTypeHeaderValue.TryParse(request.ContentType, out MediaTypeHeaderValue mediaType))
119119
{
120-
return mediaType != null && (string.Equals(mediaType.MediaType, "application/octet-stream", StringComparison.OrdinalIgnoreCase) ||
121-
mediaType.MediaType.IndexOf("multipart/", StringComparison.OrdinalIgnoreCase) >= 0);
120+
return Utility.IsMediaTypeOctetOrMultipart(mediaType);
122121
}
123122
return false;
124123
}

‎src/WebJobs.Script/ScriptConstants.cs‎

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -121,6 +121,9 @@ public static class ScriptConstants
121121
public const string NugetXmlDocModeSettingName = "NUGET_XMLDOC_MODE";
122122
public const string NugetXmlDocSkipMode = "skip";
123123

124+
public const string MediatypeOctetStream = "application/octet-stream";
125+
public const string MediatypeMutipartPrefix = "multipart/";
126+
124127
public const int MaximumHostIdLength = 32;
125128
public const int DynamicSkuConnectionLimit = 50;
126129

‎src/WebJobs.Script/Utility.cs‎

Lines changed: 7 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -9,6 +9,7 @@
99
using System.IO;
1010
using System.IO.Abstractions;
1111
using System.Linq;
12+
using System.Net.Http.Headers;
1213
using System.Reflection;
1314
using System.Text;
1415
using System.Text.RegularExpressions;
@@ -752,6 +753,12 @@ public static string BuildStorageConnectionString(string accountName, string acc
752753
return $"DefaultEndpointsProtocol=https;AccountName={accountName};AccountKey={accessKey};EndpointSuffix={suffix}";
753754
}
754755

756+
public static bool IsMediaTypeOctetOrMultipart(MediaTypeHeaderValue mediaType)
757+
{
758+
return mediaType != null && (string.Equals(mediaType.MediaType, ScriptConstants.MediatypeOctetStream, StringComparison.OrdinalIgnoreCase) ||
759+
mediaType.MediaType.IndexOf(ScriptConstants.MediatypeMutipartPrefix, StringComparison.OrdinalIgnoreCase) >= 0);
760+
}
761+
755762
private class FilteredExpandoObjectConverter : ExpandoObjectConverter
756763
{
757764
public override bool CanWrite => true;

‎src/WebJobs.Script/Workers/Http/DefaultHttpWorkerService.cs‎

Lines changed: 45 additions & 14 deletions
Original file line numberDiff line numberDiff line change
@@ -5,6 +5,7 @@
55
using System.Collections.Generic;
66
using System.Linq;
77
using System.Net.Http;
8+
using System.Net.Http.Headers;
89
using System.Net.Sockets;
910
using System.Threading;
1011
using System.Threading.Tasks;
@@ -21,17 +22,19 @@ public class DefaultHttpWorkerService : IHttpWorkerService
2122
private readonly HttpClient _httpClient;
2223
private readonly HttpWorkerOptions _httpWorkerOptions;
2324
private readonly ILogger _logger;
25+
private readonly bool _enableRequestTracing;
2426

25-
public DefaultHttpWorkerService(IOptions<HttpWorkerOptions> httpWorkerOptions, ILoggerFactory loggerFactory)
26-
: this(new HttpClient(), httpWorkerOptions, loggerFactory.CreateLogger<DefaultHttpWorkerService>())
27+
public DefaultHttpWorkerService(IOptions<HttpWorkerOptions> httpWorkerOptions, ILoggerFactory loggerFactory, IEnvironment environment)
28+
: this(new HttpClient(), httpWorkerOptions, loggerFactory.CreateLogger<DefaultHttpWorkerService>(), environment)
2729
{
2830
}
2931

30-
internal DefaultHttpWorkerService(HttpClient httpClient, IOptions<HttpWorkerOptions> httpWorkerOptions, ILogger logger)
32+
internal DefaultHttpWorkerService(HttpClient httpClient, IOptions<HttpWorkerOptions> httpWorkerOptions, ILogger logger, IEnvironment environment)
3133
{
3234
_httpClient = httpClient ?? throw new ArgumentNullException(nameof(httpClient));
3335
_httpWorkerOptions = httpWorkerOptions.Value ?? throw new ArgumentNullException(nameof(httpWorkerOptions.Value));
3436
_logger = logger ?? throw new ArgumentNullException(nameof(logger));
37+
_enableRequestTracing = environment.IsCoreTools();
3538
}
3639

3740
public Task InvokeAsync(ScriptInvocationContext scriptInvocationContext)
@@ -74,9 +77,7 @@ internal async Task ProcessHttpInAndOutInvocationRequest(ScriptInvocationContext
7477
{
7578
AddHeaders(httpRequestMessage, scriptInvocationContext.ExecutionContext.InvocationId.ToString());
7679

77-
_logger.LogDebug("Forwarding http request for httpTrigger function: '{functionName}' invocationId: '{invocationId}'", scriptInvocationContext.FunctionMetadata.Name, scriptInvocationContext.ExecutionContext.InvocationId);
78-
HttpResponseMessage invocationResponse = await _httpClient.SendAsync(httpRequestMessage);
79-
_logger.LogDebug("Received http response for httpTrigger function: '{functionName}' invocationId: '{invocationId}'", scriptInvocationContext.FunctionMetadata.Name, scriptInvocationContext.ExecutionContext.InvocationId);
80+
HttpResponseMessage invocationResponse = await SendInvocationRequestAsync(scriptInvocationContext, httpRequestMessage);
8081

8182
BindingMetadata httpOutputBinding = scriptInvocationContext.FunctionMetadata.OutputBindings.FirstOrDefault();
8283
if (httpOutputBinding != null)
@@ -95,6 +96,38 @@ internal async Task ProcessHttpInAndOutInvocationRequest(ScriptInvocationContext
9596
}
9697
}
9798

99+
private async Task<HttpResponseMessage> SendInvocationRequestAsync(ScriptInvocationContext scriptInvocationContext, HttpRequestMessage httpRequestMessage)
100+
{
101+
// Only log Request / Response when running locally
102+
if (_enableRequestTracing)
103+
{
104+
scriptInvocationContext.Logger.LogTrace($"Invocation Request:{httpRequestMessage}");
105+
await TraceHttpContent(httpRequestMessage.Content, scriptInvocationContext.Logger);
106+
}
107+
_logger.LogDebug("Sending http request for function:{functionName} invocationId:{invocationId}", scriptInvocationContext.FunctionMetadata.Name, scriptInvocationContext.ExecutionContext.InvocationId);
108+
HttpResponseMessage invocationResponse = await _httpClient.SendAsync(httpRequestMessage);
109+
if (_enableRequestTracing)
110+
{
111+
scriptInvocationContext.Logger.LogTrace($"Invocation Response:{invocationResponse}");
112+
await TraceHttpContent(invocationResponse.Content, scriptInvocationContext.Logger);
113+
}
114+
_logger.LogDebug("Received http response for httpTrigger function: '{functionName}' invocationId: '{invocationId}'", scriptInvocationContext.FunctionMetadata.Name, scriptInvocationContext.ExecutionContext.InvocationId);
115+
return invocationResponse;
116+
}
117+
118+
private static async Task TraceHttpContent(HttpContent content, ILogger logger)
119+
{
120+
if (content != null)
121+
{
122+
bool isMediaTypeOctetOrMultipart = content.Headers != null && Utility.IsMediaTypeOctetOrMultipart(content.Headers.ContentType);
123+
// do not log binary data as string
124+
if (!isMediaTypeOctetOrMultipart)
125+
{
126+
logger.LogTrace(await content.ReadAsStringAsync());
127+
}
128+
}
129+
}
130+
98131
internal void AddHeaders(HttpRequestMessage httpRequest, string invocationId)
99132
{
100133
httpRequest.Headers.Add(HttpWorkerConstants.HostVersionHeaderName, ScriptHost.Version);
@@ -125,14 +158,12 @@ internal async Task ProcessDefaultInvocationRequest(ScriptInvocationContext scri
125158
{
126159
AddHeaders(httpRequestMessage, scriptInvocationContext.ExecutionContext.InvocationId.ToString());
127160

128-
_logger.LogDebug("Sending http request for function:{functionName} invocationId:{invocationId}", scriptInvocationContext.FunctionMetadata.Name, scriptInvocationContext.ExecutionContext.InvocationId);
129-
HttpResponseMessage response = await _httpClient.SendAsync(httpRequestMessage);
130-
_logger.LogDebug("Received http response for function:{functionName} invocationId:{invocationId}", scriptInvocationContext.FunctionMetadata.Name, scriptInvocationContext.ExecutionContext.InvocationId);
161+
HttpResponseMessage invocationResponse = await SendInvocationRequestAsync(scriptInvocationContext, httpRequestMessage);
131162

132163
// Only process output bindings if response is succeess code
133-
response.EnsureSuccessStatusCode();
164+
invocationResponse.EnsureSuccessStatusCode();
134165

135-
HttpScriptInvocationResult httpScriptInvocationResult = await response.Content.ReadAsAsync<HttpScriptInvocationResult>();
166+
HttpScriptInvocationResult httpScriptInvocationResult = await invocationResponse.Content.ReadAsAsync<HttpScriptInvocationResult>();
136167

137168
if (httpScriptInvocationResult != null)
138169
{
@@ -188,7 +219,7 @@ public async Task<bool> IsWorkerReady(CancellationToken cancellationToken)
188219
string requestUri = BuildAndGetUri();
189220
try
190221
{
191-
await SendRequest(requestUri);
222+
await SendPingRequestAsync(requestUri);
192223
// Any Http response indicates a valid server Url
193224
return false;
194225
}
@@ -217,7 +248,7 @@ internal string BuildAndGetUri(string pathValue = null)
217248
return new UriBuilder(WorkerConstants.HttpScheme, WorkerConstants.HostName, _httpWorkerOptions.Port, pathValue).ToString();
218249
}
219250

220-
private async Task<HttpResponseMessage> SendRequest(string requestUri, HttpMethod method = null)
251+
private async Task<HttpResponseMessage> SendPingRequestAsync(string requestUri, HttpMethod method = null)
221252
{
222253
HttpRequestMessage httpRequestMessage = new HttpRequestMessage();
223254
httpRequestMessage.RequestUri = new Uri(requestUri);
@@ -234,7 +265,7 @@ public async Task PingAsync()
234265
string requestUri = BuildAndGetUri();
235266
try
236267
{
237-
HttpResponseMessage response = await SendRequest(requestUri, HttpMethod.Get);
268+
HttpResponseMessage response = await SendPingRequestAsync(requestUri, HttpMethod.Get);
238269
_logger.LogDebug($"Response code while pinging uri '{requestUri}' is '{response.StatusCode}'");
239270
}
240271
catch (Exception ex)

0 commit comments

Comments
 (0)