The Problem

In .NET 4.x it was straightforward to read the request body of an incoming HTTP request, log the information and also log the outgoing response back to the caller. I thought it would be just as easy in .Net Core, how wrong a I was as Microsoft do their utmost to hide the Request body from you.

The Solution

Accessing the Request and Response bodies must be done in HTTP Middleware, and, after reading much on StackOverflow I came up with the following solution (and my thanks to all the original authors and people who helped me). I cannot take credit for this code, I just adapted it from ideas on StackOverflow

Remember 

For .Net Core 2.1  use  context.HttpContext.Request.EnableRewind();
For .Net Core 3.1  context.HttpContext.Request.EnableBuffering();

/// <summary>
/// Want to be able to read the Request.Body to get the incoming JSON
/// In .net 4 this was more or less simple. In Core it has changed
/// Need to be able to "rewind" of Request.Body - have to do that
/// Thanks to
/// https://stackoverflow.com/questions/40494913/how-to-read-request-body-in-a-asp-net-core-webapi-controller
/// in request pipeline middleware
/// 
/// For ASP.NET 2.1
/// context.HttpContext.Request.EnableRewind();
/// For ASP.NET 3.1
/// context.HttpContext.Request.EnableBuffering();
///
/// See also https://stackoverflow.com/questions/43403941/how-to-read-asp-net-core-response-body/43404745
/// </summary>
public class LogRequestResponseMiddleware
{
private readonly RequestDelegate _next;
private readonly ILogger _logger;

private readonly RecyclableMemoryStreamManager _recyclableMemoryStreamManager;
private const int ReadChunkBufferLength = 4096;

private bool LogRequest;
private bool logResponse;

public LogRequestResponseMiddleware(RequestDelegate next, ILoggerFactory loggerFactory, bool requestLogging, bool responseLogging)
{
//--------------------------------------------------------------------
// Config |
//--------------------------------------------------------------------

this.LogRequest = requestLogging;
this.logResponse = responseLogging;

_next = next;
_logger = loggerFactory.CreateLogger<LogRequestResponseMiddleware>();

//--------------------------------------------------------------------
// Create stream to use in place of HttpContext.Response.Body stream |
// which is write-only |
//--------------------------------------------------------------------

_recyclableMemoryStreamManager = new RecyclableMemoryStreamManager();
}


public virtual async Task Invoke(HttpContext context)
{
//-----------------------------------------------------
// Request |
//-----------------------------------------------------

if (this.LogRequest)
{
//-------------------------------------------------
// Turn on Buffering/Rewind |
//-------------------------------------------------
context.Request.EnableBuffering();

//-----------------------------------------------------
// Log Request |
//-----------------------------------------------------
await this.LogRequestAsync(context);
}


//-----------------------------------------------------
// Response |
//-----------------------------------------------------
if (this.logResponse)
{
//-----------------------------------------------------
// Log Response |
//-----------------------------------------------------
await this.LogResponseAsync(context);
}
else
{
//-----------------------------------------------------
// Fire next in chain |
//-----------------------------------------------------
await _next.Invoke(context);
}

}


/// <summary>
/// Log the incoming request
/// </summary>
/// <param name="context"></param>
/// <returns></returns>
private async Task LogRequestAsync(HttpContext context)
{
using (var requestStream = _recyclableMemoryStreamManager.GetStream())
{
var origPosition = context.Request.Body.Position;
context.Request.Body.Position = 0;
await context.Request.Body.CopyToAsync(requestStream);
context.Request.Body.Position = origPosition;

_logger.LogInformation($"Http Request Information:{Environment.NewLine}" +
$"Schema:{context.Request.Scheme} " +
$"Host: {context.Request.Host} " +
$"Path: {context.Request.Path} " +
$"QueryString: {context.Request.QueryString} " +
$"Request Body: {ReadStreamInChunks(requestStream)}");
}
}


private async Task LogResponseAsync(HttpContext context)
{
//--------------------------------------------------------
// Keep reference to original body |
//--------------------------------------------------------
var originalBody = context.Response.Body;

using (var responseStream = _recyclableMemoryStreamManager.GetStream())
{
//-----------------------------------------------------
// Replace existing with read/write stream |
//-----------------------------------------------------
context.Response.Body = responseStream;

//-----------------------------------------------------
// Fire next in chain |
//-----------------------------------------------------
await _next.Invoke(context);

//-----------------------------------------------------
// Get Result Back |
//-----------------------------------------------------
string resp = ReadStreamInChunks(responseStream);

//------------------------------------------------------
// Write it back to original Response Body |
//------------------------------------------------------

byte[] response = Encoding.ASCII.GetBytes(resp);
await originalBody.WriteAsync(response, 0, response.Length);

//------------------------------------------------------
// Log It |
//------------------------------------------------------

_logger.LogInformation($"Http Response Information:{Environment.NewLine}" +
$"Schema:{context.Request.Scheme} " +
$"Host: {context.Request.Host} " +
$"Path: {context.Request.Path} " +
$"QueryString: {context.Request.QueryString} " +
$"Response Body: {resp}");
}

//-----------------------------------------------------------
// Restore |
//-----------------------------------------------------------
context.Response.Body = originalBody;
}


private static string ReadStreamInChunks(Stream stream)
{
stream.Seek(0, SeekOrigin.Begin);
string result;
using (var textWriter = new StringWriter())
using (var reader = new StreamReader(stream))
{
var readChunk = new char[ReadChunkBufferLength];
int readChunkLength;
//do while: is useful for the last iteration in case readChunkLength < chunkLength
do
{
readChunkLength = reader.ReadBlock(readChunk, 0, ReadChunkBufferLength);
textWriter.Write(readChunk, 0, readChunkLength);
} while (readChunkLength > 0);

result = textWriter.ToString();
}

return result;
}

}

The Problem

I recently updated my Windows 10 desktop to the latest “improved” version of Windows 10. I rarely install Windows updates due to my mantra of “if it ain’t broke don’t fix it”, however, I ignored my mantra and opened up a plethora of problems.

One of the big problems is that I run (ran) VMWare Workstation – and version 7 to be specific. This is an old version but my VMs work, I purchased the copy so why upgrade? After the Windows 10 updates VMWare workstation would not run:

VMware Workstation Pro can't run on Windows

It would appear that one (or more) of the Windows updates was prevening VMWare from running.

The Solution

I googled and found many articles recommending uninstalling verious Windows updates – this seems dangerous and can leave you machine unuseable (the voice of experience). I then found this article. Scroll down to

There is no need to replace the entire sysmain.sdb (this action could expose your machine to unpredicatble problems).

You can simply run the Compatibility Administrator Toolkit (https://docs.microsoft.com/it-it/windows-hardware/get-started/adk-install), and disable the entry under the “System Database/Applications/VMware Workstation Pro” path. That’s all.

Here it explains about installing the Compatability Administrator Toolkit (downloadable from Microsoft). Then run the “Compatability Administrator” (this will have been installed as part of the toolkit) by click taskbar search, type “Compatability Administrator”. Within the tool search for “VMWare Workstation” under System Databases-> Application

Right click vmware.exe and click “Disable Entry”. Repeat for VMWare Workstation Pro.

VMWare Workstation should then run

Thanks MicroSoft.

The Problem

I was attempting to follow the Docker “Getting Started” documentation and tried to run the “Hello World” Example and I got

C:\>docker run hello-world
Unable to find image 'hello-world:latest' locally
latest: Pulling from library/hello-world
docker: no matching manifest for windows/amd64 10.0.16299 in the manifest list entries.
See 'docker run --help'.

What does this mean ?

After much head-scratching and searching (mostly unhelpful posts about using Linux containers or “experimental mode”) I came across this article about docker manifests. It did not make much sense but after some more head-scratching I worked out what the error message meant.

I ran

C:\>docker manifest inspect hello-world:latest

And got (not all the file is listed):

{
"schemaVersion": 2,
"mediaType": "application/vnd.docker.distribution.manifest.list.v2+json",
"manifests": [
{
"mediaType": "application/vnd.docker.distribution.manifest.v2+json",
"size": 524,
"digest": "sha256:92c7f9c92844bbbb5d0a101b22f7c2a7949e40f8ea90c8b3bc396879d95e899a",
"platform": {
"architecture": "amd64",
"os": "linux"
}
},

..... text chopped out for this post....

{
"mediaType": "application/vnd.docker.distribution.manifest.v2+json",
"size": 1357,
"digest": "sha256:f9fea6a66184b4907c157323de7978942eab1815be146c93a578b01a3a43ad6d",
"platform": {
"architecture": "amd64",
"os": "windows",
"os.version": "10.0.17134.1006"
}
},
{
"mediaType": "application/vnd.docker.distribution.manifest.v2+json",
"size": 1046,
"digest": "sha256:2bff08b2d77710d0a0a1608b35ea4dfdc28f698f6da86991c3da755968fa56d6",
"platform": {
"architecture": "amd64",
"os": "windows",
"os.version": "10.0.17763.737"
}
}
]
}

The Answer

All the error means is that the docker image repository (the place on the internet where the docker hello world image is stored) does not have a version built for your version of windows. i.e. it has one for Windows 10.0.17134.1006 and Windows 10.0.17763.737 but not for my version of windows: Windows 10.0.16299

How hard would an error message to that effect be?

The problem

NHibernate maintains internal state of the entities that it has loaded from the database. When saving an entity back to the DB you may want some properties (columns) included in the UPDATE SQL generated although the property value hasn’t changed. Why ? Because the update on a particular column might force a database trigger to run.

Or, to put it another way:

Database triggers are not really compatible with Object Relationship Mappers

In my naievety I had assumed that NHibernate would contain a “simple” option to turn on “please generate all columns in UPDATE SQL”, but, alas, no.

The Solution

I consulted StackOverflow – many posts, all leading nowhere. Then I stumbled across one post which spoke of NHibernate IInterceptors. I then consulted the NHibernate documentation – to say the documentation on interceptors is brief and concise does not do it justice.

After much messing about I worked out how interceptors work and got a working implementation so that my UPDATE SQL now includes all the columns that I require.

To make an interceptor work you need

• Interceptor code (which implements FindDirty method)
• Plug interceptor into NHibernate Session Create

Interceptor

The “documentation” recommends deriving your interceptor from the NHibernate EmptyInterceptor. The FindDirty method must be overriden in your interceptor, it returns an array [] of ints, the value represent the index of the propertyNames parameter of the FindDirty method – which is a list of the properties of the entity being saved. In my case I returned all items – so that all UPDATE SQL columns were included

Plug Into NHibernate

In your code (in my case, UnitofWork/Repo pattern code) you need to pass the interceptor as a parameter to the SessionFactory.OpenSession() method – this registers the interceptor with NHibernate and it will be called for all Saves

Code Example

Interceptor

public class MyInterceptor : EmptyInterceptor
{
	/// <summary>
	/// Interceptor method
	/// Return array of indices into propertyNames of columns that will be maked
	/// as dirty i.e. SQL will be generated from them
	/// </summary>
	/// <param name="entity"></param>
	/// <param name="id"></param>
	/// <param name="currentState"></param>
	/// <param name="previousState"></param>
	/// <param name="propertyNames"></param>
	/// <param name="types"></param>
	/// <returns></returns>
	public override int[] FindDirty(object entity, object id, object[] currentState,
	object[] previousState, string[] propertyNames, IType[] types)
	{
		List<int> dirty = new List<int>();

		//---------------------------------------------
		// Mark as dirty for all except for ....      |
		//---------------------------------------------
		for (int i = 0; i < propertyNames.Length; i++)
		{
			if (propertyNames[i] != "ColumnIDontwantInSql" && propertyNames[i] != "AnotherColumnIDontwantInSql")
			{
				dirty.Add(i);
			}
		}
		return dirty.ToArray();
	}
}

Wiring Up

CODE SNIPPET FROM UNIT OF WORK



 public UnitOfWork(INHibernateContext context, ISaveInterceptor interceptor)
 {
     this.context = context;
     this.Interceptor = interceptor;

     // See here for why dummy session
     ISession dummy = context.SessionFactory.OpenSession(this.Interceptor);
     this.Session = context.SessionFactory.OpenSession(dummy.Connection, this.Interceptor);
 }

The Problem

Using Hibernate on a (.Net/C#) project and came to delete a record from a “collection” and this threw an error

the given key was not present in the dictionary

After much head scratching it was determined that the problem was down to a subtle interaction between NHibernate and a DataBase C# entity class.The class overrode the GetHashCod() method

public override int GetHashCode()

{
   ...
}

Originally the underlying database table has a composite key utilising two integer columns, the GetHashCode() method used both of these columns to generate the (unique) hash code. A database modification moved from a composite key to a single key, however, the GetHashCode() method was not updated.

Everything worked fine for read but Delete threw an exception. So what was going on?

Upon investigation it was found that, as part of NHibernate initialisation or lazy-loading, when reading the data the primary key column was populated but the defunct key column was zero, but the GetHashCode() method was called. Later on in the lifecycle all the properties of the Db class were populated and this meant a different hash code was generated (as the defunct column’s value was populated and the GetHashCode() method used this value as well as the primary key value – see earlier). So it looks like that, initially, items were read by NHibernate and added to it’s internal “collection” with hash-codes from partially loaded data, whereas the delete was being made for an item with a hash-code generated from fully populated data – and NHibernate could not find that item in the collection. It looked like NHibernate was using the hash-code to identify individual items.

The solution

Generate a hash-code (GetHashCode() method) using only the primary key.