Thursday, 29 September 2016

IBM ODM Rules on Liberty on Docker - Tracing the RES

One of my friends challenged me to work out how to enable a more detailed trace for IBM ODM Rules, running on WebSphere Liberty Profile.

I've written a bit about ODM on Liberty, both with and without Docker, recently: -






However, my pal wanted to go one step further; he wanted to enable Execution Unit (XU) tracing on his Rule Execution Server (RES) - aka Decision Server.

Another of the team directed me here: -


which includes the various trace strings: -


Specifically, he wanted this: -

Ruleset execution: rule session, execution units (XU) com.ibm.rules.res.execution

In essence, it requires a change to the server.xml which is one of the main Liberty configuration files.

Thus I inserted this: -

...
        <featureManager>
                <feature>servlet-3.1</feature>
                <feature>jsp-2.3</feature>
                <feature>jdbc-4.1</feature>
                <feature>appSecurity-2.0</feature>
                <feature>jaxrs-1.1</feature>
                <feature>concurrent-1.0</feature>
                <feature>jndi-1.0</feature>
                <feature>ssl-1.0</feature>
        </featureManager>

        <logging  traceSpecification="com.ibm.rules.res.execution=all"
                traceFileName="trace.log"
                maxFileSize="20"
                maxFiles="10"
                traceFormat="BASIC" />

        <httpSession cookieName="DCSESSIONID"
                invalidateOnUnauthorizedSessionRequestException="true" />
...

into an existing server.xml.

As I'm running ODM on Liberty on Docker, I decided to take the somewhat "nuclear" step of discarding my existing Container, and creating a brand new Image.

This I did the following: -

Stop the existing Container ( instance )

docker kill cf93bfdacb28

Remove the existing Container

docker rm cf93bfdacb28

Remove the Image from which the Container was instantiated

docker rmi ad81c81be14d

and then created a new Image: -

docker build -t odm88 .

and then instantiated a Container from the newly created Image: 

odm88=`docker run -d -t -p 80:9080 -p 443:9443 odm88:latest`

I monitored the logs to ensure that the server was up: -

docker logs $odm88 -f

…
[AUDIT   ] CWWKZ0001I: Application teamserver started in 25.915 seconds.
[AUDIT   ] CWWKZ0022W: Application decisioncenter has not started in 30.001 seconds.
[AUDIT   ] CWWKF0012I: The server installed the following features: [jsp-2.3, concurrent-1.0, servlet-3.1, ssl-1.0, jndi-1.0, json-1.0, distributedMap-1.0, appSecurity-2.0, jdbc-4.1, jaxrs-1.1, el-3.0].
[AUDIT   ] CWWKF0011I: The server defaultServer is ready to run a smarter planet.
[WARNING ] [dc] Solr index directory '/tmp/solr.data1447360524204199981.dir/index' doesn't exist. Creating new index...
[AUDIT   ] CWWKZ0001I: Application decisioncenter started in 33.707 seconds.
…

Once up, I opened a command prompt to the Container: -

docker exec -i -t $odm88 /bin/bash

and confirmed that my newly created trace.log file existed: -

ls -al /logs/

total 436
drwxr-xr-x  2 root root   4096 Sep 29 14:12 .
drwxr-xr-x 64 root root   4096 Sep 29 14:12 ..
-rw-r-----  1 root root 210983 Sep 29 14:32 messages.log
-rw-r-----  1 root root 221913 Sep 29 14:32 trace.log

I also confirmed that stuff was being logged, by hitting a test Rule Service via the built-in REST Service tester: -


and monitored the trace.log file for output: -

...
[9/29/16 14:32:44:425 UTC] 00000121 execution     2 com.ibm.rules.res.xu.work.internal.WorkManagerImpl startWork com.ibm.rules.res.xu.work.internal.WorkManagerImpl startWork ENTERING com.ibm.rules.res.xu.ruleset.internal.RulesetParsingWork@c53d8f51
[9/29/16 14:32:44:427 UTC] 00000124 execution     2 com.ibm.rules.res.xu.work.internal.WorkManagerImpl workStarted com.ibm.rules.res.xu.work.internal.WorkManagerImpl workStarted ENTERING javax.resource.spi.work.WorkEvent[source=Thread[Thread-22,5,Default Executor Thread Group]]
[9/29/16 14:32:44:428 UTC] 00000124 execution     2 com.ibm.rules.res.xu.work.internal.WorkManagerImpl workStarted com.ibm.rules.res.xu.work.internal.WorkManagerImpl workStarted EXIT RETURN
[9/29/16 14:32:44:427 UTC] 00000121 execution     2 com.ibm.rules.res.xu.work.internal.WorkManagerImpl workAccepted com.ibm.rules.res.xu.work.internal.WorkManagerImpl workAccepted ENTERING javax.resource.spi.work.WorkEvent[source=com.ibm.rules.res.xu.work.internal.WorkManagerImpl@54266e07]
[9/29/16 14:32:44:428 UTC] 00000121 execution     2 com.ibm.rules.res.xu.work.internal.WorkManagerImpl workAccepted com.ibm.rules.res.xu.work.internal.WorkManagerImpl workAccepted EXIT RETURN
[9/29/16 14:32:44:429 UTC] 00000121 execution     2 com.ibm.rules.res.xu.work.internal.WorkManagerImpl startWork com.ibm.rules.res.xu.work.internal.WorkManagerImpl startWork RETURN 0
[9/29/16 14:32:45:094 UTC] 00000124 execution     2 com.ibm.rules.res.xu.work.internal.WorkManagerImpl workCompleted com.ibm.rules.res.xu.work.internal.WorkManagerImpl workCompleted ENTERING javax.resource.spi.work.WorkEvent[source=Thread[Thread-22,5,Default Executor Thread Group]]
[9/29/16 14:32:45:094 UTC] 00000124 execution     2 com.ibm.rules.res.xu.work.internal.WorkManagerImpl removeWork com.ibm.rules.res.xu.work.internal.WorkManagerImpl removeWork ENTERING com.ibm.rules.res.xu.ruleset.internal.RulesetParsingWork@c53d8f51
[9/29/16 14:32:45:095 UTC] 00000124 execution     2 com.ibm.rules.res.xu.work.internal.WorkManagerImpl removeWork com.ibm.rules.res.xu.work.internal.WorkManagerImpl removeWork EXIT RETURN
[9/29/16 14:32:45:095 UTC] 00000124 execution     2 com.ibm.rules.res.xu.work.internal.WorkManagerImpl workCompleted com.ibm.rules.res.xu.work.internal.WorkManagerImpl workCompleted EXIT RETURN
[9/29/16 14:32:50:585 UTC] 00000121 SystemOut     O   Hello Dave Hay Rules!
…

Bottom line, ODM on Liberty, with/out Docker, is just SO amazingly flexible.

Of course, I didn't need to throw away the Container and Image just to change a few lines of XML.

This is what I should have done: -

Update the source server.xml file

Changing the trace string to: -

        <logging  traceSpecification="com.ibm.rules.res.execution=all:com.ibm.rules.res.console=all"
                traceFileName="trace.log"
                maxFileSize="20"
                maxFiles="10"
                traceFormat="BASIC" />

Copying the source server.xml to the existing Container

docker cp server.xml $odm88:/opt/ibm/wlp/usr/servers/defaultServer

Commit the change

docker commit $odm88

Stop the Liberty Server

docker exec -i -t $odm88 /bin/bash -c "/opt/ibm/wlp/bin/server stop"

Stopping server defaultServer.
Server defaultServer stopped.

Restart the existing Container

docker restart $odm88

5cfcc8ec2443cedeea0f6ed6456829d1a0f994c169855da7c4e2593bef0f47f0

Monitor the logs

docker logs $odm88 -f

Launching defaultServer (WebSphere Application Server 8.5.5.9/wlp-1.0.12.cl50920160227-1523) on IBM J9 VM, version pxa6480sr3-20160428_01 (SR3) (en_US)
[AUDIT   ] CWWKE0001I: The server defaultServer has been launched.
[AUDIT   ] CWWKE0100I: This product is licensed for development, and limited production use. The full license terms can be viewed here: https://public.dhe.ibm.com/ibmdl/export/pub/software/websphere/wasdev/license/base_ilan/ilan/8.5.5.9/lafiles/en.html
[AUDIT   ] CWWKG0093A: Processing configuration drop-ins resource: /opt/ibm/wlp/usr/servers/defaultServer/configDropins/defaults/keystore.xml
[AUDIT   ] CWWKZ0058I: Monitoring dropins for applications. 
[AUDIT   ] CWWKT0016I: Web application available (default_host): http://5cfcc8ec2443:9080/testing/
[AUDIT   ] CWWKT0016I: Web application available (default_host): http://5cfcc8ec2443:9080/DecisionRunner/
[AUDIT   ] CWWKT0016I: Web application available (default_host): http://5cfcc8ec2443:9080/DecisionService/
[AUDIT   ] CWWKT0016I: Web application available (default_host): http://5cfcc8ec2443:9080/res/
[AUDIT   ] CWWKT0016I: Web application available (default_host): http://5cfcc8ec2443:9080/teamserver/
[AUDIT   ] CWWKT0016I: Web application available (default_host): http://5cfcc8ec2443:9080/decisioncenter/
[AUDIT   ] CWWKZ0001I: Application DecisionService started in 8.615 seconds.
[AUDIT   ] CWWKZ0001I: Application testing started in 8.746 seconds.
[AUDIT   ] CWWKZ0001I: Application DecisionRunner started in 9.413 seconds.
[AUDIT   ] CWWKZ0001I: Application res started in 9.422 seconds.
[AUDIT   ] CWWKZ0001I: Application teamserver started in 12.839 seconds.
[WARNING ] [dc] Solr index directory '/tmp/solr.data912267916741895538.dir/index' doesn't exist. Creating new index...
[AUDIT   ] CWWKZ0001I: Application decisioncenter started in 17.642 seconds.
[AUDIT   ] CWWKF0012I: The server installed the following features: [jsp-2.3, concurrent-1.0, servlet-3.1, ssl-1.0, jndi-1.0, json-1.0, distributedMap-1.0, appSecurity-2.0, jdbc-4.1, jaxrs-1.1, el-3.0].
[AUDIT   ] CWWKF0011I: The server defaultServer is ready to run a smarter planet.

Start a shell against the Container

docker exec -i -t $odm88 /bin/bash

Check the trace.log to validate the new trace string

cat /logs/trace.log |grep -i console

trace.specification = *=info:com.ibm.rules.res.console=all:com.ibm.rules.res.execution=all
[9/29/16 18:06:29:515 UTC] 0000001d id=         com.ibm.ws.logging.internal.TraceSpecification               I TRAS0018I: The trace state has been changed. The new trace state is *=info:com.ibm.rules.resconsole=all:com.ibm.rules.res.execution=all.
[9/29/16 18:06:31:667 UTC] 00000026 WebGroup      I   SRVE0169I: Loading Web Module: Rule Execution Server Console.
[9/29/16 18:06:31:667 UTC] 00000026 webcontainer  I com.ibm.ws.webcontainer.osgi.DynamicVirtualHost addWebApplication SRVE0250I: Web Module Rule Execution Server Console has been bound to default_host.
[9/29/16 18:06:37:144 UTC] 00000026 console       2   logging path and file name: res-console.log
[9/29/16 18:06:37:157 UTC] 00000026 console       C   GBRXC0180W 
                                 res-console.log
[9/29/16 18:06:37:157 UTC] 00000026 console       2   Default logging file name is used: res-console
[9/29/16 18:06:37:158 UTC] 00000026 console       2   logging file name: res-console
[9/29/16 18:06:37:188 UTC] 00000026 console       I   The operating system is Linux amd64 4.4.20-moby.
[9/29/16 18:06:37:189 UTC] 00000026 console       I   The JVM is IBM Corporation IBM J9 VM 2.8.
[9/29/16 18:06:37:189 UTC] 00000026 console       I   The class path is /opt/ibm/wlp/bin/tools/ws-server.jar:/opt/ibm/wlp/bin/tools/ws-javaagent.jar:/opt/ibm/wlp/bin/tools/ws-javaagent.jar. 
[9/29/16 18:06:37:205 UTC] 00000026 console       I   Logging started. Rule Execution Server console version: Decision Server
[9/29/16 18:06:37:212 UTC] 00000026 console       I   Properties used for initialization: 
ilog.rules.res.HELP_INDEX = http://www.ibm.com/support/knowledgecenter/SSQP76_8.8.1/com.ibm.odm.dserver.rules.res.console/cshelp_resconsole.xml
ilog.rules.res.HELP_TOPIC = com.ibm.odm.dserver.rules.res.console
resconsole-logging-config-filename = resconsole-logging.properties
[9/29/16 18:06:37:282 UTC] 00000026 console       2   Properties: {org.apache.myfaces.AUTO_SCROLL=true, ilog.rules.res.HELP_TOPIC=com.ibm.odm.dserver.rules.res.console, ilog.rules.res.HELP_CONTEXT=http://www.ibm.com/support/knowledgecenter/SSQP76_8.8.1, org.apache.myfaces.COMPRESS_STATE_IN_SESSION=false, javax.faces.STATE_SAVING_METHOD=server, fileXomPersistenceDirectory=res_xom, org.apache.myfaces.SERIALIZE_STATE_IN_SESSION=false, calendarType=gregorian, distributed.mode=true, org.apache.myfaces.READONLY_AS_DISABLED_FOR_SELECTS=true, ilog.rules.res.RTS_CONTEXT=/teamserver, management.protocol=jmx, server-info-max-length=100, org.apache.myfaces.ADD_RESOURCE_CLASS=org.apache.myfaces.renderkit.html.util.DefaultAddResource, org.apache.myfaces.CHECK_EXTENSIONS_FILTER=false, org.jboss.jbossfaces.WAR_BUNDLES_JSF_IMPL=true, defaultDWConfiguration=factoryClassname=ilog.rules.res.persistence.impl.jdbc.IlrDatasourceTraceDAOFactory;JNDI_NAME=jdbc/resdatasource, persistenceType=datasource, filePersistenceDirectory=res_data, allowIframe=true, org.apache.myfaces.VALIDATE=false, org.apache.myfaces.NUMBER_OF_VIEWS_IN_SESSION=10, org.apache.myfaces.RESOURCE_VIRTUAL_PATH=/faces/myFacesExtensionResource, ilog.rules.res.SSP_CONTEXT=/testing, management.tcpip.timeout=20, ilog.rules.res.HELP_INDEX=http://www.ibm.com/support/knowledgecenter/SSQP76_8.8.1/com.ibm.odm.dserver.rules.res.console/cshelp_resconsole.xml, org.apache.myfaces.PRETTY_HTML=true, org.apache.myfaces.DETECT_JAVASCRIPT=false, ilog.rules.res.trace.DECISIONWAREHOUSE_CONFIGURATIONS=defaultDWConfiguration, xomPersistenceType=datasource, resconsole-logging-config-filename=resconsole-logging.properties, autoCreateSchema=false, management.tcpip.port=1883, ilog.rules.res.HTDS_CONTEXT=/DecisionService, org.apache.myfaces.ALLOW_JAVASCRIPT=true}
[9/29/16 18:06:39:206 UTC] 00000026 console       I   Reading Decision Warehouse configurations from web.xml
[9/29/16 18:06:39:223 UTC] 00000026 console       I   The Decision Warehouse configuration defaultDWConfiguration was loaded.
[9/29/16 18:06:39:231 UTC] 00000026 console       I   The trace DAO factory was initialized: ilog.rules.res.persistence.impl.jdbc.IlrDatasourceTraceDAOFactory
[9/29/16 18:06:39:861 UTC] 00000026 console       2   JMX implementation used: Sun
[9/29/16 18:06:39:985 UTC] 00000026 console       I   The initialization was successful. 1 RuleApps are available in the RES repository.

which is nice :-)

Source: -

at

No comments:

Post a Comment

Subscribe to: Post Comments (Atom)

Note to self - use kubectl to query images in a pod or deployment

In both cases, we use JSON ... For a deployment, we can do this: - kubectl get deployment foobar --namespace snafu --output jsonpath="{...