ADF Runtime Diagnostics: Instrumenting your ADF Application – Part 2
In a series of blog articles I show how you can instrument your ADF Application key actions. Instrumenting gives visibility and insight of what is happening inside the ADF application and in the ADF framework (what methods and queries are executed, when and how often). These runtime diagnostics can be very effective in identifying and solving performance issues. This enables developers to diagnose and solve performance problems at an early stage and to build an efficient, responsive ADF application before it goes into production. Part one was about instrumenting the ADF ViewObject. In this blog, part two, I will discuss instrumenting the ADF BC ApplicationModule.
ADF BC framework extension classes
As discussed in part one, you can instrument your ADF application with the use of ADF BC framework extension classes and overriding specific methods to measure important key actions inside the ADF framework. For an ADF BC ApplicationModule you can create a metrics ApplicationModule (for example called MetricsApplicationModuleImpl) that extends from oracle.jbo.server.ApplicationModuleImpl. Your project base class can extend from this MetricsApplicationModuleImpl:
You can look at the ApplicationModuleImpl API doc for important and interesting methods to monitor.
Monitor ApplicationModule activation and passivation
As you know, ApplicationModule pooling enables multiple users to share several application module instances. It involves saving and retrieving session state data from the database, file, or Java memory. This mechanism is provided to make the application scalable and becomes very important under high load with many concurrent users. The default values can be very inefficient and may cause many unneeded passivations and activations. A quick and simple way to monitor passivations in ADF is to override the ApplicationModule method passivateState() in your metrics base class:
And to monitor activations override the ApplicationModule method activateState() in your metrics base class:
In this way you can monitor which ApplicationModules are activated/passivated, their activation/passivation time, when and how often it is executed. Run your ADF application with -Djbo.ampool.doampooling=false to test this:
Logging JDevelopers console log:
You might detect very frequent and long running activations and passivations. With this information you can experiment en test with ApplicationModule pooling parameters. It is especially useful to monitor this during load tests to find your most optimal ApplicationModule pooling parameter settings. In most cases, unfortunately, the default values are not the most optimal values. Carefully read the documentation in the ADF Fusion developers Guide (Ch. 44 of the 11gR2) for more information about these parameter settings.
Monitor ApplicationModule creation time & database connecting time
We can configure a custom DefaultConnectionStrategy class to measure ApplicationModule creation time and database connecting time. Our custom class must extend oracle.jbo.common.ampool.DefaultConnectionStrategy. In the same way as we did before, we can measure the creation and connect time.
Configuration on the ApplicationModule:
in JDevelopers console log:
These methods are also interesting to monitor during a load test. For example, the connect() method could run very long when there are not enough database connections available, and it needs to wait for one. The next step could be to increase the maximum capacity in the datasource connection pool. Or to decrease the number of root ApplicationModules (and the number of database connections).
Monitor PLSQL calls
In the same way as described before you can instrument your PLSQL calls executed from your ApplicationModule. Frequently utility methods on the ApplicationModule are created for this purpose and they can be instrumented. You can log the execution time, the PLSQL statement, the ApplicationModule instance name, the IN and OUT parameters, e.g.
ADF Performance Monitor
The ADF Performance Monitor uses (amongst others) the extension points and methods described in this blog (and part one) to measure and record performance. It collects not only execution time but many additional metrics like ApplicationModule definition name, usage name, instance id, for which ViewObject data are being activated/passivated during an activation/passivation, e.g. . For every HTTP request a so called ‘ADF call stack’ is printed. These are the methods that we have overridden in our metrics class and other extension points in the ADF framework. The runtime diagnostics are available in JDeveloper and in a test/production environment.
In the image below an example of a long running ApplicationModule activation of 22048 milliseconds (usage name HRService).
As we can see, the slow activation is caused by activating the transient ViewObject attributes of HRService.LocationsViewRO in activateTransients(). We can see the value of instrumenting our ADF application and monitoring – now we can do something about the slow activation. For example to uncheck the ‘Passivate State – Including All Transient Values’ checkbox at the ViewObject tuning section for HRService.LocationsViewRO.
Shown below is an example of a long running ApplicationModule passivation of 3796 milliseconds (usage name of HRService). This is caused by the same ViewObject, that passivates its transient attributes (HRService.LocationsViewRO):
An example of a long running PLSQL statement and an ApplicationModule connect():
Worst ApplicationModule activations & passivations overview
In the ADF BC overview (filtered on ApplicationModule pooling) the ApplicationModule pooling performance can be analyzed. This overview gives more insight in the effect of these parameter settings (how often passivations and activations happen, how long their AVG and total execution time is). On each ApplicationModule activation/passivation can be drilled down, to see the ADF request call stacks. Dev and QA teams can research and experiment with these parameter settings on test environments during load tests and evaluate the performance results in the monitor. They can determine the most optimal ApplicationModule pooling parameter settings for their situation. Operation teams can monitor the ApplicationModule pooling behavior in production.
Total time of worst ApplicationModule activations & passivations
The performance impact of frequent invoked activations and passivations can be much higher than those that occur only a few times but are very slow on average. It is important to know which activations/passivations have the biggest impact on the resources of your ADF application. In this overview the x-as shows the AVG execution time (seconds) and the y-as shows the occurrences. The size of the bubble is total time (AVG execution time * occurrences).
The occurrences overview shows how often activations and passivations are executed:
We can see that PjtShowPaga001AM.passivateState, PjtShowPaga001AM.activateState and Pagd001AM.passivateState are executed very frequently. If we don’t want this behavior, we can adjust the pooling parameter settings.