Fun with Linux disks

So this morning, when I landed into work, I saw an unexpected set of symptoms from my partially built IBM Business Monitor environment.

First of all, I saw this when I attempted to list my WAS profiles: -

$ /opt/IBM/WebSphere/AppServer/profiles/BAMDMProfile/bin/manageprofiles.sh -list 

JVMSHRC226E Error opening shared class cache file 
JVMSHRC336E Port layer error code = -300 
JVMSHRC337E Platform error message: Read-only file system 
JVMJ9VM015W Initialization error for library j9shr26(11): JVMJ9VM009E J9VMDllMain failed 
Could not create the Java virtual machine.

Then I saw these errors: -

<snip>

[3/1/13 15:30:05:202 GMT] 0000001c MMRoutingConf E com.ibm.wbimonitor.lifecycle.routing.MMRoutingConfigFlowDaemon checkForStateChanges CWMLC0274E: An error occurred while trying to determine the state of an MM.  This will be retried shortly.  The condition was caused by: com.ibm.wbimonitor.persistence.metamodel.spi.MetaModelPersistenceException: com.ibm.db2.jcc.am.SqlSyntaxErrorException: DB2 SQL Error: SQLCODE=-204, SQLSTATE=42704, SQLERRMC=MONITOR.META_MODEL_UNVERSIONED_T, DRIVER=4.11.69.

[3/1/13 15:30:05:740 GMT] 0000001b LifecycleStop E com.ibm.wbimonitor.lifecycle.LifecycleStopRequestScanTask run() CWMLC0012E: Unexpected exception [com.ibm.db2.jcc.am.SqlSyntaxErrorException: DB2 SQL Error: SQLCODE=-204, SQLSTATE=42704, SQLERRMC=MONITOR.META_MODEL_T, DRIVER=4.11.69].
</snip>

in the SystemOut.log file for the Deployment Manager, even though I knew that (a) it was fine on Friday and (b) that DB2 was up-and-running ( validated via the command db2 connect to MONITOR ).

When I went to check the file systems on the box: -

$ mount 

/dev/mapper/vglinux-rootlv on / type ext3 (rw) 
proc on /proc type proc (rw) 
sysfs on /sys type sysfs (rw) 
devpts on /dev/pts type devpts (rw,gid=5,mode=620) 
/dev/mapper/vglinux-tmplv on /tmp type ext3 (rw) 
/dev/mapper/vglinux-varlv on /var type ext3 (rw) 
/dev/dasda1 on /boot type ext3 (rw) 
tmpfs on /dev/shm type tmpfs (rw) 
/dev/mapper/vgapp-optlv on /opt type ext3 (rw) 
/dev/mapper/vgapp-homelv on /home type ext3 (rw) 
none on /proc/sys/fs/binfmt_misc type binfmt_misc (rw) 
sunrpc on /var/lib/nfs/rpc_pipefs type rpc_pipefs (rw) 
LBPM002L:/store/ on /store type nfs (rw,addr=10.222.36.21)

mount: warning: /etc/mtab is not writable (e.g. read-only filesystem). 
       It's possible that information reported by mount(8) is not 
       up to date. For actual information about system mount points 
       check the /proc/mounts file.

When I attempted to change the RWX permissions for /tmp: -

$ chmod 777 /tmp 

chmod: changing permissions of `/tmp': Read-only file system

When I attempted to update the locate database ( as root ): -

$ updatedb 

updatedb: can not open a temporary file for `/var/lib/mlocate/mlocate.db'

At this point, I figured that something serious had occurred; this was validated by messages such as: -

<snip>

EXT3-fs error (device dm-1): ext3_journal_start_sb: Detected aborted journal 
Remounting filesystem read-only 
EXT3-fs error (device dm-1): ext3_lookup: unlinked inode 229390 in dir #229378 
EXT3-fs error (device dm-1): ext3_lookup: unlinked inode 229384 in dir #229378 
EXT3-fs error (device dm-1): ext3_lookup: unlinked inode 229390 in dir #229378 
EXT3-fs error (device dm-1): ext3_lookup: unlinked inode 229384 in dir #229378 
attempt to access beyond end of device
</snip>

in the kernel ring buffer ( via the dmesg command ).

Then I called the Unix sysadm who realised that there was a much bigger problem with the disks, leading to a rebuild ( of / as /opt and /home appeared to be OK ).

Ah well, one lives and one learns ….

Performance issues while accessing LDAP in Federated repository environment

Also saw this on Twitter today: -

Problem(Abstract)

Slow response time is experienced while VMM makes calls to LDAP during login, membership resolution, search, and so on.

Symptom

Slow response time of VMM when configured with LDAP.

Cause

There could be several cause for slow response time: amount of data in LDAP, how data is stored in LDAP, LDAP response time, how the LDAP repository is configured in VMM, and so on. Review the Resolving the problem section and find the cause that might be  causing the issue in your environment.

Performance issues while accessing LDAP in Federated repository environment

Configuring IBM Business Process Management Human Task Management widgets for use in WebSphere Portal

Saw this on Twitter earlier: -

The Human Task Management widgets in IBM®Business Process Manager V7.5 are designed to run in a Business Space environment, but they can also be run in IBM WebSphere®Portal V7. This article describes how to install, configure, and customize these widgets in a Portal environment. This enables you to build a unified environment of portlets and widgets within a single web portal page, so that you can run BPM processes and tasks in your portal pages. This content is part of the IBM Business Process Management Journal.

Configuring IBM Business Process Management Human Task Management widgets for use in WebSphere Portal

IBM Business Monitor 8.0.1 - DB2 or not DB2

This post is most definitely a Work-in-Progress, as I get to grips with IBM Business Monitor ( aka Business Activity Monitoring or BAM ).

BAM includes, and makes use, of Cognos Business Intelligence 10.1 ( aka Cognos BI ), which is installed with the product.

Cognos BI runs, in this particular instance, on one of the WebSphere Application Server (WAS) instances that forms the BAM infrastructure.

In my case, I'm following good practice for scalability and resilience by deploying BAM in the so-called "Gold Standard' deployment pattern, similar to IBM Business Process Manager.

This involves BAM ( or BPM ) being clustered across four discrete WAS instances: -

Messaging engine cluster

• Messaging engine for the IBM Business Monitor bus
• Messaging engine for the common event infrastructure (CEI) bus

Support cluster

• CEI event service
• Event emitter services
• Action services
• Monitor scheduled services
• IBM Cognos Business Intelligence service

Application cluster

• Monitor model applications Web cluster

Business Space application

• Business Space widgets
• Representational State Transfer (REST) services application

and is known as the "Remote Messaging, Remote Support, and Web topology pattern".

The IBM documentation: -

Topologies of a network deployment environment

explains this, and other topologies, further.

So, as is evident from above, Cognos is deployed onto the Support cluster.

I had assumed that Cognos would be a well-behaved client of WAS, and make use of JNDI and JDBC to connect, via WAS, to it's underlying database - COGNOSCS.

However, now I'm not quite so sure.

I have already blogged about the need to configure WAS to make use of the 32-bit native DB2 drivers: -

java.lang.UnsatisfiedLinkError: JCAM_Crypto_JNI (libCCLCore.so: cannot open shared object file: No such file or directory)

and thought that was all I had to do.

However, I spent the best part of a day struggling to work out why Cognos wouldn't fully start.

In terms of logging, apart from the WAS SystemOut.log file: -

/opt/IBM/WebSphere/AppServer/profiles/AppSrv01/logs/PCSR011.Support/SystemOut.log 

Cognos also has its own set of logs: -

$ ls -al /opt/IBM/WebSphere/AppServer/profiles/AppSrv01/cognos/PCSR011.Support/logs

total 44

drwxr-xr-x  3 wasadmin mqbrkrs   4096 Mar  2 17:08 .
drwxr-xr-x 30 wasadmin mqbrkrs   4096 Feb  8 14:04 ..
-rw-r--r--  1 wasadmin wasadmins 1401 Mar  3 09:40 cmMetrics_2013-03-02.log
-rw-r--r--  1 wasadmin wasadmins    0 Mar  2 17:06 cogconfigipf.log
-rw-r--r--  1 wasadmin wasadmins 1729 Mar  2 17:06 cogconfig_response.csv
-rw-r--r--  1 wasadmin wasadmins  311 Mar  2 17:07 cogserver_default_55087.log
-rw-r--r--  1 wasadmin wasadmins  155 Mar  2 17:08 cogserver_default_55441.log
-rw-r--r--  1 wasadmin wasadmins 6504 Mar  2 17:09 cogserver.log
-rw-r--r--  1 wasadmin wasadmins    0 Mar  2 17:06 ipfInternal_cpp.log
-rw-r--r--  1 wasadmin wasadmins    0 Mar  2 17:06 ipfInternal_java.log
-rw-r--r--  1 wasadmin wasadmins 7870 Mar  3 07:48 pogo_2013-03-02.log
-rw-r--r--  1 wasadmin wasadmins    0 Mar  2 17:07 pogoMetrics_2013-03-02.log
-rw-r--r--  1 wasadmin wasadmins    0 Mar  2 17:08 qs_cmMetrics_2013-03-02.log
-rw-r--r--  1 wasadmin wasadmins    0 Mar  2 17:08 qs_pogo_2013-03-02.log
-rw-r--r--  1 wasadmin wasadmins    0 Mar  2 17:08 qs_pogoMetrics_2013-03-02.log
drwxr-xr-x  4 wasadmin wasadmins 4096 Mar  2 17:08 XQE

More specifically: -

$ cat cogconfig_response.csv 

INFO, "[main]", "Silent Execution Mode (start)"
EXEC, "[main]", "Loading configuration file"
SUCCESS, "[main]", "Completed successfully."
EXEC, "[Validation]", "Checking for errors and configuration integrity"
SUCCESS, "[Validation]", "Completed successfully."
EXEC, "[Cryptography]", "Generating cryptographic information"
SUCCESS, "[Cryptography]", "Completed successfully."
EXEC, "[Data Encryption]", "Checking integrity of encrypted data"
SUCCESS, "[Data Encryption]", "Completed successfully."
EXEC, "[Backup]", "Backing up configuration files"
SUCCESS, "[Backup]", "Completed successfully."
EXEC, "[Save Configuration]", "Saving configuration parameters"
SUCCESS, "[Save Configuration]", "Completed successfully."
EXEC, "[Checking upgrade status]", "Checking upgrade status"
SUCCESS, "[Checking upgrade status]", "Completed successfully."
EXEC, "[Cryptography]", "Generating cryptographic information"
SUCCESS, "[Cryptography]", "Completed successfully."
EXEC, "[''VMMAuth'']", "Testing ''WBM_Provider'' namespace."
SUCCESS, "[''VMMAuth'']", "Completed successfully."
EXEC, "[Trust Root Test]", "Checking for same Trust Root."
SUCCESS, "[Trust Root Test]", "Completed successfully."
EXEC, "[CSK Request Test]", "Checking CSK availability."
SUCCESS, "[CSK Request Test]", "Completed successfully."
EXEC, "[Content Manager database connection]", "Testing Content Manager database connection."
ERROR, "[Content Manager database connection]", "The database connection failed."
ERROR, "[Content Manager database connection]", "Content Manager failed to start because it could not load driver "com.ibm.db2.jcc.DB2Driver"."
FAILURE, "[Content Manager database connection]", "Failed."
INFO, "[main]", "Silent Execution Mode (end)"

and: -

$ cat cogserver.log 

127.0.0.1:9081 63902 2013-02-08 16:29:02.408 +0 server.startup : 1 LOGSV 6235 1 server.Audit.IPF StartService LogService Success <parameters><item name="Port"><![CDATA[9381]]></item><item name="Mode"><![CDATA[UDP]]></item><item name="Secure"><![CDATA[FALSE]]></item></parameters>
127.0.0.1:9081 63902 2013-02-08 16:29:22.361 +0 Initialization_SESS Initialization_REQ Thread-54 CM 6235 1 Audit.cms.CM StartService ContentManagerService Info CM-SYS-2057 Creating content store tables (schema version 6.0022).
127.0.0.1:9081 63902 2013-02-08 16:31:56.905 +0 Initialization_SESS Initialization_REQ Thread-54 CM 6235 1 Audit.cms.CM StartService ContentManagerService Info CM-SYS-2215 A Content Manager internal PRECACHEINITACTIONS task started.
127.0.0.1:9081 63902 2013-02-08 16:31:56.967 +0 Initialization_SESS Initialization_REQ Thread-54 CM 6235 1 Audit.cms.CM StartService ContentManagerService Info CM-SYS-2216 A Content Manager internal PRECACHEINITACTIONS task is complete.
127.0.0.1:9081 63902 2013-02-08 16:31:57.103 +0 Initialization_SESS Initialization_REQ Thread-54 CM 6235 1 Audit.cms.CM StartService ContentManagerService Info CM-SYS-2215 A Content Manager internal POSTINITACTIONS task started.
127.0.0.1:9081 63902 2013-02-08 16:31:57.389 +0 Initialization_SESS Initialization_REQ Thread-54 CM 6235 1 Audit.cms.CM StartService ContentManagerService Info CM-SYS-2216 A Content Manager internal POSTINITACTIONS task is complete.
127.0.0.1:9081 63902 2013-02-08 16:32:16.391 +0 Initialization_SESS Initialization_REQ Thread-54 CM 6235 1 Audit.RTUsage.cms.CM StartService ContentManagerService Info CM-SYS-2215 A Content Manager internal CMUPGRADESCRIPT task started.
127.0.0.1:9081 63902 2013-02-08 16:32:17.257 +0   Thread-54 CM 6235 1 Audit.RTUsage.cms.CM StartService ContentManagerService Success CM-SYS-5090 Content Manager build 10.1.6235.601 started (None;20110713180135, schema version 6.0022, implementation: CMDbStore - Java CMCache).
127.0.0.1:9081 63902 2013-02-08 16:32:17.257 +0   Thread-54 CM 6235 1 Audit.RTUsage.cms.CM StartService ContentManagerService InfCM-SYS-5159 Content Manager is running in active mode.
127.0.0.1:9081 63902 2013-02-08 16:32:19.456 +0 pogoStartup na na 0 Thread-54 DISP 6235 1 Audit.Other.dispatcher.DISP.com.cognos.pogo.services.DispatcherServices StartService relationalMetadataService Success
127.0.0.1:9081 63902 2013-02-08 16:32:19.588 +0 pogoStartup na na 0 Thread-54 DISP 6235 1 Audit.Other.dispatcher.DISP.com.cognos.pogo.contentmanager.coordinator.CMBootstrap getActiveContentManager ContentManager Failure <messages><message><messageString>DPR-CMI-4006 Unable to determine the active Content Manager. Will retry periodically.</messageString></message></messages>
127.0.0.1:9081 63902 2013-02-08 16:32:19.605 +0 pogoStartup na na 0 Thread-54 DISP 6235 1 Audit.Other.dispatcher.DISP.pogo pogo com.cognos.pogo.contentmanager.coordinator.ActiveCMControl Failure <messages><message><messageString>DPR-DPR-1035 Dispatcher detected an error.</messageString></message><message><messageString>DPR-DPR-1004 Expecting a BI Bus XML response but got:   </messageString></message></messages> DPR-CMI-4007 Unable to perform an active Content Manager election on the local IP node. For more information, see the dispatcher and Content Manager detailed logs. Ensure that the local Content Manager service is started.DPR-DPR-1004 Expecting a BI Bus XML response but got: com.cognos.pogo.bibus.CommandExecutionException: DPR-DPR-1004 Expecting a BI Bus XML response but got:  at com.cognos.pogo.bibus.BIBusCommand.handleDefaultException(BIBusCommand.java:294) at com.cognos.pogo.bibus.BIBusCommand.execute(BIBusCommand.java:194at com.cognos.pogo.contentmanager.StandbyContentManagerElectionCommand.executeIfLocal(StandbyContentManagerElectionCommand.java:53) at com.cognos.pogo.contentmanager.coordinator.ActiveCMControl.sendElectCommand(ActiveCMControl.java:230) at com.cognos.pogo.contentmanager.coordinator.ActiveCMControl.startTimer(ActiveCMControl.java:175) at com.cognos.pogo.contentmanager.coordinator.ActiveCMControl.startupFindCM(ActiveCMControl.java:142) at com.cognos.pogo.contentmanager.coordinator.RuntimeInfoPublishHandler.start(RuntimeInfoPublishHandler.java:113) at com.cognos.pogo.services.DefaultHandlerService.start(DefaultHandlerService.java:94) at com.cognos.pogo.services.DispatcherServices.startInititalServices(DispatcherServices.java:388) at com.cognos.pogo.transport.PogoServlet$PogoStartup.run(PogoServlet.java:690) at com.cognos.pogo.util.threads.SafeThread.safeRun(SafeThread.java:70) at com.cognos.pogo.util.threads.SafeThread.run(SafeThread.java:61)Caused by: com.cognos.pogo.bibus.CommandExecutionException: DPR-DPR-1004 Expecting a BI Bus XML response but got:  at com.cognos.pogo.bibus.BIBusCommand.checkResponseContentType(BIBusCommand.java:326) at com.cognos.pogo.bibus.BIBusCommand.getSinglePartInputStream(BIBusCommand.java:273) at com.cognos.pogo.bibus.BIBusCommand.getInputStream(BIBusCommand.java:259) at com.cognos.pogo.bibus.BIBusCommand.parseResponse(BIBusCommand.java:248) at com.cognos.pogo.bibus.BIBusCommand.processResponse(BIBusCommand.java:242) at com.cognos.pogo.bibus.BIBusCommand.executeCommand(BIBusCommand.java:204) at com.cognos.pogo.bibus.BIBusCommand.execute(BIBusCommand.java:190) ... 10 more
127.0.0.1:9081 63902 2013-02-08 16:49:51.894 +0 na na stopper-runTimeInfoPublisher DISP 6235 1 Audit.Other.dispatcher.DISP.pogo pogo com.cognos.pogo.services.DefaultHandlerService Failure <messages><message><messageString>DPR-DPR-1035 Dispatcher detected an error.</messageString></message><message><messageString>null</messageString></message></messages> problem stopping handler runTimeInfoPublishernulljava.lang.NullPointerException at com.cognos.pogo.contentmanager.coordinator.RuntimeInfoPublishHandler.stopAciveCMChecking(RuntimeInfoPublishHandler.java:273) at com.cognos.pogo.contentmanager.coordinator.RuntimeInfoPublishHandler.stop(RuntimeInfoPublishHandler.java:124) at com.cognos.pogo.services.DefaultHandlerService.stop(DefaultHandlerService.java:168) at com.cognos.pogo.services.DispatcherServices$ServiceStopper.safeRun(DispatcherServices.java:335) at com.cognos.pogo.util.threads.SafeThread.run(SafeThread.java:61)
127.0.0.1:9081 63902 2013-02-08 16:49:51.894 +0 shutdown na na 0 Non-deferrable Alarm : 2 DISP 6235 1 Audit.Other.dispatcher.DISP.com.cognos.pogo.services.DispatcherServices StopService CPS Producer Registration Service Success
127.0.0.1:9081 63902 2013-02-08 16:49:52.101 +0 stopper-eventManagementService EMS 6235 1 Audit.ems.EMS StopService EventService Success
127.0.0.1:9081 63902 2013-02-08 16:49:52.103 +0 shutdown na na 0 Non-deferrable Alarm : 2 DISP 6235 1 Audit.Other.dispatcher.DISP.com.cognos.pogo.services.DispatcherServices StopService MetadataService Success
127.0.0.1:9081 63902 2013-02-08 16:49:52.111 +0 stopper-jobService JOBS 6235 1 Audit..JOBS StopService JobService Success
127.0.0.1:9081 63902 2013-02-08 16:49:52.115 +0 shutdown na na 0 Non-deferrable Alarm : 2 DISP 6235 1 Audit.Other.dispatcher.DISP.com.cognos.pogo.services.DispatcherServices StopService DimensionManagementService Success
127.0.0.1:9081 63902 2013-02-08 16:49:52.165 +0 stopper-monitorService MS 6235 1 Audit.ms.MS StopService MonitorService Success
127.0.0.1:9081 63902 2013-02-08 16:49:52.169 +0 shutdown na na 0 Non-deferrable Alarm : 2 DISP 6235 1 Audit.Other.dispatcher.DISP.com.cognos.pogo.services.DispatcherServices StopService ReportService Success
127.0.0.1:9081 63902 2013-02-08 16:49:52.173 +0 shutdown na na 0 Non-deferrable Alarm : 2 DISP 6235 1 Audit.Other.dispatcher.DISP.com.cognos.pogo.services.DispatcherServices StopService ContentManagerCacheService Success
127.0.0.1:9081 63902 2013-02-08 16:49:52.177 +0 shutdown na na 0 Non-deferrable Alarm : 2 DISP 6235 1 Audit.Other.dispatcher.DISP.com.cognos.pogo.services.DispatcherServices StopService CacheService Success
127.0.0.1:9081 63902 2013-02-08 16:49:52.177 +0 shutdown na na 0 Non-deferrable Alarm : 2 DISP 6235 1 Audit.Other.dispatcher.DISP.com.cognos.pogo.services.DispatcherServices StopService camAsyncAA Success
127.0.0.1:9081 63902 2013-02-08 16:49:52.178 +0 shutdown na na 0 Non-deferrable Alarm : 2 DISP 6235 1 Audit.Other.dispatcher.DISP.com.cognos.pogo.services.DispatcherServices StopService IBM Cognos Enhanced Search Service Success
127.0.0.1:9081 63902 2013-02-08 16:49:52.179 +0 shutdown na na 0 Non-deferrable Alarm : 2 DISP 6235 1 Audit.Other.dispatcher.DISP.com.cognos.pogo.services.DispatcherServices StopService ReportDataService Success
127.0.0.1:9081 63902 2013-02-08 16:49:52.187 +0 shutdown na na 0 Non-deferrable Alarm : 2 DISP 6235 1 Audit.Other.dispatcher.DISP.com.cognos.pogo.services.DispatcherServices StopService GraphicsService Success
127.0.0.1:9081 63902 2013-02-08 16:49:52.193 +0 na na stopper-graphicsService DISP 6235 1 Audit.Other.dispatcher.DISP.pogo pogo com.cognos.pogo.services.DefaultHandlerService Failure <messages><message><messageString>DPR-DPR-1035 Dispatcher detected an error.</messageString></message><message><messageString>null</messageString></message></messages> problem stopping handler graphicsServiceHandlernulljava.lang.NullPointerException at com.ibm.cgsBus.service.GraphicsServiceHandler.stop(Unknown Source) at com.cognos.pogo.services.DefaultHandlerService.stop(DefaultHandlerService.java:168) at com.cognos.pogo.services.DispatcherServices$ServiceStopper.safeRun(DispatcherServices.java:335) at com.cognos.pogo.util.threads.SafeThread.run(SafeThread.java:61)
127.0.0.1:9081 63902 2013-02-08 16:49:52.196 +0 shutdown na na 0 Non-deferrable Alarm : 2 DISP 6235 1 Audit.Other.dispatcher.DISP.com.cognos.pogo.services.DispatcherServices StopService SystemService Success
127.0.0.1:9081 63902 2013-02-08 16:49:52.197 +0 shutdown na na 0 Non-deferrable Alarm : 2 DISP 6235 1 Audit.Other.dispatcher.DISP.com.cognos.pogo.services.DispatcherServices StopService buxService Success
127.0.0.1:9081 63902 2013-02-08 16:49:52.223 +0 stopper-logService LOGSV 6235 1 server.Audit.IPF StopService LogService Success <parameters><item name="Port"><![CDATA[9381]]></item><item name="Mode"><![CDATA[UDP]]></item><item name="Secure"><![CDATA[FALSE]]></item></parameters>

So, thus far, I've not managed to get to the bottom of why Cognos appears to have an issue with DB2, given that WAS is connecting quite happily using JNDI/JDBC.

As per the aforementioned blog post: -

java.lang.UnsatisfiedLinkError: JCAM_Crypto_JNI (libCCLCore.so: cannot open shared object file: No such file or directory)

I thought I'd fixed the core issue of allowing Cognos access to the native 32-bit JDBC driver, by setting LD_LIBRARY_PATH to: -

/opt/IBM/WebSphere/AppServer/profiles/AppSrv01/cognos/PCSR011.Support/bin64:/opt/ibm/db2/V9.7/lib32/

but it's still not happy, as can be seen above.

In addition, I was seeing the following exception: -

DPR-ERR-2109 The dispatcher cannot service the request at this time. The dispatcher is still initializing. Contact administrator if this problem persists.

when attempting to access the Cognos Dispatcher URL: -

http://rhel6.uk.ibm.com:9081/p2pd

Despite reading scores of IBM documentation: -

Rational Common Reporting: DPR-ERR-2109 The dispatcher cannot service the request at this time. The dispatcher is still initialising..

Error 'Content Manager failed to start because it could not load driver com.ibm.db2.jcc.DB"Drive' when upgrading to 8.4

In the end, I looked back through a design document that I'd recently written for an IBM Business Monitor client, who's actually using Oracle rather than DB2, where I'd recommended that they use Dynamic Query Mode, which makes full use of WAS' own JDBC driver, rather than needing a native, client-side driver.

This Technote describes this more fully: -

IBM Business Monitor is unable to publish cubes to IBM Cognos BI service

but, in essence, it's a matter of setting a generic JVM argument ( for the Support cluster member ): -

-Dinit.dqm.enabled=true

and restarting the cluster member.

Having done this, I still see: -

<snip>

EXEC, "[Content Manager database connection]", "Testing Content Manager database connection."
ERROR, "[Content Manager database connection]", "The database connection failed."
ERROR, "[Content Manager database connection]", "Content Manager failed to start because it could not load driver "com.ibm.db2.jcc.DB2Driver"."
FAILURE, "[Content Manager database connection]", "Failed."
</snip>

in cogconfig_response.csv, but Cognos now behaves itself perfectly, as per conserver.log: -

$ cat cogserver.log 

127.0.0.1:9081 55087 2013-03-02 17:07:19.386 +0 server.startup : 0 LOGSV 6235 1 server.Audit.IPF StartService LogService Success <parameters><item name="Port"><![CDATA[9381]]></item><item name="Mode"><![CDATA[UDP]]></item><item name="Secure"><![CDATA[FALSE]]></item></parameters>
127.0.0.1:9081 55087 2013-03-02 17:07:27.722 +0 Initialization_SESS Initialization_REQ Thread-54 CM 6235 1 Audit.cms.CM StartService ContentManagerService Info CM-SYS-2215 A Content Manager internal PRECACHEINITACTIONS task started.
127.0.0.1:9081 55087 2013-03-02 17:07:27.976 +0 Initialization_SESS Initialization_REQ Thread-54 CM 6235 1 Audit.cms.CM StartService ContentManagerService Info CM-SYS-2215 A Content Manager internal POSTINITACTIONS task started.
127.0.0.1:9081 55087 2013-03-02 17:07:27.725 +0 Initialization_SESS Initialization_REQ Thread-54 CM 6235 1 Audit.cms.CM StartService ContentManagerService Info CM-SYS-2216 A Content Manager internal PRECACHEINITACTIONS task is complete.
127.0.0.1:9081 55087 2013-03-02 17:07:28.072 +0 Initialization_SESS Initialization_REQ Thread-54 CM 6235 1 Audit.cms.CM StartService ContentManagerService Info CM-SYS-2216 A Content Manager internal POSTINITACTIONS task is complete.
127.0.0.1:9081 55087 2013-03-02 17:07:28.238 +0 Initialization_SESS Initialization_REQ Thread-54 CM 6235 1 Audit.cms.CM StartService ContentManagerService Info CM-SYS-2215 A Content Manager internal CMUPGRADESCRIPT task started.
127.0.0.1:9081 55087 2013-03-02 17:07:28.911 +0   Thread-54 CM 6235 1 Audit.RTUsage.cms.CM StartService ContentManagerService Success CM-SYS-5090 Content Manager build 10.1.6235.601 started (None;20110713180135, schema version 6.0022, implementation: CMDbStore - Java CMCache).
127.0.0.1:9081 55087 2013-03-02 17:07:28.913 +0   Thread-54 CM 6235 1 Audit.RTUsage.cms.CM StartService ContentManagerService InfCM-SYS-5159 Content Manager is running in active mode.
127.0.0.1:9081 55087 2013-03-02 17:07:29.357 +0 pogoStartup na na 0 Thread-54 DISP 6235 1 Audit.Other.dispatcher.DISP.com.cognos.pogo.services.DispatcherServices StartService relationalMetadataService Success
127.0.0.1:9081 55087 2013-03-02 17:07:29.587 +0 BootstrapConfigurePublish na 0 Thread-54 DISP 6235 1 Audit.Other.dispatcher.DISP.com.cognos.pogo.contentmanager.coordinator.CMBootstrap StartService dispatcherBootstrap Info DPR-DPR-1002 Successfully registered the dispatcher http://rhel6.uk.ibm.com:9081/p2pd in Content Manager.
127.0.0.1:9081 55087 2013-03-02 17:08:03.321 +0 Thread-76 AAA 6235 1 Audit.cms.CAM.AAA StartService camAsyncService Success
127.0.0.1:9081 55087 2013-03-02 17:08:14.125 +0 na na Thread-76 DISP 6235 1 Audit.Other.dispatcher.DISP.com.cognos.pogo.services.DispatcherServices StartService Fragment Server Service Success
127.0.0.1:9081 55087 2013-03-02 17:08:14.129 +0 na na Thread-76 DISP 6235 1 Audit.Other.dispatcher.DISP.com.cognos.pogo.services.DispatcherServices StartService BatchReportService Success
127.0.0.1:9081 55087 2013-03-02 17:08:14.131 +0 na na Thread-76 DISP 6235 1 Audit.Other.dispatcher.DISP.com.cognos.pogo.async.service.connection.bibustkserver.BIBusTKServerManager Start com.cognos.pogo.reportservice Info Start a External Process because the start count 1 is larger than 0.
127.0.0.1:9081 55087 2013-03-02 17:08:39.399 +0 na na Thread-76 DISP 6235 1 Audit.Other.dispatcher.DISP.com.cognos.pogo.services.DispatcherServices StartService QueryService Success
127.0.0.1:9081 55087 2013-03-02 17:08:39.903 +0 na na Thread-76 DISP 6235 1 Audit.Other.dispatcher.DISP.com.cognos.pogo.services.DispatcherServices StartService SystemService Success
127.0.0.1:9081 55087 2013-03-02 17:08:39.902 +0 na na Thread-76 DISP 6235 1 Audit.Other.dispatcher.DISP.com.cognos.pogo.services.DispatcherServices StartService buxService Success
127.0.0.1:9081 55087 2013-03-02 17:08:46.171 +0 na na Thread-76 DISP 6235 1 Audit.Other.dispatcher.DISP.com.cognos.pogo.services.DispatcherServices StartService GraphicsService Success
127.0.0.1:9081 55087 2013-03-02 17:08:46.281 +0 na na Thread-76 DISP 6235 1 Audit.Other.dispatcher.DISP.com.cognos.pogo.services.DispatcherServices StartService ReportDataService Success
127.0.0.1:9081 55087 2013-03-02 17:08:51.733 +0 Thread-76 xts 6235 1 Audit.ps.xts Upgrade PresentationService Success PRS-ACF-0413 Successfully wrote the upgraded cogadmin/system.xml file.
127.0.0.1:9081 55087 2013-03-02 17:09:00.803 +0 Thread-76 xts 6235 1 Audit.ps.xts StartService PresentationService Success
127.0.0.1:9081 55087 2013-03-02 17:09:00.804 +0 na na Thread-76 DISP 6235 1 Audit.Other.dispatcher.DISP.com.cognos.pogo.services.DispatcherServices StartService IBM Cognos Enhanced Search Service Success
127.0.0.1:9081 55087 2013-03-02 17:09:00.804 +0 na na Thread-76 DISP 6235 1 Audit.Other.dispatcher.DISP.com.cognos.pogo.services.DispatcherServices StartService camAsyncAA Success
127.0.0.1:9081 55087 2013-03-02 17:09:00.808 +0 na na Thread-76 DISP 6235 1 Audit.Other.dispatcher.DISP.com.cognos.pogo.services.DispatcherServices StartService CacheService Success
127.0.0.1:9081 55087 2013-03-02 17:09:00.808 +0 na na Thread-76 DISP 6235 1 Audit.Other.dispatcher.DISP.com.cognos.pogo.services.DispatcherServices StartService ContentManagerCacheService Success
127.0.0.1:9081 55087 2013-03-02 17:09:00.985 +0 na na Thread-76 DISP 6235 1 Audit.Other.dispatcher.DISP.com.cognos.pogo.services.DispatcherServices StartService ReportService Success
127.0.0.1:9081 55087 2013-03-02 17:09:01.008 +0 Thread-76 MS 6235 1 Audit.ms.MS StartService MonitorService Success
127.0.0.1:9081 55087 2013-03-02 17:09:01.008 +0 na na Thread-76 DISP 6235 1 Audit.Other.dispatcher.DISP.com.cognos.pogo.services.DispatcherServices StartService DimensionManagementService Success
127.0.0.1:9081 55087 2013-03-02 17:09:01.009 +0 Thread-76 JOBS 6235 1 Audit..JOBS StartService JobService Success
127.0.0.1:9081 55087 2013-03-02 17:09:01.289 +0 na na Thread-76 DISP 6235 1 Audit.Other.dispatcher.DISP.com.cognos.pogo.services.DispatcherServices StartService MetadataService Success
127.0.0.1:9081 55087 2013-03-02 17:09:01.434 +0 Thread-76 EMS 6235 1 Audit.ems.EMS StartService EventService Success
127.0.0.1:9081 55087 2013-03-02 17:09:13.223 +0 na na Thread-76 DISP 6235 1 Audit.Other.dispatcher.DISP.com.cognos.pogo.services.DispatcherServices StartService CPS Producer Registration Service Success

and I can access the Cognos URLs: -

http://rhel6.uk.ibm.com:9081/p2pd/servlet/dispatch/ext?b_action=xts.run&m=portal/welcome/welcome.xts

and also add/remove/edit Cognos iWidgets within Business Space: -

https://rhel6.uk.ibm.com:8443/mum/resources/bootstrap/login.jsp

One final point - it's sometimes necessary to modify the Cognos configuration outside of the WAS/BAM environment.

This can be achieved in one of two ways: -

(1) Use the cogconfig.sh GUI -

$ /opt/IBM/WebSphere/AppServer/profiles/AppSrv01/cognos/PCSR011.Support/bin64/cogconfig.sh

This requires a GUI environment ( X11 or VNC on Linux ), which may be a problem for some Unix boxes.

For me, I accessed my RHEL VM as follows: -

$ ssh -X wasadmin@rhel6

and then started the tool: -

$ source /opt/IBM/WebSphere/AppServer/profiles/Dmgr01/bin/setupCmdLine.sh 

$ /opt/IBM/WebSphere/AppServer/profiles/AppSrv01/cognos/PCSR011.Support/bin64/cogconfig.sh

which loads the GUI up via my Mac's X11 client Xquartz.

(2) Use the wsadmin scripts that come with BAM: -

wbmDeployCEIEventService to create and configure the CEI event service and its required resources for receiving and sending events

wbmConfigureEventEmitterFactory to configure the outbound event emitter factory for sending events

wbmDeployMessagingEngine to install and configure the messaging engine and service integration bus

wbmDeployActionServices to install and configure the action services for invoking actions

wbmDeployScheduledServices to install and configure the Monitor scheduled services for scheduling recurring services

wbmDeployEventEmitterServices to install and configure the JMS and REST event emitter services

wbmDeployBPMEmitterServices to install and configure the BPM emitter service for use by IBM BPM

wbmDeployCognosService to install the IBM Cognos® Business Intelligence service for multidimensional analysis, or wbmSetCognosDispatcher to point to an IBM Cognos BI service that is already installed

wbmSetCognosDatabaseUser to set the IBM Cognos BI content store database password, and wbmSetCognosAdminUser to set the IBM Cognos BI administrator password.

as per the following link: -

Configuration commands (wsadmin)

Of course, there is a third option - one that I would not recommend - to hand-edit the Cognos configuration file: -

/opt/IBM/WebSphere/AppServer/profiles/AppSrv01/cognos/PCSR011.Support/configuration/cogstartup.xml

This is, I believe, modified ( and, more importantly, validated ) by options (1) and (2) above.

As I say, this is a W-I-P. Next on my list is to find out whether I can configure the Cognos dispatcher to work with SSL.

I did try changing the dispatcher endpoints to HTTPS URLs, but then got exceptions such as: -

    CM-SYS-5157 Content Manager failed to notify the dispatcher "https://rhel6.uk.ibm.com:8443/p2pd/servlet/dispatch" of a running status change. CM-REQ-4128 An input/output error occurred executing an external request to the connector "CM". java.security.cert.CertificateException: CAM-CRP-1072 The certificate with the DN 'CN=rhel6.uk.ibm.com, O=ibm' issued by the Certificate Authority with the DN 'CN=rhel6.uk.ibm.com, O=ibm' is not trusted. Cause: java.security.cert.CertificateException: CAM-CRP-1072 The certificate with the DN 'CN=rhel6.uk.ibm.com, O=ibm' issued by the Certificate Authority with the DN 'CN=rhel6.uk.ibm.com, O=ibm' is not trusted.  Runtime Exception stack trace: javax.net.ssl.SSLHandshakeException: java.security.cert.CertificateException: CAM-CRP-1072 The certificate with the DN 'CN=rhel6.uk.ibm.com, O=ibm' issued by the Certificate Authority with the DN 'CN=rhel6.uk.ibm.com, O=ibm' is not trusted.   

but that's a problem for another day.

Importing SSL certificates into the WebSphere Application Server CACerts certificate store

So I saw this in my WAS logs ( for the IBM Business Monitor instance that hosts Cogos ): -

/opt/IBM/WebSphere/AppServer/profiles/AppSrv01/cognos/PCSR011.Support/logs/cogserver.log

  CM-SYS-5157 Content Manager failed to notify the dispatcher "https://rhel6.uk.ibm.com:8443/p2pd/servlet/dispatch" of a running status change. CM-REQ-4128 An input/output error occurred executing an external request to the connector "CM". java.security.cert.CertificateException: CAM-CRP-1072 The certificate with the DN 'CN=rhel6.uk.ibm.com, O=ibm' issued by the Certificate Authority with the DN 'CN=rhel6.uk.ibm.com, O=ibm' is not trusted. Cause: java.security.cert.CertificateException: CAM-CRP-1072 The certificate with the DN 'CN=rhel6.uk.ibm.com, O=ibm' issued by the Certificate Authority with the DN 'CN=rhel6.uk.ibm.com, O=ibm' is not trusted.  Runtime Exception stack trace: javax.net.ssl.SSLHandshakeException: java.security.cert.CertificateException: CAM-CRP-1072 The certificate with the DN 'CN=rhel6.uk.ibm.com, O=ibm' issued by the Certificate Authority with the DN 'CN=rhel6.uk.ibm.com, O=ibm' is not trusted.   at com.ibm.jsse2.o.a(o.java:33)         at com.ibm.jsse2.SSLSocketImpl.a(SSLSocketImpl.java:649)        at com.ibm.jsse2.kb.a(kb.java:56)       at com.ibm.jsse2.kb.a(kb.java:502)      at com.ibm.jsse2.lb.a(lb.java:107)      at com.ibm.jsse2.lb.a(lb.java:570)      at com.ibm.jsse2.kb.s(kb.java:327)      at com.ibm.jsse2.kb.a(kb.java:529)      at com.ibm.jsse2.SSLSocketImpl.a(SSLSocketImpl.java:300)        at com.ibm.jsse2.SSLSocketImpl.h(SSLSocketImpl.java:403)        at com.ibm.jsse2.SSLSocketImpl.a(SSLSocketImpl.java:774)        at com.ibm.jsse2.k.write(k.java:7)      at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:76)       at java.io.BufferedOutputStream.write(BufferedOutputStream.java:115)    at org.apache.commons.httpclient.HttpConnection.write(HttpConnection.java:975)  at org.apache.commons.httpclient.HttpConnection.write(HttpConnection.java:943)  at com.cognos.cm.connectors.BusPostMethod.writeRequestBody(BusPostMethod.java:117)      at org.apache.commons.httpclient.HttpMethodBase.writeRequest(HttpMethodBase.java:2114)  at org.apache.commons.httpclient.HttpMethodBase.execute(HttpMethodBase.java:1096)       at org.apache.commons.httpclient.HttpMethodDirector.executeWithRetry(HttpMethodDirector.java:398)       at org.apache.commons.httpclient.HttpMethodDirector.executeMethod(HttpMethodDirector.java:171)  at org.apache.commons.httpclient.HttpClient.executeMethod(HttpClient.java:397)  at org.apache.commons.httpclient.HttpClient.executeMethod(HttpClient.java:323)  at com.cognos.cm.connectors.BusConnectionPool$BusConnection.execute(BusConnectionPool.java:85)  at com.cognos.cm.connectors.CMConnector.CMConnector$CMConnectorRunnable.run(CMConnector.java:469)       at java.lang.Thread.run(Thread.java:772) Caused by: java.security.cert.CertificateException: CAM-CRP-1072 The certificate with the DN 'CN=rhel6.uk.ibm.com, O=ibm' issued by the Certificate Authority with the DN 'CN=rhel6.uk.ibm.com, O=ibm' is not trusted.         at com.cognos.accman.jcam.crypto.misc.CAMX509TrustManager14.checkServerTrusted(CAMX509TrustManager14.java:354)  at com.ibm.jsse2.lb.a(lb.java:323)      ... 21 more

This led me to the JVM's CACerts store: -

Dumped out the current list of CAs in CACerts

$ /opt/IBM/HTTPServer/java/jre/bin/ikeycmd -cert -list -db /opt/IBM/WebSphere/AppServer/java/jre/lib/security/cacerts -pw changeit -type jks > /tmp/cacerts.out

Used a simple shell script to remove these 77 CAs

for c in `cat /tmp/cacerts.out`
do
/opt/IBM/HTTPServer/java/jre/bin/ikeycmd -cert -delete -db /opt/IBM/WebSphere/AppServer/java/jre/lib/security/cacerts -pw changeit -type jks -label $c
done

none of which are required for MY specific environment.

Used OpenSSL to retrieve the certificate from the IHS box to a file

$ openssl s_client -connect https://rhel6.uk.ibm.com:8443 > ihs.cer

Edited the file down to the certificate itself

$ vi ihs.cer

<snip>

-----BEGIN CERTIFICATE-----
MIICzjCCAbagAwIBAgIEURUitDANBgkqhkiG9w0BAQUFADApMQwwCgYDVQQKEwNp
Ym0xGTAXBgNVBAMTEHJoZWw2LnVrLmlibS5jb20wHhcNMTMwMjA4MTYwNzE2WhcN
MTQwMjA4MTYwNzE2WjApMQwwCgYDVQQKEwNpYm0xGTAXBgNVBAMTEHJoZWw2LnVr
LmlibS5jb20wggEiMA0GCSqGSIb3DQEBAQUAA4IBDwAwggEKAoIBAQCDsSbw27hU
M+1xIMapH4KJD3maj046A6k2GyUzsvKzH25OA/cmSo4LQByAHXc6O9wlFAbsRf4H
NWZemrGPtk2DqJQkLUMnTckLL5hb3Vt0RocnoBfbPJgNB8jwkUocF22aLEJ0Btqi
ppCbX2Gmkg+vFNMPSkGL89W5QGcnxeAwWASJRcITIEsxJ8JNRqZtrCz2IiUrC7li
ef1eIObt7eW/tr6xLpup8K0DFtI1FK27wMTCSb9B84yWYyIWKm30cgPlUHZqJJfQ
Rt5veMdmVfWN0vA4t6ctux5bD/HmcjMHRvXrM98vU2juq8l4JBd2HXVRZzblCRom
baAz5oqT4D6XAgMBAAEwDQYJKoZIhvcNAQEFBQADggEBAEAyzeQPW5Y88qUHg8sb
OpzzDE7pQMAudsBUlZG7hyz2hFXrao2P2h/JkOoOlvjmYm+e2A1GxO2DRVEj6tvw
V5AzjVw2XuVL0nRmaDDVOFgMsV+6LurXFj4TWG7nbFNvFNBHKGDzfbl9j4Zp8fsK
CGU1k8xQVQIykP6PptazjD5nAny4C1bWVDNNPiev7pJSR4Ki5tMuCNK5EHqeZ1PX
gO4kiBLDdS7RNgszxgkCdPF4pPvqis0tcl9zoXenzNOyEvJU9L1/Q7dhTq81uBMU
e0kh5b3OXPT92UD7xB87o8oUTlNrPfX4fKR6zTDEYLhgPTwYBGDpQJj6mD3wbnJV
a3I=
-----END CERTIFICATE-----

</snip>

Imported the certificate into CACerts

$ /opt/IBM/HTTPServer/java/jre/bin/ikeycmd -cert -add -db /opt/IBM/WebSphere/AppServer/java/jre/lib/security/cacerts -pw changeit -type jks -file ihs.cer

Restarted my JVM ….

Resolving WAS -> DB2 problems - create the darned database

If you get: -

[2/28/13 12:22:51:686 GMT] 00000067 DataSourceCon E   DSRA8040I: Failed to connect to the DataSource.  Encountered "": java.sql.SQLException: null DSRA0010E: SQL State = 58031, Error Code = -1,031

Check that the database has been created: -

$ db2 create database RTSDB automatic storage yes using codeset UTF-8 territory US pagesize 32768

DB20000I  The CREATE DATABASE command completed successfully.

Fun with IBM HTTP Server

I was getting HTTP 404 for: -

https://10.222.36.21:8443/teamserver/faces/login.jsp

Looking at the IHS  error.log, I saw: -

[Thu Feb 28 11:39:16 2013] [error] [client 28.103.96.87] File does not exist: /opt/IBM/HTTPServer/htdocsext/teamserver

and the Plugin log ( with LogLevel="Error" in plugin-cfg.xml ): -

[Thu Feb 28 11:39:16 2013] 00003c42 04cfe950 - DETAIL: ws_common: websphereShouldHandleRequest: trying to match a route for: vhost='10.222.36.21'; uri='/teamserver/faces/login.jsp'

[Thu Feb 28 11:39:16 2013] 00003c42 04cfe950 - TRACE: ws_common: webspherePortNumberForMatching: Using logical. 
[Thu Feb 28 11:39:16 2013] 00003c42 04cfe950 - TRACE: ws_common: websphereVhostMatch: Comparing '*:5065' to '10.222.36.21:8443' in VhostGroup: default_host

[Thu Feb 28 11:39:16 2013] 00003c42 04cfe950 - TRACE: ws_common: websphereVhostMatch: Comparing '*:9445' to '10.222.36.21:8443' in VhostGroup: default_host

[Thu Feb 28 11:39:16 2013] 00003c42 04cfe950 - TRACE: ws_common: websphereVhostMatch: Comparing '*:5063' to '10.222.36.21:8443' in VhostGroup: default_host

[Thu Feb 28 11:39:16 2013] 00003c42 04cfe950 - TRACE: ws_common: websphereVhostMatch: Comparing '*:9444' to '10.222.36.21:8443' in VhostGroup: default_host

[Thu Feb 28 11:39:16 2013] 00003c42 04cfe950 - TRACE: ws_common: websphereVhostMatch: Comparing '*:5061' to '10.222.36.21:8443' in VhostGroup: default_host

[Thu Feb 28 11:39:16 2013] 00003c42 04cfe950 - TRACE: ws_common: websphereVhostMatch: Comparing '*:9443' to '10.222.36.21:8443' in VhostGroup: default_host

[Thu Feb 28 11:39:16 2013] 00003c42 04cfe950 - TRACE: ws_common: websphereVhostMatch: Failed to match: 10.222.36.21:8443

This led me to check the WAS Virtual Hosts ( via the WAS ISC -> Environment -> Virtual hosts -> default_host ) and realised that 9443 was there but 8443 was NOT :-)

I changed it, regenerated the plugin, restarted the cluster and …. job done :-)

Can you say "Doh!" ?