Monitoring Servers

Monitor Server command

You can issue the monitor server command against a running server through the emxRunMQL admin tool, or by connecting directly to the server from a separate, stand-alone Java program or custom JSP. See "monitor Command" in the Reference Commands chapter of the MQL Concepts.

UNIX Kill -QUIT command

The UNIX kill -QUIT command has always provided a dump of the Java threads currently executing when issued against a running Java process, such as an app server or RMI server. This is a function of the JVM. It does not stop the server; it merely reports the program stack for the current Java threads on stdout.

These Java stacks do not by default extend down into native libraries such as the 3DSpace kernel library. However, when kill -QUIT is issued on an 3DSpace Service on Unix, the specific thread details (both C++ and Java) are prepended to the output. This is supported on all 3DSpace Service Java 1.4 deployments on Unix. Solaris and HP also support this interface with Java 1.3.

Note: You must include the process ID (PID) as follows:

kill -QUIT PID

The PID is the app server's JVM PID. The output goes to stdout, so you should start the server with the nohup option or redirect the output to a file.

Note: While the kill command is not available on Windows, you can use Ctrl+Break from a Windows app server's console to get a thread dump.

TCP Listener

If your servers do not support kill -QUIT, or if you want to set up a program to ping multiple servers periodically, you must ensure that your servers are listening for server monitor requests. It may also be useful if Java threads seem not to be responding.

In order to set up a listener thread, 3DSpace needs a distinct TCP port specification for each 3DSpace Service that is running on the same machine. By default, output is sent to a server-assigned port, and the port number is identified in mxtrace.log:

Notice #4000047 Listening on MX_DEBUG_PORT 4465

You can connect to this port from a separate process (with telnet, for instance) and get the monitor server output.

You can also provide a port number by setting MX_DEBUG_PORT in the environment from which the server is started. By default it is set to 0, so that the system assigns an available port. If you set it to -1, listening on a port is disabled.

The MX_DEBUG_PORT is run on a thread separate from 3DSpace. Consequently, when mxAudit.log is generated at system startup, there is the possibility that the MX_DEBUG_PORT listener thread is not yet done setting up the port. In this case, mxAudit.log will contain a message such as the following:

MX_DEBUG_PORT listener not yet running at time of audit - check 
mxtrace.log.

In any case, if an 3DSpace Service is unable to start a listener thread, it reports the failure in the mxtrace.log file, together with the port number that failed. If it succeeds, it also puts a confirmation notice into mxtrace.log, including the port number that it is listening on. Example mxtrace.log entries follow:

If listen fails:

#0 System Error #4000046 Failed to listen on MX_DEBUG_PORT 1099 (port 
in use)

Other informational messages:

Notice #4000047 Listening on MX_DEBUG_PORT 4465

Notice #4000049 MX_DEBUG_PORT explicitly disabled.

Output

The MQL monitor server command returns output to the caller as a string, or dumped to a plain text file. The signal interface will dump thread information to stdout.

The format of this information may change, possibly significantly, in future releases as further phases of the server monitor are developed.

The output represents the state of all threads executing in the 3DSpace library, (or a subset if the age option is specified) at the time the request is made.

The following types of information are reported in the phase 3 core server monitor. For each thread reported on, a stack consisting of these types of entries is output.

Studio Customization Toolkit call information
Includes the header <ADK Trace Entry> followed by Studio Customization Toolkit call type, user, session, and parameters of the Studio Customization Toolkit call being processed. Also includes Studio Customization Toolkit origin stack trace if available.
Program information
Includes the header <Launching Program Object> followed by the Program name, arguments, user, and deferred status of the 3DSpace program object being launched. Indicates how the program was invoked with one of program, method, check, action, or override, and lists program global and local environment variables.
Note: Due to the nature of the thread dump utility, some information, such as program environment variables, may be slightly out-of-sync with actual current values in use by the 3DSpace thread, especially if MX_JIT_TRIGGER_MACROS = TRUE. Some environment variables are listed as <not evaluated>. This is because evaluation by the monitor would violate the JIT setting.
JPO information
Includes the header <Launching Java Object> and is generally preceded by a <Launching Program Object> entry, except when the JPO is run via the JPO.invoke Studio Customization Toolkit call, as MX_PAM_AUTHENTICATION_CLASS, or as part of an access control check. Provides details including JPO name, constructor parameters, Class name, method name, and method parameters.
Note: Environment variables are not included in the output of monitor server when a program is run with JPO.invoke or as external authentication programs. However, environment variables are available when a program is run for an access check (such as a rule or filter program).

Trigger information
Includes the header <Launching Trigger Program> followed by the type (such as PromoteCheck, LockOverride, CreateAction, etc.), program name and arguments for the Trigger program being processed.
MQL command information
Includes the header <Executing MQL Command> followed by the command.

All entries also include the total processing time and any resulting mxtrace.log entries.

Every thread running in the kernel is the result of an Studio Customization Toolkit call that originates from an ENOVIA app JSP or servlet, a JPO, a custom jsp, Web Navigator, or a custom app. Therefore, for each thread reported by the monitor, the first entry is always: <1- ADK Trace Entry>. The numbers following the opening bracket "<" indicate the sequence in which the entries occurred. Unlike programming stacks, the entries are listed oldest to youngest. For instance you might see the following headers in the output:

<1- ADK Verbose Trace Entry>...
<2- Launching Trigger Program>...
<3- Launching Program Object>...
<4- Launching Java Object>...
<5- ADK Verbose Trace Entry>...

Notice that entries 1 and 5 are both Studio Customization Toolkit entries, because the JPO launched in entries 3 and 4 is making an Studio Customization Toolkit call back into 3DSpace.

Sample Output

Note: Be aware that the format of the below information will change, possibly significantly, in future releases.

***************************************************
eMatrix Server Trace - Version 10.6.2.0 - 11/21/2005 18:18:13 GMT:
>>>>
>>>> Tells how long the server has been up.
>>>>
eMatrix Active: 1 hour 5 minutes
>>>>
>>>> Thread #1 entered the server as user creator to evaluate a and has
>>>> been doing so for 0 seconds. Query fields are provided
>>>>
Thread #1: t@053, ref=0x485b98
  session=mx113259838319617870931
  ms=78e2fe00x08
<Start Stack Trace>
  <1 - ADK Verbose Trace Entry>
  stateless dispatch for evaluateSelect.bosQuery executing
  Active: 0 seconds
  parameters:
    bosContext _cntx:
      user:
        creator
      depth:
        1
      session id:
        mx113259838319617870931
    bosString _name:
      
    bosQuerySt _query:
      bosQueryClauseSt clause
        bosString typePattern
          CaseOutline
        bosString namePattern
          *
        bosString revisionPattern
          *
        bosString latticePattern
          *
        bosString ownerPattern
          *
        bosString where
          name matchlist "*mon-yen,*tue-yng" "," && ((current ~= 
"Active") && ("attribute[RAPTestName]" ~~ "**") && ("attribute[Last 
Name]" ~~ "**") && ("relationship[Employee].from.name" ~= "Acme 
Technologies"))
      bosString fullTextSearch
        
      bosString fullTextFormat
        
      short limit
        100
      uint8 expandTypes
        1
      uint8 queryTrigger
        0
      bosString description
        
      bosDataList icon
        0 entries
    bosStringList _objectSelect:
      5 entries
          bosString str
            attribute[First Name]
          bosString str
            attribute[Last Name]
          bosString str
            name
          bosString str
            id
          bosString str
            relationship[CaseOutlineToRAPPackageData].from
      stacktrace: 
    at 
com.MatrixOne.jdl.bosQueryShim.evaluateSelect(bosQueryShim.java:102)
    at matrix.db.Query.select(Query.java:821)
    at ContextTest.doQuery(ContextTest.java:109)
    at ContextTest.run(ContextTest.java:64)
>>>>
>>>> If there are any warnings/errors that have occurred in this thread
>>>> they will be shown here.
>>>>
Error Stack:
        Warning #1500568: Where clause is not valid; contains term 
'attribute[Last Name]' referring to a non-existent attribute.
<End Stack Trace>
>>>>
>>>> Thread #2 entered the server as user creator to execute an mql 
command 
>>>> and has been doing so for 0 seconds. 
>>>> The mql command is provided - 'exec prog JPOTest'
>>>>
Thread #2: t@024, ref=0x36e268
  session=mx1132597948702605645
  ms=1a3a380x08
<Start Stack Trace>
  <1 - ADK Verbose Trace Entry>
  stateless dispatch for executeCmd.bosMQLCommand executing
  Active: 0 seconds
  parameters:
    bosContext _cntx:
      user:
        creator
      depth:
        3
      session id:
        mx1132597948702605645
    bosString _cmd:
      exec prog JPO_Test
      stacktrace: 
    at 
com.MatrixOne.jdl.bosMQLCommandShim.executeCmd(bosMQLCommandShim.java:
32)
    at matrix.db.MQLCommand.executeCommand(MQLCommand.java:90)
    at DiagTestProg.run(DiagTestProg.java:55)
  Error Stack:
<2 - Executing MQL Command>
  Active: 0 seconds
  cmd=exec prog JPO_Test
  Error Stack:
>>>>
>>>> entries 3,4 show the launching of the program
>>>>
<3 - Launching Program Object>
  Active: 0 seconds
    Name=JPO_Test, user=, invocation=program
  Global env at program launch:
  Local env at program launch:
    APPLICATION=BOS
    INVOCATION=program
    MATRIXHOME=/local/home/dvlp/ksmith/rmi10550
    MATRIXPATH=
    PATH=/usr/j2se/bin:/local/home/dvlp/ksmith/rmi10550/bin/solaris4:/
usr/dt/bin:/usr/openwin/bin:/usr/openwin/bin/xview:/sbin:/bin:/usr/
bin:/usr/sbin:/opt/SUNWspro/prod/bin:/usr/ucb:/usr/ccs/bin:/etc:/usr/
etc:/usr/etc/install:.:/sqa/netlib:/usr/local/bin:/usr/local/bin/X11:/
app/qausr/matrix-install/scripts:/app/verity/k2/k2/_ssol26/bin
  Deferred:
    false
  Error Stack:
  
  <4 - Launching Java Object>
  Active: 0 seconds
  progName:
    JPO_Test
  constructor parameters: 
  className:
    JPO_Test_mxJPOA9VrXAAAAAEAAAAG
  methodName:
    mxMain
  method parameters:
  
  Error Stack:
>>>>
>>>> The program calls back through the ADK interface to execute 
another MQL
>>>> command - 'monitor server'
>>>>
<5 - ADK Verbose Trace Entry>
  stateless dispatch for executeCmd.bosMQLCommand executing
  Active: 0 seconds
  parameters:
    bosContext _cntx:
      user:
        creator
      depth:
        3
      session id:
        mx1132597948702605645
    bosString _cmd:
      monitor server
>>>>
>>>> And finally, the java stack trace that led to the initial ADK call 
is also 
>>>> provided.(This is not provided by default - ADK Origin trace must 
be enabled)
>>>>
stacktrace: 
    at 
com.MatrixOne.jdl.bosMQLCommandShim.executeCmd(bosMQLCommandShim.java:
32)
    at matrix.db.MQLCommand.executeCommand(MQLCommand.java:90)
    at 
JPO_Test_mxJPOA9VrXAAAAAEAAAAG.mxMain(JPO_Test_mxJPOA9VrXAAAAAEAAAAG.j
ava:25)
    at java.lang.reflect.Method.invoke(Native Method)
    at 
matrix.db.MatrixClassLoader.invokeObject(MatrixClassLoader.java:383)
    at 
matrix.db.MatrixClassLoader.invokeObject(MatrixClassLoader.java:400)
    at com.MatrixOne.jni.MatrixKernel.statelessDispatch(Native Method)
    at 
com.MatrixOne.jdl.rmi.bosMQLCommandImpl.executeCmd(bosMQLCommandImpl.j
ava:46)
    at java.lang.reflect.Method.invoke(Native Method)
    at 
sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:236)
    at sun.rmi.transport.Transport$1.run(Transport.java:147)
    at java.security.AccessController.doPrivileged(Native Method)
    at sun.rmi.transport.Transport.serviceCall(Transport.java:143)
    at 
sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:46
0)
    at 
sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.
java:701)
    at java.lang.Thread.run(Thread.java:479)
>>>>
>>>> No errors for Thread #2
>>>>
Error Stack:
  
  <End Stack Trace>
>>>>
>>>> Thread #3 is also executing an MQL command - 'promote bus PART-u 
Test 0'
>>>>
Thread #3: t@021, ref=0x36e2e0
  session=mx113259964028925613505
  ms=42f1b80x08
  <Start Stack Trace>
  <1 - ADK Verbose Trace Entry>
  stateless dispatch for executeCmd.bosMQLCommand executing
  Active: 4.00 seconds 
  parameters:
    bosContext _cntx:
      user:
        creator
      depth:
        1
      session id:
        mx113259964028925613505
    bosString _cmd:
      promote bus PART-u Test 0;
  
  Error Stack:
        Warning #1500318: The ConnectString in your connection 
(bootstrap) file does not match the ConnectString of any server object 
defined in the database
  <2 - Executing MQL Command>
  Active: 4.00 seconds 
  cmd=promote bus PART-u Test 0;
  Error Stack:
>>>>
>>>> The promotion launches a trigger.  Trigger macros and RPE values 
are shown
>>>>
<3 - Launching Trigger Program>
  Active: 4.00 seconds 
    TriggerState
    active=true
    owner Oid=212401520
    name=JPO_DiagTest
    args=
    info=PromoteCheck
  Error Stack:
  
  <4 - Launching Program Object>
  Active: 4.00 seconds 
    Name=JPO_DiagTest, user=, invocation=check
  Global env at program launch:
  Local env at program launch:
    ACCESSFLAG=True
    APPLICATION=BOS
    AUTOPROMOTE=False
    CHECKACCESSFLAG=True
    CURRENTSTATE=one
    DESCRIPTION=
    ENFORCEDLOCKINGFLAG=False
    EVENT=Promote
    HASACTUALDATE=True
    HASSCHEDULEDATE=False
    INVOCATION=check
    ISCURRENT=True
    ISDISABLED=False
    ISENABLED=True
    ISOVERRIDDEN=False
    ISREVISIONABLE=True
    ISVERSIONABLE=True
    LATTICE=unit1
    LOCKER=
    LOCKFLAG=False
    MATRIXHOME=/local/home/dvlp/kkohn/rmi10550
    MATRIXPATH=
    NAME=Test
    NEXTSTATE=final
    OBJECT="PART-u" "Test" "0"
    OBJECTID=32541.36365.3240.64880
    OWNER=creator
    PATH=/usr/j2se/bin:/local/home/dvlp/kkohn/rmi10550/bin/solaris4:/
usr/dt/bin:/usr/openwin/bin:/usr/openwin/bin/xview:/sbin:/bin:/usr/
bin:/usr/sbin:/opt/SUNWspro/prod/bin:/usr/ucb:/usr/ccs/bin:/etc:/usr/
etc:/usr/etc/install:.:/sqa/netlib:/usr/local/bin:/usr/local/bin/X11:/
app/qausr/matrix-install/scripts:/app/verity/k2/k2/_ssol26/bin
    POLICY=simple-u
    REVISION=0
    STATENAME=one
    TIMESTAMP=Mon Nov 21, 2005 2:01:30 PM EST
    TRIGGER_VAULT=unit1
    TYPE=PART-u
    USER=creator
    VAULT=unit1
  Deferred:
    false
  Error Stack:
  
  <5 - Launching Java Object>
  Active: 4.00 seconds 
  progName:
    JPO_DiagTest
  constructor parameters: 
  className:
    JPO_DiagTest_mxJPOAeDjNAAAAAEAAAAC
  methodName:
    mxMain
  method parameters:
>>>>
>>>> No errors for Thread #3
>>>>
Error Stack:
<End Stack Trace>
Monitored 3 active eMatrix threads
***************************************************

Since it passes large strings across the Studio Customization Toolkit connection for every server call, thereby affecting performance, Studio Customization Toolkit Origin trace output is not included in server monitor output by default. However, if diagnostic efforts would be significantly aided by knowing the appserver-tier Java stack (JSP's and beans) that initiated certain Studio Customization Toolkit calls, it can be useful, and is therefore included in server monitor output when enabled.

With the introduction of Flash DB, 3DSpace supports multi/hyper threaded CPUs. Hyper-threading support provides better utilization of multi-core CPUs which are becoming common place. This support introduces background threads that do work which, in prior releases, occurred in a single threaded fashion. The result is improved performance and higher throughput. The threads consume very little memory and are transparent to the JVM and/or app server.

Server monitor output has been enhanced to include these threads, as in the example below:

>>>>
>>>> Thread #1 is the parent thread of "Background Task" example below.
>>>>
Thread #1: t@155, ref=0x855400, 
session=mx16717111951ee8e:mx1688703977961823, ms=0x01e28c00
<Start Stack Trace>
  <1 - ADK Verbose Trace Entry>
  stateless dispatch for executeCmd.bosMQLCommand executing
  Active: 0 seconds
  User:
    creator
  Session:
    mx16717111951ee8e:mx1688703977961823
  Parameters:
    bosContext _cntx:
      user:
        creator
      depth:
        1
      session id:
        mx16717111951ee8e:mx1688703977961823
    bosString _cmd:
      list prog
  Error Stack:
>>>>
>>>> ADK call MQLCommand issued "list prog"
>>>>
<2 - Executing MQL Command>
  Active: 0 seconds
  Command:
    list prog
  Error Stack:
  
<End Stack Trace>
Thread #2: t@158, ref=0x80f918, 
session=mx16717111951ee8e:mx1688703977961823, ms=0x01e28c00
<Start Stack Trace>
  <1 - Launching Background Task>
  Active: 0 seconds
>>>>
>>>> Task type: "FlashNextTask" indicates cache is being read. Parent 
thread id is found 
>>>> in thread #1 above.
>>>>
Task type: FlashNextTask
  Parent Thread: t@155  
  Priority: high
  Reference count: 2
  Error Stack:
  
<End Stack Trace>
Monitored 2 active threads

The defined background task types are:

SessionTask—generic task
ExitTask—session exit task
SyncTask—administration task
InsertTask—database insert task
UpdateTask—database update task
SQLNextTask—database read task
FlashNextTask—FlashDB cache management task
IdCacheTask—object ID management task