Fork me on GitHub
cougar from Betfair

What Cougar Logs and Where

Effective Configuration Log

Location: Available on JMX console under MBean “name=ApplicationProperties” as in https://localhost:9999/ViewObjectRes//CoUGAR%3Aname%3DApplicationProperties

Contains a dump of all the properties Cougar has been configured to use (including those of your applications and modules).

...
cougar.client.log.level=INFO
cougar.client.log.request=true
cougar.commandProcessor.corePoolSize=5
cougar.commandProcessor.keepAliveTime=600
...

HTTP Endpoint Log

Location: Available on JMX console under MBean “name=EndPoints” as in https://localhost:9999/ViewObjectRes//CoUGAR%3Aname%3DEndPoints

Contains a dump of the endpoints available over the HTTP transport.

RESCRIPT : Health/v2.0/getDetailedHealthStatus => http://10.20.183.161:8080/healthcheck/v2/detailed
RESCRIPT : Health/v2.0/isHealthy => http://10.20.183.161:8080/healthcheck/v2/summary
...
SOAP     : Health/v2.0/getDetailedHealthStatus => http://10.20.183.161:8080/HealthService/v2/
SOAP     : Health/v2.0/isHealthy => http://10.20.183.161:8080/HealthService/v2/
...

Server Log

Location: <cougar.log.dir>/<system.hostname>-server.log.

Contains Cougar framework logging (startup progress, property dump, Exceptions, shutdown info) and anything logged to a CougarLogger.

{info} Note that CougarLoggingUtils uses the System Property “cougar.log.factory” to decide which LoggingFactory to use. {info}

Example:

package com.whatever;
public class Thing {
    final static CougarLogger logger = CougarLoggingUtils.getLogger(Thing.class);
    public void logSomething(String what) {
        logger.log(Level.INFO, "%s", what);
    }
}

This will produce the following output in the server log (assuming you passed in “Hello, World!”):

2011-06-23 13:14:42.130: com.whatever.Thing INFO - Hello, World!

To configure the level of a specific category in configuration:


(you can specify this in your service defaults, in an overrides file, or as a system property)

## Access Logs

Location:&nbsp;```<cougar.log.dir>/dw/<system.hostname>-access.log```.

Cougar HTTP transport creates a comma-delimited entry in the access log at the point that the HTTP response is ready to
be sent. An example for an access log entry is :

2012-07-17 09:37:30.949,localhost-07170935-000000004f,/api/v2/creditFunds/,gzip,10.2.5.172,10.2.5.172,–,Ok,81287000,329,13,json,json,[User-Agent=Cougar Client 2.4.0]


So the following are the fields (Refer&nbsp;com.betfair.cougar.transport.impl.protocol.http.HttpRequestLogger for the relevant Java code)
# Received date-time, format yyyy-MM-dd HH:mm:ss.SSS
# Request UUID
# Path
# Compression (gzip/none)
# User remote IP address
# User resolved IP address
# User country
# Response Code
# Process time in nanoseconds
# Number of bytes read
# Number of bytes written
# Request media sub-type
# Response media sub-type
# Extra fields (such as User-Agent) etc



## Operation Event Log (AKA 'request log')

Location: ```<cougar.log.dir>/dw/<system.hostname>-request-<serviceName>.log```

A comma-delimited entry is created in the event log upon completion of each operation by the application, and before
marshalling the result back via the transport. The first fields in the log will be of the following format:

# Received date-time, format yyyy-MM-dd HH:mm:ss.SSS
# Invocation UUID
# Service version
# Operation name
# Fault code (if there was one)
# Operation process time in nanoseconds (this does not include transport mashalling and unmarshalling time)

Application-specific fields may follow this mandatory data afterwards (see below).

### Extending the Event Log

# Implement a ```com.betfair.cougar.api.LogExtension```.  The method ```getFieldsToLog``` returns an consistent-size
array of Objects that will be output (comma-separated) to the event log after the mandatory fields.
# Register the ```LogExtension``` in your service interface implementation's ```init``` method.  At this time you have
to specify how many fields your ```LogExtension``` will return.

@Override public void init(ContainerContext cc) { this.containerContext = cc; cc.registerExtensionLoggerClass(MyLogExtension.class, 1); }


# Whenever you want to use extension logging on the request, use the ```setRequestLogExtension``` method on the operation's ```ExecutionContext```.

```java
ctx.setRequestLogExtension(new MyLogExtension(thing, otherThing));

Trace Logs

Location: <cougar.log.dir>/<system.hostname>-trace.log.

Please refer to this documentation.

Key Performance Indicator Log

Location: <cougar.log.dir>/kpi/<system.hostname>-kpi.log.

Contains entries generated by KPI monitoring.

To hook a method (service interface operation or otherwise) up with KPI monitoring:

@Override
    @KPITimedEvent(value = "ExampleServiceImpl.getSimpleResponse", catchFailures = true)
	public SimpleResponseObject getSimpleResponse(RequestContext ctx, String message) throws SimpleException {
            ...

Log entries will be made around every minute (give or take a few milliseconds).

The log entry format is a JSON object, which can contain many methods’ KPIs. Each method’s KPI entry is split into time ranges, or “buckets”. Here is an example of the ExampleServiceImpl.getSimpleResponse method returning without Exception 59 times, 58 of those times in under 0-25ms (the time range is known bucket) and 1 in the 250-500ms range.

2011-02-03 10:26:00.017: com.betfair.KPI INFO - \{"startTime":1296728700026,"endTime":1296728760016,"ExampleServiceImpl.getSimpleResponse.OK":\{"\[0-25.0\]":\{"avg":0.431,"ttl":25.0,"cnt":58.0,"min":0.0,"max":2.0,"dev":0.534\},"\[250.0-500.0\]":\{"avg":291.0,"ttl":291.0,"cnt":1.0,"min":291.0,"max":291.0,"dev":0.0\}\}\}

The keys are broken down as follows:

Name Significance
startTime KPI logging timeframe start time in millis (since the epoch)
endTime KPI logging timeframe end time in millis (since the epoch), ~6000ms after the start time
avg The average response time in this bucket (total / cnt)
ttl The total response time in this bucket
cnt The number of calls
min The minimum response time
max The maximum response time
dev Presumably the deviation, not entirely sure what this signifies

If catchFailures is true (the default is false), then the KPI log will distinguish between successful and failed (ie. exception thrown) invocations by using <operationName>.OK and <operationName.Failed. Example:

2011-02-03 10:46:00.018: com.betfair.KPI INFO - \{"startTime":1296729900030,"endTime":1296729960017,"ExampleServiceImpl.getSimpleResponse.Failed":\{"\[0-25.0\]":\{"avg":0.071,"ttl":1.0,"cnt":14.0,"min":0.0,"max":1.0,"dev":0.267\}\},"ExampleServiceImpl.getSimpleResponse.OK":\{"\[0-25.0\]":\{"avg":1.167,"ttl":7.0,"cnt":6.0,"min":1.0,"max":2.0,"dev":0.408\}\}\}

Both checked (i.e. BSIDL-defined) and unchecked (runtime) Exceptions are classified as failures by the KPI framework by default.

Custom Event Logs

You will want to define a custom event log if you require any log with a format that you control exclusively.

Defining the Custom Event Log

This is simplest to do using your module’s Spring assembly file (conf/cougar-application-spring.xml).

<bean class="com.betfair.cougar.logging.EventLogDefinition" init-method="register">
        <property name="logName" value="ADDITIONAL-LOG"/>
	<property name="registry" ref="eventLoggingRegistry"/>
	<property name="handler">
	    <bean class="com.betfair.cougar.logging.handlers.TextEventLogHandler">
                <constructor-arg value="$COUGAR{cougar.log.dir}/$COUGAR{system.hostname}-additional.log"/>
                <constructor-arg value="$MY_APP{cougar.log.ADDITIONAL-LOG.flush}"/> <!-- true or false -->
                <constructor-arg value="$MY_APP{cougar.log.ADDITIONAL-LOG.append}"/> <!-- true or false -->
		<constructor-arg value="$MY_APP{cougar.log.ADDITIONAL-LOG.rotation}"/> <!-- HOUR usually -->
		<constructor-arg value="false"/> <!-- this isn't an 'abstract' handler -->
	    </bean>
	</property>
    </bean>

Notes:

Logging to the Custom Event Log

Implement a com.betfair.cougar.api.LoggableEvent (which also encapsulates the name of the log which the event will be recorded-to, e.g. ADDITIONAL_LOG)

Whenever you want to log a custom event, use the addEventLogRecord method on the operation’s RequestContext

ctx.addEventLogRecord(new MyLoggableEvent(thing, otherThing));

Logging an event from an interceptor

For a pre processing interceptor, you can cast the ExecutionContext to a RequestContext and invoke addEventLogRecord that way

For a post processing interceptor, you have to inject the correct com.betfair.cougar.core.api.logging.EventLogger into the place you need to log from, and use the logEvent methods directly. The event logger bean you will need to inject is called cougar.core.EventLogger.

Archive Suffix

The suffix used for rotating logs is .YYYY-MM-DD-HH.

Changing log levels at runtime using JMX

Go to Cougar’s logging control bean at http{}[s]://localhost:9999/ViewObjectRes/CoUGAR%3Aname%3DLoggingControl

Fill out setLogLevel operation parameters

p1 -> The name of the package or fully qualified class to start logging

p2 -> a JULI log level, e.g. WARNING or FINEST

p3 -> true if you want the logging level change to be recursive, false otherwise

Muffling Cougar logs from code

CougarLoggingUtils.suppressAllRootLoggerOutput();

Echoing of Cougar logs to stdout

Override: cougar.log.echoToStdout=true