Bug 106130 - applying around advice on a method it rewrites the method wrongly
Summary: applying around advice on a method it rewrites the method wrongly
Status: RESOLVED FIXED
Alias: None
Product: AspectJ
Classification: Tools
Component: AJBrowser (show other bugs)
Version: 1.2.1   Edit
Hardware: PC Windows XP
: P3 normal (vote)
Target Milestone: ---   Edit
Assignee: Adrian Colyer CLA
QA Contact:
URL:
Whiteboard:
Keywords:
: 101290 (view as bug list)
Depends on:
Blocks:
 
Reported: 2005-08-05 00:39 EDT by karunyan CLA
Modified: 2012-04-03 16:08 EDT (History)
1 user (show)

See Also:


Attachments
attachment as posted to aspectj-dev (37.70 KB, application/zip)
2005-08-10 07:07 EDT, Adrian Colyer CLA
no flags Details
Java and class files compiled using ajc (17.92 KB, application/x-zip-compressed)
2005-08-11 00:56 EDT, karunyan CLA
no flags Details
TransactionDAO compiling with logging included (4.77 KB, patch)
2005-08-13 01:52 EDT, karunyan CLA
aclement: iplog+
Details | Diff
Patch to backport this fix to AspectJ 1.2.1 (1.96 KB, application/octet-stream)
2005-08-16 07:53 EDT, Adrian Colyer CLA
no flags Details

Note You need to log in before you can comment on or make changes to this bug.
Description karunyan CLA 2005-08-05 00:39:49 EDT
Hi,

When applying around advice on a method it rewrites the method wrongly.  This 
happens only when I try to apply aspects to bytecode as against source code.

Without Aspects
---------------

int i;
        for(; rs.next(); transactionList.add(new Transaction(rs.getString
(i++), rs.getFloat(i++), rs.getString(i++), rs.getString(i++), rs.getString
(i++), rs.getString(i++), rs.getString(i++), rs.getString(i++), rs.getString
(i++), rs.getString(i++), rs.getFloat(i++), rs.getDate(i++), rs.getString
(i++), rs.getString(i++), rs.getString(i++))))

            i = 1;

With Aspects
------------

 

        for(; resultset.next(); arraylist.add(new Transaction
(resultset.getString(j), resultset.getFloat(j), resultset.getString(j), 
resultset.getString(j), resultset.getString(j), resultset.getString(j), 
resultset.getString(j), resultset.getString(j), resultset.getString(j), 
resultset.getString(j), resultset.getFloat(j), resultset.getDate(j), 
resultset.getString(j), resultset.getString(j), resultset.getString(j))))

        {
            int j = 1;
            i++;
            i++;
            i++;
            i++;
            i++;
            i++;
            i++;
            i++;
            i++;
            i++;
            i++;
            i++;
            i++;
            i++;
            i++;
        }

 Obviously since j is never incremented our program fails with returning an 
invalid value for getFloat() call.


The actual size of this method is around 220 lines. I’ve reduced the size of 
this method to around 175 odd lines. Then I’m not facing this problem.It works 
fine giving me the following result
 

preparedstatement = (PreparedStatement)definePreparedStatement_aroundBody21
$advice(transactiondao, dbconnectionwrapper9, s20,         
preparedstatement.setString(1, s);

        int i;

        for(resultset = preparedstatement.executeQuery(); resultset.next(); 
arraylist.add(new Transaction(resultset.getString(i++),             i = 1;

(i++), resultset.getString(i++), resultset.getString(i++), resultset.getString
(i++), resultset.getFloat(i++), resultset.getDate(i++), resultset.getString
(i++))

Is it something to do with the size of the method??

Any ideas why this would be happening and how to solve it?
Comment 1 Adrian Colyer CLA 2005-08-10 07:06:44 EDT
Additional information from Hari:

2. We are using standard javac to compile.

3. Java Version is 1.4.2

4. All the 40 lines that I removed were the log statements .

5. I'm attaching the following things in my mail
Aspects- These aspects are quite simple. They just print a SOP before
and after a method call
Classes - There are 3 types of class files attached with this zip file
1)Original class file
2)Class files with strange behaviour that throw exception.
3)Class files that works fine after weaving
(but some line of codes(all log statements) were removed).
Comment 2 Adrian Colyer CLA 2005-08-10 07:07:48 EDT
Created attachment 25958 [details]
attachment as posted to aspectj-dev
Comment 3 Adrian Colyer CLA 2005-08-10 07:55:03 EDT
Initial testing seems to confirm that the combination of large method size PLUS
the unusual for loop syntax is required to recreate this bug. In addition, Sun's
javac 1.4.2 must produce different byte codes to the JDT compiler when compiling
this source.

I'm curious to know if you still see the problem when rewriting the loop as follows:

rs = ps.executeQuery();
while (rs.next()) {
  int i = 1;
  transactionList.add(rs.getString(i++), rs.getFloat(i++), ...);
}

thanks, A.
Comment 4 Adrian Colyer CLA 2005-08-10 07:57:51 EDT
One other piece of information that would be very useful too: please could you
compile this program using ajc (but not including the aspects) and attach the
TransactionDAO.class produced by ajc as an attachment to this bug report. The
difference in the byte codes between that class file and the one produced by
Sun's java compiler will hold the biggest clue...

Thanks again, A.
Comment 5 karunyan CLA 2005-08-11 00:56:34 EDT
Created attachment 26007 [details]
Java and class files compiled using ajc
Comment 6 karunyan CLA 2005-08-11 01:01:35 EDT
Actually we've coded them as u've mentioned.I've attached the java files for 
your reference.
Also i've compiled the java files (with and with out logging statements) using 
ajc without aspects . I've attached those files also for your reference
Comment 7 Adrian Colyer CLA 2005-08-12 08:20:50 EDT
In your original attachment, the .class file in the "original class" appears to
be a version compiled without the logging statements. Since the failure only
occurs when logging is included, could you also please attach the javac output
of compiling the version with logging included?  I'm going to keep looking at
what I've got in the meantime anyway...

Thks, A.
Comment 8 Adrian Colyer CLA 2005-08-12 09:55:07 EDT
OK, big clue to the source of the bug....

In the working version with the logging statements removed, the size of the
generated method is such that all the loads, stores etc. are done with regular
ldc, aload, ... intstructions.

In the failing version, the method is longer, and the loads, stores etc. are
done with ldc_w, astore_w, aload_w etc..  BUT the instructions that aspectj has
woven in are not wide versions, they're just regular versions.

The code generated by the ajc (jdt) compiler does NOT use _w instructions, even
when compiling the version with log statements in. Hence it's a pretty sure bet
that the _w instructions are in some way the source of the problem.

(which means of course that writing a shorter method would get you going as a
workaround - maybe move some of the function into helper methods and delegate to
them).
Comment 9 Adrian Colyer CLA 2005-08-12 10:17:35 EDT
Snippet of bytecode from successful weave:

 LOOP BODY

   1282:	goto	1483   JUMP TO TEST
   1285:	iconst_1
   1286:	istore	98      STORE i IN SLOT 98
   1288:	aload	14
   1290:	new	#43; //class com/infosys/j2ee/setlbank/model/transaction/Transaction
   1293:	dup
   1294:	aload	16
   1296:	iload	98      LOAD i
   1298:	iinc	98, 1   INC i

Snippet of bytecode from failing weave:

   LOOP BODY STARTS HERE

   3112:	goto	3345     JUMP TO TEST
   3115:	iconst_1
   3116:	istore_w 330     STORE i IN SLOT 330
   3120:	aload	34
   3122:	new	#131; //class com/infosys/j2ee/setlbank/model/transaction/Transaction
   3125:	dup
   3126:	aload	36
   3128:	iload_w 330      LOAD i FROM SLOT 330
   3132:	iinc	74, 1    INC SLOT 74!  (what's the betting this was the
                                 location of i prior to weaving...)
Comment 10 Adrian Colyer CLA 2005-08-12 10:19:29 EDT
and as andy points out.... 256 + 74 = ........ 330!
Comment 11 Adrian Colyer CLA 2005-08-12 11:26:33 EDT
Good progress, self-contained reproducable test case now checked into the test
harness under bugs150/pr106130.

Can also explain why the javac compiler output fails but ajc output works : ajc
(jdt) eliminates all unused local variables as part of its code generation,
whereas javac does not (look at LotsOfVars.java in the test dir - under ajc the
variables that are never used are thrown away, but under javac they are kept).
Pass the -preserveAllLocals flag to ajc and you get the same failure there too.

(Sorry for all the progress spam, this bug is tricky enough that i need to keep
a record as i go along...)
Comment 12 Adrian Colyer CLA 2005-08-12 11:51:31 EDT
tracked it down to a simple bug in BCEL : the test in IINC to see whether or not
to generate a wide instruction used n > Constants.MAX_SHORT .... when the test
should of course be n > Constants.MAX_BYTE.  Another BCEL improvement only
available in the AspectJ tree...

Just running all the tests, and then I'll commit the fix. Should be available
for you to pick up in the next published AspectJ build (I'll close this bug
report off once that is published). 
Comment 13 karunyan CLA 2005-08-13 01:52:35 EDT
Created attachment 26086 [details]
TransactionDAO compiling with logging included

attaching the javac output of compiling the version with logging included
incase if u need for anymore test
Comment 14 Adrian Colyer CLA 2005-08-16 05:32:08 EDT
fix available in published build, awaiting confirmation that it fixes the
original problem report before closing out.
Comment 15 karunyan CLA 2005-08-16 07:29:45 EDT
(In reply to comment #14)
> fix available in published build, awaiting confirmation that it fixes the
> original problem report before closing out.

Itz working fine for the latest published build for version 1.5. It would be 
of great help if u r making the patch availble for making the changes in 
version 1.2.1. Also let me know the exact root cause for this problem.
Comment 16 Adrian Colyer CLA 2005-08-16 07:53:31 EDT
Created attachment 26145 [details]
Patch to backport this fix to AspectJ 1.2.1 

To apply the fix to a 1.2.1 version of AspectJ:

1) download this attachment and save it in $ASPECTJ_HOME/lib
2) cd $ASPECTJ_HOME/lib
3) jar -xvf pr106130Patch.jar
4) jar -uvf aspectjtools.jar org/aspectj/apache/bcel/generic/IINC.class
5) verify: jar -xvf aspectjtools.jar | grep IINC
   output should show that IINC.class has the date that you applied the patch
6) you can now delete the patch file and the org directory created when you
expanded it.
Comment 17 Adrian Colyer CLA 2005-08-16 07:54:10 EDT
closing out bug report, fix verified by reporter.
Comment 18 Adrian Colyer CLA 2005-08-16 07:55:58 EDT
doh. I'm trying to get to the RESOLVED FIXED state. Have to reopen to do that....
Comment 19 Adrian Colyer CLA 2005-08-16 07:56:17 EDT
at last.
Comment 20 Adrian Colyer CLA 2005-08-16 08:14:59 EDT
Hari wrote : Also let me know the exact root cause for this problem.

The bug would exhibit when advising a method that has > 255 local variables
after weaving. Due to the differences in bytecode output by different compilers,
compiling the same source code with different compilers can result in differing
numbers of local vars in the bytecode (hence the reason you saw the bug with
javac but not with ajc). When a method had > 255 local vars, the code to move
the instructions in the method to accomodate the advice set the new index for an
IINC instruction using the Bcel API IINC.setIndex(). A bug in BCEL caused the
IINC class to always use the single byte iinc instruction rather than the wide
iinc_w instruction, even when the index was set to a number > 255. 
Comment 21 Andrew Clement CLA 2005-12-01 10:33:34 EST
*** Bug 101290 has been marked as a duplicate of this bug. ***