mqweb – displaying the secret statistics

Yes, mqweb does provide statistics; through the standard JMX interface provided as part of the base Liberty function.  I expect most people do not know they are available.   The data gets less useful over time, for example you get the “average time” since the mqweb started, rather than the last minute.  See here on how to extract useful information from the data, and show useful averages.

You need in mqwebuser.xml .

<featureManager>
<feature>monitor-1.0</feature>
</featureManager>

and in jvm.options

-Dcom.sun.management.jmxremote
-Dcom.sun.management.jmxremote.port=9010
-Dcom.sun.management.jmxremote.local.only=true
-Dcom.sun.management.jmxremote.authenticate=false
-Dcom.sun.management.jmxremote.ssl=false

These options should be suitable in your test environment.  You will want to change them for production.

You need the port number (9010 in the above example) when you extract jmx data.

How do you display the data?

For a quick sniff, (no good for extracting data and plotting charts)  you can use jconsole.  Use remote connection localhost:9010 .  it does not display all of the data.

I found jmxquery very useful.  I updated the github version to fix a bug which caused a loop.  See here.

The query is

java -jar JMXQuery.jar -url service:jmx:rmi:///jndi/rmi://127.0.0.1:9010/jmxrmi -q ‘WebSphere:*’

You get data on

• WebSphere:type=JvmStats
• WebSphere:type=ThreadPoolStats,name=Default Executor
• WebSphere:type=ServletStats,name=com.ibm.mq.console.javax.ws.rs.core.Application/AppName (String) = com.ibm.mq.console
• WebSphere:type=ServletStats,name=com.ibm.mq.rest.javax.ws.rs.core.Application/AppName (String) = com.ibm.mq.rest

To get ‘console’  and ‘ResponseTime’ data I used

java -jar JMXQuery.jar -url service:jmx:rmi:///jndi/rmi://127.0.0.1:9010/jmxrmi 
-q 'WebSphere:*' 
-count 20 -every 60 
|grep --line-buffered console
|grep --line-buffered ResponseTime
|python3 mqweb.py

• Where
• java -jar JMXQuery.jar – invoke the program
• -url service:jmx:rmi:///jndi/rmi://127.0.0.1:9010/jmxrmi – with this url and the above port number from the jvm.options
• -q ‘WebSphere:*’ – give me only data for this components
• -count 20 -every 60 – my extensions giving a record every 60 seconds, and doing 20 of them
• |grep –line-buffered console – only pull out the console records, ( ignore the ‘rest’ records).  The –line-buffered tells grep to flush it immediately
• |grep –line-buffered ResponseTime – only interested in this detailed level
• |python3 mqweb.py – pass it into the python program.  This calculates the delta between records and prints out the count and mean value for that interval

If you are collecting data in real time from a stream, you need to ensure any processing is unbufferred.  Often the default behavior is to accumulate the data in a big buffer, and write the buffer when it is full.  Check any filters you use, for example grep –line-buffered.

One line of output from the JMXQuery program for the console activity is

WebSphere:type=ServletStats,name=com.ibm.mq.console.javax.ws.rs.core.Application/ResponseTimeDetails/count (Long) = 5

JvmStats

This comes under WebSphere:type=JvmStats/  See here.

• FreeMemory (Long) = 13350536
• ProcessCPU (Double) = 0.658040027605245
• UsedMemory (Long) = 75131256
• GcTime (Long) = 539
• UpTime (Long) = 1048277
• GcCount (Long) = 118
• Heap (Long) = 88473600
• FreeMemory (Long) = 13350536
• ProcessCPU (Double) = 0.658040027605245
• UsedMemory (Long) = 75131256
• GcTime (Long) = 539
• UpTime (Long) = 1048277
• GcCount (Long) = 118

ThreadPoolStats

This comes under WebSphere:type=ThreadPoolStats,name=Default Executor/

• PoolSize (Integer) = 8
• ActiveThreads (Integer) = 2
• PoolName (String) = Default Executor

See here.

com.ibm.mq.console and  com.ibm.mq.rest

The data is similar between them.  One has name=com.ibm.mq.console.javax.ws.rs.core.Application, the other has name=com.ibm.mq.rest.javax.ws.rs.core.Application

The data (in italics) with my comments in plain font are

• AppName (String) = com.ibm.mq.console
• RequestCountDetails/currentValue (Long) = 116
• RequestCountDetails/description (String) = This shows number of requests to a servlet
• RequestCountDetails/unit (String) = ns – this looks like a bug as it is a count not nanoseconds
• RequestCount (Long) = 116
• ServletName (String) = javax.ws.rs.core.Application
• ResponseTimeDetails/count (Long) = 116
• ResponseTimeDetails/description (String) = Average Response Time for servlet
• ResponseTimeDetails/maximumValue (Long) = 3060146565 – in nanoseconds ( see below for the unit)
• ResponseTimeDetails/mean (Double) = 8.796846855172414E7 – in nanoseconds
• ResponseTimeDetails/minimumValue (Long) = 793871 – in nanoseconds
• ResponseTimeDetails/standardDeviation (Double) = 4.198572684166255E8
• ResponseTimeDetails/total (Double) = 1.0204342352E10 – in nanoseconds – used in calculations
• ResponseTimeDetails/unit (String) = ns  – this is the units.  ns is nanoseconds
• ResponseTimeDetails/variance (Double) = 1.64064538075292096E17 –  used in calculations
• Description (String) = Report Servlet Stats for specified Servlet and application.
• ResponseTime (Double) = 8.796846855172414E7 – same as the ResponseTimeDetails

So we can see that there were

• 116 console requests since the mqweb server was started
• the units are ns (nano seconds)
• the console requests taking an average of 8.796846855172414E7  nanoseconds, 0.0879 seconds with
• a standard deviation of  4.136787844033974E7 – nanoseconds = 0.04198 seconds
• the maximum value was 3 060 146 565 ns = 3.060 seconds
• the minimum time was  793 871 ns or 0.000793 seconds

Some other data, showing how it changed over time

Data	Values	Later values	Much later values
Number of requests	82	3590	22920
Average (seconds)	0.158	0.0108	0.0099
Standard deviation (seconds)	0.487	0.034	0.035
Maximum (seconds)	2.3	2.3	2.3
Minimum(seconds)	0.001	0.0001	0.0001

Notes:

• There is data only once a request has been processed, so if you have not run a rest request, there will be no JMX data for rest activity.
• These values are from start of the mqweb server. I did not see them reset, so you could have a data for a whole week or more.
• The maximum was from the first requests to run.  I expect this includes the “warm up” costs,  of loading the code and JITing it.
• The average values are from the start, so will be impacted by peaks and troughs.

For the each mqconsole window, there are two console counts every 10 seconds.  Any charts are refreshed every 10 seconds, so  I think this is a “I am still here, please send me any data you have for me”.

Data for rest

I started my mqweb server, and ran a python program which opened a connected and got three messages.

• Maximum time 0.3486
• Minimum time 0.0026
• Calculate the other one 0.0028

Because the first request takes a long time, you can adjust for this in your calculations to get a truer mean.

For example

I reran the script and processed 100 messages.  The average time of these was 0.003 seconds.

• Maximum 0.3486
• Mean 0.00637
• Count 103
• Total 0.656

The calculations are

• Mean * count =  0.656 (which matches Total as expected)
• Subtract the maximum, first time value 0.656 – 0.349 = 0.307
• Calculate the improved mean value ignoring the first value,  0.307 /(103 -1) = 0.003

So the adjusted mean time is 0.003 seconds – compared to the 0.006 which the JMX stats report.