Logging

Silverback logs quite a few events that may be very useful for troubleshooting. It is recommended to set the minum log level to Information for the Silverback namespace, in order to have the important logs while avoiding too much noise.

Customizing log levels

The WithLogLevels configuration method can be used to tweak the log levels of each event.

public class Startup
{
    public void ConfigureServices(IServiceCollection services)
    {
        services
            .AddSilverback()
            .WithLogLevels(configurator => configurator
                .SetLogLevel(IntegrationLogEvents.MessageSkipped, LogLevel.Critical)
                .SetLogLevel(IntegrationLogEvents.ErrorProcessingInboundMessage, LogLevel.Error));
    }
}

Each package (that writes any log) has a static class declaring each log event (see next chapter).

Logged events

Here is a list of all events that are being logged and their default log level.

See also:

Core

Id Level Message Reference
11 Debug Discarding result of type {type} because it doesn't match the expected return type {expectedType}. SubscriberResultDiscarded
21 Information Trying to acquire lock {lockName} ({lockUniqueId})... AcquiringDistributedLock
22 Information Acquired lock {lockName} ({lockUniqueId}). DistributedLockAcquired
23 Debug Failed to acquire lock {lockName} ({lockUniqueId}). FailedToAcquireDistributedLock
24 Information Released lock {lockName} ({lockUniqueId}). DistributedLockReleased
25 Warning Failed to release lock {lockName} ({lockUniqueId}). FailedToReleaseDistributedLock
26 Error Failed to check lock {lockName} ({lockUniqueId}). FailedToCheckDistributedLock
27 Error Failed to send heartbeat for lock {lockName} ({lockUniqueId}). FailedToSendDistributedLockHeartbeat
41 Information Starting background service {backgroundService}... BackgroundServiceStarting
42 Information Lock acquired, executing background service {backgroundService}. BackgroundServiceLockAcquired
43 Error Background service {backgroundService} execution failed. BackgroundServiceException
51 Information Background service {backgroundService} stopped. RecurringBackgroundServiceStopped
52 Debug Background service {backgroundService} sleeping for {delay} milliseconds. RecurringBackgroundServiceSleeping
53 Warning Background service {backgroundService} execution failed. RecurringBackgroundServiceException

Integration

Id Level Message Reference
1001 Information Processing inbound message. ProcessingInboundMessage
1002 Error Error occurred processing the inbound message. ErrorProcessingInboundMessage
1003 Debug Message '{messageId}' added to {sequenceType} '{sequenceId}'. | length: {sequenceLength} MessageAddedToSequence
1004 Debug Started new {sequenceType} '{sequenceId}'. SequenceStarted
1005 Debug {sequenceType} '{sequenceId}' completed. | length: {sequenceLength} SequenceCompleted
1006 Debug The {sequenceType} '{sequenceId}' processing has been aborted. | length: {sequenceLength}, reason: {reason} SequenceProcessingAborted
1007 Error Error occurred processing the {sequenceType} '{sequenceId}'. | length: {sequenceLength} ErrorProcessingInboundSequence
1008 Warning The incomplete {sequenceType} '{sequenceId}' is aborted. | length: {sequenceLength} IncompleteSequenceAborted
1009 Warning Skipping the incomplete sequence '{sequenceId}'. The first message is missing. SkippingIncompleteSequence
1110 Warning Error occurred aborting the {sequenceType} '{sequenceId}'. ErrorAbortingInboundSequence
1011 Debug {broker} connecting to message broker... BrokerConnecting
1012 Information {broker} connected to message broker. BrokerConnected
1013 Debug {broker} disconnecting from message broker... BrokerDisconnecting
1014 Information {broker} disconnected from message broker. BrokerDisconnected
1015 Information Creating new consumer for endpoint '{endpointName}'. CreatingNewConsumer
1016 Information Creating new producer for endpoint '{endpointName}'. CreatingNewProducer
1017 Error Error occurred connecting to the message broker(s). BrokerConnectionError
1021 Debug Connected consumer to endpoint. ConsumerConnected
1022 Debug Disconnected consumer from endpoint. ConsumerDisconnected
1023 Critical Fatal error occurred processing the consumed message. The consumer will be stopped. ConsumerFatalError
1024 Warning Error occurred while disposing the consumer. ConsumerDisposingError
1025 Error Commit failed. ConsumerCommitError
1026 Error Rollback failed. ConsumerRollbackError
1127 Error Error occurred while connecting the consumer. ConsumerConnectError
1128 Error Error occurred while disconnecting the consumer. ConsumerDisconnectError
1129 Error Error occurred while (re)starting the consumer. ConsumerStartError
1130 Error Error occurred while stopping the consumer. ConsumerStopError
1131 Warning Failed to reconnect the consumer. Will retry in {retryDelay} milliseconds. ErrorReconnectingConsumer
1027 Debug Connected producer to endpoint. ProducerConnected
1028 Debug Disconnected producer from endpoint. ProducerDisconnected
1031 Information Message produced. MessageProduced
1032 Warning Error occurred producing the message. ErrorProducingMessage
1041 Trace The {policyType} will be skipped because the current failed attempts ({failedAttempts}) exceeds the configured maximum attempts ({maxFailedAttempts}). PolicyMaxFailedAttemptsExceeded
1042 Trace The {policyType} will be skipped because the {exceptionType} is not in the list of handled exceptions. PolicyExceptionNotIncluded
1043 Trace The {policyType} will be skipped because the {exceptionType} is in the list of excluded exceptions. PolicyExceptionExcluded
1044 Trace The {policyType} will be skipped because the apply rule evaluated to false. PolicyApplyRuleReturnedFalse
1045 Trace All policies have been applied but the message(s) couldn't be successfully processed. The consumer will be stopped. PolicyChainCompleted
1046 Information The message(s) will be processed again. RetryMessageProcessing
1047 Trace Waiting {delay} milliseconds before retrying to process the message(s). RetryDelayed
1048 Information The message will be moved to the endpoint '{targetEndpointName}'. MessageMoved
1049 Information The message(s) will be skipped. MessageSkipped
1050 Warning The message belongs to a {sequenceType} and cannot be moved. CannotMoveSequences
1051 Warning Error occurred while rolling back, the retry error policy cannot be applied. The consumer will be reconnected. RollbackToRetryFailed
1052 Warning Error occurred while rolling back or committing, the skip message error policy cannot be applied. The consumer will be reconnected. RollbackToSkipFailed
1061 Warning Not used anymore. ErrorInitializingActivity
1062 Information The null message will be skipped. NullMessageSkipped
1072 Information Message is being skipped since it was already processed. MessageAlreadyProcessed
1073 Debug Writing the outbound message to the transactional outbox. MessageWrittenToOutbox
1074 Trace Reading a batch of {readBatchSize} messages from the outbox queue... ReadingMessagesFromOutbox
1075 Trace The outbox is empty. OutboxEmpty
1076 Debug Processing outbox message {currentMessageIndex} of {totalMessages}. ProcessingOutboxStoredMessage
1077 Error Failed to produce the message stored in the outbox. ErrorProducingOutboxStoredMessage
1078 Error Error occurred processing the outbox. ErrorProcessingOutbox
1079 Warning An invalid message has been produced. | validation errors:{validationErrors} InvalidMessageProduced
1080 Warning An invalid message has been processed. | validation errors:{validationErrors} InvalidMessageProcessed
1101 Critical Invalid configuration for endpoint '{endpointName}'. InvalidEndpointConfiguration
1102 Critical Error occurred configuring the endpoints. | configurator: {endpointsConfiguratorName} EndpointConfiguratorError
1103 Error Error occurred invoking the callback handler(s). CallbackHandlerError
1999 Trace The actual message will vary. LowLevelTracing

Kafka

Id Level Message Reference
2011 Debug Consuming message: {topic}[{partition}]@{offset}. ConsumingMessage
2012 Information Partition EOF reached: {topic}[{partition}]@{offset}. EndOfPartition
2013 Warning An error occurred while trying to pull the next message. The consumer will try to recover. KafkaExceptionAutoRecovery
2014 Error An error occurred while trying to pull the next message. The consumer will be stopped. Enable auto recovery to allow Silverback to automatically try to recover (EnableAutoRecovery=true in the consumer configuration). KafkaExceptionNoAutoRecovery
2015 Warning Not used anymore. ErrorRecoveringFromKafkaException
2016 Trace Consuming canceled. ConsumingCanceled
2021 Debug Creating Confluent.Kafka.Producer... CreatingConfluentProducer
2022 Warning The message was transmitted to broker, but no acknowledgement was received. ProduceNotAcknowledged
2031 Information Assigned partition {topic}[{partition}]. PartitionAssigned
2032 Debug {topic}[{partition}] offset will be reset to {offset}. PartitionOffsetReset
2033 Information Revoked partition {topic}[{partition}] (offset was {offset}). PartitionRevoked
2034 Debug Successfully committed offset {topic}[{partition}]@{offset}. OffsetCommitted
2035 Error Error occurred committing the offset {topic}[{partition}]@{offset}: '{errorReason}' ({errorCode}). OffsetCommitError
2036 Error Fatal error in Kafka consumer: '{errorReason}' ({errorCode}). ConfluentConsumerFatalError
2037 Error Error in Kafka error handler. KafkaErrorHandlerError
2038 Debug Kafka consumer statistics received: {statistics} ConsumerStatisticsReceived
2039 Debug Kafka producer statistics received: {statistics} ProducerStatisticsReceived
2040 Error The received statistics JSON couldn't be deserialized. StatisticsDeserializationError
2041 Information Assigned partition {topic}[{partition}]@{offset}. PartitionManuallyAssigned
2042 Warning Error in Kafka consumer: '{errorReason}' ({errorCode}). ConfluentConsumerError
2043 Error Error in Kafka log handler. KafkaLogHandlerError
2050 Warning An error occurred while disconnecting the consumer. ConfluentConsumerDisconnectError
2060 Warning {sysLogLevel} event from Confluent.Kafka consumer: '{logMessage}'. -> The consumer will try to recover. PollTimeoutAutoRecovery
2061 Error {sysLogLevel} event from Confluent.Kafka consumer: '{logMessage}'. -> Enable auto recovery to allow Silverback to automatically try to recover (EnableAutoRecovery=true in the consumer configuration). PollTimeoutNoAutoRecovery
2201 Critical {sysLogLevel} event from Confluent.Kafka producer: '{logMessage}'. ConfluentProducerLogCritical
2202 Error {sysLogLevel} event from Confluent.Kafka producer: '{logMessage}'. ConfluentProducerLogError
2203 Warning {sysLogLevel} event from Confluent.Kafka producer: '{logMessage}'. ConfluentProducerLogWarning
2204 Information {sysLogLevel} event from Confluent.Kafka producer: '{logMessage}'. ConfluentProducerLogInformation
2205 Debug {sysLogLevel} event from Confluent.Kafka producer: '{logMessage}'. ConfluentProducerLogDebug
2211 Critical {sysLogLevel} event from Confluent.Kafka consumer: '{logMessage}'. ConfluentConsumerLogCritical
2212 Error {sysLogLevel} event from Confluent.Kafka consumer: '{logMessage}'. ConfluentConsumerLogError
2213 Warning {sysLogLevel} event from Confluent.Kafka consumer: '{logMessage}'. ConfluentConsumerLogWarning
2214 Information {sysLogLevel} event from Confluent.Kafka consumer: '{logMessage}'. ConfluentConsumerLogInformation
2215 Debug {sysLogLevel} event from Confluent.Kafka consumer: '{logMessage}'. ConfluentConsumerLogDebug

MQTT

Id Level Message Reference
4011 Debug Consuming message '{messageId}' from topic '{topic}'. ConsumingMessage
4021 Warning Error occurred connecting to the MQTT broker. | clientId: {clientId} ConnectError
4022 Debug Error occurred retrying to connect to the MQTT broker. | clientId: {clientId} ConnectRetryError
4023 Warning Connection with the MQTT broker lost. The client will try to reconnect. | clientId: {clientId} ConnectionLost
4031 Debug Producer queue processing was canceled. ProducerQueueProcessingCanceled
4101 Error Error from MqttClient ({source}): '{logMessage}'. MqttClientLogError
4102 Warning Warning from MqttClient ({source}): '{logMessage}'. MqttClientLogWarning
4103 Information Information from MqttClient ({source}): '{logMessage}'. MqttClientLogInformation
4104 Trace Verbose from MqttClient ({source}): '{logMessage}'. MqttClientLogVerbose

Tracing

An Activity is created:

  • in the Consumer when a message is received (initialized with the traceparent header, if submitted)
  • in the Producer when a message is being sent (submitting the Activity.Id in the traceparent header )
  • when a sequence (e.g. a BatchSequence) is being consumed
  • when a subscriber is being invoked (either internally or from a consumer)

This allows to trace the methods execution and follow a message across different services (distributed tracing).

The following table summarizes the activities and the information being tracked.

Id Description / Tags
Silverback.Integration.Produce A message is being produced to a message broker.

Tags:
  • messaging.message_id
  • messaging.destination
  • [messaging.kafka.message_key]
  • [messaging.kafka.partition]
Silverback.Integration.Consume A consumed message is being processed.

Tags:
  • messaging.message_id
  • messaging.destination
  • [messaging.sequence.activity]
  • [messaging.kafka.message_key]
  • [messaging.kafka.partition]
Silverback.Integration.Sequence A sequence of messages is being processed.

Tags: none
Silverback.Core.Subscribers.InvokeSubscriber A subscriber is being invoked to process a message.

Tags:
  • SubscriberType
  • SubscriberMethod