Monitoring¶

Monitoring

JMX Instrumentation¶

Enabling the Support¶

Configuring the FWD Server¶

Some settings for monitoring are required at the FWD server startup. The following should be defined to the jvm (with -D):

com.sun.management.jmxremote
com.sun.management.jmxremote.ssl=true
com.sun.management.jmxremote.port=9010
com.sun.management.jmxremote.rmi.port=9010
com.sun.management.jmxremote.registry.ssl=true
com.sun.management.jmxremote.local.only=false
com.sun.management.jmxremote.authenticate=true
com.sun.management.jmxremote.password.file=[server.dir]/security/jmxremote.password
com.sun.management.jmxremote.access.file=[server.dir]/security/jmxremote.access
java.rmi.server.hostname=[jmx.hostname]
javax.net.ssl.keyStore=[server.dir]/security/jmxremote.keystore.jks
javax.net.ssl.keyStorePassword=[cert.password]

The truststore should be setup similar to the below:

# Generate Keystore
keytool -genkeypair -alias jmxserver -keyalg RSA -keystore keystore.jks -validity 3650

# Export certificate
keytool -export -alias jmxserver -file jmxserver.cer -keystore keystore.jks

# Import into Truststore
keytool -import -alias jmxserver -file jmxserver.cer -keystore truststore.jks

Caveats and Limitations¶

Some things that were tried:

Some values can be placed in a configuration file, but password related values simply did not work.
The certificate was newly created and self signed.
The public key needs to be known to tools like jconsole. For example, put it in the cacerts of the JDK involved. Using a separate truststore can be very challenging, and a lot of the examples found on the internet on setting the truststore for monitoring tools just don't work.

Using VisualVM¶

TBD: How the configuration is done (regarding public keys)
TBD: How to connect and use JMX tracepoints

Using JConsole¶

TBD: How the configuration is done (regarding public keys)
TBD: How to connect and use JMX tracepoints

FWD Appserver Agent State Instrumentation¶

Appserver Agents are used for appserver requests as well as REST/SOAP/WebHandler processing. Agent state is being tracked using JMX beans with the name having the AppServer_ prefix followed by the appserver name (like AppServer_hotel, for an appserver name hotel).

Each metric allows these int attributes:

MaxAgents, for the number of maximum agents configured for this appserver.
RunningAgents, for the number of agents running at this point (executing tasks or otherwise waiting for work).
AvailableAgents, for the number of agents currently available for executing tasks.

FWD Server - Persistence and ORM Instrumentation¶

Name	Type	API 2	Description
OrmDynParseFind	TIMER	`DynamiQueryHelper.parseFindQuery`	Dynamic FIND query parse.
OrmDynParseQuery	TIMER	`DynamiQueryHelper.parseQuery`	Dynamic query parse.
OrmHydrateRecord	TIMER	`SQLQuery.hydrateRecord`	Record hydration (from a `ResultSet`)
OrmFqlParse	TIMER	`Query.createSqlQuery`	FQL query parse.
OrmTempTableQuery	TIMER	`UnclosablePreparedStatement`	H2 query `execute` method calls.
OrmDynQueryInterpret	TIMER	`RuntimeJastInterpreter.interpret`	Dynamic query interpret.
OrmHqlHelperParse	TIMER	`HQLHelper.obtain`	Helper for an in-memory state of a converted query (static or dynamic).
OrmPreselectQueryAssemble	TIMER	`PreselectQuery.assembleHQL`	Calculate the final FQL for a converted query (static or dynamic).
OrmCreateDynamicTable	TIMER	`TempTableBuilder.tempTablePrepareImpl`	DATASET-HANDLE parameter processing.
OrmCreateDynamicBuffer	TIMER	`TemporaryBuffer.createDynamicBufferForTempTable`	Dynamic buffer definition.
OrmBufferDefineTemp	TIMER	`TemporaryBuffer.define`	temp-table buffer definition.
OrmBufferDefinePerm	TIMER	`RecordBuffer.define`	permanent schema buffer definition.
OrmBufferDelete	TIMER	`BufferImpl.resourceDelete`	record buffer delete.
OrmTableMapperMap	TIMER	`TableMapper.mapTemporaryTable`	API called during temp-table definition.
OrmTempTableParam	TIMER	`TemporaryBuffer.associate`	TABLE parameter processing.
OrmDynamicTableParam	TIMER	`TemporaryBuffer.createDynamicTable`	TABLE-HANDLE parameter processing.
OrmDataSetParam	TIMER	`DataSet.associate`	DATASET parameter processing.
OrmDynamicDataSetParam	TIMER	`DataSet.createDynamicDataSet`	DATASET-HANDLE parameter processing.
OutputTableCopier	TIMER	`OutputTableCopier.finished`	Processing of a OUTPUT TABLE parameter (at end of call).
OutputTableHandleCopier	TIMER	`OutputTableHandleCopier.finished`	Processing of a OUTPUT TABLE-HANDLE parameter (at end of call).
OutputDataSetCopier	TIMER	`OutputDataSetCopier.finished`	Processing of a OUTPUT DATASET parameter (at end of call).
OutputDataSetHandleCopier	TIMER	`OutputDataSetHandleCopier.finished`	Processing of a OUTPUT DATASET-HANDLE parameter (at end of call).
QueryCounter	-	-	Per database read/write query counting.

Note:
The QueryCounter JMX exposes 2 attributes:

ReadQueriesCount - the number of read queries executed on the enabled databases.
WriteQueriesCount - the number of write queries executed on the enabled databases.

It also has the following methods:

startCounting(String databaseName) - enables query counting on a specific database.
startCountingAll() - enables query counting on all connected databases.
stopCounting(String databaseName, String csvFileOutput) - stops counting queries executed on the specific database and generates a report at the configured path.
stopCountingAll(String csvFileOutput) - stops counting queries executed on the enabled databases and generates a report at the configured path.
reset(String databaseName) - resets count values for the specific database.
reset(String databaseName) - resets count values for all enabled databases.

QueryCounter Limitation: this query counter only considers SQLs executed over the physical database. Caching may affect the numbers of this JMX. To improve stability:

set the session lifespan to -1 to disable time based caching: https://proj.goldencode.com/projects/p2j/wiki/Database_Configuration#Session-Lifespan
you can control cache sizes with: https://proj.goldencode.com/projects/p2j/wiki/Cache_sizes
- [AL2] there is no obvious and clean way to disable them; maybe set 0 as a cache size?
- of interest are: com.goldencode.p2j.persist.FastFindCache.cache and com.goldencode.p2j.persist.orm.Session.cache

FWD Server - Dynamic Query Processing¶

OrmDynQueryProcess_SymRes	TIMER	`DynamicQueryHelper.parse`	Instrumentation for preparing the SymbolResolver
OrmDynQueryProcess_SchemaDict	TIMER	`DynamicQueryHelper.parse`	Instrumentation for preparing the SchemaDictionary
OrmDynQueryProcess_Parse	TIMER	`DynamicQueryHelper.parse`	Instrumentation for preparing the lexer and parser.
OrmDynQueryProcess_Parse2	TIMER	`DynamicQueryHelper.parse`	Instrumentation for running ONLY the parser.
OrmDynQueryProcess_Setup	TIMER	`DynamicQueryHelper.parse`	Instrumentation for setting up for TRPL processing.
OrmDynQueryProcess_Annotation	TIMER	`DynamicQueryHelper.parse`	Instrumentation for running ONLY the annotations TRPL.
OrmDynQueryProcess_Base	TIMER	`DynamicQueryHelper.parse`	Instrumentation for running ONLY the base_structure TRPL.
OrmDynQueryProcess_Core	TIMER	`DynamicQueryHelper.parse`	Instrumentation for running ONLY the core_conversion TRPL.
OrmDynQueryProcess_Post	TIMER	`DynamicQueryHelper.parse`	Instrumentation for running ONLY the postprocessing TRPL.
OrmDynQueryProcess_Intern	TIMER	`DynamicQueryHelper.parse`	Instrumentation for optimizing the result JAST by interning the String instances.

FWD Server Runtime Instrumentation¶

Name	Type	API 2	Description
ContextLocalGet	TIMER	`ContextLocal.get`	Context-local state.
MessagePayloadS11n	TIMER	`Message.read/writeExternal`	`Message.payload` (de)serialization
objToByteArray	TIMER	`Protocol.objToByteArray`
ServerStateS11n	TIMER	`p2j.ui.ServerState.read/writeExternal`	`ServerState.widgetAttrValues` (de)serialization
sslSend	TIMER	`SSL.send`	SSL send time
sslWrap	TIMER	`SSL.wrap`	SSL wrap time
sslUnwrap	TIMER	`SSL.unwrap`	SSL unwrap time
TMCommit	TIMER	`TransactionManager.processCommit`	Block commit processing.
TMRollback	TIMER	`TransactionManager.processRollback`	Block rollback processing.
TMValidate	TIMER	`TransactionManager.processValidate`	Block validate processing.

FWD OpenClient Runtime Instrumentation¶

Add this code to enable JMX instrumentation in the FWD OpenClient runtime, preferably at the beginning of the main method:

      FwdJMX.init();

All JMX beans are prefixed with Appserver:

Name	Type	API 2	Description
AppserverAddTableMetaData	TIMER	`LegacyJavaAppserver.addTableMetaData`	Time spent when adding a new table to a graph.
ApperverGetJavaParameter	TIMER	`LegacyJavaAppserver.getJavaParameter`	Time spent when processing the arguments passed to a remote call.
AppserverGetOutputParameter	TIMER	`LegacyJavaAppserver.getOutputParameter`	Time spent when processing the OUTPUT arguments from a remote call.

Other Miscellaneous Metrics¶

Name	Type	API 2	Description
LegacyServiceWorkerTaskCounter	MAP	`LegacyServiceWorker.addWork`	The number of executed requests for each REST, SOAP or Web worker thread.
WidgetAttrEnqueues	MAP	`LogicalTerminal.enqueuWidgetAttr`	Number of changes in the widget attributes, for each attribute.
WidgetAttrFlushes	COUNTER	`LogicalTerminal.flushEnqueuedWidgetAttrs`	Total number of batched attribute flushes, to the FWD client.
NetworkReads	COUNTER	`Protocol$Reader.run`	Number of bytes read from the network.
NetworkWrites	COUNTER	`Protocol$Writer.run`	Number of bytes sent over the network.
QueryProfiler	QUERY	`SQLQuery` APIs	Track per-query time spent for record hydration, number of records returned, cache hits or misses.
SpreadsheetCmdNanos	MAP	`SpreadsheetWidget.invokeWidgetCommand`	Accumulated execution time (nanoseconds) of each `SPREADSHEET` widget backend command.
<db>.locks	LOCK	`LockTableUpdater` APIs	Created for each database.

VisualVM (Java 8)¶

VisualVM is a free tool that comes with the the Oracle reference JDK distribution, many (all?) OpenJDK distributions, and probably others. If you've installed the full JDK, you should already have this tool available on your system.

VisualVM is a graphical application based on the NetBeans IDE platform, but it runs stand-alone. It can perform a range of troubleshooting operations, including real-time memory, thread, and performance monitoring, as well as thread and heap dump creation and analysis. It is extensible; additional plug-ins can be downloaded and installed from within the application. This discussion is focused primarily on the CPU sampling aspects of the tool, though the optional "Visual GC" tool is excellent for monitoring memory allocation and garbage collection in real time. IIRC, the CPU profiling/sampling facility is part of the base platform.

VisualVM's CPU sampling can be used to track down performance bottlenecks, where there is a test/process/routine for which performance differs between the original code running in Progress and the corresponding, converted code running in FWD. It is most useful to have a test that runs for a long enough time (at least a minute, if not longer), to generate enough CPU sample data to come to a meaningful conclusion. Generally, the shorter a sampling session, the less reliable the results, and the less obvious it is to determine the cause.

VisualVM is very accessible to use. If you didn't install the visualvm package when you installed your JDK, you will need to do so. The project has a home page at https://visualvm.github.io/, but you don't need to do much research to get started. Just run "visualvm" from the command line (or set up a launcher for it). If you find you need to increase the max heap (usually the only configuration that one must change), you can find the configuration file at /etc/visualvm/visualvm.conf on Ubuntu Linux.

TBD: Confirm if there is a corresponding file for Windows JDKs.

You must connect to a running JVM to access any details. To connect, hover over the vertical "Applications" button in the left margin, and it will open a view of all running JVMs. Double click on the JVM you want to monitor.

The tab you need for CPU performance profiling (sampling, actually) is the "Sampler" tab. It is not recommended to use the "Profiler" tab for anything but the simplest application; it will spend forever instrumenting your bytecode and ultimately is so slow to be unusable for anything complex. The settings for the Sampler let you specify the packages you want to include or exclude from sampling. Generally, the only settings changes I've made are to set the sampling frequency to its most granular (20ms) and to exclude the com.goldencode.p2j.net package. The latter is useful, because otherwise your results are dominated by the time spent waiting on sockets (which the sampler counts in its profiling, because the socket reader threads are marked "runnable", rather than "waiting").

Start up the FWD server on an otherwise quiet system. When you're measuring performance, you don't want background tasks to skew your results and you don't want to swap, ever. Attach the sampler to the FWD application server JVM as described above (or to the client JVM, if measuring client performance; note that the client does not execute converted business logic). A common approach is to sort by the "Self Time (CPU)" column, both while the sampler is running and when reviewing snapshots. Run the target test/process/routine whose performance you want to measure. When the test is done, or at any time during its execution, you can push the "Snapshot" button to capture accumulated results. Each snapshot is separate from the others, so you can take multiple without dropping earlier ones. It is from the snapshots and the active sampling view that you can get an idea where the performance bottlenecks are. You may have to do a little googling or reading from the project home page to get a better idea how to interpret your results; it's too much to summarize these techniques here.

One useful feature is "backtraces". From the "HotSpots" tab in a snapshot view, right-click on any row and select "Show Back Traces". When using these, it is helpful to also enable the "Samples" column, using the little table icon at the far right of the column headers. This can be annoying in that you have to do this every time you open the view, though. This column will tell you how many samples were taken in each method reported in the backtraces.

The thing to keep in mind when using the sampler is that the times are not necessarily accurate. They are a statistical estimate of the times spent in individual methods, based on how many times the CPU sampler found itself in a given method when taking a sample every x milliseconds. So, if the sampler is set to a 20ms frequency and takes 10 samples in a certain method, it will attribute 20ms x 10 = 200ms to that method, regardless of how long it actually takes. The idea is that over a long enough time period, statistically, the accumulated sample times will estimate reality.

Thus, it is important to determine whether an apparent bottleneck is due to a method's implementation being inefficient, or just because it was called a gazillion times. Usually, the truth is some combination of both. It is important to know as a starting point whether to look at the method's implementation itself (i.e., it is not called that often, but takes a long time to execute), or at the method's caller(s) (i.e., it is not necessarily slow to execute, but is called often). This informs which code needs to be scrutinized for potential performance problems. Hence, the note about enabling the samples column in the previous paragraph.

Record Locks¶

The database persistence compatibility framework in the FWD application server manages database record locks in a way that is consistent with the behavior of an application in the legacy environment. This compatibility is necessary in order for applications to work properly. This compatibility cuts both ways, of course, so if an application was able to deadlock on a record in the legacy environment, it will still be able to do so in the FWD environment. Fortunately, there are some tools to help deal with these incidents. In addition, there are some planned improvements to the FWD runtime environment to make this task easier.

Standard User Feedback¶

FWD works similarly to Progress with respect to providing feedback to the user of a lock contention issue. This consists of posting a status message to the user's console, in the form of: "<table name> in use by <list of users>. Wait or press CTRL-C to stop. (121)".

However, this feedback may be disabled under certain conditions. For instance, the status message area may be hidden by certain GUI applications. Also, the status area window decoration is not present for a converted GUI application running in an iframe within an embedded web application.

FWD Administration Console¶

The FWD Administration Console provides some tools to view and interactively manage record locks.

The console is a web application which can be accessed in a JavaScript-enabled web browser at https://<FWD server host>:<admin port>/admin. The admin port is 7443 by default, but can be set to a different value in the application server's directory ($P2J_HOME/deploy/server/directory.xml by default).

[Note: this web application is not yet released (see #3222); it is in final testing. An older version of this utility, implemented as a Java applet, is available in the current version of FWD.]

View Record Locks¶

The "Record Locks" view displays a snapshot of all the record locks currently active across an application. This information is transient (i.e., not updated in real time), but it can be refreshed at any time. The data can be filtered to make it easier to view a particular subset of locks.

For each record locked, this view displays:

primary key (i.e., rowid/recid);
database;
table;
type of lock held (shared or exclusive);
identifiers of the sessions which have acquired the lock;
timestamp the lock was acquired.

This view is informational only; lock states can not be altered from this screen.

Acquire Record Locks¶

Individual records can be locked on an administrator's behalf from this view in the FWD Administration Console. This may be necessary to prevent data corruption in the event one must manually perform CRUD operations on specific records by directly accessing the database (i.e., outside the FWD application server). Note that a lock can be created for a record which does not yet exist by specifying the primary key which will be assigned when that record is created manually.

This view only will acquire and release locks in the context of the current administrative session. It can not be used to release arbitrary locks held by other sessions, as doing so could cause data corruption.

Locks acquired through this interface can (and should) be released from here as well, once the corresponding, manual data operation is complete. Any locks not released explicitly through this interface are released when the administrative session ends.

Sessions View¶

This view shows all non-administrative sessions currently logged into the application server. From here, an administrator can terminate any listed session.

Terminating a session is the only safe way (outside of normal use of the system) to release that session's record locks while preserving the application's transaction semantics. Of course, any work not yet committed in an active transaction in the terminated session will be rolled back. Thus, it is incumbent upon an administrator to terminate a session only as a last resort to break a deadlock.

Debug-Level Logging¶

The FWD lock manager implementation includes a debug mode, which can be useful to track down the root cause of a record deadlock, if a problem can be recreated in a test or development environment.

This mode should not be used in production, as it can have a serious impact on performance.

To enable debug-level lock manager logging, set a com.goldencode.p2j.persist.lock.LockManager logger in the application server's directory to logging level FINE or FINEST, and ensure that the console handler is set to the same (or more verbose) level. For example:

<node class="container" name="logging">
   ...
   <node class="container" name="handlers">
      <node class="container" name="console">
         <node class="string" name="level">
            <node-attribute name="value" value="FINE"/>
         </node>
      </node>
   </node>
   ...
   <node class="container" name="loggers">
      ...
      <node class="string" name="com.goldencode.p2j.persist.lock.LockManager">
        <node-attribute name="value" value="FINE"/>
      </node>
      ...

When debug mode is enabled, any lock contention results in a verbose log entry, which describes:

the record (database, table, primary key) whose lock is causing contention;
which session is trying to a acquire the lock;
what type of lock that session is requesting;
where in the code the lock is being requested;
which session(s) currently hold a lock which is blocking the new request;
what type of lock currently is being held;
where in the code the currently held lock was acquired.

For example, this log entry was generated using two sessions requesting a lock on the same record in the Hotel GUI demo application:

[06/29/2017 16:44:06 EDT] (com.goldencode.p2j.persist.lock.InMemoryLockManager$LockStatus:FINE) [00000008:0000001E:bogus] --> local/hotel/primary.stay:34166 LOCK CONTENTION;  requested SHARE at location:
         com.goldencode.p2j.persist.lock.InMemoryLockManager$LockStatus.logContention(InMemoryLockManager.java:1718)
         com.goldencode.p2j.persist.lock.InMemoryLockManager.lockWhenAvailable(InMemoryLockManager.java:1358)
         com.goldencode.p2j.persist.lock.InMemoryLockManager.acquireShare(InMemoryLockManager.java:1008)
         com.goldencode.p2j.persist.lock.InMemoryLockManager.lockImpl(InMemoryLockManager.java:1253)
         com.goldencode.p2j.persist.lock.InMemoryLockManager.lock(InMemoryLockManager.java:507)
         com.goldencode.p2j.persist.Persistence.lock(Persistence.java:3329)
         com.goldencode.p2j.persist.lock.RecordLockContext$Perm.lock(RecordLockContext.java:502)
         com.goldencode.p2j.persist.Persistence.load(Persistence.java:2607)
         com.goldencode.p2j.persist.Persistence.load(Persistence.java:2446)
         com.goldencode.p2j.persist.RandomAccessQuery.processDirtyResults(RandomAccessQuery.java:4159)
         com.goldencode.p2j.persist.RandomAccessQuery.executeImpl(RandomAccessQuery.java:4017)
         com.goldencode.p2j.persist.RandomAccessQuery.execute(RandomAccessQuery.java:3046)
         com.goldencode.p2j.persist.RandomAccessQuery.last(RandomAccessQuery.java:1524)
         com.goldencode.p2j.persist.RandomAccessQuery.last(RandomAccessQuery.java:1423)
         com.goldencode.hotel.UpdateStayDialog.lambda$execute$13(UpdateStayDialog.java:1331)
         com.goldencode.p2j.util.Block.body(Block.java:604)
         com.goldencode.p2j.util.BlockManager.processBody(BlockManager.java:6985)
         com.goldencode.p2j.util.BlockManager.topLevelBlock(BlockManager.java:6776)
         com.goldencode.p2j.util.BlockManager.externalProcedure(BlockManager.java:343)
         com.goldencode.p2j.util.BlockManager.externalProcedure(BlockManager.java:317)
         com.goldencode.hotel.UpdateStayDialog.execute(UpdateStayDialog.java:669)
         sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
         sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
         sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
         java.lang.reflect.Method.invoke(Method.java:498)
         com.goldencode.p2j.util.ControlFlowOps$InternalEntryCaller.invokeImpl(ControlFlowOps.java:5385)
         com.goldencode.p2j.util.ControlFlowOps$InternalEntryCaller.invoke(ControlFlowOps.java:5363)
         com.goldencode.p2j.util.ControlFlowOps.invokeImpl(ControlFlowOps.java:4424)
         com.goldencode.p2j.util.ControlFlowOps.invoke(ControlFlowOps.java:3453)
         com.goldencode.p2j.util.ControlFlowOps.invokeImpl(ControlFlowOps.java:4101)
         com.goldencode.p2j.util.ControlFlowOps.invokeImpl(ControlFlowOps.java:4030)
         com.goldencode.p2j.util.ControlFlowOps.invokeWithMode(ControlFlowOps.java:404)
         com.goldencode.p2j.util.ControlFlowOps.invokeWithMode(ControlFlowOps.java:386)
         com.goldencode.hotel.AvailRoomsFrame$TriggerBlock0.lambda$body$0(AvailRoomsFrame.java:1752)
         com.goldencode.p2j.util.Block.body(Block.java:604)
         com.goldencode.p2j.util.BlockManager.processBody(BlockManager.java:6985)
         com.goldencode.p2j.util.BlockManager.doBlockWorker(BlockManager.java:7926)
         com.goldencode.p2j.util.BlockManager.doBlock(BlockManager.java:683)
         com.goldencode.hotel.AvailRoomsFrame$TriggerBlock0.body(AvailRoomsFrame.java:1750)
         com.goldencode.p2j.util.BlockManager.processBody(BlockManager.java:6985)
         com.goldencode.p2j.util.BlockManager.topLevelBlock(BlockManager.java:6776)
         com.goldencode.p2j.util.Trigger.run(Trigger.java:316)
         com.goldencode.p2j.ui.LogicalTerminal.lambda$trigger$1(LogicalTerminal.java:9702)
         com.goldencode.p2j.ui.LogicalTerminal.invokeOnServer(LogicalTerminal.java:15230)
         com.goldencode.p2j.ui.LogicalTerminal.trigger(LogicalTerminal.java:9702)
         sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
         sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
         sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
         java.lang.reflect.Method.invoke(Method.java:498)
         com.goldencode.p2j.util.MethodInvoker.invoke(MethodInvoker.java:124)
         com.goldencode.p2j.net.Dispatcher.processInbound(Dispatcher.java:757)
         com.goldencode.p2j.net.Conversation.block(Conversation.java:412)
         com.goldencode.p2j.net.Conversation.waitMessage(Conversation.java:348)
         com.goldencode.p2j.net.Queue.transactImpl(Queue.java:1170)
         com.goldencode.p2j.net.Queue.transact(Queue.java:641)
         com.goldencode.p2j.net.BaseSession.transact(BaseSession.java:271)
         com.goldencode.p2j.net.HighLevelObject.transact(HighLevelObject.java:211)
         com.goldencode.p2j.net.RemoteObject$RemoteAccess.invokeCore(RemoteObject.java:1473)
         com.goldencode.p2j.net.InvocationStub.invoke(InvocationStub.java:145)
         com.sun.proxy.$Proxy17.waitFor(Unknown Source)
         com.goldencode.p2j.ui.LogicalTerminal.waitFor(LogicalTerminal.java:6330)
         com.goldencode.p2j.ui.LogicalTerminal.waitFor(LogicalTerminal.java:6100)
         com.goldencode.hotel.Emain.lambda$execute$1(Emain.java:751)
         com.goldencode.p2j.util.Block.body(Block.java:604)
         com.goldencode.p2j.util.BlockManager.processBody(BlockManager.java:6985)
         com.goldencode.p2j.util.BlockManager.topLevelBlock(BlockManager.java:6776)
         com.goldencode.p2j.util.BlockManager.externalProcedure(BlockManager.java:343)
         com.goldencode.p2j.util.BlockManager.externalProcedure(BlockManager.java:317)
         com.goldencode.hotel.Emain.execute(Emain.java:309)
         sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
         sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
         sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
         java.lang.reflect.Method.invoke(Method.java:498)
         com.goldencode.p2j.util.Utils.invoke(Utils.java:1336)
         com.goldencode.p2j.main.StandardServer$MainInvoker.execute(StandardServer.java:1969)
         com.goldencode.p2j.main.StandardServer.invoke(StandardServer.java:1464)
         com.goldencode.p2j.main.StandardServer.standardEntry(StandardServer.java:524)
         sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
         sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
         sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
         java.lang.reflect.Method.invoke(Method.java:498)
         com.goldencode.p2j.util.MethodInvoker.invoke(MethodInvoker.java:124)
         com.goldencode.p2j.net.Dispatcher.processInbound(Dispatcher.java:757)
         com.goldencode.p2j.net.Conversation.block(Conversation.java:412)
         com.goldencode.p2j.net.Conversation.run(Conversation.java:232)
         java.lang.Thread.run(Thread.java:748)
current status:  EXCLUSIVE [bogus:00000008]
Locker bogus:00000008 acquisition location:
         com.goldencode.p2j.persist.lock.InMemoryLockManager$TraceLockStatus.addLocker(InMemoryLockManager.java:1982)
         com.goldencode.p2j.persist.lock.InMemoryLockManager.acquireExclusive(InMemoryLockManager.java:1063)
         com.goldencode.p2j.persist.lock.InMemoryLockManager.lockImpl(InMemoryLockManager.java:1257)
         com.goldencode.p2j.persist.lock.InMemoryLockManager.lock(InMemoryLockManager.java:507)
         com.goldencode.p2j.persist.Persistence.lock(Persistence.java:3329)
         com.goldencode.p2j.persist.lock.RecordLockContext$Perm.lock(RecordLockContext.java:502)
         com.goldencode.p2j.persist.RecordBuffer.upgradeLock(RecordBuffer.java:7117)
         com.goldencode.p2j.persist.RecordBuffer$Handler.invoke(RecordBuffer.java:11009)
         com.goldencode.p2j.persist.$__Proxy8.setStayId(Unknown Source)
         com.goldencode.hotel.UpdateStayDialog.lambda$execute$13(UpdateStayDialog.java:1345)
         com.goldencode.p2j.util.Block.body(Block.java:604)
         com.goldencode.p2j.util.BlockManager.processBody(BlockManager.java:6985)
         com.goldencode.p2j.util.BlockManager.topLevelBlock(BlockManager.java:6776)
         com.goldencode.p2j.util.BlockManager.externalProcedure(BlockManager.java:343)
         com.goldencode.p2j.util.BlockManager.externalProcedure(BlockManager.java:317)
         com.goldencode.hotel.UpdateStayDialog.execute(UpdateStayDialog.java:669)
         sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
         sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
         sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
         java.lang.reflect.Method.invoke(Method.java:498)
         com.goldencode.p2j.util.ControlFlowOps$InternalEntryCaller.invokeImpl(ControlFlowOps.java:5385)
         com.goldencode.p2j.util.ControlFlowOps$InternalEntryCaller.invoke(ControlFlowOps.java:5363)
         com.goldencode.p2j.util.ControlFlowOps.invokeImpl(ControlFlowOps.java:4424)
         com.goldencode.p2j.util.ControlFlowOps.invoke(ControlFlowOps.java:3453)
         com.goldencode.p2j.util.ControlFlowOps.invokeImpl(ControlFlowOps.java:4101)
         com.goldencode.p2j.util.ControlFlowOps.invokeImpl(ControlFlowOps.java:4030)
         com.goldencode.p2j.util.ControlFlowOps.invokeWithMode(ControlFlowOps.java:404)
         com.goldencode.p2j.util.ControlFlowOps.invokeWithMode(ControlFlowOps.java:386)
         com.goldencode.hotel.AvailRoomsFrame$TriggerBlock0.lambda$body$0(AvailRoomsFrame.java:1752)
         com.goldencode.p2j.util.Block.body(Block.java:604)
         com.goldencode.p2j.util.BlockManager.processBody(BlockManager.java:6985)
         com.goldencode.p2j.util.BlockManager.doBlockWorker(BlockManager.java:7926)
         com.goldencode.p2j.util.BlockManager.doBlock(BlockManager.java:683)
         com.goldencode.hotel.AvailRoomsFrame$TriggerBlock0.body(AvailRoomsFrame.java:1750)
         com.goldencode.p2j.util.BlockManager.processBody(BlockManager.java:6985)
         com.goldencode.p2j.util.BlockManager.topLevelBlock(BlockManager.java:6776)
         com.goldencode.p2j.util.Trigger.run(Trigger.java:316)
         com.goldencode.p2j.ui.LogicalTerminal.lambda$trigger$1(LogicalTerminal.java:9702)
         com.goldencode.p2j.ui.LogicalTerminal.invokeOnServer(LogicalTerminal.java:15230)
         com.goldencode.p2j.ui.LogicalTerminal.trigger(LogicalTerminal.java:9702)
         sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
         sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
         sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
         java.lang.reflect.Method.invoke(Method.java:498)
         com.goldencode.p2j.util.MethodInvoker.invoke(MethodInvoker.java:124)
         com.goldencode.p2j.net.Dispatcher.processInbound(Dispatcher.java:757)
         com.goldencode.p2j.net.Conversation.block(Conversation.java:412)
         com.goldencode.p2j.net.Conversation.waitMessage(Conversation.java:348)
         com.goldencode.p2j.net.Queue.transactImpl(Queue.java:1170)
         com.goldencode.p2j.net.Queue.transact(Queue.java:641)
         com.goldencode.p2j.net.BaseSession.transact(BaseSession.java:271)
         com.goldencode.p2j.net.HighLevelObject.transact(HighLevelObject.java:211)
         com.goldencode.p2j.net.RemoteObject$RemoteAccess.invokeCore(RemoteObject.java:1473)
         com.goldencode.p2j.net.InvocationStub.invoke(InvocationStub.java:145)
         com.sun.proxy.$Proxy17.waitFor(Unknown Source)
         com.goldencode.p2j.ui.LogicalTerminal.waitFor(LogicalTerminal.java:6330)
         com.goldencode.p2j.ui.LogicalTerminal.waitFor(LogicalTerminal.java:6100)
         com.goldencode.hotel.Emain.lambda$execute$1(Emain.java:751)
         com.goldencode.p2j.util.Block.body(Block.java:604)
         com.goldencode.p2j.util.BlockManager.processBody(BlockManager.java:6985)
         com.goldencode.p2j.util.BlockManager.topLevelBlock(BlockManager.java:6776)
         com.goldencode.p2j.util.BlockManager.externalProcedure(BlockManager.java:343)
         com.goldencode.p2j.util.BlockManager.externalProcedure(BlockManager.java:317)
         com.goldencode.hotel.Emain.execute(Emain.java:309)
         sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
         sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
         sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
         java.lang.reflect.Method.invoke(Method.java:498)
         com.goldencode.p2j.util.Utils.invoke(Utils.java:1336)
         com.goldencode.p2j.main.StandardServer$MainInvoker.execute(StandardServer.java:1969)
         com.goldencode.p2j.main.StandardServer.invoke(StandardServer.java:1464)
         com.goldencode.p2j.main.StandardServer.standardEntry(StandardServer.java:524)
         sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
         sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
         sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
         java.lang.reflect.Method.invoke(Method.java:498)
         com.goldencode.p2j.util.MethodInvoker.invoke(MethodInvoker.java:124)
         com.goldencode.p2j.net.Dispatcher.processInbound(Dispatcher.java:757)
         com.goldencode.p2j.net.Conversation.block(Conversation.java:412)
         com.goldencode.p2j.net.Conversation.run(Conversation.java:232)
         java.lang.Thread.run(Thread.java:748)

Note that the collection of the information about where the lock originally was acquired is quite an expensive operation, and only occurs when FINE (or higher) lock manager logging is enabled, not under normal circumstances. Since this information must be collected for every lock acquired, whether or not contention ever occurs for that lock, we reiterate that debug record lock logging should only be enabled in a non-production environment. Be sure to reset the logging levels in the directory back to their original settings after using this mode.

Lock Metadata (`_Lock` table)¶

FWD includes a basic implementation of the _Lock metadata table, which, when enabled, tracks record lock changes in an embedded H2 database. This information is accessible via the usual means of querying the _Lock metadata table. However, at this time, this feature is disabled by default, since the current implementation causes a performance drag on a running system, and the implementation is not feature complete. Further development work and testing is needed to make this feature production ready.

Planned Enhancements¶

In addition to the tools described above, the FWD team plans to enhance the FWD Administration Console to provide additional record lock information, to make it easier to detect the details about record contention and deadlock conditions. See issue #3307 for details.

Project

General

Profile

FWD

Wiki

Monitoring¶

JMX Instrumentation¶

Enabling the Support¶

Configuring the FWD Server¶

Caveats and Limitations¶

Using VisualVM¶

Using JConsole¶

FWD Appserver Agent State Instrumentation¶

FWD Server - Persistence and ORM Instrumentation¶

FWD Server - Dynamic Query Processing¶

FWD Server Runtime Instrumentation¶

FWD OpenClient Runtime Instrumentation¶

Other Miscellaneous Metrics¶

VisualVM (Java 8)¶

Record Locks¶

Standard User Feedback¶

FWD Administration Console¶

View Record Locks¶

Acquire Record Locks¶

Sessions View¶

Debug-Level Logging¶

Lock Metadata (`_Lock` table)¶

Planned Enhancements¶

Project

General

Profile

FWD

Wiki

Monitoring¶

JMX Instrumentation¶

Enabling the Support¶

Configuring the FWD Server¶

Caveats and Limitations¶

Using VisualVM¶

Using JConsole¶

FWD Appserver Agent State Instrumentation¶

FWD Server - Persistence and ORM Instrumentation¶

FWD Server - Dynamic Query Processing¶

FWD Server Runtime Instrumentation¶

FWD OpenClient Runtime Instrumentation¶

Other Miscellaneous Metrics¶

VisualVM (Java 8)¶

Record Locks¶

Standard User Feedback¶

FWD Administration Console¶

View Record Locks¶

Acquire Record Locks¶

Sessions View¶

Debug-Level Logging¶

Lock Metadata (_Lock table)¶

Planned Enhancements¶

Lock Metadata (`_Lock` table)¶