FubarDevelopment
Webdav Get 0 bytes - stream already consumed by loggingresponse
We found an issue that emerged in our test/QA-environment where if debug-logging is activated a WebDav GET request would return 0 bytes. Traced this (after many a wild goose chases :)) to the behaviour of the WebDavIndirectResult.cs (in branch release/2.0 which we're using).
public override async Task ExecuteResultAsync(ActionContext context)
{
var response = context.HttpContext.Response;
// Register the WebDAV response if it's disposable
if (_result is IDisposable disposableResult)
{
response.RegisterForDispose(disposableResult);
}
_logger?.LogDebug("WebDavIndirectResult before ExecuteResultAsync");
// Sets the HTTP status code
await base.ExecuteResultAsync(context).ConfigureAwait(false);
_logger?.LogDebug("WebDavIndirectResult after ExecuteResultAsync");
// Sets the reason phrase
var responseFeature = context.HttpContext.Features.Get<IHttpResponseFeature>();
if (responseFeature != null)
{
responseFeature.ReasonPhrase = _result.StatusCode.GetReasonPhrase();
}
if (_logger?.IsEnabled(LogLevel.Debug) ?? false)
{
_logger?.LogDebug("WebDavIndirectResult logging before");
var loggingResponse = new LoggingWebDavResponse(_context);
//Stream consumed here
await _result.ExecuteResultAsync(loggingResponse, context.HttpContext.RequestAborted).ConfigureAwait(false);
if (!string.IsNullOrEmpty(loggingResponse.ContentType))
{
var mediaType = new MediaType(loggingResponse.ContentType);
if (_supportedMediaTypes.Any(x => mediaType.IsSubsetOf(x)))
{
var doc = loggingResponse.Load();
if (doc != null)
{
_logger.LogDebug(
"WebDAV Response: {Response}",
doc.ToString(SaveOptions.OmitDuplicateNamespaces));
}
}
}
_logger?.LogDebug("WebDavIndirectResult logging return");
return;
}
// Writes the XML response
//Stream also consumed here
await _result.ExecuteResultAsync(new WebDavResponse(_context, response), context.HttpContext.RequestAborted).ConfigureAwait(false);
}
The above code causes the document stream to be consumed twice, first in the LoggingWebDavResponse and then in the await _result.ExeCuteResultAsync(...) at the bottom. Second time the stream is already consumed causing the stream.CopyToAsync(body) to write 0 bytes.
I'd be happy to put up a PR but there are multiple ways this issue can be alleviated so I would need your input on the preferred way.
The preferred (easiest) solution would be to add a Body.Position = 0 in a finally block in the LoggingWebDavResponse.Load function.
That wont work though. The final output to the http body, written to by the FullDocumentResult, doesn't read from the loggingresponse's body memorystream.
A couple of idea's:
The loggingwebdavresponse will always consume the body since the ContentType is hardcoded so the
if (!RequestLogMiddleware.IsXml(ContentType)) { return null; }
will never be entered since IsXml(ContentType) will always be true.
This would seem like a good candidate to fix, but not really sure how.
Would it be possible to get the final output contenttype and provide that to the loggingwebdavresponse?
We could check the type of result (in the WebDavIndirectResult.ExecuteResult) and omit the entire loggingwebdavresponse? if ((_logger?.IsEnabled(LogLevel.Debug) ?? false) && !(_result is WebDavFullDocumentResponse)). Would introduce some coupling and need a project reference.
In LoggingWebDavResponse, don't load XDocument for http GET, unsure about this one. Might return file data as well as xml in webdav. Not familiar enough with the standard or the lib.
Provide the loggingsresponse's buffered output to the WebDavFullDocumentResult,