Access Keys:
Skip to content (Access Key - 0)









Hints and Tips for Debugging SLEE Applications

Print this page

Introduction

This guide introduces the important topic of debugging and provides hints and tips for debugging SLEE applications.

Observing Behaviour with Logs

The first step to debug your application is observing the logs.

Log Keys

Subsystems within the Rhino SLEE send logger messages to various appropriate logger keys. An example logger key is "rhino.facility.alarm", which periodically receives messages about which alarms are currently active.

Logger keys are hierarchical. Parent keys receive all messages that are sent to child keys. For example, the key "rhino.facility" is a parent of "rhino.facility.alarms" and it receives all messages destined to the "rhino.facility.alarms" key. The root logger key is aptly called "root".

To get a list of all logger keys, you can use the "listLogKeys" command in the Command Console.

Log and Trace Levels

Log Levels determine how much information is sent to the logs from within the Rhino SLEE. A log level can be set for each logger key.

If a logger does not have a log level assigned to it, then it inherits its log level from its parent. By default, the root logger is configured to the INFO log level. In this way, all keys will output log messages at the INFO log level or above unless explicitly configured otherwise.

To change the log level, use the "setLogLevel <log-key> <level>" command in the Command Console. The available log levels are FATAL, ERROR, WARN, INFO and DEBUG.

JSLEE components do not use the log system directly. Instead they use the JAIN SLEE Trace Facility. The Trace Facility provides a vendor independent way for applications to generate trace messages. This allow SBBs to generate trace messages that can be logged or intercepted by JMX management clients in a standard way as notifications. In SLEE 1.1, profiles and resource adaptors can also use the tracing facility instead of the log system.

Rhino includes a management component (the NotificationRecorder) that records trace messages to a logger with log key 'notificationrecorder'.
See: How to direct logs from two SBBs to different log files? in the OpenCloud KB for help configuring the NotificationRecorder.

To change the trace level, use the "setTraceLevel" command in the Command Console. The available trace levels are Config, Fine, Finer, Finest, Info, Off, Severe, and Warning.

Set the log and trace levels to - to use the parent key level.

The "setColourConsole true" command in the Command Console turn on colour decoration of console log messages (only available on *nix platforms). It could help you to detect errors in your applications.

Appenders

See: How-to Configure File Appenders for more help creating file appenders.

After being filtered by logger keys, logger and trace messages are sent to Appenders. Appenders will append log messages to whatever they're configured to append to, such as files, sockets or the Unix syslogd daemon.

Typically, an administrator is interested in file appenders which output log messages to a set of rolling files. The actual messages that each appender receives is determined by the loggers AppenderRefs.

By default, the Rhino SLEE comes configured with the following appenders, visible using the "listAppenders" command from the Command Console:

  • RhinoLog appender: sends all its output to work/log/rhino.log. The AppenderRef which causes this appender to receive all log messages is linked from the root logger key.
  • STDERR appender: outputs all log messages to the standard error stream so that they appear on the console where a Rhino node is running. This also has an AppenderRef linked to the root logger key.
  • ConfigLog appender: outputs all log messages to the work/log/config.log file, and has an AppenderRef attached to the rhino.config logger key.

To debug your application and analyse traces easily, you can create a new file appender that only receives the traces of your SBB with two simple steps:

  1. Create a file appender that appends logging requests to a file in the work/log directory using the "createFileAppender <appender-name> <filename>" command.
  2. Configure the log keys to output their loggers messages to that appender. This is done using the "addAppenderRef <log-key> <appender-name>" command.

Log Files Rollover

Rolling file appenders can be set up so that when a log file reaches a configured size, it is automatically renamed as a numbered backup file and a new file created. When a certain number of archived log files have been made, old ones are deleted. In this way, log messages are archived and disk usage is kept at a manageable level.

Use the "rolloverAllLogFiles" command just before and after a test message flow, to request a rollover of all log files and isolate the case that you are debugging.

For more information about this topic, go to "Log System Configuration" chapter in Rhino Administration Guide.

OpenCloud Housekeeping Interface

See: How-to Use Rhino Housekeeping for more help using the Rhino Housekeeping interface

During normal Rhino SLEE operation SBB entities and Activities are removed by the SLEE when they are no longer needed. For instance, SSB entities are removed when all activities attached to the SBB have ended. In certain cases, however, the normal SBB life-cycle is interrupted and SBB entities are not removed at the appropriate time. This could occur, for instance, if the SBB has a problem or it is attached to an activity that hasn't ended correctly due to a problem in the Resource Adaptor that created it.

Rhino SLEE provides an administration interface to safeguard against the type of resource leak that unexpected problems caused by deployed Resource Adaptors or Services may cause. The Command Console:

  • Allow interrogation of SBB and Activities state.
  • Provides facilities for removing problematic SBBs and Activities.
  • Provides mechanisms for finding and removing Activity Context Naming bindings and Timers.

These utilities can use help diagnose application problems.

Inspecting Activities

The activity inspection commands allow the administrator to search for activities within the SLEE and to examine activity details. The "findActivities" command is used to search for activities corresponding to certain search parameters. Use "help findactivities" command to see the available search options.

You can interrogate the Rhino SLEE for additional information about an activity. This is achieved using the "getActivityInfo" command. The information returned is a snapshot of the Activity's state at the time the command is executed. Some values (fields pkey, ra-entity, replicated, submission-time, submitting-node, and handle) are fixed for the lifetime of the activity. Others will change as events are processed on the activity.

The activity state of an activity can provide clues about a problem. Analyse it deeply, especially the values of events-processed, sbbs-invoked, update-time and attached-sbbs.

If you determine that the activity you are examining is stale or in an unwanted state you can use the housekeeping commands to remove it. The "removeActivity" command is provided for this purpose.

Inspecting SBBs

The Housekeeping interface allow to search for and query for information about SBB entities. The SBB inspection commands work in the same way as the activity inspection commands with one main difference: when searching for SBBs, there is no SLEE-wide command that will find all SBBs. Instead, searches must be performed within a service by specifying the service's component ID, or within an SBB component type within a service by specifying both the service's component ID and the SBB's component ID.

The command to use is "findSBBs -service <serviceID>". Use "help findsbbs" command to see the available options.

Use the "getSBBInfo" command to retrieve additional information about a particular SBB entity. Particularly useful properties include: creation-time, attached-activities, parent sbb.

To remove an errant SBB entity use the "removeSBB" command.

Observing Behaviour with Statistics

Usage and platform statistics can provide very useful information about how an application is performing from a both a functional perspective and a performance perspective. Rhino provides several tools that can help you monitor your application.

rhino-stats

The Rhino SLEE provides monitoring facilities for capturing platform and usage statistics using the client side application rhino-stats. To launch the client and connect to the Rhino SLEE, execute the following command:

[user@host rhino]$ client/bin/rhino-stats

The rhino-stats application connects to the Rhino SLEE via JMX and collects requested statistics in real-time. Extracted statistics can be displayed in tabular text form on the console or graphed on a GUI using various graphing modes.

A set of related statistics is defined as a parameter set. Many of the available parameter sets are organised in an hierarchical fashion. Child parameter sets representing related statistics from a particular source may contribute to parent parameter sets that summarise statistics from a group of sources.

One example is the Events parameter set which summarises event statistics from each Resource Adaptor entity. In turn each Resource Adaptor entity parameter set summarises statistics from each event type it produces. This allows you to examine the performance of an application and to drill down and analyse statistics on a per event basis.

Three types of statistic are collected:

  • Counters count the number of occurrences of a particular event or occurrence such as a lock wait or a rejected event.
  • Gauges show the quantity of a particular object or item such as the amount of free memory, or the number of active activities.
  • Sample type statistics collect sample values every time a particular event or action occurs. Examples of sample type statistics are event processing time, or lock manager wait time.

Counter and gauge type statistics are read as absolute values while sample type statistics are collected into a frequency distribution and then read and printed in 3 columns, showing the 50th, 90th and 95th percentile.

Monitoring the 95th percentile can be very instructive. The 95th percentile is very sensitive to load and is more likely to change in load and overload scenarios

In console mode the rhino-stats client has two main modes of execution. When run with the -l parameter rhino-stats will list the available types of statistics the Rhino SLEE is capable of supplying. To query the available parameter sets within a parameter set type, use -l <type name> option.

To monitor a parameter set in real-time using the console interface use the -m command line argument followed by the parameter set name. Once started rhino-stats will continue to extract and print the latest statistics every 1 second. This period can be changed using the -s switch.

When run in graphical mode using the -g switch the rhino-stats client offers a range of options for interactively extracting and graphically displaying statistics gathered from Rhino SLEE.

How to monitor the Sbb usage parameters

rhino-stats application can be used to monitor the SBB usage parameters. You can use it to check if the usage parameters are updated as expected after each call, message or test.

Use one of the following commands:

[user@host rhino]$ client/bin/rhino-stats -m "SBB-Usage.<serviceID>.<sbbID>"
[user@host rhino]$ client/bin/rhino-stats -m "SBB-Usage.<serviceID>.<sbbID>.<parameterset>"

Useful parameters to monitor

Much of the statistical information gathered is very useful to service developers. For instance, you can use performance data such as event processing time statistics to evaluate the impact of SBB code changes on overall performance.

As a start point, it is useful to monitor the following parameters and statistics:

  • Parameter set Services and its childs:
    • Check created statistic is equal to removed statistic.
    • Check sbbLifeTime sample statistic has the expected value.
  • Parameter set Events and its childs:
    • Check there are not failed and rejected events.
    • For an specific event type, check the sbbProcessingTime and the numSbbsInvoked statistics have the expected values.

For more information about this topic, go to "Statistics and Monitoring" chapter in Rhino Administration Guide.

Dumpthread

Sometimes, you application appears to hang and you find SBBs entities doing SBB Inspection. You may also notice warning log messages about long running transactions. Maybe your SBB has an infinite loop or it is stuck at some point.

You can analyse these situations and find out where the SBB is stuck using rhino/dumpthreads.sh script. This utility does a full thread dump of the JVM and prints in the standard out the current state of each thread. Analyse the threads that are handling your SBB and check if they are blocked in your code.

Furthermore, you can do periodic thread dumps, and search for threads that are always at the same point. It could indicate that they are blocked.

For more information about the output of a thread dump, you can read "An Introduction to Java Stack Traces" in http://java.sun.com/developer/technicalArticles/Programming/Stacktrace.

Debugging from your IDE

You can debug your application from your IDE as other Java applications when they are deployed in the Rhino SLEE.

Enabling Remote Debug in Rhino SLEE

To enable remote debug on the production version of Rhino, edit the last lines of the $RHINO_NODE/read-config-variables file, including the following debug options when starting the Java server and restart the Rhino SLEE after the change:

DEBUGOPTIONS="-Xdebug -Xnoagent -Djava.compiler=NONE -Xrunjdwp:transport=dt_socket,server=y,suspend=n,address=8000"
JAVA="${JAVA_HOME}/bin/java $DEBUGOPTIONS -server"

To enable remote debug on the SDK version of Rhino 2.1+, add the following lines to the end of the file $RHINO_HOME/config/jvm_args:

# Debug
-Xdebug
-Xnoagent
-Djava.compiler=NONE
-Xrunjdwp:transport=dt_socket,server=y,suspend=n,address=8000

Configuring the IDE

The next step is adding a Remote Java Application Debug Configuration to your IDE that connects to the Rhino SLEE. The steps to follow depend on your IDE. In Eclipse, for instance, the steps are:

  1. Go to "Run" menu, "Debug..." option.
  2. Go to "Remote Java Application".
  3. Press in "New" button to create a new configuration.
  4. Give a name to your configuration.
  5. Select the project that you are going to debug.
  6. Indicate the host where the Rhino SLEE is running and the port to connect to (configured above as 8000).
  7. Press in "Apply" button.

Debugging

Once you have created the Remote Debug Configuration, debug as usual, adding the desired break points. Invoke your service with an incoming initial event and start to debug.

Tracking Down Missing Events and Messages

One of the common problems that people initially see during development is that an event appear to be missing or is never received by the service. That is: your network is sending a message to the Rhino SLEE and your SBB appears not to receive it. This section introduces some common causes for this problem.

Initial Events

Sometimes, the event is not delivered to your SBB due to an error in the SBB deployment descriptor. Check that you have defined the event properly (for instance, as initial event if a root SBB entity has to be created with this incoming event).

In case that the event should be received by a child SBB entity, the child must be created by the root sbb before receiving the event.

Resource Adaptor or Service is In-Active

The Resource Adaptor entity could be inactive and/or it could not be listening to incoming traffic in the expected port. Use "getRAEntityState" Command Console command to check that the entity is active and use the netstat operating system tool to check that the expected port is listening.

Furthermore, the Service could be inactive, so although the Resource Adaptor receives the message, the service is never invoked. Use "getServiceState" command to check the state of your service.

You should also check that your SLEE is in the RUNNING state (use the "getSleeState" Command Console command)

Message Discarded by the Resource Adaptor

The message could be received by the Resource Adaptor entity but the entity could not fire an event for that message. Check that the expected event is created by the Resource Adaptor entity when the message is received, monitoring the parameter set Events.<raentity>.<eventtype> with rhino-stats.

If you can not see the expected event using rhino-stat, the Resource Adaptor entity could be discarding the message (because it is malformed, not supported, unexpected,...). Set the Resource Adaptor log level to debug and check the logs, they could contains some tips about the resource adaptor entity behaviour.

One common mistake is for a developer to create a new activity in their SBB to initiate and outgoing request (e.g to query an HLR or HSS, or send an SMS message) but they forget to attach to the newly created activity in order to receive the response event!

Firewall

The message could be blocked by the firewall, so is not really received by Rhino. Use Whireshark (www.wireshark.org) or other network tool to check that the message flow is as expected and does actually reach Rhino.

Trace level

Maybe the SBB is receiving the message, but you could have not changed the trace level of your service after deploying it (by default traces are off), so you can not see what your application is doing with the event. Set the SBB trace level to Finest.

Adaptavist Theme Builder Powered by Atlassian Confluence