Skip to main content
R
RajuPulavarthi1-Visitor
1-Visitor
October 11, 2010
Question

Monitoring the execution times of Windchill operations within Method server.

  • October 11, 2010
  • 4 replies
  • 1544 views
Fellow members,

When Method timing logging is turned on, the following information is
printed within the Method server. Currently we parse them using Unix
scripts to look at the time consuming activities. Sometimes this effort
is cumbersome because of the amount of operations and the number of
Method Server logs we have.



What I want to find is if there is any way to monitor the value of this
time, define a Threshold (ex: 2000 ms) and get notified via JMX mBeans,
in case an operation takes more time than the Threshold. This would
enable us being proactive on some of the operations that take long time
because of either loads, lack of DB Indexes or because of the upgrade to
new DSU .



I would appreciate if you can share anything in this matter. Please do
share any custom mBean you may have created so that we can leverage that
to start creating our own in case there is no OOTB way.



Mon 10/11/10 10:10:45: RMI TCP Connection(4994)-127.0.0.1: INFO :
wt.method.server.timing - INVOKE: end
com.ptc.netmarkets.util.misc.NmActionServiceFwd.getAction
[gf3s5ndl;18518;106955], 2 ms (1/0/0)



Thanks,

Raju





Raju Pulavarthi

St. Jude Medical

- <blocked::<a style="COLOR:" blue;=" text-decoration:=" underline&quot;=" target="_BLANK" href="mailto:-">">mailto:->

sjm.com

4 replies

P
pyalavarthi1-Visitor
1-Visitor
October 11, 2010
Raju,
I used a unix and python script combination to get the automated email
notifications. Here is the unix command that I used to find the Long Running
calls. You might have to change it little bit based on your requirements.
You can setup a cron job along with shell script to send automated
notifications.

*ms | xargs -n1 cat | egrep "INVOKE.*end" | sed "s#/# / #g" | gawk
"(\$(NF-2)-9999>0){print \$(NF-2),\$0}"|sort -k 1,1n | sed "s# / #/#g" |
gawk "{\$1=\"\";print}" > MS_LongRunningInvokes.log*

Alias for methodserver log file.

*alias ms ='ls -trC1 /opt/ptc/windchill91/Windchill/logs/MethodServer-*.log
| tail -1'*


Regards,
Prathap <">http://goo.gl/LuT5>



J
jessh12-Amethyst
12-Amethyst
October 11, 2010
There are no JMX notifications that occur upon individual method
contexts (or servlet requests) taking longer than a threshold.

That said, there are extensive logging options for both method contexts
and servlet requests in R9 and higher. [There are fairly extensive
logging options for servlet requests in R8 M050 when JMX is enabled
there, but method context improvements are not present until R9.x.]

What options depends on the release and MOR level you're at, but some
things to note:

* The wt.method.server.timing logger output can be routed to a
separate file via normal log4j configuration approaches.
* The wt.method.MethodContextMonitor.contexts logger provides much
more capability than wt.method.server.timing.
o This logger can be dynamically configured through the
corresponding MBean (located at com.ptc -> Monitors ->
MethodContexts in the MBean tree).
o There is a similar logger for servlet requests,
wt.servlet.ServletRequestMonitor.request -- also configured
through a corresponding MBean (located at com.ptc ->
WebAppContexts -> /WindchillWebAppName /-> Monitors ->
ServletRequests).
o For both of these loggers:
+ Only ERRORs are logged out-of-the-box, but you can
increase the verbosity.
# INFO will log all requests/contexts.
# WARN will log only those which take longer than
a specified threshold.
* One could actually configure a
wt.log4j.jmx.JMXAppender on the logger in
such a case to produce a JMX notification
for each log message. One could then add
a NotificationHandler to the JMX
configuration to produce e-mails to the
administrator in such a case.
+ One can control which attributes are logged and how
the data is formatted through the corresponding MBean.
+ In recent R9.1 MORs, one can output this data to a
log4j Appender using a wt.log4j.jmx.TSVLayout, which
will produce a tab separated value file (for easy
reading by Excel or OpenOffice) or to the relational
database using a wt.log4j.jmx.AsyncJDBCAppender.
# In either case each attribute goes to a separate
column for easy data mining without ugly parsing.
# In recent R9.1 MORs there are similar loggers,
wt.method.MethodContext.contextMBean.finish and
wt.servlet.ServletRequestMonitor.requestMBean.finish,
that allow you to choose which attributes are
logged separately from the "normal" logging and
at what verbosity.
* This is specifically to facilitate logging
one set of attributes to normal log files
at one verbosity and a different set at a
different verbosity to a specialized log4j
layout or appender like TSVLayout or
AsyncJDBCAppender.
* The attribute selection is done by layout
or appender in this case.
o In recent releases/MORs, there are also FilteredLogger
MBeans associated with the MethodContexts and
ServletRequests MBeans that allow you do log specific to a
separate logger at a different log level for specific users,
request URIs, etc.
o In recent releases/MORs, there's also functionality to allow
addition of custom request and/or method context listeners
to these MBeans to allow you to do you own logging, etc,
upon the begin and end of any request or method context.

In short, use wt.method.MethodContextMonitor.contexts (and
wt.servlet.ServletRequestMonitor.request) rather than
wt.method.server.timing in most cases and use as much of the other
material noted above as you have time/energy/need for.

--
Jess Holle

J
jessh12-Amethyst
12-Amethyst
October 12, 2010
Of course I forgot to mention at least a couple of things:

* These MBeans track overall statistics for average method context
and servlet request time (elapsed and CPU).
o Some of this data is shown on the Server Status page.
* There is method context histogrammer MBean that can produce such
data on a per target class/method basis.
o Such functionality will be provided for servlet requests as
well in the future. Until then, one could create a similar
servlet request histogrammer as a custom listener.

R
RajuPulavarthi1-VisitorAuthor
1-Visitor
October 26, 2010
Thanks Jess. I will look into these further. I am sorry for the late response. These messages from the solution groups have been going to a separate outlook folder based on the filters and I missed them.

Raju Pulavarthi
-<">mailto:->
sjm.com
Terms & ConditionsCookie settingsAccessibility statement