When developing and/or debugging BPEL processes, the Oracle BPEL Console is your best friend. Every change to every variable, every activity that was executed, everything is right there for you to inspect, whether the instance is still in-flight or already completed. But although this sounds like the ultimate debugging tool, I’m sure you’ve noticed like me that when your processes get really big (which they tend to do rather quickly), there’s two reasons why debugging can be difficult. The first is plain and simple “information overload”. If your audit flow contains hundreds of activities and possibly thousands of variable data changes, finding an individual piece of information is not trivial. I find the second reason, however, to be of even more profound impact: the BPEL console will not show you the execution path through your process flow (which would indicate which parts of the code got executed, and which didn’t), but rather it displays a long, sequential list of Activities that were executed. Especially if you have a lot of switch and/or pick statements, and if your code contains loops (in which case each iteration will add all executed Activities to the list), determining “what happened” during execution of your instance from this long, long audit trail might prove a challenge.
In a “mini-series” of Blog entries, I will share a number of techniques that I have used in situations like this, to extract logging/debug information from a BPEL process instance using BPEL Sensors. This first entry will focus on a simple, straightforward form of logging, using a “Variable Sensor” to provide a sort of “management summary” of the execution of a BPEL process instance.
Using Sensors for Logging and Debugging
BPEL Sensors can be very useful to extract information from the execution of a process. Basically, they come in three flavours: Activity Sensors, Fault Sensors and Variable Sensors. The first type is ideal to have a BPEL process trigger “events”, as you can configure them to “fire” when individual Activities in your process get executed. You even get to specify if they need to fire on activation (i.e. before the Activity is executed), on completion, on faults, when compensation is invoked, or on all these events. Finally, you can pass any amount of process data along to it, allowing the “Sensor Action” associated with the Sensor to use that information, for instance by posting it on a queue, storing it in the database, sending it to a BAM server, or invoking custom Java code with it.
Sometimes I use Activity Sensors for debugging purposes, by adding them to critical activities that determine process behavior, and adding process variables to them so that I can see those bits of information that were crucial at that particular moment in process execution. This is a very powerful method and I will show some examples in future Blog entries, but often, my needs are more simple, and all I really need is a BPEL equivalent of a good old Log4J statement in Java code:
log.debug(‘Entering Order line loop, with ‘+orderlines.size()+’ order lines’);
Simple logging using Variable Sensors
Configure Sensors for Logging purposes
To incorporate Sensor based logging in our process, there are two tasks to perform. The first part is configuration. You only need to do this once for the entire process. In terms of Log4J, it would compare to the code at the top of the class, defining the "log" variable that we can write to.
Log log = LogFactory.getLog(this.getClass());
In fact, this is incredibly similar to what we will do in BPEL! We also start by adding a variable, “LogMessage”, to the process, and then we add a Variable Sensor to it that will process all changes that are made to it. To get started, click on the “Variables” icon on the process diagram (x) (see screenshot below).
For simple logging like this, where the log messages are just simple strings, the “Variable Sensor” comes in handy. This type of Sensor is triggered every time a change is made to a process variable. So, unlike Activity Sensors where you need to specify exactly where in the process flow you want that sensor to fire, with Variable Sensors you only define it once and it fires automatically each and every time in your process when changes are made to the process variable it is assigned to. So basically, to get some simple debug logging going, all you need is to create one “Log” variable, add a Variable Sensor to it, and just by assigning a new value to it anywhere in the process where you need logging, the Sensor fires and processes the value of the variable.
So, how does this work? As an example, let’s take the BPEL process flow below. This is a simple demo flow and, as mentioned before, for simple flows the BPEL Console works perfectly well all by itself. Just imagine this is part of a much bigger process, and you would need to figure out what happened in this part of the flow by inspecting hundreds of audit trail entries.
In the window that pops up, create a new Variable called “LogMessage”, of type xsd:string.
Click “OK” to close this window, then select the newly created “LogMessage” variable and click on the “Edit” button:.
Select the “Sensors” tab, and press the “Create” button to create a Variable Sensor:.
Name the sensor “LogSensor”, and use the little icon on the right of the “Target” field to select the “LogMessage” variable. It’s kinda weird you need to do this since you entered this window from the “Edit Variable – LogMessage” window, but oh well….
A Sensor is like a trigger definition that indicates _when_ it fires. But in order to make it _do_ something, you’ll need to tie it to a “Sensor Action”. In PL/SQL terms, a “Sensor” is like a table trigger that invokes a PL/SQL procedure, and the “Sensor Action” is the procedure that it invokes. The Sensor Action (procedure) can therefore be re-used by many Sensors (triggers).
You can create a Sensor Action within the current dialog, by clicking the “Add” button in the “Sensor Actions” section. In the “Sensor Action Chooser” you can pick previously defined Sensor Actions, but since we have not created one yet, we’ll do that now. Notice that there are two flavors to choose from: BAM Sensor Actions, and regular “Sensor Action”. Choose the latter..
In the dialog that pops up, call the Sensor Action “LogAction”, and leave “Publish Type” to “Database”. This means that the Sensor events (including their data) will be written to a pre-defined database tables in the BPEL dehydration store. In this case (this being a Variable Sensor), that table is “VARIABLE_SENSOR_VALUES”. Unfortunately, you can NOT define your own table. But for debug logging purposes like ours this is ideal, especially since the BPEL console has maintenance facilities to clean up this table. In fact, as you’ll see later, there is not even any need to query this table, as its contents will be shown in the BPEL Console when inspecting the process instance..
Press OK, and see how the newly created LogAction is tied to the LogSensor on the LogMessage variable. Also notice you could have multiple Sensor Actions could be tied to a single LogSensor, allowing you, for instance, to write to the database AND post to a JMS queue..
OK this dialog, and see the summary: You have a LogMessage variable, with a sensor called “LogSensor” on it, which is tied to the “LogAction” Sensor Action (which will publish to the database).
This concluded the configuration part. Although it may seem like a lot of work the first time, I promise that this takes under a minute once you’ve done this a few times. And, remember, you only need to do this once for the entire process. The actual "log statements" are far simpler to create, as we’ll see next.
Adding "Log statements" to your Process
What we have now is a LogMessage variable which is “rigged” so that every change to it will automatically be published to the database (and, as you will see later, is also automatically visible in the BPEL console). All we need to do now is start creating our "log statements" in the BPEL process. This simply means: assigning values to the “LogMessage” variable at places in your process flow that currently interest you.You can add new Assign activities to your process to do this, or just add Copy Operations to existing Assigns activities in your process. In the “Assign” dialog, select the LogMessage variable on the right (notice the cool “sensor” icon to the left of it), and (typically) the ‘Expression’ type on the left. You could log simple strings by just typing something like ‘Hello, this is debug logging’ (don’t forget the single quotes), or use the Expression Builder to mix your log statements with dynamic values (typically with the ‘concat’ statement, with which you can concatenate an arbitrary number of strings, separated by commas).
Below is the result of adding a simple, static log statement to an existing Assign activity:.
The Result
Now I’m sure you are wondering where this logging turns up after initiating a process instance. Well, our “LogAction” Sensor Action published to the database, but fortunately you won’t have to go to the database and query that table to retrieve the logging information. When looking at the Flow of an individual instance in the BPEL Console, one of the tabs reads “Sensor Values”. Below, you can see the result from adding some log statements to the Process we started out with.
So there you have it. Simple, log4J style logging that requires just a little setting up at Process level, and then simply some Copy rules to a single “LogMessage” variable to create logging that is conveniently accessible from the BPEL console.
Cleaning up
To wrap things up: how to clean things up after you’re done debugging. When you no longer need your log statements, there’s a couple of things to do. First, you can purge all sensor values from the BPEL tables, by going to the “Instances” tab in the BPEL Console and clicking the “Purge All Sensor Data” button. Then, in JDeveloper, have some options. You can:- Disable logging for now (but you might want to turn it back on later)
To do this, simple delete the LogSensor from the LogMessage variable. The LogMessage variable and log statements remain in your code but will take hardly any time during execution, and no sensors will fire (and therefore no database activity to the sensor tables will take place). All you need to do to turn logging on again at a later point is recreate the LogSensor and assign it to the LogAction (which will still be there). - Remove all trace of logging
- Delete the LogMessage variable from the BPEL process.
- Rebuild the process and notice the compilation errors. Clicking on them will lead you to all the Copy operations where you wrote to the LogMessage variable. If this is the only operation in the Assign, remove the assign, otherwise just remove the Copy operation.
- Rebuild the process to make sure you’ve gotten rid of them all.
No comments:
Post a Comment