Understanding your application through logs and log analysis: Technical details – Part 2

Adrian Simionescu | 07.05.2020
Reading time 8 min

In this post, we will look at some examples of what a log entry will look like and what kind of tools you might need.

Monitoring

The first thing I would recommend is to have an understating where your logs will end up and how you are going to analyze them.

The simplest form would be a log file where you would push your log entries and then using a common text editor or development editor to look at the entries. This works fine if your application is very small or you are dealing with a script. The log entries amount will likely be small, and they won’t be stored for a long period of time.

But, if you know your application or system will produce thousands, hundreds of thousands or even millions of log entries each day and you need to store them for a longer period of time then you need a good monitoring tool that than read log entries robustly. You also need a good place to store your log entries.

What you would need normally is:

  • Receive and process a log entry, then transform it and send it to a data store
  • Index the data from the datastore
  • Search and analyze your indexed log entries

A good tool for this would be Azure Monitor which will greatly integrate with many Azure Services and Microsoft technologies to automatically gather details on your system and applications.

Common log types

There are several different log types that you need to consider but it all depends on your application and scope. I will describe here only a few of them:

  • A general log entry
  • Access log
  • Message/Event queue log
  • Metrics Log
  • Security Log

Baseline log details

Before you start logging anything, I would recommend having a baseline of what a log entry has to have to be valuable to you and your organization:

Field Sample Description
requestId/correlationId 6f88dcd0-f628-44f1-850e-962a4ba086e3 This is a value that should represent a request to your API. This request-id should be applied to all log entries to be able to group all log entries from a request. Should be unique.
userId 9ff4016d-d4e6-429f-bca8-6503b9d629e1 Same as with the request-id but a user id that represents a possible user that made the API request. Should be unique.
environmentId DEV, TEST, PROD This should tell a person looking at a log entry from which environment the log entry came for. This is important in cases where all log entries are pushed into one location and not separated physically.
appName Your Cool API Same as with the environment id but concerns the app name.
appVersion 2.1.7 Same as with the environment id but concerns the app version.
createdAt 02/08/2019 12:37:59 This should represent when the log entry has been created. This will help very much in tracking the progress of the application logic in all environments in case of troubleshooting. Preferably in UTC time.

As you can see with these baseline details, we get a pretty good view of where things are happening, who is doing things and when. I can’t stress enough how important these details are!

General log entry

This is the baseline log entry with an added message field and perhaps a title field. That’s it.

This is what you would need at a bare minimum to find out what is going on.

Access Log

Access logs are a great way to keep track of your API requests and their response to a client. It’s a way to the server to keep records of all requests processed by the server. I won’t go deeper into them, there are plenty of detail descriptions available which I recommend going through, here are a few:

Apache.org, Access Log

Wikipedia.org, Server Log

Here is an example:

Field Sample Description
clientIP 127.0.0.1 The IP address of the client that made the request to you API.
userId aa10318a-a9b7-4452-9616-0856a206da75 Preferably this should be the same user id that was used in the LogData class above
timestamp 02/08/2019 12:37:59 A date/time format of your choice when the request occurred.
method GET, POST, PUT, etc. HTTP Method of the request.
requestURL https://localhost:9000/api/customer/info The URL of the request.
protocol HTTP/1.1 The protocol used to communicate with the API request.
statusCode 200, 201, 401, 500 etc. HTTP status code of the request-response.
payloadSize 2345 The size of the payload returned to the client.
borwserAgent Mozilla/4.08 [en] (Win98; I ;Nav) “The User-Agent request header contains a characteristic string that allows the network protocol peers to identify the application type, operating system, software vendor or software version of the requesting software user agent.” – https://developer.mozilla.org/en-US/docs/Web/HTTP/Headers/User-Agent
requestId This should is the same request-Id used in the LogData class earlier.

Message queue/event log

This is related to the decoupling pattern between two or more entities. You push a message to a storage location and someone or something reads and processes it. This is a simplified description of course.

This is a bit of complex thing to go into but the main focus here is that depending on what kind of message queue or event queue technology and applications you use, you might not get a very detailed view on who, when and what happened.

An example: You have an API that a client application invokes, this request has to do an asynchronous save to a CRM, you have to make sure that this is completed and re-tried if things go bad. This is fine but what if things go bad and even after several attempts nothing has happened. A common practice is that the message is going to go to a dead letter queue, for troubleshooting and future processing.

Now to be able to find out what the problem was you need detailed information and by default messages in queues have little details. So I would recommend adding additional data to the message in a queue so that when the receiving end gets it you can log and associate that message to our previous API request. Then later when using analysis tools you can get a history of the events that have happened, for example using the requestId/correlationId.

Here is an example, what you could have:

Field Sample Description
sourceHostname Look at the LogData example earlier.
sourceAppName Look at the LogData example earlier.
sourceAppVersion Look at the LogData example earlier.
sourceEnvironmentId Look at the LogData example earlier.
sourceRequestId Look at the LogData example earlier.
sourceUserId Look at the LogData example earlier.
message JSON data JSON data representing a serialized object that hold important data to be used the the receiving end.
messageType UPDATE_USER, DELETE_USER A simple unique static ID for the message. This ID will tell the receiving end what it needs to do with the data in the message field.
createdAt 02/08/2019 12:37:59 This should represent when the message queue entry was created. Preferable in UTC time.

Metrics log

With metrics logs the idea is to be able to track desired performance and successes in your application. A common thing that you might like to track would be how external request from your own code is performing. This will allow you set up alerts and troubleshoot problem with external sources, especially if you combine an access log with a metrics log of how long you request totally took to finish.

But depending on what kind of tools you use, you might get automatic metrics for your application; like CPU usage, memory usage, data usage, etc. Here I will focus on metrics logs you would produce manually from your application.

So you could track the following metrics:

  • External sources like database, API, service, etc.
  • You request total processing time from start to end to return a response
  • Some important section of your code
Field Sample Description
title User Database A title of your desire for the message.
body Update user The main message goes here.
additional Some additional data Additional data related to the metric
url http://localhost:9200/api/car/types If this is a API request to an external service you should log the request URL.
statusCode 200, 401, 500 etc. The HTTP status code returned by the external source or some other code that you wish to use.
payloadSize 234567 The size of the returned data.
receivedResponseAtMillis 1575364455 When the response was received, this could be in UNIX epoch time.
sentRequestAtMillis 1575363455 When the request was received, this could be in UNIX epoch time.
logType API, DATABASE, CODE, etc. This could be used to identify what kind of metric this is.
elapsedTimeInSeconds 1 Calculate and write how long it took for the response to be received.
elapsedTimeInMS 1000 Calculate and write how long it took for the response to be received.
category Category1/2/3 etc. This could be used to group different metrics together.

Security Log

A security log provides tools to establish an audit trail. It allows you to record, track and investigate security related operations that happen in your system. This is a hard thing to do it right since you must have enough information to troubleshoot but keep secrets and sensitive information hidden.

Start by using default features of the technology you are using like Azure AD and Azure Monitor combined and then go into manually logging security logs to complement them which you would do normally from your application.

For each recorded event, the record in the security log includes at least the following:

  • Date and time of the event.
  • User identification including associated terminal, port, network address, or communication device
  • Type of event.
  • Names of resources accessed.
  • Success or failure of the event.