Cisco WebEx Social Troubleshooting Guide, Release 3.0
Logs
Downloads: This chapterpdf (PDF - 216.0KB) The complete bookPDF (PDF - 1.5MB) | Feedback

Logs

Table Of Contents

Logs

Logs Overview

Log Files Stored on the Director by Role

Localy-stored Log Files by Role

Understanding Logs

Monit Starts Up

Monit Check Failed

Manually Restarting Monit

Resource Overutilization

Purging /opt

Nagios Starts Up/Shuts Down

Common False Positives

Node is No Longer Active/Available but Exists in the Topology

Monit service Not Running on a Node

Chart Data Missing for a Node

Failure: Core Service is Down for an Extended Period of Time

Rsyslog Starts Up/Shuts Down

Rsyslog is Rate Limited

Service is Down

Analytics Service Initialized Successfully

MapReduce Scheduler Logs

Calendar Logs

Getting a Month Worth of Meetings with Configured Domino and WebEx (No Cached Data)

Getting a Month Worth of Meetings with Configured Domino and WebEx (Cached Data)

Getting a Month Worth of Meetings with Configured WebDAV (No Cached Data)

Selecting a Domino Event from the List of Events

Framework Logs

Incorrect Theme ID

Streams Logs

Errors During Interpretation

VDL Backend Debugging


Logs


This chapter provides information about log file names and locations as well as other log-related information.

This chapter is organized as follows:

Logs Overview

Log Files Stored on the Director by Role

Localy-stored Log Files by Role

Understanding Logs

Logs Overview

Most Cisco WebEx Social logs are centralized on the Director node. There are a few exceptions (log files with dynamic name patterns and non-critical logs) where log files are managed localy on nodes instead of streaming to the Director node.

Cisco WebEx Social uses rsyslog as a logging framework. rsyslog sends critical logs to the Director node but, if configured, can also stream logs to an upstream host (see the Cisco WebEx Social Administration Guide for details).

The central log location on the Director node is /opt/logs/<date>/ where date is the date that the log message was written. For example /opt/logs/2012_12_01/ would contain all log messages generated on Dec 1 2012.

The logs on the Director can be accessed through the Director GUI (see the Cisco WebEx Social Administration Guide for details) or through the Cisco WebEx Social API.

Log Files Stored on the Director by Role

This sections lists the log files that each role sends to the Director.

Table 4-1 Log Files Stored on the Director 

Role
Log filename

Director

%HOSTNAME%_director_web.log
%HOSTNAME%_catalina.log
%HOSTNAME%_localhost.log
%HOSTNAME%_manager.log
%HOSTNAME%_host_manager.log
%HOSTNAME%_deploy_db.log
%HOSTNAME%_graphite_access.log
%HOSTNAME%_graphite_exception.log
%HOSTNAME%_graphite_info.log
%HOSTNAME%_graphite_error.log
%HOSTNAME%_carbon_console.log
%HOSTNAME%_salt_master.log
%HOSTNAME%_mongod.log
%HOSTNAME%_jsonstore.log
%HOSTNAME%_analyticsstore.log

App Server

%HOSTNAME%_appserver.log
%HOSTNAME%_analyticsmrscheduler.log
%HOSTNAME%_catalina.log
%HOSTNAME%_localhost.log
%HOSTNAME%_tomcat-access.log
%HOSTNAME%_manager.log
%HOSTNAME%_host_manager.log
%HOSTNAME%_httpd_access.log
%HOSTNAME%_httpd_error.log
%HOSTNAME%_cmanager.log
%HOSTNAME%_cmanager_debug.log
%HOSTNAME%_cmanager_info.log
%HOSTNAME%_cmanager_warn.log
%HOSTNAME%_cmanager_error.log
%HOSTNAME%_deploy_db.log
%HOSTNAME%_audit.log

Worker

%HOSTNAME%_worker.log
%HOSTNAME%_catalina.log
%HOSTNAME%_localhost.log
%HOSTNAME%_manager.log
%HOSTNAME%_host_manager.log
%HOSTNAME%_httpd_access.log
%HOSTNAME%_httpd_error.log
%HOSTNAME%_cmanager.log
%HOSTNAME%_cmanager_debug.log
%HOSTNAME%_cmanager_info.log
%HOSTNAME%_cmanager_warn.log
%HOSTNAME%_cmanager_error.log

Message Queue

%HOSTNAME%_message-queue_wrapper.log
%HOSTNAME%_message-queue.log
%HOSTNAME%_message-queue_shutdown_err
%HOSTNAME%_message-queue_startup_err
%HOSTNAME%_message-queue_shutdown.log
%HOSTNAME%_message-queue_startup.log

Notifier

%HOSTNAME%_notifier.log
%HOSTNAME%_notifier_nohup.out
%HOSTNAME%_notifier_debug.log
%HOSTNAME%_notifier_info.log
%HOSTNAME%_notifier_warn.log
%HOSTNAME%_notifier_error.log

Cache

%HOSTNAME%_messages

Search Store

%HOSTNAME%_search.log
%HOSTNAME%_search.request.log

Index Store

%HOSTNAME%_index.log
%HOSTNAME%_index.request.log

Analytics Store

%HOSTNAME%_analyticsstore.log
%HOSTNAME%_mongod.log

JSON Store

%HOSTNAME%_jsonstore.log
%HOSTNAME%_mongod.log

RDBMS Store

%HOSTNAME%_oracle_quad_log.xml
%HOSTNAME%_oracle_alert_quad.log
%HOSTNAME%_oracle_rdfprod_log.xml
%HOSTNAME%_oracle_alert_rdfprod.log
%HOSTNAME%_oracle_sqlnet.log

Common logs (all roles)

%HOSTNAME%_secure
%HOSTNAME%_mail_log
%HOSTNAME%_cron
%HOSTNAME%_spooler
%HOSTNAME%_boot.log
%HOSTNAME%_collectd.log
%HOSTNAME%_monit.log
%HOSTNAME%_puppet.log
%HOSTNAME%_messages
%HOSTNAME%_nagios.log
%HOSTNAME%_faillog
%HOSTNAME%_lastlog
%HOSTNAME%_snmpd.log
%HOSTNAME%_yum.log
%HOSTNAME%_tallylog
%HOSTNAME%_vmware_tools_guestd
%HOSTNAME%_wtmp
%HOSTNAME%_audit_local_log
%HOSTNAME%_mail_statistics
%HOSTNAME%_pm-suspend.log
%HOSTNAME%_prelink.log
%HOSTNAME%_mod-jk.log
%HOSTNAME%_rewrite.log
%HOSTNAME%_ssl_access_log
%HOSTNAME%_ssl_request_log
%HOSTNAME%_ssl_error_log
%HOSTNAME%_install.log
%HOSTNAME%_install.log.syslog
%HOSTNAME%_salt_minion.log


Localy-stored Log Files by Role

This sections lists the log files that some roles store localy.

Table 4-2 Localy-stored Log Files

Role
Log filename

Message Queue

/opt/cisco/rabbitmq/log/rabbit@<hostname>.log
/opt/cisco/rabbitmq/log/rabbit@<hostname>-sasl.log

RDBMS Store

/opt/oracle/app/oracle/diag/rdbms/[quad, rdfprod]/[quad, rdfprod]/cdump/*
/opt/oracle/app/oracle/admin/[quad, rdfprod]/adump/*
/opt/oracle/app/oracle/diag/tnslsnr/*/listener/alert/log.xml
/opt/oracle/app/oracle/diag/tnslsnr/*/listener/trace/listener.log
/opt/oracle/app/oracle/diag/rdbms/[quad,rdfprod]/[quad, rdfprod]/trace/*.trc,*.trm

Common logs (all roles)

/var/log/sa/sa*
/var/log/httpd/[ssl*log]
/var/log/anaconda.*
/var/log/btmp
/var/log/dmesg
/var/log/dracut.log


Understanding Logs

This section contains log excerpts for variuos normal and abnormal events, as follows:

Monit Starts Up

Monit Check Failed

Manually Restarting Monit

Resource Overutilization

Purging /opt

Nagios Starts Up/Shuts Down

Common False Positives

Failure: Core Service is Down for an Extended Period of Time

Rsyslog Starts Up/Shuts Down

Rsyslog is Rate Limited

Service is Down

Analytics Service Initialized Successfully

MapReduce Scheduler Logs

Calendar Logs

Framework Logs

Streams Logs

Monit Starts Up

These log entries are generated during normal monit startup.

Mar 15 20:40:35 quad-web-a monit[19684]: Shutting down monit HTTP server
Mar 15 20:40:35 quad-web-a monit[19684]: monit HTTP server stopped
Mar 15 20:40:35 quad-web-a monit[19684]: monit daemon with pid [19684] killed
Mar 15 20:40:35 quad-web-a monit[19684]: 'system_quad-web-a.example.com' Monit stopped
 
   
Mar 15 20:40:35 quad-web-a monit[27469]: Starting monit daemon with http interface at 
[*:2812]
Mar 15 20:40:35 quad-web-a monit[27469]: Monit start delay set -- pause for 120s
Mar 15 20:42:35 quad-web-a monit[27472]: Starting monit HTTP server at [*:2812]
Mar 15 20:42:35 quad-web-a monit[27472]: monit HTTP server started
Mar 15 20:42:35 quad-web-a monit[27472]: 'system_quad-web-a.example.com' Monit started

Monit Check Failed

These log entries are generated when collectd and httpd are not running and are failing to start:

Mar 15 21:05:27 quad-web-b monit[16949]: 'collectd' process is not running
Mar 15 21:05:27 quad-web-b monit[16949]: 'collectd' trying to restart
Mar 15 21:05:27 quad-web-b monit[16949]: 'collectd' start: /etc/init.d/collectd
 
   
Mar 15 20:17:27 quad-web-a monit[19684]: 'httpd' process is not running
Mar 15 20:17:27 quad-web-a monit[19684]: 'httpd' trying to restart
Mar 15 20:17:27 quad-web-a monit[19684]: 'httpd' start: /etc/init.d/httpd
Mar 15 20:17:57 quad-web-a monit[19684]: 'httpd' failed to start

Manually Restarting Monit

These log entries are generated when a service is restarted manually in which case monit detects the PID change and logs it:

May 22 18:02:13 quad-web-c monit[1811]: 'rsyslog' process PID changed from 1425 to 2959
May 22 18:03:13 quad-web-c monit[1811]: 'rsyslog' process PID has not changed since last 
cycle

Resource Overutilization

These log entries are generated when monit has detected that a resource utilization has gone over the prefedined threshold:

May 27 18:25:11 quad-web-a monit[2236]: 'rsyslog' cpu usage of 50.1% matches resource 
limit [cpu usage>50.0%]

Purging /opt

These log entries are generated when monit has detected that the /opt usage has grown beynd 85% and the purge action has been performed:

Jun  5 01:05:44 quad-test monit[16057]: 'opt' space usage 92.6% matches resource limit 
[space usage>85.0%]
Jun  5 01:05:44 quad-test monit[16057]: 'opt' exec: /bin/bash
Jun  5 01:05:44 quad-test monit: /opt disk usage exceeded 85% threshold. Purging log 
folder: /opt/logs/2012_06_03
 
   

These log entries are generated when "today" is the only remaining folder and there is nothing left to purge:

Jun  5 01:07:44 quad-test monit: /opt disk usage exceeded 85% threshold. Purging log 
folder:

Nagios Starts Up/Shuts Down

These log entries are generated during normal Nagios startup/shutdown.

[1336003714] Nagios 3.3.1 starting... (PID=9416)
[1336003714] Local time is Thu May 03 00:08:34 UTC 2012
[1336003714] LOG VERSION: 2.0
[1336003714] Finished daemonizing... (New PID=9417)
....................
[1335307549] Auto-save of retention data completed successfully.
[1336003770] Caught SIGTERM, shutting down...
[1336003770] Successfully shutdown... (PID=9417)

Common False Positives

These false positives are known to appear:

Node is No Longer Active/Available but Exists in the Topology

Monit service Not Running on a Node

Chart Data Missing for a Node

Node is No Longer Active/Available but Exists in the Topology

[1335313142] SERVICE ALERT: test.example.com;Load: 
midterm;UNKNOWN;HARD;4;check_graphite_stats :err : getData failed 500
[1335296859] SERVICE ALERT: test.example.com;Disk: opt;CRITICAL;SOFT;1;CRITICAL: 
Exception: [Errno 113] No route to host

Monit service Not Running on a Node

 
   

Node name in the example: test.example.com.

[1335946047] SERVICE NOTIFICATION: 
nagiosadmin;test.example.com;cron;CRITICAL;notify-service-by-email;CRITICAL: Exception: 
[Errno 111] Connection refused

Chart Data Missing for a Node

The charts are fed by collectd. If you are missing data for a particular node, look for the collectd log on the Director for that node.

In many cases the counters are either 0 or missing for certain attributes on certain nodes. For example, with ActiveMQ, there is only one active node at any one time. The other node is in standby mode waiting to take over. The resulting log messages look like this for the standby AMQ node:

May 29 16:00:09 quad-queue-2 collectd[3793]: GenericJMXConfValue.query: Querying attribute 
TotalEnqueueCount failed.
May 29 16:00:09 quad-queue-2 collectd[3793]: GenericJMXConfValue.query: getAttribute 
failed: javax.management.RuntimeMBeanException: java.lang.NullPointerException
 
   

This is normal behavior in this case as the other AMQ node is currently active.

Failure: Core Service is Down for an Extended Period of Time

These log entries are generated when a core service has not been running for an extended period of time.

[1335317564] SERVICE ALERT: quad-test.example.com;ntpd;CRITICAL;SOFT;1;CRITICAL: PROCESS 
ntpd: failed to start
[1335317624] SERVICE ALERT: quad-test.example.com;ntpd;CRITICAL;SOFT;2;CRITICAL: PROCESS 
ntpd: failed to start
[1335317684] SERVICE ALERT: quad-test.example.com;ntpd;CRITICAL;SOFT;3;CRITICAL: PROCESS 
ntpd: failed to start
[1335317744] SERVICE ALERT: quad-test.example.com;ntpd;CRITICAL;HARD;4;CRITICAL: PROCESS 
ntpd: failed to start
[1335317744] SERVICE NOTIFICATION: 
test@example.com;quad-test.example.com;ntpd;CRITICAL;notify-service-by-email;CRITICAL: 
PROCESS ntpd: failed to start
[1335318044] SERVICE ALERT: quad-test.example.com;ntpd;OK;HARD;4;OK: Total 1 services are 
monitored
[1335318044] SERVICE NOTIFICATION: 
test@example.com;quad-test.example.com;ntpd;OK;notify-service-by-email;OK: Total 1 
services are monitored
 
   

The text highlighted in red shows that:

There have been four successive failures, which causes Nagios to generate an email alert.

The email address that the alert was sent to (test@example.com).

The text that was sent in the email (the rest of the message).

The very last line shows:

The service recovering (indicated by the OK: Total 1 services are monitored).

The email address that the alert was sent to (test@example.com) informing the service has gone back online.

Rsyslog Starts Up/Shuts Down

These log entries are generated during normal rsyslog startup/shutdown.

May 31 01:22:16 quad-web-a kernel: Kernel logging (proc) stopped.
May 31 01:22:16 quad-web-a rsyslogd: [origin software="rsyslogd" swVersion="5.8.6" 
x-pid="1612" x-info="http://www.rsyslog.com"] exiting on signal 15.
May 31 01:22:17 quad-web-a kernel: imklog 5.8.6, log source = /proc/kmsg started.
May 31 01:22:17 quad-web-a rsyslogd: [origin software="rsyslogd" swVersion="5.8.6" 
x-pid="28666" x-info="http://www.rsyslog.com"] start

Rsyslog is Rate Limited

These log entries are generated when rsyslog has reached the default maximum of 200 input log messages per 5 seconds. Any excess messages are dropped for the process.

May 25 23:37:36 quad-web-a rsyslogd-2177: imuxsock begins to drop messages from pid 2061 
due to rate-limiting
May 25 23:40:02 quad-web-a rsyslogd-2177: imuxsock lost 1085 messages from pid 2061 due to 
rate-limiting

Service is Down

If a service is down, collectd won't be able to collect stats for that service, for example if the Worker service is not running then the Health state manager check fails and collectd logs the following:

Jun  4 21:01:44 quad-web-b collectd[7176]: curl_json plugin: curl_easy_perform failed with 
status 7: couldn't connect to host (http://localhost:8080/monit/status.do?output=json)

If Memcached is not running, you see a message like this:

Jun  7 00:04:24 quad-cache-1 collectd[6847]: memcached: Could not connect to daemon.

Analytics Service Initialized Successfully

This log message appears if the Analytics service on an App Server or Worker node initializes successfully.

AnalyticEventReceiver initialized
 
   

MapReduce Scheduler Logs

Mapreduce jobs are run for analytics and suggestions. Typically, these jobs are run once per day (unless you change the "Analytics Store Cron Job Hour of Day (UTC)" on the Director, in which case the scheduler job might run again for the day when it was changed).

The mapreduce scheduler logs are writen to worker-host-name_analyticsmrscheduler.log. One of the Worker nodes picks up the entire job for execution.

To verify the job has started, look for:

Running Map Reduce Jobs

The end of the job is signified by this message:

-------  MapReduce Jobs completed. Exiting Program  -----------------

To see if all mapreduce jobs completed successfully, run:

cat worker-host-name_analyticsmrscheduler.log | grep 'exitValue'

The command should return something similar to:

Apr 26 00:00:08 ecp-10-194-190-32.example.com analyticsmrscheduler[]: INFO  
[ANALYTICS_MR_SCHEDULER] - [pool-32-thread-2]: Process : cmd = user_library_usage, 
exitValue = 0

An exitValue = 0 signifies that the command has executed successfully. If any command has an exitValue not equal to 0, there is likely some issue executing the mapreduce jobs.

If you see messages similar to "login failed", check for the following:

Execute:

/usr/bin/mongo -u username -p password analytics_store_host:port/dbName /opt/cisco/scheduler/analytics/mapreduce/user_library_usage.js

Verify that username, analytics_store_host, port, and dbName match the respective properties set in portal-ext.properties. If they match, ensure that the credentials are valid for the quadanalytics database on the Analytics Store.

If the credentials look good, but the login still fails, there might be no primary Analytics Store node on the cluster; all available nodes might be in secondary mode. Check if that is the case by running:

db.isMaster();

inside the mongo console on each Analytics Store node.

If you see that there are no scheduler logs being generated, go to the Director > Configuration and check the running schedule (it is set to run at midnight GMT by default). If the schedule run has passed, check if the MessageQueue Scheduler Queue has some messages stuck. If you see the messages are stuck, check if the Worker role shows exceptions. If there are no exceptions, ensure Message Queue is working properly.

Calendar Logs

This section explains the following procedures from logging standpoint:

Getting a Month Worth of Meetings with Configured Domino and WebEx (No Cached Data)

Getting a Month Worth of Meetings with Configured Domino and WebEx (Cached Data)

Getting a Month Worth of Meetings with Configured WebDAV (No Cached Data)

Selecting a Domino Event from the List of Events

Getting a Month Worth of Meetings with Configured Domino and WebEx (No Cached Data)

When you click on the arrow to go to the next month in the Calendar application (assuming that this is the first time you request the data—that is, there is no data in the cache), the application goes through the following steps, logging the respective messages:


Step 1 Display the Domino settings that are used to connect to Domino.

DEBUG 14:07:40,269 | AGGREGATED_CALENDAR:65 | [   ] Using Domino Calendar settings for 
user: "r3". Username: "vmdomino domino", Password: "****", URL: "198.51.100.35", Domain: 
"dominotest"
 
   

Step 2 Try to get the events for Domino from the cache without success.

INFO  14:07:40,279 | AGGREGATED_CALENDAR:78 | [   ] getCachedListEvents:[AggCalCacheUtil]: 
Cache miss for [Mail-Chain-10195-14610005_Sat Mar 31 21:00:00 GMT 2012_Sat May 05 20:59:59 
GMT 2012] - we got 0 meetings
 
   

Step 3 Try to get the events for WebEx from the cache without success.

INFO  14:07:40,279 | AGGREGATED_CALENDAR:78 | [   ] getCachedListEvents:[AggCalCacheUtil]: 
Cache miss for [WebEx-Chain-10195-14610005_Sat Mar 31 21:00:00 GMT 2012_Sat May 05 
20:59:59 GMT 2012] - we got 0 meetings
 
   

Step 4 Display the period for which the events are being retrieved from Domino.

INFO  14:07:40,279 | AGGREGATED_CALENDAR:78 | [   ] Get events from Sat Mar 31 21:00:00 
GMT 2012 to Sat May 05 20:59:59 GMT 2012
 
   

Step 5 Display the period for which the events are being retrieved from WebEx.

INFO  14:07:40,281 | AGGREGATED_CALENDAR:78 | [   ] Get events from Sat Mar 31 21:00:00 
GMT 2012 to Sat May 05 20:59:59 GMT 2012
 
   

Step 6 Successful creation of a Domino session.

INFO  14:07:40,289 | AGGREGATED_CALENDAR:78 | [   ] Domino session was successfully 
created for user: vmdomino domino
 
   

Step 7 Execute a query to get the events from Domino.

DEBUG 14:07:40,293 | AGGREGATED_CALENDAR:65 | [   ] SELECT 
((@IsAvailable(CalendarDateTime) & (@Explode(CalendarDateTime) *= 
@Explode(@TextToTime("04/01/2012 12:00:00 AM ZE2-05/05/2012 11:59:59 PM ZE2")))) | 
(@IsAvailable(EndDateTime) & (@Explode(EndDateTime) *= @Explode(@TextToTime("04/01/2012 
12:00:00 AM ZE2-05/05/2012 11:59:59 PM ZE2")))) & @IsUnavailable(FailureReason) & 
(@IsAvailable(AppointmentType) & AppointmentType <> "1" & AppointmentType <> "4") & (Form 
= "Appointment"))
 
   

Step 8 Parse each Domino meeting attendees by common name (CN).

DEBUG 14:07:40,376 | AGGREGATED_CALENDAR:65 | [   ] Search user document for common name: 
CN=gp gp
DEBUG 14:07:40,386 | AGGREGATED_CALENDAR:65 | [   ] Search user document for common name: 
CN=r2@example.com
DEBUG 14:07:40,388 | AGGREGATED_CALENDAR:65 | [   ] Search user document for common name: 
CN=vmdomino domino

Step 9 Output each Domino meeting after we have processed it.

TRACE 14:07:40,397 | AGGREGATED_CALENDAR:53 | [   ] Events:
[eventId : 594B9C51FA2258CCC22579AC00431138 - 1335862800000 - 1335872700000
subject : Domino - host
    location :
    organizer :
    email : vmdomino @ dominotest.com
    screenName : vmdomino
    fullName : vmdomino domino
    attendees : [
        email : gp @ dominotest.com
        screenName : ggp
        fullName : gp gp,
        email : r2 @ example.com
        screenName :
        fullame : r2 @ example.com]
    nonSendableTo : null
    required : null
    resource : null
    htmlDescription : null
    hasattachment : false
    importance : null
    allDayEvent : false
    reminderOffset : null
    href : null
    busyStatus : BUSY
    textDescription : THis is some rich text
    Lets see what goes to the client
    startDate : Tue May 01 09 : 00 : 00 GMT 2012
    endDate : Tue May 01 11 : 45 : 00 GMT 2012
    isRecurring : false
    recurrencePattern : null
    hasPartialMeetingData : false
    webExDetails : {
        null
    }
]
 
   

Step 10 Cache asynchronously the list of received Domino events.

DEBUG 14:37:41,408 | AGGREGATED_CALENDAR:65 | [   ] cacheListEvents:[AggCalCacheUtil]: 
[26] meetings cached for [Mail-Chain-10195-14610005_Sat Mar 31 21:00:00 GMT 2012_Sat May 
05 20:59:59 GMT 2012]
 
   

Step 11 Cache asynchronously each Domino event.

DEBUG 14:37:41,410 | AGGREGATED_CALENDAR:65 | [   ] cacheMeeting:[AggCalCacheUtil]: 
Meeting cached for 
[DCAED24B00328A37C22579B90057D567-1333375200000-1333378800000-10195-14610005]
DEBUG 14:37:41,410 | AGGREGATED_CALENDAR:65 | [   ] cacheMeeting:[AggCalCacheUtil]: 
Meeting cached for 
[0DE08C580301255FC22579DC002A8062-1334066400000-1334070000000-10195-14610005]
DEBUG 14:37:41,410 | AGGREGATED_CALENDAR:65 | [   ] cacheMeeting:[AggCalCacheUtil]: 
Meeting cached for 
[E371DB4510E56367C22579DC002E5EA8-1334133900000-1334134800000-10195-14610005]
DEBUG 14:37:41,411 | AGGREGATED_CALENDAR:65 | [   ] cacheMeeting:[AggCalCacheUtil]: 
Meeting cached for 
[2426637EABDBD784C22579DC002C3108-1334140200000-1334143800000-10195-14610005]
DEBUG 14:37:41,411 | AGGREGATED_CALENDAR:65 | [   ] cacheMeeting:[AggCalCacheUtil]: 
Meeting cached for 
[4D3E6229EF5DCA07C22579DC002D2EEF-1334483100000-1334484000000-10195-14610005]
...
 
   

Step 12 Cache asynchronously the list of received WebEx events.

DEBUG 14:37:44,377 | AGGREGATED_CALENDAR:65 | [   ] cacheListEvents:[AggCalCacheUtil]: 
[20] meetings cached for [WebEx-Chain-10195-14610005_Sat Mar 31 21:00:00 GMT 2012_Sat May 
05 20:59:59 GMT 2012]
 
   

Getting a Month Worth of Meetings with Configured Domino and WebEx (Cached Data)

When you click on the arrow to go to the next month in the Calendar application (assuming that this is not the first time you request the data—that is, there is data in the cache), the application logs the following messages:

INFO  12:50:05,479 | AGGREGATED_CALENDAR:78 | [   ] getCachedListEvents:[AggCalCacheUtil]: 
Cache hit for [WebEx-Chain-10195-14610005_Sat Mar 31 21:00:00 GMT 2012_Sat May 05 20:59:59 
GMT 2012] - we got 20 meetings
INFO  12:50:05,479 | AGGREGATED_CALENDAR:78 | [   ] getCachedListEvents:[AggCalCacheUtil]: 
Cache hit for [Mail-Chain-10195-14610005_Sat Mar 31 21:00:00 GMT 2012_Sat May 05 20:59:59 
GMT 2012] - we got 26 meetings
 
   

Getting a Month Worth of Meetings with Configured WebDAV (No Cached Data)

When you click on the arrow to go to the next month in the Calendar application (assuming this that is the first time you request the data—that is, there is no data in the cache), the application goes through the following steps, logging the respective messages:


Step 1 Display the Exchange settings that are used to connect to Exchange.

DEBUG 13:52:37,382 | AGGREGATED_CALENDAR:65 | [   ] Using Exchange Calendar settings for 
user: "r2". Username: "vm2007", Password: "****", URL: 
"https://198.51.100.35/exchange/vm2007/", Domain: ""
 
   

Step 2 Try to get the events for Exchange from the cache without success.

INFO  13:52:37,385 | AGGREGATED_CALENDAR:78 | [   ] getCachedListEvents:[AggCalCacheUtil]: 
Cache miss for [Mail-Chain-10195-1410026_Sun Mar 25 21:00:00 GMT 2012_Sun May 06 20:59:59 
GMT 2012] - we got 0 meetings

Step 3 Execute a WebDAV query to log into WebDAV.

DEBUG 13:52:37,421 | AGGREGATED_CALENDAR:65 | [   ] Search Query:
<?xml version='1.0'?><d:searchrequest xmlns:d="DAV:"><d:sql>SELECT 
"urn:schemas:httpmail:subject", 
"urn:schemas:calendar:location","urn:schemas:mailheader:to", 
"urn:schemas:mailheader:cc","http://schemas.microsoft.com/mapi/nonsendableto","urn:schemas
:mailheader:from","urn:schemas:calendar:organizer", 
"urn:schemas:calendar:uid","urn:schemas:calendar:instancetype", 
"urn:schemas:httpmail:htmldescription", "urn:schemas:httpmail:hasattachment", 
"urn:schemas:calendar:busystatus", "urn:schemas:httpmail:textdescription", 
"urn:schemas:calendar:alldayevent", "urn:schemas:calendar:reminderoffset", 
"urn:schemas:calendar:dtstart","urn:schemas:calendar:dtend", 
"urn:schemas:calendar:created", "urn:schemas:calendar:recurrenceid", 
"urn:schemas:calendar:lastmodified"  FROM Scope('SHALLOW TRAVERSAL OF 
"https://198.51.100.35/exchange/vm2007/calendar"') WHERE NOT 
"urn:schemas:calendar:instancetype" = 1 AND "urn:schemas:calendar:dtend" &lt;= 
CAST("2012-04-27T13:52:37.421Z" as 'dateTime') AND  "urn:schemas:calendar:dtstart" &gt;= 
CAST("2012-04-26T13:52:37.421Z" as 'dateTime')  ORDER BY "urn:schemas:calendar:dtstart" 
ASC </d:sql></d:searchrequest>

Step 4 Get the response.

INFO  13:52:37,440 | AGGREGATED_CALENDAR:78 | [   ] Number of events we got: 0
TRACE 13:52:37,441 | AGGREGATED_CALENDAR:53 | [   ] Response Document: <?xml version="1.0" 
encoding="UTF-16"?><a:multistatus xmlns:a="DAV:" 
xmlns:b="urn:uuid:c2f41010-65b3-11d1-a29f-00aa00c14882/" xmlns:c="xml:" 
xmlns:d="urn:schemas:httpmail:" xmlns:e="urn:schemas:calendar:" 
xmlns:f="urn:schemas:mailheader:" xmlns:g="http://schemas.microsoft.com/mapi/"/>

Step 5 Execute another WebDav query to get the events for the month.

DEBUG 13:52:37,441 | AGGREGATED_CALENDAR:65 | [   ] login exchange server sucessful
DEBUG 13:52:37,442 | AGGREGATED_CALENDAR:65 | [   ] resolveMailServerInfo(() success code: 
200
DEBUG 13:52:37,442 | AGGREGATED_CALENDAR:65 | [   ] Search Query:
<?xml version='1.0'?><d:searchrequest xmlns:d="DAV:"><d:sql>SELECT 
"urn:schemas:httpmail:subject", 
"urn:schemas:calendar:location","urn:schemas:mailheader:to", 
"urn:schemas:mailheader:cc","http://schemas.microsoft.com/mapi/nonsendableto", 
"urn:schemas:mailheader:from", "urn:schemas:calendar:organizer", 
"urn:schemas:calendar:uid","urn:schemas:calendar:instancetype", 
"urn:schemas:httpmail:htmldescription", "urn:schemas:httpmail:hasattachment", 
"urn:schemas:calendar:busystatus","urn:schemas:httpmail:textdescription", 
"urn:schemas:calendar:alldayevent","urn:schemas:calendar:reminderoffset", 
"urn:schemas:calendar:dtstart","urn:schemas:calendar:dtend", 
"urn:schemas:calendar:created", "urn:schemas:calendar:recurrenceid", 
"urn:schemas:calendar:lastmodified"  FROM Scope('SHALLOW TRAVERSAL OF 
"https://198.51.100.35/exchange/vm2007/calendar"') WHERE NOT 
"urn:schemas:calendar:instancetype" = 1 AND "urn:schemas:calendar:dtend" &lt;= 
CAST("2012-05-06T20:59:59.999Z" as 'dateTime') AND  "urn:schemas:calendar:dtstart" &gt;= 
CAST("2012-03-25T21:00:00.000Z" as 'dateTime')  ORDER BY "urn:schemas:calendar:dtstart" 
ASC </d:sql></d:searchrequest>
 
   

Step 6 Get the response.

INFO  13:52:37,466 | AGGREGATED_CALENDAR:78 | [   ] Number of events we got: 7
TRACE 13:52:37,475 | AGGREGATED_CALENDAR:53 | [   ] Response Document: <?xml version="1.0" 
encoding="UTF-16"?><a:multistatus xmlns:a="DAV:" 
xmlns:b="urn:uuid:c2f41010-65b3-11d1-a29f-00aa00c14882/" xmlns:c="xml:" 
xmlns:d="urn:schemas:httpmail:" xmlns:e="urn:schemas:calendar:" 
xmlns:f="urn:schemas:mailheader:" xmlns:g="http://schemas.microsoft.com/mapi/">
   <a:response>
      <a:href>https://198.51.100.35/exchange/vm2007/Calendar/Have%20fun-5.EML</a:href>
      <a:propstat>
         <a:status>HTTP/1.1 200 OK</a:status>
         <a:prop>
            <d:subject>Have fun</d:subject>
            <e:location>some location</e:location>  <e:uid> 
040000008200E00074C5B7101A82E008000000006C327C3319FDCC010000000000000000100000003AD41318CF
A170488967581FBBC63202 </e:uid>            <e:instancetype b:dt="int">3</e:instancetype>
            <d:htmldescription>&lt;!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 3.2//EN"&gt;
&lt;HTML&gt;
&lt;HEAD&gt;
&lt;META HTTP-EQUIV="Content-Type" CONTENT="text/html; charset=utf-8"&gt;
&lt;META NAME="Generator" CONTENT="MS Exchange Server version 08.03.0083.000"&gt;
&lt;TITLE&gt;Have fun&lt;/TITLE&gt;
&lt;/HEAD&gt;
&lt;BODY&gt;
&lt;!-- Converted from text/plain format --&gt;&lt;P&gt;&lt;FONT SIZE=2&gt;When: 
Wednesday, March 28, 2012 3:00 AM-4:00 AM. (GMT-08:00) Pacific Time (US &amp;amp; 
Canada)&lt;BR&gt;
Where: some location&lt;BR&gt;
&lt;BR&gt;
*~*~*~*~*~*~*~*~*~*&lt;BR&gt;
&lt;BR&gt;
&amp;nbsp;some body here&lt;BR&gt;&lt;/FONT&gt;
&lt;/P&gt;
&lt;/BODY&gt;
&lt;/HTML&gt;</d:htmldescription>
            <d:hasattachment b:dt="boolean">0</d:hasattachment>
            <e:busystatus>TENTATIVE</e:busystatus>
            <d:textdescription>When: Wednesday, March 28, 2012 3:00 AM-4:00 AM. 
(GMT-08:00) Pacific Time (US &amp; Canada)
Where: some location
*~*~*~*~*~*~*~*~*~* 
some body here
</d:textdescription>
            <e:alldayevent b:dt="boolean">0</e:alldayevent>
            <e:reminderoffset b:dt="int">900</e:reminderoffset>
            <e:dtstart b:dt="dateTime.tz">2012-03-28T10:00:00.000Z</e:dtstart>
            <e:dtend b:dt="dateTime.tz">2012-03-28T11:00:00.000Z</e:dtend>
            <e:created b:dt="dateTime.tz">2012-03-08T10:49:58.000Z</e:created>
            <e:recurrenceid b:dt="dateTime.tz">2012-03-11T10:00:00.000Z</e:recurrenceid>
            <e:lastmodified b:dt="dateTime.tz">2012-04-10T14:29:08.000Z</e:lastmodified>
         </a:prop>
      </a:propstat>
      <a:propstat>
         <a:status>HTTP/1.1 404 Resource Not Found</a:status>
         <a:prop>
            <f:to/>
            <f:cc/>
            <g:nonsendableto/>
            <f:from/>
            <e:organizer/>
         </a:prop>
      </a:propstat>
   </a:response>
   ...
</a:multistatus>

Step 7 Receive a warning because there is a meeting without an organizer.

WARN  13:52:37,505 | AGGREGATED_CALENDAR:90 | [   ] Failed to get organizer for WebDav 
event [Have fun] with ID 
[040000008200E00074C5B7101A82E008000000006C327C3319FDCC010000000000000000100000003AD41318C
FA170488967581FBBC63202@2012-03-11T10:00:00.000Z]
DEBUG 13:52:37,508 | AGGREGATED_CALENDAR:65 | [   ] <?xml version="1.0" 
encoding="UTF-16"?><a:response xmlns:a="DAV:">
   <a:href>https://198.51.100.35/exchange/vm2007/Calendar/Have%20fun-5.EML</a:href>
   <a:propstat>
      <a:status>HTTP/1.1 200 OK</a:status>
      <a:prop>
         <d:subject xmlns:d="urn:schemas:httpmail:">Have fun</d:subject>
         <e:location xmlns:e="urn:schemas:calendar:">some location</e:location>
         <e:uid xmlns:e="urn:schemas:calendar:"> 
040000008200E00074C5B7101A82E008000000006C327C3319FDCC010000000000000000100000003AD41318CF
A170488967581FBBC63202 </e:uid>
         <e:instancetype xmlns:e="urn:schemas:calendar:" 
xmlns:b="urn:uuid:c2f41010-65b3-11d1-a29f-00aa00c14882/" b:dt="int">3</e:instancetype>
         <d:htmldescription xmlns:d="urn:schemas:httpmail:">&lt;!DOCTYPE HTML PUBLIC 
"-//W3C//DTD HTML 3.2//EN"&gt;
&lt;HTML&gt;
&lt;HEAD&gt;
&lt;META HTTP-EQUIV="Content-Type" CONTENT="text/html; charset=utf-8"&gt;
&lt;META NAME="Generator" CONTENT="MS Exchange Server version 08.03.0083.000"&gt;
&lt;TITLE&gt;Have fun&lt;/TITLE&gt;
&lt;/HEAD&gt;
&lt;BODY&gt;
&lt;!-- Converted from text/plain format --&gt;&lt;P&gt;&lt;FONT SIZE=2&gt;When: 
Wednesday, March 28, 2012 3:00 AM-4:00 AM. (GMT-08:00) Pacific Time (US &amp;amp; 
Canada)&lt;BR&gt;
Where: some location&lt;BR&gt;&lt;BR&gt;
*~*~*~*~*~*~*~*~*~*&lt;BR&gt;&lt;BR&gt;&amp;nbsp;some body 
here&lt;BR&gt;&lt;/FONT&gt;&lt;/P&gt;&lt;/BODY&gt;&lt;/HTML&gt;</d:htmldescription>
<d:hasattachment xmlns:d="urn:schemas:httpmail:" 
xmlns:b="urn:uuid:c2f41010-65b3-11d1-a29f-00aa00c14882/" 
b:dt="boolean">0</d:hasattachment>
<e:busystatus xmlns:e="urn:schemas:calendar:">TENTATIVE</e:busystatus>
<d:textdescription xmlns:d="urn:schemas:httpmail:">When: Wednesday, March 28, 2012 3:00 
AM-4:00 AM. (GMT-08:00) Pacific Time (US &amp; Canada) Where: some 
location*~*~*~*~*~*~*~*~*~* some body here
</d:textdescription>
         <e:alldayevent xmlns:e="urn:schemas:calendar:" 
xmlns:b="urn:uuid:c2f41010-65b3-11d1-a29f-00aa00c14882/" b:dt="boolean">0</e:alldayevent>
         <e:reminderoffset xmlns:e="urn:schemas:calendar:" 
xmlns:b="urn:uuid:c2f41010-65b3-11d1-a29f-00aa00c14882/" b:dt="int">900</e:reminderoffset>
         <e:dtstart xmlns:e="urn:schemas:calendar:" 
xmlns:b="urn:uuid:c2f41010-65b3-11d1-a29f-00aa00c14882/" 
b:dt="dateTime.tz">2012-03-28T10:00:00.000Z</e:dtstart>
         <e:dtend xmlns:e="urn:schemas:calendar:" 
xmlns:b="urn:uuid:c2f41010-65b3-11d1-a29f-00aa00c14882/" 
b:dt="dateTime.tz">2012-03-28T11:00:00.000Z</e:dtend>
         <e:created xmlns:e="urn:schemas:calendar:" 
xmlns:b="urn:uuid:c2f41010-65b3-11d1-a29f-00aa00c14882/" 
b:dt="dateTime.tz">2012-03-08T10:49:58.000Z</e:created>
         <e:recurrenceid xmlns:e="urn:schemas:calendar:" 
xmlns:b="urn:uuid:c2f41010-65b3-11d1-a29f-00aa00c14882/" 
b:dt="dateTime.tz">2012-03-11T10:00:00.000Z</e:recurrenceid>
         <e:lastmodified xmlns:e="urn:schemas:calendar:" 
xmlns:b="urn:uuid:c2f41010-65b3-11d1-a29f-00aa00c14882/" 
b:dt="dateTime.tz">2012-04-10T14:29:08.000Z</e:lastmodified>
      </a:prop>
   </a:propstat>
   <a:propstat>
      <a:status>HTTP/1.1 404 Resource Not Found</a:status>
      <a:prop>
         <f:to xmlns:f="urn:schemas:mailheader:"/>
         <f:cc xmlns:f="urn:schemas:mailheader:"/>
         <g:nonsendableto xmlns:g="http://schemas.microsoft.com/mapi/"/>
         <f:from xmlns:f="urn:schemas:mailheader:"/>
         <e:organizer xmlns:e="urn:schemas:calendar:"/>
      </a:prop>
   </a:propstat>
</a:response>
DEBUG 13:52:37,509 | AGGREGATED_CALENDAR:65 | [   ] Event with missing information, 
subject:Have fun

Step 8 Query for additional event details.

DEBUG 13:52:37,509 | AGGREGATED_CALENDAR:65 | [   ] Search Query:
<?xml version='1.0'?><d:searchrequest xmlns:d="DAV:"><d:sql>SELECT 
"urn:schemas:mailheader:to" ,"urn:schemas:mailheader:cc", "urn:schemas:mailheader:from" , 
"urn:schemas:calendar:organizer"  FROM Scope('SHALLOW TRAVERSAL OF 
"https://198.51.100.35/exchange/vm2007/calendar"')  WHERE 
"urn:schemas:calendar:instancetype" = 1 AND "urn:schemas:calendar:uid" = 
'040000008200E00074C5B7101A82E008000000006C327C3319FDCC010000000000000000100000003AD41318C
FA170488967581FBBC63202' </d:sql></d:searchrequest>
INFO  13:52:37,518 | AGGREGATED_CALENDAR:78 | [   ] Number of events we got: 1
TRACE 13:52:37,519 | AGGREGATED_CALENDAR:53 | [   ] Response Document: <?xml version="1.0" 
encoding="UTF-16"?><a:multistatus xmlns:a="DAV:" 
xmlns:b="urn:uuid:c2f41010-65b3-11d1-a29f-00aa00c14882/" xmlns:c="xml:" 
xmlns:d="urn:schemas:mailheader:" xmlns:e="urn:schemas:calendar:">
   <a:response>
      <a:href>https://198.51.100.35/exchange/vm2007/Calendar/Have%20fun.EML</a:href>
      <a:propstat>
         <a:status>HTTP/1.1 200 OK</a:status>
         <a:prop>
            <d:to>"vm2010" &lt;vm2010@ex7aquila.com&gt;, "vm2007" 
&lt;vm2007@ex7aquila.com&gt;</d:to>
            <d:cc>&lt;vm2003@ex3aquila.com&gt;</d:cc>
            <d:from>"vm2010" &lt;vm2010@ex7aquila.com&gt;</d:from>
            <e:organizer>"vm2010" &lt;vm2010@ex7aquila.com&gt;</e:organizer>
         </a:prop>
      </a:propstat>
   </a:response>
</a:multistatus>
 
   

Step 9 Dump all returned events.

DEBUG 13:52:37,521 | AGGREGATED_CALENDAR:65 | [   ] Event Object: 
eventId:040000008200E00074C5B7101A82E008000000006C327C3319FDCC010000000000000000100000003A
D41318CFA170488967581FBBC63202@2012-03-11T10:00:00.000Z subject:Have fun
location: some location
organizer:
email : vm2010@ex7aquila.com
screenName :
fullName : vm2010
attendees: [
    email : vm2007@ex7aquila.com
    screenName :
    fullName : vm2007,
    email : vm2003@ex3aquila.com
    screenName :
    fullName : ]
nonSendableTo:
required: null
resource: null
htmlDescription: null
hasattachment: false
importance: null
allDayEvent: false
reminderOffset: 900
href: https://198.51.100.35/exchange/vm2007/Calendar/Have%20fun-5.EML
busyStatus: TENTATIVE
textDescription:When: Wednesday, March 28, 2012 3:00 AM-4:00 AM. (GMT-08:00) Pacific Time 
(US & Canada)
Where: some location *~*~*~*~*~*~*~*~*~* some body here
startDate: Wed Mar 28 10:00:00 GMT 2012
endDate: Wed Mar 28 11:00:00 GMT 2012
isRecurring: true
recurrencePattern: null
hasPartialMeetingData: false
webExDetails: {
    null
}
DEBUG 13:52:37,531 | AGGREGATED_CALENDAR:65 | [   ] Event Object:
  
eventId:040000008200E00074C5B7101A82E008000000006C5CD2E7F2F2CC01000000000000000010000000A6
30507C9F849A4D9D57EC07207E54ED@
subject:VM2010 is a host vm 2007 is invitee
location: Location
organizer:
email : vm2010@ex7aquila.com
screenName :
fullName : vm2010
attendees: [
    email : vm2007@ex7aquila.com
    screenName :
   fullName : vm2007]
nonSendableTo:
required: null
resource: null
htmlDescription: null
hasattachment: false
importance: null
allDayEvent: false
reminderOffset: 900
href: 
https://198.51.100.35/exchange/vm2007/Calendar/VM2010%20is%20a%20host%20vm%202007%20is%20i
nvitee-2.EML
busyStatus: TENTATIVE
textDescription:When: Wednesday, March 28, 2012 11:00 AM-12:00 PM. (GMT-08:00) Pacific 
Time (US & Canada)
Where: Location *~*~*~*~*~*~*~*~*~* Body
startDate: Wed Mar 28 18:00:00 GMT 2012
endDate: Wed Mar 28 19:00:00 GMT 2012
isRecurring: false
recurrencePattern: null
hasPartialMeetingData: false
webExDetails: {
    null
}
...

Step 10 Cache asynchronously the list of received WebDav events.

	DEBUG 13:52:37,567 | AGGREGATED_CALENDAR:65 | [   ] cacheListEvents:[AggCalCacheUtil]: 
[7] meetings cached for [Mail-Chain-10195-1410026_Sun Mar 25 21:00:00 GMT 2012_Sun May 06 
20:59:59 GMT 2012]
 
   

Step 11 Cache asynchronously each WebDav event.

DEBUG 13:52:37,568 | AGGREGATED_CALENDAR:65 | [   ] cacheMeeting:[AggCalCacheUtil]: 
Meeting cached for 
[040000008200E00074C5B7101A82E008000000006C327C3319FDCC010000000000000000100000003AD41318C
FA170488967581FBBC63202@2012-03-11T10:00:00.000Z-10195-1410026]

...

Selecting a Domino Event from the List of Events

The following messages are logged when a Domino event is clicked to be expanded in the list of events. The event has not been previously cached.


Step 1 Initiating call to the VDL local service.

DEBUG 14:37:44,494 | AGGREGATED_CALENDAR:65 | [   ] getMeetingDetails() method from 
AggregatedCalendarLocalServiceImpl called.
 
   

Step 2 Display the Domino settings that are used to connect to Domino.

DEBUG 14:37:44,504 | AGGREGATED_CALENDAR:65 | [   ] Using Domino Calendar settings for 
user: "r3". Username: "vmdomino domino", Password: "****", URL: "198.51.100.35", Domain: 
"dominotest"
 
   

Step 3 Try to get the events for Domino from the cache without success.

INFO  14:37:44,507 | AGGREGATED_CALENDAR:78 | [   ] getCachedEvent:[AggCalCacheUtil]: 
Cache miss for 
[C5F48FA61382B436C22579DE003AE145-1335456000000-1335459600000-10195-14610005]

Step 4 Initiate a call to the Domino server.

INFO  14:37:44,507 | AGGREGATED_CALENDAR:78 | [   ] Get events with ID 
C5F48FA61382B436C22579DE003AE145-1335456000000-1335459600000
INFO  14:37:44,512 | AGGREGATED_CALENDAR:78 | [   ] Domino session was successfully 
created for user: vmdomino domino

Step 5 Log a message just before the Domino call is initiated.

DEBUG 14:37:44,527 | AGGREGATED_CALENDAR:65 | [   ] Get meeting details for event: 
C5F48FA61382B436C22579DE003AE145-1335456000000-1335459600000

Step 6 Parse each Domino meeting attendees by common name (CN).

DEBUG 14:37:44,534 | AGGREGATED_CALENDAR:65 | [   ] Search user document for common name: 
CN=vmdomino domino
DEBUG 14:37:44,544 | AGGREGATED_CALENDAR:65 | [   ] Search user document for common name: 
CN=no mail

Step 7 Cache the event after it has been successfully retrieved.

DEBUG 14:37:44,557 | AGGREGATED_CALENDAR:65 | [   ] cacheMeeting:[AggCalCacheUtil]: 
Meeting cached for 
[C5F48FA61382B436C22579DE003AE145-1335456000000-1335459600000-10195-14610005]

Framework Logs

This section is organized as follows:

Incorrect Theme ID

Incorrect Theme ID

ERROR [org.apache.velocity] - [TP-Processor49]: Exception in macro #content_include called 
at _SERVLET_CONTEXT_/html/themes/classic/templates/portal_normal.vm[line 559, column 33]

If you see this error, it is probably the theme ID that is misconfigured. Check if these advanced portal properties have values as follows:

default.regular.theme.id = albani

control.panel.layout.regular.theme.id = albani

Streams Logs

This section is organized as follows:

Errors During Interpretation

VDL Backend Debugging

Errors During Interpretation

The most common exceptions when interpreting social activities are due to permission related errors 
(when accessing resources like documents or images). If any other type of exception appears when 
interpreting a social activity, that activity is ignored when displaying the list of activities to the user in 
which case you would usually see a log entry similar to:
 
   
quad-web-2.example.com 2012-04-17 20:52:22,522 ERROR [socialActivities] - [TP-Processor42] 
- [alafemin] - [10B879E3B61F30994AEE245D77F8F84B.quad-web-2.example.comjvm]: 
PostActivityInterpreter.doInterpretToJSON : Cannot interpret private activity.
 
   
quad-web-2.example.com 2012-04-17 20:52:22,523 ERROR 
[social.model.BaseSocialActivityInterpreter] - [TP-Processor42] - [alafemin] - 
[10B879E3B61F30994AEE245D77F8F84B.quad-web-2.example.comjvm]: Unable to interpret activity
 com.liferay.portal.PortalException: Cannot interpret private activity.
 
   

Note that this type of error is logged even for activities that are excluded from the user Streams for normal reasons such as privacy so they do not necessarily mean exceptions.

VDL Backend Debugging

If you want to debug Streams API calls on the backend, enable Debug logging for SocialActivity Application (see Streams FAQs) then look for the following in the App Server logs:

When you refresh the Home page or navigate to it:

Apr 25 18:08:01 ecp-10-194-189-67.example.com quad[]: DEBUG [socialActivities] - 
[TP-Processor47]: getUserActivities for 110060: Start
Apr 25 18:08:01 ecp-10-194-189-67.example.com quad[]: DEBUG [socialActivities] - 
[TP-Processor47]: getUserActivities for 110060, ResultSize:1, Time:21msecs: End
 
   

Where:

getUserActivities is the API called, 110060 is the userid, ResultSize shows how many activities have been returned, Time shows how long this call took.

When you navigate to your profile:

Apr 25 18:32:16 ecp-10-194-189-67.example.com quad[]: DEBUG [socialActivities] - 
[TP-Processor44]: getUserPublicActivities for 110060: Start
Apr 25 18:32:16 ecp-10-194-189-67.example.com quad[]: DEBUG [socialActivities] - 
[TP-Processor44]: getUserPublicActivities for 110060, ResultSize:3, Time:2msecs: End
 
   

When you navigate to the profile of another user:

Apr 25 18:37:06 ecp-10-194-189-67.example.com quad[]: DEBUG [socialActivities] - 
[TP-Processor47]: getUserPulbicActivities for 110112: Start
Apr 25 18:37:06 ecp-10-194-189-67.example.com quad[]: DEBUG [socialActivities] - 
[TP-Processor47]: getUserPublicActivities for 110112, ResultSize:1, Time:1msecs: End
 
   

Where:

1100112 is user ID of the user whose profile activities you are requesting.

If a certain activity does not appear on the Home page, check if it is supposed to be there. If it is supposed to appear, then check the logs for errors.

If there is an error returning the activity to the user interface, you see a warning like this followed by an exception:

Ignoring activity due to an error while building activity entry for cnId = 
<classname_id>, cpk = <postid or documentid etc.>
 
   

If there is an error during the activity creation process, it is logged. The example that follows is for a successful post creation activity. In case of an error you see the start message but not the end message and an exception is logged.

Apr 25 18:36:42 ecp-10-194-189-67.example.com quad[]: DEBUG [socialActivities] - 
[TP-Processor44]: handleSync for POST_CREATE: classNameId =  10060, classPK= 2500002: 
Start
Apr 25 18:36:42 ecp-10-194-189-67.example.com quad[]: DEBUG [socialActivities] - 
[TP-Processor44]: PostActivityHandler:handleSynchProcess: for POST_CREATE: classNameId 
=  10060, classPK= 2500002: Start
Apr 25 18:36:42 ecp-10-194-189-67.example.com quad[]: DEBUG [socialActivities] - 
[TP-Processor44]: PostActivityHandler:handleSynchProcess: for POST_CREATE: classNameId 
=  10060, classPK= 2500002, Time:7msecs: End
Apr 25 18:36:42 ecp-10-194-189-67.example.com quad[]: DEBUG [socialActivities] - 
[TP-Processor44]: handleSync for POST_CREATE: classNameId =  10060, classPK= 2500002, 
Time:7msecs: End
 
   

If DEBUG has been enabled for the QUAD_EVENTING log category:

Apr 25 18:36:42 ecp-10-194-189-67.example.com quad[]: DEBUG [QUAD_EVENTING] - 
[TP-Processor44]: Sending event POST_CREATE
Apr 25 18:36:42 ecp-10-194-189-67.example.com quad[]: DEBUG [QUAD_EVENTING] - 
[TP-Processor44]: Event content for event: POST_CREATE: 
{"addedRecipients":[{"class":"com.cisco.ecp.vdl.post.model.impl.PostRecipientImpl","id
":110112,"permission":{"allPermissions":null,"authorize":true,"authorized":true,"class
":"com.cisco.ecp.vdl.post.model.impl.PostPermissionImpl","comment":true,"commentable":
true,"edit":true,"editable":true,"share":true,"shared":true,"view":true,"viewable":tru
e},"recipientType":"USER"}],"attachmentInfo":{"attachments":[],"class":"com.cisco.ecp.
vdl.attachment.PostAttachmentInfoImpl","postVersion":1,"tnailURLs":[],"totalNumAttachm
ents":0},"class":"com.cisco.ecp.vdl.event.model.impl.post.PostCreateEvent","classNameI
d":10060,"classPK":2500002,"clientIp"...
Apr 25 18:36:42 ecp-10-194-189-67.example.com ...: 
0,"companyId":10193,"content":"hello 
sucharitha","eventCreatorFirstName":"shanthi","eventCreatorMedium1PortraitId":110561,"
eventCreatorMedium2PortraitId":110562,"eventCreatorMedium3PortraitId":3610011,"eventCr
eatorName":"shanthi 
n","eventCreatorScreenName":"shanthi","eventCreatorSmallPortraitId":110560,"eventCreat
orUserId":110112,"eventCreatorUtil":null,"eventTime":1335379001899,"eventType":"POST_C
REATE","excludes":["addedRecipients.recipient"],"extraAttributes":null,"includes":null
,"mentionedUsers":[],"ownerName":"shanthi 
n","ownerScreenName":"shanthi","ownerUserId":110112,"postType":"MICRO_POST","publicSco
pe":true,"quadServerIp":0,"question":false,"quickComment":"","tags":[],"title":"hello 
sucharitha","version":1}