Setting an MPL Log Level at a Message Level in SAP...

vadimklimov · ‎12-29-2020

Update in December 2023

To determine a log level during message processing using a Groovy script, it is recommended to retrieve it from exchange properties SAP_MPL_LogLevel_Internal, SAP_MPL_LogLevel_External and SAP_MPL_LogLevel_Overall rather than to derive it from the exchange property SAP_MessageProcessingLogConfiguration. For more information about this, please refer to the documentation here.

Intro

Message processing log (MPL) is undoubtedly one of very demanded and debated topics in SAP CPI – MPL is an invaluable source of information for monitoring and troubleshooting, a number of solutions are built on top of this functionality to facilitate additional information and message content logging, many debates occur about best practices and use cases when MPL can/shall be used and when it shall be avoided and alternatives shall be considered… Here we go with yet another blog post on this topic – this time, about changing a log level for individual messages, rather than for entire iFlows.

Let's set the scene first. SAP CPI offers four MPL log levels: NONE, INFO, DEBUG and TRACE.

It is a rare occasion when a NONE log level is used, as no data is recorded for messages processed with this log level. Under normal circumstances, iFlows are usually run with an INFO log level – this log level enables logging of basic information about message processing steps, and more detailed information about last processing steps for failed messages.

During the course of troubleshooting message processing errors in SAP CPI, integration developers often increase log verbosity of the affected deployed iFlow, reproduce an error and analyze MPL entries of the failed message. A commonly used log level here is either DEBUG (this log level enables logging of detailed information about message processing steps) or TRACE (if in addition to that, persistence of message content is also required). Currently, a TRACE log level expires after 10 minutes (after expiry, a log level of an iFlow gets reverted to a log level that was set previously, before a TRACE log level was enabled), and trace data is removed after retention time of 1 hour, but there are plans to make these time periods configurable, so stay tuned and watch this space.

A DEBUG log level is also used by some organizations for a longer-term persistence of parts of message data – for example, common operations would involve adding MPL properties for additional information logging, or custom header properties for user-defined message search, or attachments for persistence of all or part of a message payload. An approach that is based on evaluation of an MPL log level is an effective and convenient alternative to usage of an additional designated externalized and configurable parameter of an iFlow. While there is nothing wrong with the latter option and it can be met in prepackaged content and many custom iFlows, this approach requires change of a value of a configurable parameter and re-deployment of an iFlow, if additional logging needs to be enabled or disabled. In contrast, when using the former approach that is based on evaluation of an MPL log level, there is no need in any additional configurable parameters in an iFlow, since an MPL configuration (and an MPL log level being a part of it) can be retrieved during message processing by accessing an exchange property SAP_MessageProcessingLogConfiguration. Moreover, there is no need to re-deploy an iFlow, since a log level of an iFlow can be changed dynamically in SAP CPI Web UI. This approach was explained and illustrated in details by malteschluenz in his blog post, so I really encourage you to read the mentioned blog post and comments to it that provide additional instrumental ideas on usage and adaption of this approach and its variations.

In this blog post, I would like to expand on usage of an MPL log level and share a feature that might be useful in the described context – in particular, how an MPL log level can be set at a message level, but before we get to that, let's refresh our memory about how a log level can be set at an iFlow level.

Baseline scenario

Throughout the blog post, I will provide examples using an iFlow that was inspired by the above mentioned Malte's blog post and that consists of a single step – a Groovy script step that implements persistence of a message payload as an MPL attachment in case an MPL log level is DEBUG or TRACE:

An implementation of a Groovy script function is provided below:

import com.sap.gateway.ip.core.customdev.util.Message



Message processData(Message message) {



    String logLevel = message.getProperty('SAP_MessageProcessingLogConfiguration').logLevel.toString()



    if (logLevel in ['DEBUG', 'TRACE']) {

        messageLogFactory.getMessageLog(message)?.addAttachmentAsString('Payload', message.getBody(String), 'text/plain')

    }



    return message



}

Note: the function implementation is simplified – for example, it uses a fixed name for the MPL attachment and a fixed context type. In real-life scenarios, the script can be improved to become more reusable and flexible by introducing configurable attachment name and content type, as well as enriched with additional checks to make (such as nullable payload check and payload size check).

The iFlow uses HTTPS sender connection – after the iFlow is deployed to the runtime, this enables us to call the iFlow later using an HTTP client such as Postman. In sake of simplicity, CSRF protection is disabled in an HTTPS sender connection configuration.

Setting a log level at an iFlow level

One of the most common ways to set an MPL log level at an iFlow level is to use an Operations view in SAP CPI Web UI:

If a request message is sent to the endpoint of the iFlow, we will be able to see an MPL of the processed message in a Message Monitor, but it will lack an MPL attachment with a message payload, since a log level of the iFlow is INFO currently:

For those who would like to utilize the same functionality of setting a log level at an iFlow level, but programmatically, a corresponding command – IntegrationComponentSetMplLogLevelCommand – is available as a part of Operations API. This command is called by SAP CPI Web UI when we change a log level of the selected iFlow, and the same command can be called using alternative tools / HTTP clients. It shall be noted that Operations API (and a Command Framework that lies under it) hasn't been released for external usage and is currently reserved for SAP internal usage only – even though we can make use of relevant commands and the approach is functional technically, you shall be cautious and mindful about supportability aspects and take this into considerations when assessing this option.

Should you be interested in reading more about Operations API, ariel.bravoayala3 wrote an excellent blog post where he demonstrated how various Operations API commands can be called and what are prerequisites for that. I'm not going to repeat his findings here, and will only illustrate usage of the IntegrationComponentSetMplLogLevelCommand command.

Following prerequisites shall be met before calling the command:

A user has been assigned relevant and sufficient security roles – same security roles that are required for the user to change a log level of an iFlow using SAP CPI Web UI (SAP CPI Security Guide can be consulted for details on this),

A CSRF token has been acquired.

Next, we compose an HTTP POST request and send it to the command's endpoint. Amongst request headers, a header X-CSRF-Token with the valid CSRF token that was acquired earlier, has to be present, and a request body has to contain information about which log level needs to be set for which integration artifact. The request below illustrates how we can apply this technique and set a log level of the specified iFlow to DEBUG:

After the request above got successfully completed, we can observe evidences of the changed log level of the iFlow – for example, checking the log level in SAP CPI Web UI:

Next, we revert a log level of the iFlow from DEBUG back to INFO before we proceed with the demo.

Setting a log level at a message level

All messages that are processed by an iFlow, will by default use a log level that has been configured for that iFlow in either of ways described above. But this isn't the only option that is available to us for setting an MPL log level. For the specific processed message, we can override a log level that has been configured for an iFlow, with the help of a message header SAP_MessageProcessingLogLevel.
This header is mentioned in SAP Help documentation in a list of message headers and exchange properties that are provided by SAP CPI's integration framework in SAP Help documentation, but I couldn't find more information on this header usage – and as a result, decided to write about it here.

As it has been written, the header SAP_MessageProcessingLogLevel is intended to override a log level of an iFlow. In other words, this header takes precedence over a log level of an iFlow for the processed message.

This functionality is not intended to change a log level that is configured for a deployed iFlow, but to apply the specified log level to the particular message where this header is present. In fact, this is very convenient when we don't want to change a log level of all messages that are processed for an iFlow, but want to do so only for a very specific message or several messages. For example, a log level configured for an iFlow, can remain to be INFO, and all messages processed for this iFlow will use this log level, but for a specific message that we send and that is intended to reproduce some particular case (a specific use case of a scenario, or a condition that causes message processing failure), we can make it processed at runtime using a DEBUG log level.

Using this header, it is possible to set any valid log level except TRACE. This isn’t a bug, but a feature – a restriction that prevents usage of this header to set a TRACE log level was introduced deliberately and purposely.

Correspondingly, values that are valid for this header, are: NONE, INFO and DEBUG. Values are case-insensitive, so they can be set both in lower and upper case interchangeably – CPI will anyway bring this header value to an upper case when evaluating it at runtime, so that it is represented in a similar way as permissible log levels in an MPL configuration, where they are also maintained in an upper case.

The header has to be present in an incoming message – it will have no effect, if the header is added by one of message processing steps. For example, if a message that was accepted at runtime, didn't contain this header, and the header was added later in a message processing flow by a content modifier step, or a Groovy/JavaScript script step, it will have no impact on a log level of the processed message even if it was added right at the beginning of message processing in an iFlow – for instance, by the first step in an iFlow. Root cause for such behavior relates to a mechanism that prevents MPL configuration inconsistency: when an MPL configuration is determined and applied to a message at the beginning of its message processing lifecycle, an MPL configuration for the processed message is normally "locked" and cannot be changed by subsequent message processing steps using any of APIs that have been released to customers. This state becomes reflected in an MPL configuration (and consequently, in the value of the exchange property SAP_MessageProcessingLogConfiguration that reflects an MPL configuration that has been applied to a processed message) with the help of a final flag (a property isFinal of an MPL configuration, to be more precise). Any changes to an MPL configuration that is marked as final, will take no effect – and given that a log level of a processed message is one of MPL configuration parameters, this rule applies to it, too.

Note: the one may wonder if the mentioned final flag in an MPL configuration can be changed for a processed message to "unlock" an MPL configuration and change some of its properties for an in-flight message. A property isFinal of an MPL configuration holds a boolean value, we can access an MPL configuration of a message by getting access to a corresponding exchange property, we can make changes to the acquired object properties and write an amended value back to an exchange property. Hypothetically, we could have done that for the property isFinal, too, followed by changing a log level contained in an MPL configuration, and "locking" an MPL configuration back by resetting the mentioned final flag to its original state, but I strongly discourage you from applying this train of thought in practice, as this is a highway to inconsistency.

Let's add the mentioned header to the earlier used request message, set the header's value to debug and send the amended request to the endpoint of the iFlow:

Now we check an Operations view in SAP CPI Web UI once again.

Firstly, we can notice that a log level of the iFlow didn't get changed – it remains to be INFO.

Secondly, we can observe a recently processed message and evidence that a log level of the message is DEBUG, and an MPL attachment got created for it as expected:

In a similar way, we can use the mentioned header to set NONE and INFO log levels. Should we attempt to set a value TRACE to the mentioned header, it will be ignored by the runtime (a message will be processed using a log level set at an iFlow level).