5 Replies Latest reply on Jun 27, 2006 7:32 AM by Kabir Khan

    Strange regression in Proxy processing

    Adrian Brock Master

      There seems to be a regression in the proxy processing.
      It goes into a loop while trying to create the proxy.
      But I only when running the test from inside eclipse?
      Running from command line ant doesn't cause the problem.

      It is looping somewhere here:

      main" prio=1 tid=0x0805ff98 nid=0x2032 waiting on condition [0xbfeac000..0xbfeae168]
       at java.lang.String.<init>(String.java:208)
       at java.lang.StringBuilder.toString(StringBuilder.java:431)
       at java.io.UnixFileSystem.resolve(UnixFileSystem.java:93)
       at java.io.File.<init>(File.java:284)
       at sun.misc.URLClassPath$FileLoader.getResource(URLClassPath.java:891)
       at sun.misc.URLClassPath$FileLoader.findResource(URLClassPath.java:871)
       at sun.misc.URLClassPath.findResource(URLClassPath.java:142)
       at java.net.URLClassLoader$2.run(URLClassLoader.java:362)
       at java.security.AccessController.doPrivileged(Native Method)
       at java.net.URLClassLoader.findResource(URLClassLoader.java:359)
       at java.lang.ClassLoader.getResource(ClassLoader.java:977)
       at javassist.LoaderClassPath.find(LoaderClassPath.java:86)
       at javassist.ClassPoolTail.find(ClassPoolTail.java:317)
       at javassist.ClassPool.find(ClassPool.java:467)
       at javassist.ClassPool.createCtClass(ClassPool.java:451)
       at javassist.ClassPool.get0(ClassPool.java:417)
       - locked <0x88f1e8b8> (a javassist.ClassPool)
       at javassist.ClassPool.get0(ClassPool.java:426)
       - locked <0x88fbbdc8> (a org.jboss.aop.AOPClassPool)
       at javassist.ClassPool.get(ClassPool.java:386)
       at javassist.compiler.MemberResolver.lookupClass0(MemberResolver.java:415)
       at javassist.compiler.MemberResolver.lookupClass(MemberResolver.java:379)
       at javassist.compiler.MemberResolver.lookupClassByName(MemberResolver.java:306)
       at javassist.compiler.TypeChecker.atNewExpr(TypeChecker.java:95)
       at javassist.compiler.ast.NewExpr.accept(NewExpr.java:72)
       at javassist.compiler.CodeGen.doTypeCheck(CodeGen.java:235)
       at javassist.compiler.CodeGen.compileExpr(CodeGen.java:222)
       at javassist.compiler.CodeGen.atThrowStmnt(CodeGen.java:618)
       at javassist.compiler.CodeGen.atStmnt(CodeGen.java:358)
       at javassist.compiler.ast.Stmnt.accept(Stmnt.java:49)
       at javassist.compiler.CodeGen.atIfStmnt(CodeGen.java:384)
       at javassist.compiler.CodeGen.atStmnt(CodeGen.java:348)
       at javassist.compiler.ast.Stmnt.accept(Stmnt.java:49)
       at javassist.compiler.CodeGen.atStmnt(CodeGen.java:344)
       at javassist.compiler.ast.Stmnt.accept(Stmnt.java:49)
       at javassist.compiler.MemberCodeGen.atTryStmnt(MemberCodeGen.java:140)
       at javassist.compiler.CodeGen.atStmnt(CodeGen.java:360)
       at javassist.compiler.ast.Stmnt.accept(Stmnt.java:49)
       at javassist.compiler.CodeGen.atStmnt(CodeGen.java:344)
       at javassist.compiler.ast.Stmnt.accept(Stmnt.java:49)
       at javassist.compiler.CodeGen.atMethodBody(CodeGen.java:285)
       at javassist.compiler.Javac.compileBody(Javac.java:212)
       at javassist.CtBehavior.setBody(CtBehavior.java:282)
       at javassist.CtBehavior.setBody(CtBehavior.java:257)
       at javassist.CtNewMethod.make(CtNewMethod.java:135)
       at javassist.CtNewMethod.make(CtNewMethod.java:104)
       at org.jboss.aop.proxy.container.ContainerProxyFactory.createIntroductions(ContainerProxyFactory.java:571)
       at org.jboss.aop.proxy.container.ContainerProxyFactory.createMixinsAndIntroductions(ContainerProxyFactory.java:394)
       at org.jboss.aop.proxy.container.ContainerProxyFactory.addMethodsAndMixins(ContainerProxyFactory.java:361)
       at org.jboss.aop.proxy.container.ContainerProxyFactory.createProxyCtClass(ContainerProxyFactory.java:179)
       at org.jboss.aop.proxy.container.ContainerProxyFactory.createProxyCtClass(ContainerProxyFactory.java:159)
       at org.jboss.aop.proxy.container.ContainerProxyFactory.generateProxy(ContainerProxyFactory.java:131)
       at org.jboss.aop.proxy.container.ContainerProxyFactory.getProxyClass(ContainerProxyFactory.java:121)
       - locked <0x88fbbe10> (a java.lang.Object)
       at org.jboss.aop.proxy.container.GeneratedAOPProxyFactory.generateProxy(GeneratedAOPProxyFactory.java:115)
       at org.jboss.aop.proxy.container.GeneratedAOPProxyFactory.getProxy(GeneratedAOPProxyFactory.java:101)
       - locked <0x88f1e6c8> (a java.lang.Object)
       at org.jboss.aop.proxy.container.GeneratedAOPProxyFactory.createAdvisedProxy(GeneratedAOPProxyFactory.java:73)
       at org.jboss.aop.proxy.container.GeneratedAOPProxyFactory.createAdvisedProxy(GeneratedAOPProxyFactory.java:41)
       at org.jboss.rars.generic.mcf.GenericManagedConnectionFactory.createProxy(GenericManagedConnectionFactory.java:582)
      


      You'll need to checkout the separate rars project from cvs
      then run the src/tests/org.jboss.test.rars.RARAllTestSuite from inside eclipse.

        • 1. Re: Strange regression in Proxy processing
          Kabir Khan Master

          I tried this and it works fine my end. I have just got back from training for the past week and a half, so I could have missed something, but I believe I have the right files checked out.

          • 2. Re: Strange regression in Proxy processing
            Adrian Brock Master

            The issue appears to be something different in the way eclipse
            does something (classloading?) and the way the command line does things.

            The bottleneck is in CtNewMethod.make() in createIntroductions()

            Eclipse:

            6503 DEBUG [JDBCUnitTestCase] ==== Starting testNoTx ====
            6539 DEBUG [GenericManagedConnection] org.jboss.rars.generic.mcf.GenericManagedConnection@5b0668[null] CREATED
            7710 DEBUG [GenericBeanAspectFactory] Creating advice 3j001-q2b1dh-en92whoj-1-en92wi0t-8
            7717 DEBUG [GenericBeanAspectFactory] Creating advice 3j001-q2b1dh-en92whoj-1-en92wi0a-7
            7727 DEBUG [GenericBeanAspectFactory] Creating advice 3j001-q2b1dh-en92whoj-1-en92whzl-6
            ==========> generateProxy=56477ms
            ==========> requests=5
            ==========> createProxyCtClass=56365ms
            ==========> createBasics=2237ms
            ==========> addMethodsAndMixins=54103ms
            ==========> createMixinsAndIntroductions=54103ms
            ==========> createIntroductions=54088ms
            ==========> #CtNewMethod.make=389
            ==========> CtNewMethod.make=53468ms
            ==========> proxy.addMethod=74ms
            63112 DEBUG [JDBCUnitTestCase] testNoTx took 56608ms
            63113 DEBUG [JDBCUnitTestCase] ==== Stopping testNoTx ====
            


            Command line
            5067 DEBUG [GenericManagedConnection] org.jboss.rars.generic.mcf.GenericManagedConnection@10b9279[null] CREATED
            5713 DEBUG [GenericBeanAspectFactory] Creating advice 3j001-og6y3q-en935jyu-1-en935kkh-8
            5720 DEBUG [GenericBeanAspectFactory] Creating advice 3j001-og6y3q-en935jyu-1-en935kjr-7
            5727 DEBUG [GenericBeanAspectFactory] Creating advice 3j001-og6y3q-en935jyu-1-en935kj6-6
            11826 DEBUG [JDBCUnitTestCase] ==========> generateProxy=6047ms
            11826 DEBUG [JDBCUnitTestCase] ==========> requests=5
            11827 DEBUG [JDBCUnitTestCase] ==========> createProxyCtClass=5940ms
            11827 DEBUG [JDBCUnitTestCase] ==========> createBasics=428ms
            11827 DEBUG [JDBCUnitTestCase] ==========> addMethodsAndMixins=5490ms
            11827 DEBUG [JDBCUnitTestCase] ==========> createMixinsAndIntroductions=5489ms
            11827 DEBUG [JDBCUnitTestCase] ==========> createIntroductions=5489ms
            11827 DEBUG [JDBCUnitTestCase] ==========> #CtNewMethod.make=389
            11827 DEBUG [JDBCUnitTestCase] ==========> CtNewMethod.make=5067ms
            11827 DEBUG [JDBCUnitTestCase] ==========> proxy.addMethod=65ms
            11827 DEBUG [JDBCUnitTestCase] testNoTx took 6790ms
            


            Eclipse ~ 137ms per method
            Cmdline ~ 13ms per method

            • 3. Re: Strange regression in Proxy processing
              Adrian Brock Master

              I think I've found the cause for this (well not exactly :-).
              Most of the time is spent in the ClassPool/LoaderClassPath doing
              ClassPool.get() then LoaderClassPath.find()

              75369 DEBUG [JDBCUnitTestCase] CtNewMethodMakeTime=65342ms
              75371 DEBUG [JDBCUnitTestCase] setBodyTime=65063ms
              75371 DEBUG [JDBCUnitTestCase] getTime=63939ms
              75371 DEBUG [JDBCUnitTestCase] findTime=57207ms
              75371 DEBUG [JDBCUnitTestCase] find#=21931

              It is trying to load a class called NoSuchMethodError (I think this should java.lang.NoSuchMethodError) 21245 times!

              If I change the code in createIntroductions() to specify the full class name
              then it becomes a lot faster:
              9647 DEBUG [JDBCUnitTestCase] CtNewMethodMakeTime=2548ms
              9648 DEBUG [JDBCUnitTestCase] setBodyTime=2507ms
              9648 DEBUG [JDBCUnitTestCase] getTime=2365ms
              9648 DEBUG [JDBCUnitTestCase] findTime=935ms
              9649 DEBUG [JDBCUnitTestCase] find#=644

              • 4. Re: Strange regression in Proxy processing
                Kabir Khan Master

                I have had a look at the InterceptorBinding.rebind() stuff.

                When running within Eclipse, I found the same error you mention above - using a fully qualfied class name solved that in Eclipse.

                Also, in the case of advices, an interceptor class is generated every time AdviceFactory.create() is called (when the interceptor chains are created either on startup or resulting from a rebind). I now check with the classloader if the class has already been created, and reuse that instead of regenerating every time.

                • 5. Re: Strange regression in Proxy processing
                  Kabir Khan Master

                  I've set up the aop-mc tests to use

                  -Djboss.aop.exclude=org.jboss.
                  -Djboss.aop.include=org.jboss.test.

                  to avoid matching on every single loaded class