New Ranks & Badges For The Community!
Notice something different? The ranks and associated badges have gone "Star Fleet". See what they all mean HERE

Effective Logging for VisiBroker

Effective Logging for VisiBroker

[[wiki:VisiBroker - World class middleware - Wiki|Back]]

Overview

VisiBroker has a built-in logging mechanism which logs internal ORB error, warning, informational or debug messages. The logger has various features such as Filter, Appender and Layout that can be configured to allow users to customise the log output.

When is Logging Useful?

The log messages are very useful when diagnosing runtime problems encountered in the production or certification environment. If it is used together with Wireshark network sniffer and with the setup plus the configurations of the customers' system, it can help with the diagnosis.

For example, a customer reports a possible VisiBroker issue in their production environment. This issue may occur intermittently and cannot be easily replicated with a sample test case. The customer may attempt to reproduce the issue in their certification environment. If this is successful, then it will be easier for anyone debugging the customer's problem without affecting the production environment.

However, in some cases, the issue would not reproduced in the certification/staging environment as the actual production environment is much more complex; is running with higher load; uses different live data; etc.

One of the ways to diagnose such issues is to turn on logging in the production or certification system to gather some debugging information.

The logs gathered can help to understand the runtime behaviour of the ORB leading to the reported issue.

Side-Effect of Enabling Log

It is often difficult to persuade a customer to turn on logging in the production environment compare to the certification environment. The common reason given is that this may affect the performance and may destabilize the production system, which could be a valid concern.

Enabling logging in VisiBroker ORB may affect the performance because more CPU, memory and I/O resources are consumed to format and write the logs messages. In some cases, too much logs may affect the threads scheduling and execution behaviour, and this may in-turn prevent the same issue from reoccurring.

Trade-Off: Performance versus Information Gathering

Although enabling logs may affect the performance, the customer must ask themselves whether the system can bear with the degradation for the time being so that more information can be gathered to aid analysis of the reported issue. Some trade-offs may be required with the aim of resolving issues in such complex environments.

Effective Logging

Since enabling VisiBroker logs to diagnose runtime issues in a complex production/certification system is inevitable, are there any best practice to log more effectively?

Are there any recommendations to minimize the performance degradation and reduce system instability?

If the degradation is minimized to an acceptable level, maybe more are willing to enable logs in a production environment.

The following are some recommendations and guidelines for effective logging for VisiBroker:

1. Logging should be included in Software Design Requirements

For most customers, logging is not even considered during the initial software design requirement. But it can suddenly become important when an issue occurs in a complex production environment. So it is important to factor in logging needs during the software design requirements and development stage.

Some logging techniques are illustrated in the Dynamic Logging example in the VB 8.5 installation (examples\vbroker\debug\dynamic_logging). This example illustrates various ways to turn on/off VisiBroker log or change the log level during runtime without restarting the application in the production. For example:

1.1. Create IDL interface with operations to configure Logger with Property Manager

This approach requires the user to design the IDL interface with operations to turn on/off log or change log level as part of their application. For example:

module LogDemo {

  interface DemoObject {

    void changeLogLevel(in string logLevel);

    void turnOnLog(in boolean isTurnOn);

  };

};

The servant method implementation calls the VisiBroker Property Manager API to modify the logging configuration and the new log behaviour will take effect immediately. For example:

 

Java servant method implementation:

public synchronized void changeLogLevel (java.lang.String logLevel) {

  com.inprise.vbroker.properties.PropertyManager pm = _orb.getPropertyManager();

  pm.setProperty("vbroker.log.logLevel",logLevel);

  return;

}

public synchronized void turnOnLog (boolean isTurnOn) {

  com.inprise.vbroker.properties.PropertyManager pm = _orb.getPropertyManager();

  pm.setProperty("vbroker.log.enable",isTurnOn);

  return;

}

 

C++ servant method implementation:

void changeLogLevel(const char* _logLevel)

{

  VISPropertyManager_ptr pm = _orb->getPropertyManager();

  pm->setProperty("vbroker.log.logLevel",_logLevel);

};

void turnOnLog(::CORBA::Boolean _isTurnOn)

{

  VISPropertyManager_ptr pm = _orb->getPropertyManager();

  pm->setProperty("vbroker.log.enable",_isTurnOn);

};

 

The user needs to write a client program to call these operations to turn on/off log or change log level.

1.2. Load Library/Class dynamically to configure Logger with Property Manager

This approach does not require user to create a new IDL interface nor modify their existing application code to turn on/off log or change log level. The logic of turning on/off log and changing log level is implemented in a new library or class for C++ and Java respectively. The application is launched with the property “vbroker.orb.dynamicLibs” to load this library or class. The implementation uses the VisiBroker Property Manager API to modify the logging configuration. A thread is started to periodically read the logging configuration from a text file, and set them to the Property Manager. To change the logging configuration during runtime, the user can simply edit the text file.

2. Logging should be included in System Resource Requirements

Since logging will consume CPU, memory and I/O resources, so the system resources must be able to handle the extra load when logging is enabled.

2.1. Sufficient Storage Space

A large amount of logs can be generated if logging is enabled for a long period of time and the application is experiencing high load with lots of invocations. This may be necessary if the issue takes some time to occur. So it is better to configure the Logger to write to a log file instead of the default standard output. Hence sufficient disk space must be available to store the logs generated to prevent I/O error due to lack of space.

2.2. Use high performance Storage Device

Using a higher performance Storage Device can reduce the time to write to a file and thus reduce the degradation due to logging.

2.3. Use local storage instead of NFS

Using local storage to store the logs has better performance than using a Network File System (NFS) directory, since the latter approach requires the log messages to traverse through the network.

2.4. Sufficient CPU and Memory

Since logging consumes CPU and memory, so the machine CPU and memory specifications must be good enough to handle both the higher load due to logging and satisfy the application performance requirements.

3. Tune Logger Configuration for acceptable Performance

The simplest way to turn on logging for VisiBroker is by passing in the argument "vbroker.log.enable=true" to the VisiBroker Application at the command line. For example:

> VBApp -Dvbroker.log.enable=true (for VBC++ Application)

> vbj -Dvbroker.log.enable=true VBApp (for VBJ Application)

By default, the log messages are printed to the console using the most verbose (i.e. "debug") Log Level. However, if this default logging behaviour does not meet your performance requirements, you can perform further tuning to the Logger configuration.

In order to find out the performance degradation of the application due to logging, some benchmark test must be performed in the certification environment first. This allows the user to tune the Logger configuration and system resources in order to find an acceptable level of performance.

3.1. Control Log File Size and No. Backups

Configure the Logger rolling Appender to control the log file size and the number of backups to keep. This is to prevent the log files from consuming too much space if there is space constraint. Furthermore, as some text editor cannot open very large file for analysis, hence restricting the file size can cater to most text editors.

For example, the following properties configure the rolling appender to restrict each log file size to 20MB and keep 50 backups of the log files:

  • vbroker.log.default.appender.rolling.maxFileSize=20
  • vbroker.log.default.appender.rolling.maxBackupIndex=50

3.2. Control Log Level

The verbosity of the logs can be controlled with the log level. The default log level is “debug”, which is the most verbose. The verbosity of the logs has a direct impact on the performance. So set the log to a less verbose level if “debug” is not necessary.

For example, the following property set the log level to “debug”:

  • vbroker.log.logLevel=debug

3.3. Configure Source Name Filter

The log messages are categorized based on the module of the ORB from where they emit from. These categories are called "Source Name". The user can restrict the logs to a specific module by configuring the specific Source Name filter.

For example, the following properties will only print the “server” log messages:

  • vbroker.log.default.filter.all.enable=false
  • vbroker.log.default.filter.register=server
  • vbroker.log.default.filter.server.enable=true

3.4. Configure Appender

The log messages can be directed to specific destinations by configuring the "Appender". The selection of a suitable Appender (e.g. stdout, rolling) may have a performance impact.

For example, the following properties set the “rolling” appender:

  • vbroker.log.default.appenders=rolling
  • vbroker.log.default.appender.rolling.appenderType=rolling

3.5 Configure LayoutType

The log messages can be formatted using specific layouts by configuring the “LayoutType”. The selection of a suitable layout type (e.g. simple, full, xml) may have a performance impact.

For example, the following property set the rolling appender’s layoutType to “full”:

  • vbroker.log.default.appender.rolling.layoutType=full

3.5. Use Asynchronous Logging

Asynchronous Logging (only available in VB 8.5) may reduce the performance degradation since a different thread is used to write to the log file rather than the thread making the invocations.

To use asynchronous mode for VBJ, set

  • vbroker.log.async=true

To use asynchronous mode for VBC++, set

  • vbroker.log.default.appender.rolling.async=true

4. Other Best Practices

4.1. Enable low level of log in Production


The customer should consider turning on a low level of logging (e.g. error or warning level) in the production environment if the performance is found to be acceptable after doing some internal benchmark. This is even more important during the initial rollout of the application to production because the system may not be very robust yet and need more tuning. So if an issue happens to occur, at least some logs are available to start the investigation immediately instead of turning on the logs later and there is a possibility that the issue may not reoccur easily.

4.2. Each ORB writes to its own Log File

If multiple ORBs are running in the system, each ORB should write its log messages to its own unique log file name. If the different ORBs write to the same log file, it makes the analysis of the log file difficult.

Final thoughts ...

VisiBroker logs can help to resolve some runtime issues if it is used effectively. What it requires is proper planning and tuning to achieve the sort of acceptable level of performance required.

Additional VisiBroker Logging Resources

Logging Configuration Documentation for VBC++:

http://supportline.microfocus.com/Documentation/books/VisiBroker/85/properties.37.1.html#35818

Logging Configuration Documentation for VBJ:

http://supportline.microfocus.com/Documentation/books/VisiBroker/85/properties.75.1.html#19275

Plugging in a custom Appender and Layout to VBC++:

http://supportline.microfocus.com/Documentation/books/VisiBroker/85/dgloggingcpp.67.1.html#525807

VisiTelcoLog Service:

http://supportline.microfocus.com/Documentation/books/VisiBroker/85/overview.165.1.html#243206

 

[[wiki:VisiBroker - World class middleware - Wiki|Back]]

Labels (1)

DISCLAIMER:

Some content on Community Tips & Information pages is not officially supported by Micro Focus. Please refer to our Terms of Use for more detail.
Top Contributors
Version history
Revision #:
2 of 2
Last update:
‎2020-03-13 21:04
Updated by:
 
The opinions expressed above are the personal opinions of the authors, not of Micro Focus. By using this site, you accept the Terms of Use and Rules of Participation. Certain versions of content ("Material") accessible here may contain branding from Hewlett-Packard Company (now HP Inc.) and Hewlett Packard Enterprise Company. As of September 1, 2017, the Material is now offered by Micro Focus, a separately owned and operated company. Any reference to the HP and Hewlett Packard Enterprise/HPE marks is historical in nature, and the HP and Hewlett Packard Enterprise/HPE marks are the property of their respective owners.