Issue Details (XML | Word | Printable)

Key: ADFEMG-79
Type: Bug Bug
Status: Closed Closed
Resolution: Fixed
Priority: Minor Minor
Assignee: Unassigned
Reporter: chriscmuir
Votes: 0
Watchers: 0
Operations

If you were logged in you would be able to see more operations.
adfemg

BTF doesn't honor restore to save point on first run

Created: 17/Dec/12 09:17 AM   Updated: 05/Sep/13 02:56 AM   Resolved: 05/Sep/13 02:56 AM
Component/s: None
Affects Version/s: None
Fix Version/s: None

Time Tracking:
Not Specified

File Attachments: 1. Zip Archive SavePointTaskFlowTransactionsOneAM.zip (334 kB) 17/Dec/12 09:17 AM - chriscmuir
2. Zip Archive SavePointTaskFlowTransactionsSplitAM.zip (291 kB) 17/Dec/12 09:17 AM - chriscmuir


Tags:
Participants: chriscmuir and Jan Vervecken


 Description  « Hide

Logged this issue and the relating bug 16009286 for Leon so he can track it without having to lodge an SR. The issue isn't critical to his business, just an anomaly he's detected.

<-bug text->

I've logged this issue against controller-transaction
component-subscomponents, but could equally go against ADF BC, it's hard to
me to guess where the fault lies.

A customer has discovered a scenario where Bounded Task Flow (BTF) with Task
Flow Return activity "Restore Save Point" set is ignored with multiple root
AMs, but only on the first run, appears the save points work in all
subsequent runs.

Characteristics of app:

1) Application based on Oracle HR schema
2) Two separate root ADF BC Application Modules (AMs), one exposing
DepartmentsView, the other EmployeesView
3) Three task flows called in a chain, UTF to view & select departments,
BTF#1 to edit the 1st DepartmentsView row, BTF#2 to edit the 1st
EmployeesView row
4) Task flow options:

4.1) BTF#1 EditDepartmentsTaskFlow - Always Begin New Transaction + Shared
data control scope + Commit & Return Task Flow Return activities
4.2) BTF#2 EditEmployeesTaskFlow - Always Use Existing Transaction + Shared
data control scope + "None" Task Flow Return activity + "Restore Save Point"
Task Flow Return activity

No other default settings have been changed to build this application.

To reproduce the issue follow these steps:

1) Unzip uploaded simple test case SavePointTaskFlowTransactionsSplitAM.zip
2) Open the unzipped application in JDeveloper
3) Change the configuration of the database connection to point to an Oracle
HR demo schema you can access
4) Run the ViewDepartments.jsf page in the adfc-config.xml

5) In the running app ViewDepartments.jsf page select any record and select
the edit button
6) On arriving in BTF#1 change the current department's name
7) Select the Edit Employees button
8) On arriving in BTF#2 change the current employee's name
9) Select the RollbackSavepoint button
10) On returning to BTF#1 select Commit

11) Via the database navigator in JDev, note that both the departments and
employees record have been updated with your changes. The employees record
should not have been as step #9 was rolling back to the savepoint established
with BTF#2 was called. The savepoint is created because on BTF#2 the No Save
Point on Task Flow Entry check box is not set (implying the savepoint was
created).

12) Now repeat steps to 5 to 11. Note that once you inspect the changes in
the database for every subsequent run of steps 5 to 11, the departments
record will be changed, but the employees record will not. This is the
expected behaviour.

As such to explicitly state the problem, the savepoint is dishonoured the 1st
time through the above scenario, but every subsequent time it is followed.

As follow up to this bug I've also uploaded a separate test case
SavePointTaskFlowTransactionsOneAM.zip, which doesn't use two root AMs. If
you repeat the previous steps you wont see the issue described above. As
such at face value the problem appears to be related to how ADFc and the dual
root AMs are interacting.

<-end bug text->



Jan Vervecken added a comment - 18/Dec/12 09:10 PM

hi Chris

On My Oracle Support I have been able to find 16009286, "BTF DOESN'T HONOR RESTORE TO SAVE POINT ON FIRST RUN", which currently has "Product Version 11.1.1.6.0".

If I run some VersionFinder code [1] on the files in SavePointTaskFlowTransactionsSplitAM.zip and SavePointTaskFlowTransactionsOneAM.zip (attached to this JIRA issue ADFEMG-79), I find multiple occurences of version 11.1.2.62.94 in both ZIP files.

Can someone please point out which JDeveloper version should be used on the contents of SavePointTaskFlowTransactionsSplitAM.zip and SavePointTaskFlowTransactionsOneAM.zip ?

thanks
Jan Vervecken


chriscmuir added a comment - 20/Dec/12 03:03 AM

Well spotted, logged against the wrong version. Corrected the bug to 11.1.2.3.0, though the issue can also be reproduced in 11.1.1.6.0.

CM.


Jan Vervecken added a comment - 28/Dec/12 09:03 AM

Thank you for the update Chris.

  • about "Corrected the bug to 11.1.2.3.0 ..."
    • Yes, bug 16009286 currently has "Product Version 11.1.2.3.0":
      *** 12/18/12 04:31 pm *** (CHG: Comp. Ver-> 11.1.1.6.0 -> 11.1.2.3.0)
      *** 12/18/12 04:31 pm ***
      Corrected component version, the sample apps are built against 11.1.2.3.0, 
      not 11.1.1.6.0 as originally specified.  However issue is observed in both 
      11.1.1.6.0 and 11.1.2.3.0.
      
  • about "... I find multiple occurences of version 11.1.2.62.94 in both ZIP files. ..."
    • Noticed that my JDeveloper 11.1.2.3.0 adds attributes like Version="11.1.2.62.76", not "11.1.2.62.94", wonder which JDeveloper version does that.

Also wanted to confirm that I have been able to reproduce the behaviour you describe, using SavePointTaskFlowTransactionsSplitAM.zip and SavePointTaskFlowTransactionsOneAM.zip and JDeveloper 11.1.2.3.0 .

regards
Jan Vervecken


Jan Vervecken added a comment - 05/Jan/13 07:06 PM

hi Chris

There seem to be functional differences between the application in "SavePointTaskFlowTransactionsOneAM.zip" (which uses a child View Object instance that allows to edit the first employee for a department) and "SavePointTaskFlowTransactionsSplitAM.zip" (which has no such child View Object instance (also because of the separate Application Modules) only allowing to edit the first employee, unrelated to a department), so a functional difference.
So, I'm not sure if these can properly be compared related to their transactional behaviour.

regards
Jan Vervecken


Jan Vervecken added a comment - 05/Jan/13 07:10 PM

hi Chris

Did you notice that two separate database session/connection SID values are involved for a single request, for the scenario you describe using SavePointTaskFlowTransactionsSplitAM.zip ?
I wonder if "Bruce" [1] is doing a proper job here.

To illustrate this I added some logging (using a MyApplicationModuleListener [2]) resulting in the example application
at http://www.consideringred.com/files/oracle/2013/SavePointTaskFlowTransactionsSplitAM-v20130105.zip
An extract of the logged information (see "maml-log-20130105.txt"):

...
[0102][C][L][r1007][(ctx31) /faces : /EditEmployeesTaskFlow/EditEmployees] onAfterDoPoolMessage() : [(am502) EmpAppModule (is root)][(ses101) MESSAGE_TYPE_RELEASING (2) STATUS_SUCCESS (8) (rp 3)]
[0103](am502) SID = 48 for select sys_context('USERENV', 'SID') as sid from dual
...
[0105][C][L][r1007][(ctx31) /faces : /EditEmployeesTaskFlow/EditEmployees] onAfterDoPoolMessage() : [(am501) DeptAppModule (is root)][(ses101) MESSAGE_TYPE_RELEASING (2) STATUS_SUCCESS (8) (rp 3)]
[0106](am501) SID = 40 for select sys_context('USERENV', 'SID') as sid from dual
...

Notice the different SID values "[0103](am502) SID = 48" and "[0106](am501) SID = 40" for different Application Module instances during request [r1007].

If on the task-flow "EditDepartmentsTaskFlow" the Transaction option "Share data controls with calling task flow" is changed from checked to unchecked (so from "shared" to "isolated") the same request no longer reports two separate database session/connection SID values used, only one for both Application Module instances.
An extract of the logged information (see "maml-log-20130105-isolated.txt"):

...
[0112][C][L][r1007][(ctx32) /faces : /EditEmployeesTaskFlow/EditEmployees] onAfterDoPoolMessage() : [(am503) EmpAppModule (is root)][(ses101) MESSAGE_TYPE_RELEASING (2) STATUS_SUCCESS (8) (rp 3)]
[0113](am503) SID = 17 for select sys_context('USERENV', 'SID') as sid from dual
...
[0115][C][L][r1007][(ctx32) /faces : /EditEmployeesTaskFlow/EditEmployees] onAfterDoPoolMessage() : [(am502) DeptAppModule (is root)][(ses101) MESSAGE_TYPE_RELEASING (2) STATUS_SUCCESS (8) (rp 3)]
[0116](am502) SID = 17 for select sys_context('USERENV', 'SID') as sid from dual
...

(Yes, this also changes the functional behaviour of the application (no longer allowing to edit the selected department), but it is just to illustrate the difference.)

Notice the same SID values "[0113](am503) SID = 17" and "[0116](am502) SID = 17" for different Application Module instances during request [r1007].

(Also notice that, instead of one, now two Application Module instances are created in the ApplicationPool "model.AppModuleLocal", "[0118](ap21)[cre 2 ... tot am 2 ..." compared to "[0108](ap21)[cre 1 .. tot am 1 ..." before, as can be expected after the data-control-scope isolated change.)

regards
Jan Vervecken


chriscmuir added a comment - 06/Jan/13 01:36 AM - edited

Good spot on SavePointTaskFlowTransactionsOneAM.zip Jan. I've retested with the EmployeesView3 as a parent VO under the AM to get the same expected behaviour. I can't upload the updated zip here until the Java.net file attachment issue is resolved, but I'll upload it to the bug.

On your other observations, (and btw, your logging software once again proves very useful to show the internal behaviour, well done), I think it explains an important part about the task flow transaction options and that is about where the AMs are instantiated.

As you likely already know (but as a recap for other readers), specifically using a combination of ADF BC and the task flow transaction options (that is, Always Begin New Transaction, Always Use Existing Transaction, Use Existing Transaction if Possible, but*not <No Controller Transaction>), root AM connections will be shared. If you wish to use root AM's that definitely have separate data sources (connections), look to using the <No Controller Transaction> option instead.

One thing to keep in mind is the UTF has no transaction settings but is the equivalent of using <No Controller Transaction>.

Returning to your observations with all this logic in hand, we would expect the connections of the two separate AMs to be shared (or in other words, just 1 connection).

But there is something else important to note & it will change the behaviour, and that is when/where the AMs are instantiated.

As the DeptAppModule is first instantiated in the UTF, it is in fact running under the <No Controller Transaction> regime. This will influence it's behaviour right through the other BTFs. As such even though the EmpAppModule is instantiated under a BTF transaction option that wants to share connections with other root AMs, the DeptAppModule wont play ball as when it was instantiated the UTF said it shouldn't participate in the task flow transaction regime with other AMs.

(Hopefully that language makes sense, I'm still thinking about how to articulate this clearly and simply)

Now when you switch over to the isolated data control scope, as the DeptAppModule is instantiated twice, once in the UTF, and once separately in the first BTF, that second BTF DeptAppModule is a BTF that's working under the task flow transaction options that want to share connections and it will join/share connections with the EmpAppModule that is also running under the same task flow transaction regime.

So I believe this explains the different connection behaviour you've discovered.

As you've observed, with the joined connection behaviour it seems to get the rollback behaviour right. And in my mind this should be very functionally similar to SavePointTaskFlowTransactionsOneAM.zip. However I still don't get the original bug observed. Given that it works the 2nd iteration I feel as if there is code in there to deal with this scenario, but somehow the first iteration it's not working.

We have observed in other tests that there is in another connection taken out with the database, it's something internal to the framework, but just once and it has something to do with the savepoint mechanism too. I was hoping this bug logged with the dev team will give us a chance to understand what's happening under the covers.

This description has all been written up on the weekend and hasn't had my full attention, let me know is there is anything that isn't clear.


chriscmuir added a comment - 17/May/13 06:48 AM

Dev team have notified that the issue isn't reproducible in 12.1.2, but is in 11.1.2.4.0. They continue to investigate.


chriscmuir added a comment - 05/Sep/13 02:56 AM

This has been fixed in an internal release 11.1.2.4.1.

As this is no longer reproducible/is fixed in the 12.1.2.0.0 release there is no further work to pursue on this issue. Will close issue.

CM.