messaging logs

Messaging Logs

This topic discusses the logs that are written when messages are dispatched. Since plugins such as the following:

• NetFusion.Integration.ServiceBus
• NetFusion.Integration.RabbitMQ
• NetFusion.Integration.Redis

all extend the base messaging pipeline, all of the log topics discussed in this section also apply when messages are published out of process.

This topic will create a command when processed, will publish a domain event allowing multiple related message logs to be viewed.

Define Messages

Start by creating the following command:

using System;
using NetFusion.Messaging.Types;

namespace Examples.Messaging.Domain.Commands;

public class AddTaskItemCommand : Command<string>
{
    public string Name { get; }
    public string Description { get; }
    public DateTime DateDue { get; }
    public bool IsBlocked { get; }
    
    public AddTaskItemCommand(string name, string description, DateTime dateDue, bool isBlocked)
    {
        Name = name;
        Description = description;
        DateDue = dateDue;
        IsBlocked = isBlocked;
    }
}

Then create the following domain-event:

using System;
using NetFusion.Messaging.Types;

namespace Examples.Messaging.Domain.Events;

public class ImportantTaskCreated : DomainEvent
{
    public string TaskId { get; }
    public string TaskName { get; }
    public DateTime DateDue { get; }
    public int NumberDaysTillDue { get; }
    
    public ImportantTaskCreated(string taskId, string taskName, DateTime dateDue, int numberDaysTillDue)
    {
        TaskId = taskId;
        TaskName = taskName;
        DateDue = dateDue;
        NumberDaysTillDue = numberDaysTillDue;
    }
}

Define Message Consumers

Add the following message consumer to process the command:

using System;
using System.Threading.Tasks;
using Examples.Messaging.Domain.Commands;
using Examples.Messaging.Domain.Events;
using NetFusion.Messaging;

namespace Examples.Messaging.App.Handlers;

public class TaskItemHandler
{
    private readonly IMessagingService _messaging;

    public TaskItemHandler(IMessagingService messaging)
    {
        _messaging = messaging;
    }
    
    public async Task<string> CreateTask(AddTaskItemCommand command)
    {
        var taskId = Guid.NewGuid().ToString();

        var domainEvt = new ImportantTaskCreated(taskId, command.Name, command.DateDue,
            command.DateDue.Subtract(DateTime.Now).Days);

        await _messaging.PublishAsync(domainEvt);

        return taskId;
    }
}

Then add the following message consumer to process the domain-event:

using System;
using Examples.Messaging.Domain.Events;
using NetFusion.Common.Extensions;

namespace Examples.Messaging.App.Handlers;

public class TaskReminderHandler
{
    public void OnSendReminder(ImportantTaskCreated domainEvent)
    {
        if (domainEvent.NumberDaysTillDue < 0)
        { 
            throw new InvalidOperationException("Invalid number of days.");
        }
        
        Console.WriteLine(domainEvent.ToIndentedJson());
    }
}

With the messages and consumers defined, route the command an domain-event by adding the following lines to the InMemoryRouter class:

OnCommand<AddTaskItemCommand, string>(route => route.ToConsumer<TaskItemHandler>(c => c.CreateTask));
OnDomainEvent<ImportantTaskCreated>(route => route.ToConsumer<TaskReminderHandler>(c => c.OnSendReminder));

Create API Controller

Define an API controller that will create and send a command using the posted data. Create the following API model:

using System.ComponentModel.DataAnnotations;

namespace Examples.Messaging.WebApi.Models;

public class TaskItemModel
{
    [Required] public string Name { get; set; } = string.Empty;
    [Required] public string Description { get; set; } = string.Empty;
    public DateTime DateDue { get; set; }
    public bool IsBlocked { get; set; }
}

Then define the following controller method:

[HttpPost("add/task")]
public async Task<IActionResult> AddTaskItem([FromBody]TaskItemModel model)
{
    if (!ModelState.IsValid)
    {
        return BadRequest(ModelState);
    }

    var command = new AddTaskItemCommand(model.Name, model.Description, 
        model.DateDue, 
        model.IsBlocked);

    var result = await _messaging.SendAsync(command);
    return Ok(result);
}

With the above messages and consumers in place, different message related logs can be discussed.

Message Logs

There are two types of message logs that are written. When a microservice bootstraps, the configured messages and consumers are logged at the information log level. This provides a central location for all supported messages and their corresponding consumers supported by the microservice. Once a message instances are dispatched, the contents of the messages are logged if the current log level is debug.

Bootstrap Message Logs

The following shows the logs in SEQ added to the compose-application log when the messaging plugin is bootstrapped:

Expand the log entry named "CorePlugin NetFusion:Messaging" then expand the "module" property and find the log for the "MessageDispatchModule" module. Each message type's associated consumer(s) and method handlers are listed as shown below:

Dispatch Message Logs

Next, dispatch the command defined above by making a POST to the following URL:

http://localhost:5670/api/messaging/add/task

{
    "name": "Add new service method",
    "description": "Add new service method to delete task if not completed.",
    "dateDue": "2023-05-10",
    "isBlocked": false 
}

When a message is dispatched, the messaging plugin logs the contents of the message when logging is configured at the debug log level. After making the request, view the SEQ log to see the following associated log entries:

The first set of log entires are from dispatching AddTaskItemCommand and show the following:

• The second log entry from the bottom shows that the command was published.
• Next, a log is written showing that the command is being dispatched to it consumer.
• The fifth log entry from the bottom shows the domain-event that was published from the command handler.
• Then the next entry shows the domain-event being dispatched to is consumer.
• The last log message then shows the log entry containing the result of the command.

Each of the above log entries can be expanded to view more details. Expanding the log entries listed in the order above shows the following:

The above shows the details of the command and it associated attributes.

The details property shows the consumer's message handler to which the command was routed.

The above shows the details of the published domain-event.

Shown above is the consumer and handler method to which the domain-event was delivered.

The above log shows the result of the command that was published. In this case, the result was just a string containing a GUID value.

Dispatch Message Exception Logs

This section will show the information logged when a message consumer's handler method throws an exception. In this given example, the handler for the domain-event will throw an exception if a DueDate in the past is specified.

{
    "name": "Add new service method",
    "description": "Add new service method to delete task if not completed.",
    "dateDue": "2023-02-10",
    "isBlocked": false 
}

When the above message is posed, the SEQ log will look as follows:

Expanding the fourth entry from the top will show information about the failed domain-event which was the source of the exception. The below shows the exception within SEQ:

Since the above wraps, the following shows the details property using another JSON viewer found here: https://jsonviewer.stack.hu Clicking on the details node has an option to copy the JSON:

The following shows the JSON viewed using the viewer making it easier to navigate:

When an exception occurs, the original exception is augmented with additional details. For example, in the above log, the dispatch details of the consumer and message handler where the exception occurred are included. The red arrows indicates that the error originated from the in-process message publisher. If this exception happened when sending a message to either RabbitMQ or Azure Service Bus, the corresponding publisher would be logged. Above, the blue arrow shows the details of the consumer to which the message was dispatched. If this was an exception dispatching to RabbitMQ or Azure Service Bus, the details of the queue or topic would be shown. When a microservice subscribes to a queue or topic and the associated consumer throws an exception, details similar to the above would be shown.

Since the domain-event was published when processing the AddTaskItemCommand, the following shows the details of the third log entry from the top corresponding to the sent command:

Above the log with the blue arrow shows that an exception was raised when the command of type AddTaskItemCommand was dispatched to the TaskItemHandler consumer's CreateTask method.

Correlated Log Messages

When multiple microserivces send logs to a central log store such as SEQ, it is important to be able to filter message log entries for a specified messaged and/or microservice.

The above shows a filter baed on CorrelationId and Microservice. The CorrelationId will limit all log entries to just those messages associated with the same CorrelationId. If this message was published using either RabbitMQ or Azure Service Bus, then the logs of the published and subscribing microservice would both be included. To limit the logs to either the publishing or subscribing microservice, the name or id of the microservice can be specified as above.