Record Lock Monitoring¶

Record Lock Monitoring

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

Record Lock Monitoring¶

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

Record Lock Monitoring¶

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)¶