RI PC Platform Logging - Controlling and Understanding RI Logging Messages

This page explains the log messages that are usually of interest to OCAP application developers. Log messages describing the usual life-cycle for an RI application are identified. Briefly covered here are the settings to control log messages.

Many of the messages written by the RI may be of no interest to an application developer. These messages may de selectively disabled by adjusting the logging level for a category of messages. Remember to turn on logging before you report an issue. Log messages that are distractions to you may be just the information needed to debug problems with the RI.

For a more detailed discussion of RI logging, including the architecture and design, see RI PC Platform Logging

Table of Contents

Anatomy of RI log messages and FAQ

Basic information

By default RI log messages are appended to the file:

$PLATFORMROOT/RILog.txt.

The default format and information in a log message is shown in the example below:

Date     Time         Level    Category   - message
20100414 13:52:35.750 INFO     RI.Platform- ri_platform_init -- Starting up RI platform

For brevity the following examples do not show the date and time. Also, not all log messages are shown – just the ones we believe are of interest to application developers.

What are the logging levels for this run?

The first log messages echo the logging levels themselves.

NOTICE   RI-
NOTICE   RI- -=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-
NOTICE   RI- Platform category logging levels:
NOTICE   RI- root                       : NOTSET
NOTICE   RI- RI.DRI                     : FATAL ERROR WARNING INFO
NOTICE   RI- RI.Cablecard               : FATAL ERROR WARNING INFO
NOTICE   RI- RI.Stack                   : FATAL ERROR WARNING INFO DEBUG TRACE

For each of the stack logging categories the enabled levels are listed in a series of messages. In the above example, DEBUG as well as TRACE messages are enabled for the category RI.Stack but not for RI.Cablecard.
Logging levels are set in the file:

$PLATFORMROOT/log4crc

Did the stack initialize and start properly?

Look for the stack to be initialized with the message:

INFO     RI.Platform- ri_platform_init -- Starting up RI platform

followed by many simple bookkeeping messages as the various components of the stack initialize.

INFO     RI.UI- Device screen resolution: 640 x 480
INFO     RI.UI- Initializing wxWidgets application UI
INFO     RI.UI- Created TV Screen.
INFO     RI.UI- Created Remote.

And finally an inventory of more logging categories:

INFO     RI.Stack-
INFO     RI.Stack- -=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-
INFO     RI.Stack- Stack level logging levels:
INFO     RI.Stack- Initial Logging Level for TARGET    :  FATAL ERROR WARNING INFO
INFO     RI.Stack- Initial Logging Level for CC        :  FATAL ERROR WARNING INFO
INFO     RI.Stack- Initial Logging Level for CDL       :  FATAL ERROR WARNING INFO
INFO     RI.Stack- Initial Logging Level for COND      :  FATAL ERROR WARNING INFO
INFO     RI.Stack- Initial Logging Level for DBG       :  FATAL ERROR WARNING INFO

Did my application start properly?

Now that the stack is initialized attention turns to the Xlet to be launched. Look for a long message like the following one. It is lengthy but it is packed with useful information. The parameters in the hostapp.properties file are echoed in this message. For example:

 INFO     RI.Stack- 8094 [System-1] INFO  application.AppDomainImpl - Launching AppEntry[id=17202,names=
[eng:PODTest],code=1,bound=true,visibility=3,priority=220,baseDir=/syscwd/qa/xlet,classPath=[],
classname=org.cablelabs.xlet.PODTest.PODTestXlet,params=[],icon=null,icon_flags=0,transport_protocols=
[org.cablelabs.impl.signalling.AppEntry$LocalTransportProtocol@24800da5],prefetch=null,dii=null,
service=12345,version=0,storagePriority=0,launchOrder=0,registered_apis=[],]

In the above example, corresponding hostapp.properties file was:

# Version: 1.0.0
################################################################################
################################################################################

###############################################
## Application 0 - POD Testing
###############################################
app.0.application_identifier=0x000000017202
app.0.application_control_code=AUTOSTART
app.0.visibility=VISIBLE
app.0.priority=220
app.0.application_name=PODTest
app.0.base_directory=/syscwd/qa/xlet
app.0.initial_class_name=org.cablelabs.xlet.PODTest.PODTestXlet

###############################################################################

You can see the correspondence between the log and the hostapp.properties file. Should your application fail to start look here for clues.
After the app was found by the RI and loading is underway. Note the appid the messages refers the hostapp.properties – thei is especially useful if you are launching multiple apps.

INFO     RI.Stack\- 8125 \[pool-4\] INFO  application.Application$State - appid=17202 NOT_LOADED->~AUTO_PARTIALLY_LOADED success

What permissions are granted to my application?

Next, the log lists the permissions granted to the application. A asterisk means all permissions of that type.

 INFO     RI.Stack- 8188 [pool-4] INFO  security.Policy - Permissions for (17202 file:/syscwd/qa/xlet/ <no certificates>)
 are org.cablelabs.impl.security.AppPermissions@6696b62e( (javax.tv.service.selection.ServiceContextPermission * own)
 (javax.tv.service.ReadPermission *)
 (javax.tv.media.MediaSelectPermission *)
 (org.ocap.application.OcapIxcPermission /service-2/signed/*/*/* lookup)
 (org.ocap.application.OcapIxcPermission /service-2/signed/1/7202/* bind)
 (java.util.PropertyPermission mhp.ia.version.* read)
 (java.util.PropertyPermission gem.recording.version.micro read)
 (java.util.PropertyPermission gem.recording.version.minor read)

At what point is my app booted and running?

OCAP applications are typically OCAP Xlets meaning they implement the OCAP Xlet interface which defines the mechanism for launching applications. The OCAP stack is responsible of launching the OCAP Xlets which are signaled either via XAIT or the hostapp.properties. The OCAP Xlet transitions through several states prior to completing its startup. These states have corresponding methods in the OCAP Xlet interface which are called.
The initXlet() is called followed to a called to startXlet(). The launch of OCAP Xlet is considered complete when the startXlet() method completes. An OCAP application should include log messages when the initXlet() and startXlet() methods complete in order to verify application startup has completed. The following log snippet shows the stack and application log message related launching an application:

 INFO     RI.Stack- 8672 [pool-4] INFO  application.Application$State - appid=15204 ~AUTO_PARTIALLY_LOADED->LOADED success
INFO     RI.Stack- (JVM stdout) TuneTest initXlet
...
INFO     RI.Stack- 8734 [pool-4] INFO  application.Application$State - appid=15204 LOADED->~INITED success
INFO     RI.Stack- (JVM stdout) TuneTest startXlet

Logging Setup and Troubleshooting Tips

Good description of logging can be found here:

RI PC Platform Logging

There are two command line options which affect logging (use ./runRI.sh --h for complete listing of command line options):

 -capall combined with any [other option], captures stdout & stderr to ri-iter-N.log [in addition to all other log messages]

 -deletelog deletes RILog.txt [and ri-iter-N.log] at the start of this script

For example, to use the above options:

 ./runRI.sh -capall -deletelog

Log messages come from three major areas of the RI and the logging levels are controlled via three different configuration files:

OCAP Stack logging – controlled via mpeenv.ini located in $OCAPROOT/$OCAPTC/env
Platform level logging – log4crc located in $PLATFORMROOT
GStreamer level logging – platform.cfg located in $PLATFFORMROOT

GStreamer Logging

The RI utilizes a framework called GStreamer. In addition to the components which are part of the standard GStreamer framework, RI specified GStreamer components exists and are located in $PLATFORMROOT/src/gstreamer. The log level is numeric based 0 to 5, with 5 being the most verbose. The logging level can be controlled via the following lines in platform.cfg:

 RI.Platform.gstargs.0 = --gst-debug-level=2
RI.Platform.gstargs.1 = --gst-debug=pidfilter:2,transportsync:2,sectionfilter:2,sectionassembler:2,sectionsink:2,esassembler:2,mpegdecoder:3,trickplayfilesrc:3,display:2

When I suspect a bug in the stack, at what level should logs be created for attaching to the issue?

Turn on Java debug logging via mpeenv.ini by un-commenting this line (remove the pound sign)

 #LOG.MPE.JAVA = ALL DEBUG

How do I shut down all stack logging except FATAL and ERROR?

Set the following and ensure no other levels of LOG.MPE… are enabled.

 LOG.MPE.DEFAULT = ALL FATAL ERROR !INFO

To turn off all stack logging, comment out the following line in mpeenv.ini file:

 #LOG.MPE.DEFAULT = ALL

To "compile out" all java logging modify $OCAPROOT/java/src/base/org/cablelabs/impl/debug/Logging.java so that this line reads:

    public static final boolean LOGGING = false;

The clean/purge/build your stack.

How can my app write to the file RILog.txt?

Log messages from an application will be included in the log if they are directed to stdout. A simple way to create a log message from an OCAP Xlet is to print to standard out via System.out.println("your app message here");.
The messages will be captured by the stack and will be formatted similar to the following:

 INFO     RI.Stack- (JVM stdout) TuneTestXlet Tuning Event received

Page tree

RI PC Platform Logging - Controlling and Understanding RI Logging Messages