Request / Response Logging

An extension of the Start / Stop Logging is the Request / Response Logging. In this case, instead of merely logging the fact that the service call was started, and then completed, we log the request that starts the service call, and the response that will be returned.

namespace FunctionalLayer.Objects { public class Request { public string RequestId { get; set; } public string Account { get; set; } public string ProductCode { get; set; } public int Quantity { get; set; } } public class Response { public ResultCode Result { get; set; } public int Quantity { get; set; } // actual amount ordered public decimal Cost { get; set; } public string ErrorMessage { get; set; } // only has a value if there is an error } public class ServiceOne { ... public virtual Response CallA(Request request) { ... return response; } protected virtual void Log(LogLevel level, string logMessage) {} } } namespace LoggingLayer.Objects { public class ServiceOne : FunctionalLayer.Objects.ServiceOne { private ILogger _logger; ... public override Response CallA(Request request) { Log(LogLevel.Info, string.Format("CallA=Request RequestId={0} Account={1} ProductCode={2} Quantity={3}", request.RequestId, request.Account, request.ProductCode, request.Quantity)); var response = base.CallA(request); string message = response.ErrorMessage != null && response.ErrorMessage.Length > 0 ? string.Format(" ErrorMessage=\"{0}\", response.Message) : string.Empty; Log(LogLevel.Info, string.Format( "CallA=Response RequestId={0} Account={1} Result={2} Quantity={3} Cost={4}{5}", request.RequestId, request.Account, response.Result, response.Quantity, response.Cost, message)); return response; } protected override void Log(LogLevel level, string logMessage) { _logger.WriteLine(level, logMessage); } } }

The logging from this example provides us with a lot of information that can be easily searched and analyzed.

CallA=Request|Response lets us clearly determine which service call generated the logged line, as well as if it was the request line or the response line.

RequestID allows us to easily associate a specific request line with a specific response.

Account lets us know the specific account that made the service call.

ProductCode tells us what product the customer was interested in.

Quantity tells us how much the customer ordered, or received.

Result indicates if the call was successful or not.

Cost tells us how much the order cost.

ErrorMessage tells us what the error was, if one occurred. Note that the expected result in this example is that there will be no error message, so the ErrorMessage will not display anything if there is not one.

What can we get from this info? A lot!

  • We can easily find all orders placed by a specific account.
  • If an ErrorMessage shows up, we can search for that error, and get a list of every account that was impacted by that error.
  • We can search for requests for a specific type of product, and thus have a list of every account that requested that product.
  • We can search for every request whose response was in a certain price range (via cost).

If the logging search interface allows us to associate multiple log lines, then we can make even more complicated searches, by using the RequestID to associate the request line with the response line:

  • List all customers who ordered a specific product and whose cost was over a certain amount.
  • List all customers who ordered more than 100 units, and got an error back as a result.

We can further extend the use of the RequestID by making sure that any external service that is called is passed the same RequestID. That way, any logging generated by the sub-calls has the same RequestID, and thus we can easily determine that the logging generated by the two services are related.

Next: Metrics

Copyright © 2017-2018 Adin H. Baber, all rights reserved.