Community
Participate
Working Groups
Hi, I've enabled LTW in my project which is using Hibernate. Hibernate's framework produces cglib generated proxies for several classes. The problem is, when LTW is enabled the generated proxies throw this exception: proxy.CGLIBLazyInitializer (CGLIBLazyInitializer.java:104) - CGLIB Enhancement failed: com.mprv.secsph.profile.domain.UrlItem java.lang.VerifyError: (class: com/mprv/secsph/profile/domain/UrlItem$$EnhancerByCGLIB$$859d1101, method: changeItemMode signature: (Lcom/mprv/secsph/profile/domain/ProfileItem$ItemStatus;Lcom/mprv/secsph/profile/domain/ProfileItem$StatusReason;Z)Z) Inconsistent stack height 2 at java.lang.Class.getDeclaredMethods0(Native Method) at java.lang.Class.privateGetDeclaredMethods(Class.java:2365) at java.lang.Class.getDeclaredMethod(Class.java:1907) at net.sf.cglib.proxy.Enhancer.getCallbacksSetter(Enhancer.java:597) at net.sf.cglib.proxy.Enhancer.setCallbacksHelper(Enhancer.java:585) at net.sf.cglib.proxy.Enhancer.setThreadCallbacks(Enhancer.java:579) at net.sf.cglib.proxy.Enhancer.createUsingReflection(Enhancer.java:601) at net.sf.cglib.proxy.Enhancer.firstInstance(Enhancer.java:532) at net.sf.cglib.core.AbstractClassGenerator.create(AbstractClassGenerator.java:220) at net.sf.cglib.proxy.Enhancer.createHelper(Enhancer.java:373) at net.sf.cglib.proxy.Enhancer.create(Enhancer.java:281) at net.sf.cglib.proxy.Enhancer.create(Enhancer.java:640) at org.hibernate.proxy.CGLIBLazyInitializer.getProxyFactory(CGLIBLazyInitializer.java:95) at org.hibernate.proxy.CGLIBProxyFactory.postInstantiate(CGLIBProxyFactory.java:42) at org.hibernate.tuple.PojoTuplizer.buildProxyFactory(PojoTuplizer.java:144) at org.hibernate.tuple.AbstractTuplizer.<init>(AbstractTuplizer.java:83) at org.hibernate.tuple.PojoTuplizer.<init>(PojoTuplizer.java:54) at org.hibernate.tuple.TuplizerLookup.create(TuplizerLookup.java:47) at org.hibernate.tuple.EntityMetamodel.<init>(EntityMetamodel.java:218) at org.hibernate.persister.entity.BasicEntityPersister.<init>(BasicEntityPersister.java:400) at org.hibernate.persister.entity.SingleTableEntityPersister.<init>(SingleTableEntityPersister.java:104) at org.hibernate.persister.PersisterFactory.createClassPersister(PersisterFactory.java:55) at org.hibernate.impl.SessionFactoryImpl.<init>(SessionFactoryImpl.java:211) at org.hibernate.cfg.Configuration.buildSessionFactory(Configuration.java:1005) … Notice: class com/mprv/secsph/profile/domain/UrlItem$$EnhancerByCGLIB$$859d1101 was woven by AspectJ. According to the long discussion in the mailing list (http://dev.eclipse.org/mhonarc/lists/aspectj-dev/msg01869.html), I understand that the problem with AjAttribute should affect only AspectJ functionality, because someone who is "lower" in the stack (ASM or whatever) ignores those attributes on it's way. But here we are seeing something else. CGLIB is the one which fails … Is it something new, or I'm running into the same bug? Thanks a lot! Misha. P.S. Andy, i think that binary weaving wouldn't cause this problem, because generated classes doesn't exist at this point. Thanks!
Can you tell me what the setup is? Are the CGLIB proxies generated offline i.e. do they exist before you start the system or are they generated online? Have you configured LTW using -javaagent? Can you post the aspect you are using? Thanks
The details are: Hibernate 3.0.5 - CGLib and ASM libraries are those which bundled with this Hibernate version. AspectJ - Dev. build from yesterday (Nov 23). CGLIB proxies are generated online - they don't before the system starts. Take a look at Hibernate's CGLIBLazyInitializer class. Yes, I've configured LTW using -javaagent option. The aspect, I think, have to contain "method-execution" pointcat which refers to getters/setters in the domain objects which are mapped to DB with Hibernate. (I hope it was understandable sentence :-) ). If you need something, I'm here. Thanks!
I meant: " ... they don't exist ..."
We are building a new version of AspectJ that will allow the dumping of selected byte-code both before and after weaving. There may be a problem weaving the generated byte-code. Does your aspect use "around" advice?
Created attachment 30622 [details] Allow dump both before and after LTW 1. Added support for <weaver><dump within="com.*" beforeandafter="true"/> in aop.xml to allow dumping of generated proxies both before and after weaving 2. Moved dump() method into WeavingAdaptor 3. Added new dump tests
patches checked in.
Yes, I have an around advices. I'll post the dumps right after the new DEV build will be available. Thanks!
There is now a special build available: http://www.eclipse.org/downloads/download.php?file=/technology/aspectj/dev/aspectj-DEVELOPMENT-maw.jar Please include the appropriate entry in your aop.xml files to dump the generated files both before and after weaving: <weaver options="-verbose"><dump within="*" beforeandafter="true"/>
Created attachment 30762 [details] Dump + weaver output + application log Hi, I'm attaching the requested dump and log files. When you will open the tar, you will find: 1. _ajdump - I intentionally left only the relevant packages (you know, we are a commercial company :-) ): * com/mprv/secsph/profile/changes - contains compiled Aspects * com/mprv/secsph/profile/domain - contains Hibernate's domain objects. Here Hibernate generates it's proxies at runtime. * com/mprv/secsph/profiling/impl - contains code which is proxied by Spring - also at runtime 2. application.log - Log4J output - Here you will find the exceptions which we are trying to fix :) thrown by CGLib. 3. output.log - mostly weaver output (-showWeaveInfo -verbose) If i've missed something, tell me. Thanks!
First impressions: - All the VerifyError exceptions are caused CGLIB generated classes which have a name containing 2 consecutive $ symbols. Some fail with "Inconsistent stack height", others with "Illegal instruction". - Unfortunately we do not have the dumped bytecode for any of the generated classes. This is possible because the "shouldDump()" method in ClassLoaderWeavingAdaptor tries to resolve the type whixh will of course fail. The matching logic needs to cope with generated code (including closures which cannot be dumped for a similar reason). - There are a _lot_ of [Xlint:adviceDidNotMatch] messages, one for each piece of advice in each aspect that does not match the particular class being woven. This is highly likely in a large system using multiple (11) aspects. I think this warning should be automatically suppressed but overrideable for LTW.
Starting with com/mprv/secsph/profile/domain/UrlItem$$EnhancerByCGLIB$$b7f17874 application.log "2005-11-29 11:40:14,989 ERROR [Server Startup] proxy.CGLIBLazyInitializer (CGLIBLazyInitializer.java:104) - CGLIB Enhancement failed: com.mprv.secsph.profile.domain.UrlItem "java.lang.VerifyError: (class: com/mprv/secsph/profile/domain/UrlItem$$EnhancerByCGLIB$$b7f17874, method: changeItemMode signature: (Lcom/mprv/secsph/profile/domain/ProfileItem$ItemStatus;Lcom/mprv/secsph/profile/domain/ProfileItem$StatusReason;Z)Z) Inconsistent stack height 2 at java.lang.Class.getDeclaredMethods0(Native Method) at java.lang.Class.privateGetDeclaredMethods(Class.java:2365) at java.lang.Class.getDeclaredMethod(Class.java:1907) at net.sf.cglib.proxy.Enhancer.getCallbacksSetter(Enhancer.java:597) at net.sf.cglib.proxy.Enhancer.setCallbacksHelper(Enhancer.java:585) at net.sf.cglib.proxy.Enhancer.setThreadCallbacks(Enhancer.java:579) at net.sf.cglib.proxy.Enhancer.createUsingReflection(Enhancer.java:601) at net.sf.cglib.proxy.Enhancer.firstInstance(Enhancer.java:532) at net.sf.cglib.core.AbstractClassGenerator.create(AbstractClassGenerator.java:220) at net.sf.cglib.proxy.Enhancer.createHelper(Enhancer.java:373) at net.sf.cglib.proxy.Enhancer.create(Enhancer.java:281) at net.sf.cglib.proxy.Enhancer.create(Enhancer.java:640) at org.hibernate.proxy.CGLIBLazyInitializer.getProxyFactory(CGLIBLazyInitializer.java:95) at org.hibernate.proxy.CGLIBProxyFactory.postInstantiate(CGLIBProxyFactory.java:42) at org.hibernate.tuple.PojoTuplizer.buildProxyFactory(PojoTuplizer.java:144) at org.hibernate.tuple.AbstractTuplizer.<init>(AbstractTuplizer.java:83) at org.hibernate.tuple.PojoTuplizer.<init>(PojoTuplizer.java:54) at org.hibernate.tuple.TuplizerLookup.create(TuplizerLookup.java:47) at org.hibernate.tuple.EntityMetamodel.<init>(EntityMetamodel.java:218) at org.hibernate.persister.entity.BasicEntityPersister.<init>(BasicEntityPersister.java:400) at org.hibernate.persister.entity.SingleTableEntityPersister.<init>(SingleTableEntityPersister.java:104) at org.hibernate.persister.PersisterFactory.createClassPersister(PersisterFactory.java:55) at org.hibernate.impl.SessionFactoryImpl.<init>(SessionFactoryImpl.java:211) at org.hibernate.cfg.Configuration.buildSessionFactory(Configuration.java:1005) at org.springframework.orm.hibernate3.LocalSessionFactoryBean.newSessionFactory(LocalSessionFactoryBean.java:758) at org.springframework.orm.hibernate3.LocalSessionFactoryBean.afterPropertiesSet(LocalSessionFactoryBean.java:685) at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:937) at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:334) at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:222) at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:146) at org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:271) at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:310) at org.springframework.web.context.support.AbstractRefreshableWebApplicationContext.refresh(AbstractRefreshableWebApplicationContext.java:133) at com.mprv.secsph.migration.MigrationListener.loadAppContext(MigrationListener.java:122) at com.mprv.secsph.migration.MigrationListener.contextInitialized(MigrationListener.java:50) at com.mprv.secsph.server.loader.AsyncServletContextListener$1.run(AsyncServletContextListener.java:67) at java.lang.Thread.run(Thread.java:595) output.log info weaving 'com/mprv/secsph/profile/domain/UrlItem$$EnhancerByCGLIB$$b7f17874' weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setSubclassDefaultFieldValues(com.mprv.secsph.profile.domain.ProfileItem))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by after advice from 'com.mprv.secsph.profile.changes.ChangeRecordManager' (ChangeRecordManager.aj:53) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setSubTreeCounterHib(com.mprv.secsph.profile.domain.SubTreeCounterUrls))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by after advice from 'com.mprv.secsph.profile.changes.ChangeRecordManager' (ChangeRecordManager.aj:53) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setIsLocked(com.mprv.secsph.profile.domain.IsLockedProperty))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by after advice from 'com.mprv.secsph.profile.changes.ChangeRecordManager' (ChangeRecordManager.aj:53) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setBindingUrls(com.mprv.secsph.profile.domain.BindingUrlsProperty))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by after advice from 'com.mprv.secsph.profile.changes.ChangeRecordManager' (ChangeRecordManager.aj:53) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setObservedSoapOccurrences(com.mprv.secsph.profile.domain.SlidingCounter))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by after advice from 'com.mprv.secsph.profile.changes.ChangeRecordManager' (ChangeRecordManager.aj:53) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setObservedStandardHttpOccurrences(com.mprv.secsph.profile.domain.SlidingCounter))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by after advice from 'com.mprv.secsph.profile.changes.ChangeRecordManager' (ChangeRecordManager.aj:53) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setDecidedSoap(java.lang.Boolean))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by after advice from 'com.mprv.secsph.profile.changes.ChangeRecordManager' (ChangeRecordManager.aj:40) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setDecidedSoap(java.lang.Boolean))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by after advice from 'com.mprv.secsph.profile.changes.ChangeRecordManager' (ChangeRecordManager.aj:53) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setDecidedSoap(java.lang.Boolean))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by around advice from 'com.mprv.secsph.profile.changes.RedundantUpdatesFilter' (RedundantUpdatesFilter.aj:34) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setDecidedSoap(java.lang.Boolean))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by after advice from 'com.mprv.secsph.profile.changes.ProfileChangeLogManager' (ProfileChangeLogManager.aj:153) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setDecidedStandardHttp(java.lang.Boolean))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by after advice from 'com.mprv.secsph.profile.changes.ChangeRecordManager' (ChangeRecordManager.aj:40) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setDecidedStandardHttp(java.lang.Boolean))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by after advice from 'com.mprv.secsph.profile.changes.ChangeRecordManager' (ChangeRecordManager.aj:53) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setDecidedStandardHttp(java.lang.Boolean))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by around advice from 'com.mprv.secsph.profile.changes.RedundantUpdatesFilter' (RedundantUpdatesFilter.aj:34) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setDecidedStandardHttp(java.lang.Boolean))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by after advice from 'com.mprv.secsph.profile.changes.ProfileChangeLogManager' (ProfileChangeLogManager.aj:153) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setSoapActions(java.util.Set))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by after advice from 'com.mprv.secsph.profile.changes.ChangeRecordManager' (ChangeRecordManager.aj:53) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setSoapActions(java.util.Set))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by around advice from 'com.mprv.secsph.profile.changes.RedundantUpdatesFilter' (RedundantUpdatesFilter.aj:34) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setParameters(java.util.Set))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by after advice from 'com.mprv.secsph.profile.changes.ChangeRecordManager' (ChangeRecordManager.aj:53) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setParameters(java.util.Set))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by around advice from 'com.mprv.secsph.profile.changes.RedundantUpdatesFilter' (RedundantUpdatesFilter.aj:34) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setPrefixParameters(java.util.Set))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by after advice from 'com.mprv.secsph.profile.changes.ChangeRecordManager' (ChangeRecordManager.aj:53) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setPrefixParameters(java.util.Set))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by around advice from 'com.mprv.secsph.profile.changes.RedundantUpdatesFilter' (RedundantUpdatesFilter.aj:34) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setFullPath(java.lang.String))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by after advice from 'com.mprv.secsph.profile.changes.ChangeRecordManager' (ChangeRecordManager.aj:53) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setFullPath(java.lang.String))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by around advice from 'com.mprv.secsph.profile.changes.RedundantUpdatesFilter' (RedundantUpdatesFilter.aj:34) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setStartingUrl(com.mprv.secsph.profile.domain.IsStartingProperty))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by after advice from 'com.mprv.secsph.profile.changes.ChangeRecordManager' (ChangeRecordManager.aj:53) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setLinkStatus(com.mprv.secsph.profile.domain.LinkStatusProperty))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by after advice from 'com.mprv.secsph.profile.changes.ChangeRecordManager' (ChangeRecordManager.aj:53) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setAllowedMethods(com.mprv.secsph.profile.domain.AllowedMethodsProperty))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by after advice from 'com.mprv.secsph.profile.changes.ChangeRecordManager' (ChangeRecordManager.aj:53) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setLatency(com.mprv.secsph.profile.domain.LatencyProperty))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by after advice from 'com.mprv.secsph.profile.changes.ChangeRecordManager' (ChangeRecordManager.aj:53) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setWebApplicationItem(com.mprv.secsph.profile.domain.WebApplicationItem))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by after advice from 'com.mprv.secsph.profile.changes.ChangeRecordManager' (ChangeRecordManager.aj:53) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setFolderItem(com.mprv.secsph.profile.domain.FolderItem))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by after advice from 'com.mprv.secsph.profile.changes.ChangeRecordManager' (ChangeRecordManager.aj:53) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setParent(com.mprv.secsph.profile.domain.ProfileItem))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by after advice from 'com.mprv.secsph.profile.changes.ChangeRecordManager' (ChangeRecordManager.aj:53) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setStatus(com.mprv.secsph.profile.domain.ProfileItem$ItemStatus))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by after advice from 'com.mprv.secsph.profile.changes.ChangeRecordManager' (ChangeRecordManager.aj:53) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setStatus(com.mprv.secsph.profile.domain.ProfileItem$ItemStatus))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by around advice from 'com.mprv.secsph.profile.changes.RedundantUpdatesFilter' (RedundantUpdatesFilter.aj:34) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setStatus(com.mprv.secsph.profile.domain.ProfileItem$ItemStatus))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by after advice from 'com.mprv.secsph.profile.changes.ProfileChangeLogManager' (ProfileChangeLogManager.aj:127) weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setDBPK(java.lang.String))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by after advice from 'com.mprv.secsph.profile.changes.ChangeRecordManager' (ChangeRecordManager.aj:53) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setDBPK(java.lang.String))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by around advice from 'com.mprv.secsph.profile.changes.RedundantUpdatesFilter' (RedundantUpdatesFilter.aj:34) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setItemId(com.mprv.secsph.profile.domain.ProfileItemId))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by after advice from 'com.mprv.secsph.profile.changes.ChangeRecordManager' (ChangeRecordManager.aj:53) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setDn(java.lang.String))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by after advice from 'com.mprv.secsph.profile.changes.ChangeRecordManager' (ChangeRecordManager.aj:53) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setDn(java.lang.String))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by around advice from 'com.mprv.secsph.profile.changes.RedundantUpdatesFilter' (RedundantUpdatesFilter.aj:34) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setParentId(com.mprv.secsph.profile.domain.ProfileItemId))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by after advice from 'com.mprv.secsph.profile.changes.ChangeRecordManager' (ChangeRecordManager.aj:53) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setProtectionMode(com.mprv.secsph.profile.domain.ProfileItem$ProtectionMode))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by after advice from 'com.mprv.secsph.profile.changes.ChangeRecordManager' (ChangeRecordManager.aj:28) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setProtectionMode(com.mprv.secsph.profile.domain.ProfileItem$ProtectionMode))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by after advice from 'com.mprv.secsph.profile.changes.ChangeRecordManager' (ChangeRecordManager.aj:53) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setProtectionMode(com.mprv.secsph.profile.domain.ProfileItem$ProtectionMode))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by after advice from 'com.mprv.secsph.profile.changes.AtomicOperationMarker' (AtomicOperationMarker.aj:23) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setProtectionMode(com.mprv.secsph.profile.domain.ProfileItem$ProtectionMode))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by around advice from 'com.mprv.secsph.profile.changes.RedundantUpdatesFilter' (RedundantUpdatesFilter.aj:34) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setItemConverged(java.lang.Boolean))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by after advice from 'com.mprv.secsph.profile.changes.ChangeRecordManager' (ChangeRecordManager.aj:53) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setItemConverged(java.lang.Boolean))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by around advice from 'com.mprv.secsph.profile.changes.RedundantUpdatesFilter' (RedundantUpdatesFilter.aj:34) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setItemStatusStr(java.lang.String))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by after advice from 'com.mprv.secsph.profile.changes.ChangeRecordManager' (ChangeRecordManager.aj:53) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setItemStatusStr(java.lang.String))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by around advice from 'com.mprv.secsph.profile.changes.RedundantUpdatesFilter' (RedundantUpdatesFilter.aj:34) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setProtectionModeStr(java.lang.String))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by after advice from 'com.mprv.secsph.profile.changes.ChangeRecordManager' (ChangeRecordManager.aj:53) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setProtectionModeStr(java.lang.String))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by around advice from 'com.mprv.secsph.profile.changes.RedundantUpdatesFilter' (RedundantUpdatesFilter.aj:34) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setRecommendedStatus(com.mprv.secsph.profile.domain.ProfileItem$ItemStatus))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by after advice from 'com.mprv.secsph.profile.changes.ChangeRecordManager' (ChangeRecordManager.aj:53) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setRecommendedStatus(com.mprv.secsph.profile.domain.ProfileItem$ItemStatus))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by around advice from 'com.mprv.secsph.profile.changes.RedundantUpdatesFilter' (RedundantUpdatesFilter.aj:34) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setItemRecommendedStatusStr(java.lang.String))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by after advice from 'com.mprv.secsph.profile.changes.ChangeRecordManager' (ChangeRecordManager.aj:53) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setItemRecommendedStatusStr(java.lang.String))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by around advice from 'com.mprv.secsph.profile.changes.RedundantUpdatesFilter' (RedundantUpdatesFilter.aj:34) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setStatusReasonStr(java.lang.String))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by after advice from 'com.mprv.secsph.profile.changes.ChangeRecordManager' (ChangeRecordManager.aj:53) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setStatusReasonStr(java.lang.String))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by around advice from 'com.mprv.secsph.profile.changes.RedundantUpdatesFilter' (RedundantUpdatesFilter.aj:34) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setStatusReason(com.mprv.secsph.profile.domain.ProfileItem$StatusReason))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by after advice from 'com.mprv.secsph.profile.changes.ChangeRecordManager' (ChangeRecordManager.aj:53) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setStatusReason(com.mprv.secsph.profile.domain.ProfileItem$StatusReason))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by around advice from 'com.mprv.secsph.profile.changes.RedundantUpdatesFilter' (RedundantUpdatesFilter.aj:34) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setCreateTime(java.util.Date))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by after advice from 'com.mprv.secsph.profile.changes.ChangeRecordManager' (ChangeRecordManager.aj:53) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setLastUpdate(long))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by after advice from 'com.mprv.secsph.profile.changes.ChangeRecordManager' (ChangeRecordManager.aj:53) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setLastUpdate(long))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by around advice from 'com.mprv.secsph.profile.changes.RedundantUpdatesFilter' (RedundantUpdatesFilter.aj:34) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setLastUpdateTime(java.util.Date))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by after advice from 'com.mprv.secsph.profile.changes.ChangeRecordManager' (ChangeRecordManager.aj:53) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setLastStatusChangeTime(java.util.Date))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by after advice from 'com.mprv.secsph.profile.changes.ChangeRecordManager' (ChangeRecordManager.aj:53) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setObservedOccurrence(com.mprv.secsph.profile.domain.SlidingCounter))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by after advice from 'com.mprv.secsph.profile.changes.ChangeRecordManager' (ChangeRecordManager.aj:53) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setObservedOccurrenceSinceLastStatusChange(com.mprv.secsph.profile.domain.SlidingCounter))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by after advice from 'com.mprv.secsph.profile.changes.ChangeRecordManager' (ChangeRecordManager.aj:53) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setParentDBPK(java.lang.String))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by after advice from 'com.mprv.secsph.profile.changes.ChangeRecordManager' (ChangeRecordManager.aj:53) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setParentDBPK(java.lang.String))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by around advice from 'com.mprv.secsph.profile.changes.RedundantUpdatesFilter' (RedundantUpdatesFilter.aj:34) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setIsNew(boolean))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by after advice from 'com.mprv.secsph.profile.changes.ChangeRecordManager' (ChangeRecordManager.aj:53) [with runtime test] weaveinfo Join point 'method-execution(void com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874.setIsNew(boolean))' in Type 'com.mprv.secsph.profile.domain.UrlItem$$EnhancerByCGLIB$$b7f17874' (<generated>) advised by around advice from 'com.mprv.secsph.profile.changes.RedundantUpdatesFilter' (RedundantUpdatesFilter.aj:34) [with runtime test] info at /root/Work/trunk/SecureSphereServerDev/SecureSphereServer/src/com/mprv/secsph/management/JmxOperationInvokerGuard.aj:11::0 advice defined in com.mprv.secsph.management.JmxOperationInvokerGuard has not been applied [Xlint:adviceDidNotMatch] ... public final boolean changeItemMode(com.mprv.secsph.profile.domain.ProfileItem$ItemStatus, com.mprv.secsph.profile.domain.ProfileItem$StatusReason, boolean); Code: 0: getstatic #2113; //Field com/mprv/secsph/profile/domain/ChangeItemModeProtector.ajc$cflowCounter$0:Lorg/aspectj/runtime/internal/CFlowCounter; 3: invokevirtual #2116; //Method org/aspectj/runtime/internal/CFlowCounter.inc:()V 6: aload_0 7: getfield #38; //Field CGLIB$CALLBACK_0:Lnet/sf/cglib/proxy/MethodInterceptor; 10: dup 11: ifnonnull 23 14: pop 15: aload_0 16: invokestatic #42; //Method CGLIB$BIND_CALLBACKS:(Ljava/lang/Object;)V 19: aload_0 20: getfield #38; //Field CGLIB$CALLBACK_0:Lnet/sf/cglib/proxy/MethodInterceptor; 23: dup 24: ifnull 81 27: aload_0 28: getstatic #141; //Field CGLIB$changeItemMode$8$Method:Ljava/lang/reflect/Method; 31: iconst_3 32: anewarray #46; //class java/lang/Object 35: dup 36: iconst_0 37: aload_1 38: aastore 39: dup 40: iconst_1 41: aload_2 42: aastore 43: dup 44: iconst_2 45: iload_3 46: new #143; //class java/lang/Boolean 49: dup_x1 50: swap 51: invokespecial #146; //Method java/lang/Boolean."<init>":(Z)V 54: aastore 55: getstatic #148; //Field CGLIB$changeItemMode$8$Proxy:Lnet/sf/cglib/proxy/MethodProxy; 58: invokeinterface #54, 5; //InterfaceMethod net/sf/cglib/proxy/MethodInterceptor.intercept:(Ljava/lang/Object;Ljava/lang/reflect/Method;[Ljava/lang/Object;Lnet/sf/cglib/proxy/MethodProxy;)Ljava/lang/Object; 63: dup 64: ifnonnull 72 67: pop 68: iconst_0 69: goto 78 72: checkcast #143; //class java/lang/Boolean 75: invokevirtual #152; //Method java/lang/Boolean.booleanValue:()Z 78: goto 102 81: aload_0 82: aload_1 83: aload_2 84: iload_3 85: invokespecial #139; //Method com/mprv/secsph/profile/domain/UrlItem.changeItemMode:(Lcom/mprv/secsph/profile/domain/ProfileItem$ItemStatus;Lcom/mprv/secsph/profile/domain/ProfileItem$StatusReason;Z)Z 88: goto 102 91: astore 5 93: getstatic #2113; //Field com/mprv/secsph/profile/domain/ChangeItemModeProtector.ajc$cflowCounter$0:Lorg/aspectj/runtime/internal/CFlowCounter; 96: invokevirtual #2119; //Method org/aspectj/runtime/internal/CFlowCounter.dec:()V 99: aload 5 101: athrow 102: getstatic #2113; //Field com/mprv/secsph/profile/domain/ChangeItemModeProtector.ajc$cflowCounter$0:Lorg/aspectj/runtime/internal/CFlowCounter; 105: invokevirtual #2119; //Method org/aspectj/runtime/internal/CFlowCounter.dec:()V 108: ireturn Exception table: from to target type 6 91 91 Class java/lang/Throwable Note: - The failing method changeItemMode() is not actually - There is a cflow counter for ChangeItemProtector - There is neither a weavInfo nor info/Xlint for this aspect
General comments: - The same aspects are registered a number of times suggesting there are multiple class loaders (applications) - We probably need to run with "aj.weaving.verbose=true" to get messages before aop.xml parsing. Alternatively this could be "held" until verbose mode is know when they can be deleted or released to the console - We should enhance the default message handler to append class loader name/identity and even a time stamp - We need the before byte-code for the failing classes - We should make matching on "*" simpler with no need to resolve types
Now looking at com/mprv/secsph/profile/domain/IpValue$$EnhancerByCGLIB$$4fe075c$$FastClassByCGLIB$$5f1ec221 ___applicaton.log___ "2005-11-29 11:40:34,061 ERROR [Server Startup] proxy.CGLIBLazyInitializer (CGLIBLazyInitializer.java:104) - CGLIB Enhancement failed: com.mprv.secsph.profile.domain.IpValue "java.lang.VerifyError: (class: com/mprv/secsph/profile/domain/IpValue$$EnhancerByCGLIB$$4fe075c$$FastClassByCGLIB$$5f1ec221, method: getIndex signature: (Ljava/lang/String;[Ljava/lang/Class;)I) Illegal instruction found at offset 2566 at java.lang.Class.getDeclaredConstructors0(Native Method) at java.lang.Class.privateGetDeclaredConstructors(Class.java:2328) at java.lang.Class.getConstructor0(Class.java:2640) at java.lang.Class.getDeclaredConstructor(Class.java:1953) at net.sf.cglib.core.ReflectUtils.getConstructor(ReflectUtils.java:244) at net.sf.cglib.core.ReflectUtils.newInstance(ReflectUtils.java:220) at net.sf.cglib.reflect.FastClass$Generator.firstInstance(FastClass.java:79) at net.sf.cglib.core.AbstractClassGenerator.create(AbstractClassGenerator.java:220) at net.sf.cglib.reflect.FastClass$Generator.create(FastClass.java:67) at net.sf.cglib.proxy.MethodProxy.helper(MethodProxy.java:81) at net.sf.cglib.proxy.MethodProxy.create(MethodProxy.java:47) at com.mprv.secsph.profile.domain.IpValue$$EnhancerByCGLIB$$4fe075c.CGLIB$STATICHOOK8(<generated>:1) at com.mprv.secsph.profile.domain.IpValue$$EnhancerByCGLIB$$4fe075c.<clinit>(<generated>:1) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:585) at net.sf.cglib.proxy.Enhancer.setCallbacksHelper(Enhancer.java:586) at net.sf.cglib.proxy.Enhancer.setThreadCallbacks(Enhancer.java:579) at net.sf.cglib.proxy.Enhancer.createUsingReflection(Enhancer.java:601) at net.sf.cglib.proxy.Enhancer.firstInstance(Enhancer.java:532) at net.sf.cglib.core.AbstractClassGenerator.create(AbstractClassGenerator.java:220) at net.sf.cglib.proxy.Enhancer.createHelper(Enhancer.java:373) at net.sf.cglib.proxy.Enhancer.create(Enhancer.java:281) at net.sf.cglib.proxy.Enhancer.create(Enhancer.java:640) at org.hibernate.proxy.CGLIBLazyInitializer.getProxyFactory(CGLIBLazyInitializer.java:95) at org.hibernate.proxy.CGLIBProxyFactory.postInstantiate(CGLIBProxyFactory.java:42) at org.hibernate.tuple.PojoTuplizer.buildProxyFactory(PojoTuplizer.java:144) at org.hibernate.tuple.AbstractTuplizer.<init>(AbstractTuplizer.java:83) at org.hibernate.tuple.PojoTuplizer.<init>(PojoTuplizer.java:54) at org.hibernate.tuple.TuplizerLookup.create(TuplizerLookup.java:47) at org.hibernate.tuple.EntityMetamodel.<init>(EntityMetamodel.java:218) at org.hibernate.persister.entity.BasicEntityPersister.<init>(BasicEntityPersister.java:400) at org.hibernate.persister.entity.SingleTableEntityPersister.<init>(SingleTableEntityPersister.java:104) at org.hibernate.persister.PersisterFactory.createClassPersister(PersisterFactory.java:55) at org.hibernate.impl.SessionFactoryImpl.<init>(SessionFactoryImpl.java:211) at org.hibernate.cfg.Configuration.buildSessionFactory(Configuration.java:1005) at org.springframework.orm.hibernate3.LocalSessionFactoryBean.newSessionFactory(LocalSessionFactoryBean.java:758) at org.springframework.orm.hibernate3.LocalSessionFactoryBean.afterPropertiesSet(LocalSessionFactoryBean.java:685) at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:937) at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:334) at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:222) at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:146) at org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:271) at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:310) at org.springframework.web.context.support.AbstractRefreshableWebApplicationContext.refresh(AbstractRefreshableWebApplicationContext.java:133) at com.mprv.secsph.migration.MigrationListener.loadAppContext(MigrationListener.java:122) at com.mprv.secsph.migration.MigrationListener.contextInitialized(MigrationListener.java:50) at com.mprv.secsph.server.loader.AsyncServletContextListener$1.run(AsyncServletContextListener.java:67) at java.lang.Thread.run(Thread.java:595) ___output.log___ info weaving 'com/mprv/secsph/profile/domain/IpValue$$EnhancerByCGLIB$$4fe075c$$FastClassByCGLIB$$5f1ec221' weaveinfo Join point 'field-get(com.mprv.secsph.profile.domain.ProfileItem com.mprv.secsph.profile.domain.ProfileEntity.ownerItem)' in Type 'com.mprv.secsph.profile.domain.IpValue$$EnhancerByCGLIB$$4fe075c$$FastClassByCGLIB$$5f1ec221' (<generated>) advised by around advice from 'com.mprv.secsph.profile.changes.ChangeRecordPropagator' (ChangeRecordPropagator.aj:80) info at /root/Work/trunk/SecureSphereServerDev/SecureSphereServer/src/com/mprv/secsph/management/JmxOperationInvokerGuard.aj:11::0 advice defined in com.mprv.secsph.management.JmxOperationInvokerGuard has not been applied [Xlint:adviceDidNotMatch] ... public int getIndex(java.lang.String, java.lang.Class[]); Code: 0: aload_1 1: aload_2 2: swap 3: dup 4: invokevirtual #22; //Method java/lang/Object.hashCode:()I 7: lookupswitch{ //51 -1853434142: 424; -1846477896: 459; -1776922004: 537; -1644271222: 570; -1544210033: 621; -1536524468: 683; -1362869029: 733; -1310797198: 767; -1295482945: 803; -1074578383: 853; -1057313569: 887; -1057313565: 951; -1053468136: 1015; -1039689911: 1051; -989054513: 1087; -989054511: 1151; -875366579: 1215; -574574724: 1293; -489084459: 1415; -163942459: 1451; -75308287: 1487; 3641717: 1522; 5451258: 1617; 7717296: 1665; 85179481: 1699; 98245393: 1749; 147696667: 1783; 161998116: 1819; 193978866: 1855; 220068332: 1891; 236410712: 1927; 279757982: 1991; 368337804: 2041; 381763725: 2075; 495524492: 2111; 598781625: 2161; 688312521: 2195; 700591008: 2245; 1010135362: 2278; 1060146578: 2315; 1080396449: 2351; 1154623345: 2415; 1727847844: 2466; 1811874389: 2517; 1817099975: 2698; 1902066072: 2764; 1905679803: 2799; 1950568386: 2849; 1984801293: 2887; 2062787579: 2937; 2120551293: 2975; default: 3025 } 424: ldc #143; //String CGLIB$getUniqueName$7 426: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 429: ifeq 3026 432: dup 433: arraylength 434: tableswitch{ //0 to 0 0: 452; default: 456 } 452: pop 453: bipush 42 455: ireturn 456: goto 3029 459: ldc #145; //String writeXML 461: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 464: ifeq 3026 467: dup 468: arraylength 469: tableswitch{ //3 to 3 3: 488; default: 534 } 488: dup 489: iconst_0 490: aaload 491: invokevirtual #150; //Method java/lang/Class.getName:()Ljava/lang/String; 494: ldc #152; //String com.mprv.secsph.utils.xmlwriter.XMLWriter 496: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 499: ifeq 3029 502: dup 503: iconst_1 504: aaload 505: invokevirtual #150; //Method java/lang/Class.getName:()Ljava/lang/String; 508: ldc #154; //String java.lang.String 510: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 513: ifeq 3029 516: dup 517: iconst_2 518: aaload 519: invokevirtual #150; //Method java/lang/Class.getName:()Ljava/lang/String; 522: ldc #156; //String com.mprv.secsph.profile.domain.SerializationType 524: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 527: ifeq 3029 530: pop 531: bipush 12 533: ireturn 534: goto 3029 537: ldc #157; //String toString 539: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 542: ifeq 3026 545: dup 546: arraylength 547: tableswitch{ //0 to 0 0: 564; default: 567 } 564: pop 565: iconst_1 566: ireturn 567: goto 3029 570: ldc #159; //String CGLIB$setDecided$1 572: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 575: ifeq 3026 578: dup 579: arraylength 580: tableswitch{ //1 to 1 1: 600; default: 618 } 600: dup 601: iconst_0 602: aaload 603: invokevirtual #150; //Method java/lang/Class.getName:()Ljava/lang/String; 606: ldc #161; //String java.lang.Boolean 608: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 611: ifeq 3029 614: pop 615: bipush 36 617: ireturn 618: goto 3029 621: ldc #163; //String CGLIB$readXML$5 623: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 626: ifeq 3026 629: dup 630: arraylength 631: tableswitch{ //2 to 2 2: 648; default: 680 } 648: dup 649: iconst_0 650: aaload 651: invokevirtual #150; //Method java/lang/Class.getName:()Ljava/lang/String; 654: ldc #165; //String org.w3c.dom.Node 656: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 659: ifeq 3029 662: dup 663: iconst_1 664: aaload 665: invokevirtual #150; //Method java/lang/Class.getName:()Ljava/lang/String; 668: ldc #154; //String java.lang.String 670: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 673: ifeq 3029 676: pop 677: bipush 40 679: ireturn 680: goto 3029 683: ldc #167; //String ajc$privFieldGet$com_mprv_secsph_profile_changes_ChangeRecordPropagator$com_mprv_secsph_profile_domain_ProfileEntity$ownerItem 685: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 688: ifeq 3026 691: dup 692: arraylength 693: tableswitch{ //1 to 1 1: 712; default: 730 } 712: dup 713: iconst_0 714: aaload 715: invokevirtual #150; //Method java/lang/Class.getName:()Ljava/lang/String; 718: ldc #169; //String com.mprv.secsph.profile.domain.ProfileEntity 720: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 723: ifeq 3029 726: pop 727: bipush 49 729: ireturn 730: goto 3029 733: ldc #171; //String CGLIB$isDecided$0 735: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 738: ifeq 3026 741: dup 742: arraylength 743: tableswitch{ //0 to 0 0: 760; default: 764 } 760: pop 761: bipush 35 763: ireturn 764: goto 3029 767: ldc #173; //String CGLIB$getOwnerItem$12 769: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 772: ifeq 3026 775: dup 776: arraylength 777: tableswitch{ //0 to 0 0: 796; default: 800 } 796: pop 797: bipush 26 799: ireturn 800: goto 3029 803: ldc #174; //String equals 805: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 808: ifeq 3026 811: dup 812: arraylength 813: tableswitch{ //1 to 1 1: 832; default: 850 } 832: dup 833: iconst_0 834: aaload 835: invokevirtual #150; //Method java/lang/Class.getName:()Ljava/lang/String; 838: ldc #176; //String java.lang.Object 840: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 843: ifeq 3029 846: pop 847: bipush 46 849: ireturn 850: goto 3029 853: ldc #178; //String CGLIB$writeReplace$16 855: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 858: ifeq 3026 861: dup 862: arraylength 863: tableswitch{ //0 to 0 0: 880; default: 884 } 880: pop 881: bipush 30 883: ireturn 884: goto 3029 887: ldc #180; //String setId_aroundBody0 889: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 892: ifeq 3026 895: dup 896: arraylength 897: tableswitch{ //2 to 2 2: 916; default: 948 } 916: dup 917: iconst_0 918: aaload 919: invokevirtual #150; //Method java/lang/Class.getName:()Ljava/lang/String; 922: ldc #182; //String com.mprv.secsph.profile.domain.ProfileValue 924: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 927: ifeq 3029 930: dup 931: iconst_1 932: aaload 933: invokevirtual #150; //Method java/lang/Class.getName:()Ljava/lang/String; 936: ldc #154; //String java.lang.String 938: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 941: ifeq 3029 944: pop 945: bipush 48 947: ireturn 948: goto 3029 951: ldc #184; //String setId_aroundBody4 953: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 956: ifeq 3026 959: dup 960: arraylength 961: tableswitch{ //2 to 2 2: 980; default: 1012 } 980: dup 981: iconst_0 982: aaload 983: invokevirtual #150; //Method java/lang/Class.getName:()Ljava/lang/String; 986: ldc #186; //String com.mprv.secsph.profile.domain.IpValue$$EnhancerByCGLIB$$4fe075c 988: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 991: ifeq 3029 994: dup 995: iconst_1 996: aaload 997: invokevirtual #150; //Method java/lang/Class.getName:()Ljava/lang/String; 1000: ldc #154; //String java.lang.String 1002: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 1005: ifeq 3029 1008: pop 1009: bipush 33 1011: ireturn 1012: goto 3029 1015: ldc #188; //String getCallbacks 1017: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 1020: ifeq 3026 1023: dup 1024: arraylength 1025: tableswitch{ //0 to 0 0: 1044; default: 1048 } 1044: pop 1045: bipush 20 1047: ireturn 1048: goto 3029 1051: ldc #190; //String notify 1053: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 1056: ifeq 3026 1059: dup 1060: arraylength 1061: tableswitch{ //0 to 0 0: 1080; default: 1084 } 1080: pop 1081: bipush 55 1083: ireturn 1084: goto 3029 1087: ldc #192; //String setName_aroundBody0 1089: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 1092: ifeq 3026 1095: dup 1096: arraylength 1097: tableswitch{ //2 to 2 2: 1116; default: 1148 } 1116: dup 1117: iconst_0 1118: aaload 1119: invokevirtual #150; //Method java/lang/Class.getName:()Ljava/lang/String; 1122: ldc #194; //String com.mprv.secsph.profile.domain.SqlSourceValue 1124: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 1127: ifeq 3029 1130: dup 1131: iconst_1 1132: aaload 1133: invokevirtual #150; //Method java/lang/Class.getName:()Ljava/lang/String; 1136: ldc #154; //String java.lang.String 1138: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 1141: ifeq 3029 1144: pop 1145: bipush 47 1147: ireturn 1148: goto 3029 1151: ldc #196; //String setName_aroundBody2 1153: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 1156: ifeq 3026 1159: dup 1160: arraylength 1161: tableswitch{ //2 to 2 2: 1180; default: 1212 } 1180: dup 1181: iconst_0 1182: aaload 1183: invokevirtual #150; //Method java/lang/Class.getName:()Ljava/lang/String; 1186: ldc #186; //String com.mprv.secsph.profile.domain.IpValue$$EnhancerByCGLIB$$4fe075c 1188: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 1191: ifeq 3029 1194: dup 1195: iconst_1 1196: aaload 1197: invokevirtual #150; //Method java/lang/Class.getName:()Ljava/lang/String; 1200: ldc #154; //String java.lang.String 1202: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 1205: ifeq 3029 1208: pop 1209: bipush 32 1211: ireturn 1212: goto 3029 1215: ldc #198; //String CGLIB$writeXML$6 1217: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 1220: ifeq 3026 1223: dup 1224: arraylength 1225: tableswitch{ //3 to 3 3: 1244; default: 1290 } 1244: dup 1245: iconst_0 1246: aaload 1247: invokevirtual #150; //Method java/lang/Class.getName:()Ljava/lang/String; 1250: ldc #152; //String com.mprv.secsph.utils.xmlwriter.XMLWriter 1252: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 1255: ifeq 3029 1258: dup 1259: iconst_1 1260: aaload 1261: invokevirtual #150; //Method java/lang/Class.getName:()Ljava/lang/String; 1264: ldc #154; //String java.lang.String 1266: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 1269: ifeq 3029 1272: dup 1273: iconst_2 1274: aaload 1275: invokevirtual #150; //Method java/lang/Class.getName:()Ljava/lang/String; 1278: ldc #156; //String com.mprv.secsph.profile.domain.SerializationType 1280: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 1283: ifeq 3029 1286: pop 1287: bipush 41 1289: ireturn 1290: goto 3029 1293: ldc #200; //String setDecided_aroundBody0 1295: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 1298: ifeq 3026 1301: dup 1302: arraylength 1303: tableswitch{ //2 to 2 2: 1320; default: 1412 } 1320: dup 1321: iconst_0 1322: aaload 1323: invokevirtual #150; //Method java/lang/Class.getName:()Ljava/lang/String; 1326: dup 1327: invokevirtual #22; //Method java/lang/Object.hashCode:()I 1330: lookupswitch{ //2 534825951: 1356; 1595851297: 1382; default: 1408 } 1356: ldc #202; //String com.mprv.secsph.profile.domain.IpValue 1358: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 1361: ifeq 1409 1364: dup 1365: iconst_1 1366: aaload 1367: invokevirtual #150; //Method java/lang/Class.getName:()Ljava/lang/String; 1370: ldc #161; //String java.lang.Boolean 1372: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 1375: ifeq 3029 1378: pop 1379: bipush 44 1381: ireturn 1382: ldc #186; //String com.mprv.secsph.profile.domain.IpValue$$EnhancerByCGLIB$$4fe075c 1384: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 1387: ifeq 1409 1390: dup 1391: iconst_1 1392: aaload 1393: invokevirtual #150; //Method java/lang/Class.getName:()Ljava/lang/String; 1396: ldc #161; //String java.lang.Boolean 1398: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 1401: ifeq 3029 1404: pop 1405: bipush 14 1407: ireturn 1408: pop 1409: goto 3029 1412: goto 3029 1415: ldc #204; //String writeReplace 1417: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 1420: ifeq 3026 1423: dup 1424: arraylength 1425: tableswitch{ //0 to 0 0: 1444; default: 1448 } 1444: pop 1445: bipush 8 1447: ireturn 1448: goto 3029 1451: ldc #206; //String CGLIB$finalize$13 1453: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 1456: ifeq 3026 1459: dup 1460: arraylength 1461: tableswitch{ //0 to 0 0: 1480; default: 1484 } 1480: pop 1481: bipush 27 1483: ireturn 1484: goto 3029 1487: ldc #207; //String getName 1489: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 1492: ifeq 3026 1495: dup 1496: arraylength 1497: tableswitch{ //0 to 0 0: 1516; default: 1519 } 1516: pop 1517: iconst_0 1518: ireturn 1519: goto 3029 1522: ldc #209; //String wait 1524: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 1527: ifeq 3026 1530: dup 1531: arraylength 1532: tableswitch{ //0 to 2 0: 1560; 1: 1564; 2: 1582; default: 1614 } 1560: pop 1561: bipush 54 1563: ireturn 1564: dup 1565: iconst_0 1566: aaload 1567: invokevirtual #150; //Method java/lang/Class.getName:()Ljava/lang/String; 1570: ldc #211; //String long 1572: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 1575: ifeq 3029 1578: pop 1579: bipush 52 1581: ireturn 1582: dup 1583: iconst_0 1584: aaload 1585: invokevirtual #150; //Method java/lang/Class.getName:()Ljava/lang/String; 1588: ldc #211; //String long 1590: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 1593: ifeq 3029 1596: dup 1597: iconst_1 1598: aaload 1599: invokevirtual #150; //Method java/lang/Class.getName:()Ljava/lang/String; 1602: ldc #213; //String int 1604: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 1607: ifeq 3029 1610: pop 1611: bipush 53 1613: ireturn 1614: goto 3029 1617: ldc #215; //String CGLIB$setName$4 1619: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 1622: ifeq 3026 1625: dup 1626: arraylength 1627: tableswitch{ //1 to 1 1: 1644; default: 1662 } 1644: dup 1645: iconst_0 1646: aaload 1647: invokevirtual #150; //Method java/lang/Class.getName:()Ljava/lang/String; 1650: ldc #154; //String java.lang.String 1652: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 1655: ifeq 3029 1658: pop 1659: bipush 39 1661: ireturn 1662: goto 3029 1665: ldc #217; //String getOwnerItem 1667: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 1670: ifeq 3026 1673: dup 1674: arraylength 1675: tableswitch{ //0 to 0 0: 1692; default: 1696 } 1692: pop 1693: bipush 9 1695: ireturn 1696: goto 3029 1699: ldc #219; //String CGLIB$SET_THREAD_CALLBACKS 1701: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 1704: ifeq 3026 1707: dup 1708: arraylength 1709: tableswitch{ //1 to 1 1: 1728; default: 1746 } 1728: dup 1729: iconst_0 1730: aaload 1731: invokevirtual #150; //Method java/lang/Class.getName:()Ljava/lang/String; 1734: ldc #221; //String [Lnet.sf.cglib.proxy.Callback; 1736: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 1739: ifeq 3029 1742: pop 1743: bipush 16 1745: ireturn 1746: goto 3029 1749: ldc #223; //String getId 1751: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 1754: ifeq 3026 1757: dup 1758: arraylength 1759: tableswitch{ //0 to 0 0: 1776; default: 1780 } 1776: pop 1777: bipush 6 1779: ireturn 1780: goto 3029 1783: ldc #224; //String hashCode 1785: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 1788: ifeq 3026 1791: dup 1792: arraylength 1793: tableswitch{ //0 to 0 0: 1812; default: 1816 } 1812: pop 1813: bipush 45 1815: ireturn 1816: goto 3029 1819: ldc #226; //String CGLIB$STATICHOOK8 1821: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 1824: ifeq 3026 1827: dup 1828: arraylength 1829: tableswitch{ //0 to 0 0: 1848; default: 1852 } 1848: pop 1849: bipush 34 1851: ireturn 1852: goto 3029 1855: ldc #228; //String getUniqueName 1857: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 1860: ifeq 3026 1863: dup 1864: arraylength 1865: tableswitch{ //0 to 0 0: 1884; default: 1888 } 1884: pop 1885: bipush 15 1887: ireturn 1888: goto 3029 1891: ldc #230; //String CGLIB$getName$2 1893: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 1896: ifeq 3026 1899: dup 1900: arraylength 1901: tableswitch{ //0 to 0 0: 1920; default: 1924 } 1920: pop 1921: bipush 37 1923: ireturn 1924: goto 3029 1927: ldc #232; //String ajc$privFieldSet$com_mprv_secsph_profile_changes_ChangeRecordPropagator$com_mprv_secsph_profile_domain_ProfileEntity$ownerItem 1929: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 1932: ifeq 3026 1935: dup 1936: arraylength 1937: tableswitch{ //2 to 2 2: 1956; default: 1988 } 1956: dup 1957: iconst_0 1958: aaload 1959: invokevirtual #150; //Method java/lang/Class.getName:()Ljava/lang/String; 1962: ldc #169; //String com.mprv.secsph.profile.domain.ProfileEntity 1964: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 1967: ifeq 3029 1970: dup 1971: iconst_1 1972: aaload 1973: invokevirtual #150; //Method java/lang/Class.getName:()Ljava/lang/String; 1976: ldc #234; //String com.mprv.secsph.profile.domain.ProfileItem 1978: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 1981: ifeq 3029 1984: pop 1985: bipush 50 1987: ireturn 1988: goto 3029 1991: ldc #236; //String CGLIB$setParent$9 1993: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 1996: ifeq 3026 1999: dup 2000: arraylength 2001: tableswitch{ //1 to 1 1: 2020; default: 2038 } 2020: dup 2021: iconst_0 2022: aaload 2023: invokevirtual #150; //Method java/lang/Class.getName:()Ljava/lang/String; 2026: ldc #234; //String com.mprv.secsph.profile.domain.ProfileItem 2028: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 2031: ifeq 3029 2034: pop 2035: bipush 23 2037: ireturn 2038: goto 3029 2041: ldc #238; //String CGLIB$getParent$3 2043: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 2046: ifeq 3026 2049: dup 2050: arraylength 2051: tableswitch{ //0 to 0 0: 2068; default: 2072 } 2068: pop 2069: bipush 38 2071: ireturn 2072: goto 3029 2075: ldc #240; //String CGLIB$clone$14 2077: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 2080: ifeq 3026 2083: dup 2084: arraylength 2085: tableswitch{ //0 to 0 0: 2104; default: 2108 } 2104: pop 2105: bipush 28 2107: ireturn 2108: goto 3029 2111: ldc #242; //String setCallbacks 2113: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 2116: ifeq 3026 2119: dup 2120: arraylength 2121: tableswitch{ //1 to 1 1: 2140; default: 2158 } 2140: dup 2141: iconst_0 2142: aaload 2143: invokevirtual #150; //Method java/lang/Class.getName:()Ljava/lang/String; 2146: ldc #221; //String [Lnet.sf.cglib.proxy.Callback; 2148: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 2151: ifeq 3029 2154: pop 2155: bipush 18 2157: ireturn 2158: goto 3029 2161: ldc #244; //String CGLIB$toString$15 2163: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 2166: ifeq 3026 2169: dup 2170: arraylength 2171: tableswitch{ //0 to 0 0: 2188; default: 2192 } 2188: pop 2189: bipush 29 2191: ireturn 2192: goto 3029 2195: ldc #246; //String CGLIB$setId$10 2197: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 2200: ifeq 3026 2203: dup 2204: arraylength 2205: tableswitch{ //1 to 1 1: 2224; default: 2242 } 2224: dup 2225: iconst_0 2226: aaload 2227: invokevirtual #150; //Method java/lang/Class.getName:()Ljava/lang/String; 2230: ldc #154; //String java.lang.String 2232: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 2235: ifeq 3029 2238: pop 2239: bipush 24 2241: ireturn 2242: goto 3029 2245: ldc #248; //String getParent 2247: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 2250: ifeq 3026 2253: dup 2254: arraylength 2255: tableswitch{ //0 to 0 0: 2272; default: 2275 } 2272: pop 2273: iconst_5 2274: ireturn 2275: goto 3029 2278: ldc #250; //String CGLIB$getId$8 2280: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 2283: ifeq 3026 2286: dup 2287: arraylength 2288: tableswitch{ //0 to 0 0: 2308; default: 2312 } 2308: pop 2309: bipush 22 2311: ireturn 2312: goto 3029 2315: ldc #252; //String getHibernateLazyInitializer 2317: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 2320: ifeq 3026 2323: dup 2324: arraylength 2325: tableswitch{ //0 to 0 0: 2344; default: 2348 } 2344: pop 2345: bipush 13 2347: ireturn 2348: goto 3029 2351: ldc #254; //String readXML 2353: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 2356: ifeq 3026 2359: dup 2360: arraylength 2361: tableswitch{ //2 to 2 2: 2380; default: 2412 } 2380: dup 2381: iconst_0 2382: aaload 2383: invokevirtual #150; //Method java/lang/Class.getName:()Ljava/lang/String; 2386: ldc #165; //String org.w3c.dom.Node 2388: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 2391: ifeq 3029 2394: dup 2395: iconst_1 2396: aaload 2397: invokevirtual #150; //Method java/lang/Class.getName:()Ljava/lang/String; 2400: ldc #154; //String java.lang.String 2402: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 2405: ifeq 3029 2408: pop 2409: bipush 11 2411: ireturn 2412: goto 3029 2415: ldc_w #256; //String CGLIB$findMethodProxy 2418: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 2421: ifeq 3026 2424: dup 2425: arraylength 2426: tableswitch{ //1 to 1 1: 2444; default: 2463 } 2444: dup 2445: iconst_0 2446: aaload 2447: invokevirtual #150; //Method java/lang/Class.getName:()Ljava/lang/String; 2450: ldc_w #258; //String net.sf.cglib.core.Signature 2453: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 2456: ifeq 3029 2459: pop 2460: bipush 21 2462: ireturn 2463: goto 3029 2466: ldc_w #260; //String getAttributeList 2469: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 2472: ifeq 3026 2475: dup 2476: arraylength 2477: tableswitch{ //1 to 1 1: 2496; default: 2514 } 2496: dup 2497: iconst_0 2498: aaload 2499: invokevirtual #150; //Method java/lang/Class.getName:()Ljava/lang/String; 2502: ldc #156; //String com.mprv.secsph.profile.domain.SerializationType 2504: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 2507: ifeq 3029 2510: pop 2511: bipush 10 2513: ireturn 2514: goto 3029 2517: ldc_w #262; //String newInstance 2520: invokevirtual #28; //Method java/lang/Object.equals:(Ljava/lang/Object;)Z 2523: ifeq 3026 2526: dup 2527: arraylength 2528: tableswitch{ //1 to 3 1: 2556; 2: 2615; 3: 2648; default: 2695 } 2556: dup 2557: iconst_0 2558: aaload 2559: invokevirtual #150; //Method java/lang/Class.getName:()Ljava/lang/String; 2562: dup 2563: invokevirtual #22; //Method java/lang/Object.hashCode:()I 2566: tableswitch{ //-845341380 to 1730110032 default: 2611 } public int getIndex(java.lang.Class[]); ...
On the first case I'd suspect the code around the handler being manipulated incorrectly (we may be assuming something about javac output...): 88: goto 102 91: astore 5 93: getstatic #2113; //Field com/mprv/secsph/profile/domain/ChangeItemModeProtector.ajc$cflowCounter$0:Lorg/aspectj/runtime/internal/CFlowCounter; 96: invokevirtual #2119; //Method org/aspectj/runtime/internal/CFlowCounter.dec:()V 99: aload 5 101: athrow 102: getstatic #2113; //Field com/mprv/secsph/profile/domain/ChangeItemModeProtector.ajc$cflowCounter$0:Lorg/aspectj/runtime/internal/CFlowCounter; 105: invokevirtual #2119; //Method org/aspectj/runtime/internal/CFlowCounter.dec:()V 108: ireturn Exception table: from to target type 6 91 91 Class java/lang/Throwable I'd like to see the 'before weaving' code for that case. On the second case, I've fixed multiple bugs this release in the BCEL handling of switch statements. The instruction at 2566 suggests bcel has messed up how it manipulated the tableswitch: 2566: tableswitch{ //-845341380 to 1730110032 default: 2611 } again it would be great to see the code 'before' weaving to see what this switch statement looked like. There are multiple formats for tableswitch and in particluar I think there is a special format when there is only a default entry or very few entries (if thats what this was in the original...). It doesn't matter that the switch isn't advised - the fact that the method is advised means bcel has cracked open the method and started tinkering with it. get me the before bytecode !!! :)
Created attachment 30873 [details] New dump with generated classes in "_before" Hi, Here is it ... Enjoy ;-)
Looking again at com/mprv/secsph/profile/domain/UrlItem$$EnhancerByCGLIB$$... there does not appear to be an existing exception handler: public final boolean changeItemMode(com.mprv.secsph.profile.domain.ProfileItem$ItemStatus, com.mprv.secsph.profile.domain.ProfileItem$StatusReason, boolean); Code: 0: aload_0 1: getfield #38; //Field CGLIB$CALLBACK_0:Lnet/sf/cglib/proxy/MethodInterceptor; 4: dup 5: ifnonnull 17 8: pop 9: aload_0 10: invokestatic #42; //Method CGLIB$BIND_CALLBACKS:(Ljava/lang/Object;)V 13: aload_0 14: getfield #38; //Field CGLIB$CALLBACK_0:Lnet/sf/cglib/proxy/MethodInterceptor; 17: dup 18: ifnull 73 21: aload_0 22: getstatic #141; //Field CGLIB$changeItemMode$8$Method:Ljava/lang/reflect/Method; 25: iconst_3 26: anewarray #46; //class java/lang/Object 29: dup 30: iconst_0 31: aload_1 32: aastore 33: dup 34: iconst_1 35: aload_2 36: aastore 37: dup 38: iconst_2 39: iload_3 40: new #143; //class java/lang/Boolean 43: dup_x1 44: swap 45: invokespecial #146; //Method java/lang/Boolean."<init>":(Z)V 48: aastore 49: getstatic #148; //Field CGLIB$changeItemMode$8$Proxy:Lnet/sf/cglib/proxy/MethodProxy; 52: invokeinterface #54, 5; //InterfaceMethod net/sf/cglib/proxy/MethodInterceptor.intercept:(Ljava/lang/Object;Ljava/lang/reflect/Method;[Ljava/lang/Object;Lnet/sf/cglib/proxy/MethodProxy;)Ljava/lang/Object; 57: dup 58: ifnonnull 66 61: pop 62: iconst_0 63: goto 72 66: checkcast #143; //class java/lang/Boolean 69: invokevirtual #152; //Method java/lang/Boolean.booleanValue:()Z 72: ireturn 73: aload_0 74: aload_1 75: aload_2 76: iload_3 77: invokespecial #139; //Method com/mprv/secsph/profile/domain/UrlItem.changeItemMode:(Lcom/mprv/secsph/profile/domain/ProfileItem$ItemStatus;Lcom/mprv/secsph/profile/domain/ProfileItem$StatusReason;Z)Z 80: ireturn
Created attachment 31037 [details] Use MissingResolvedTypeWithKnownSignature instead of ResolvedType.MISSING In order to dump generated code using type patterns either before weaving proxies or after generating closures we need to be able to match on missing type names. World.resolveToReferenceType() is changed to return MissingResolvedTypeWithKnownSignature where possible. This patch includes: 1. The necessary one line change to World 2. Replacement of "resolved == ResolvedType.MISSING" with "resolved.isMissing()" and "unresolved == ResolvedType.MISSING" with "ResolvedType.isMissing(unresolved)". The existing public MISSING field should probably be removed to avoid use. 3. Two new dump testcases that rely on the changes.
Matthew, You want me to run the "dump" again?
no need to take the dumps again - we still need to look at the bytecode.
First step is that I'd like to create the verify problem on the command line - the one that I can see in the log file. Can I ask how many dependencies there are for this system? Right now I'm finding I don't have: IllegalProfileValueException - is it possible for you to email me the jar that solves this dependency? (I hope there aren't too many after that - I've already grabbed hibernate which satisfies the hibernate and cglib dependencies) Also - due to the way cglib seems to be generating things, it might be best if I have a set of dumps where the _before matches the 'after' variant of the code - that doesn't currently seem to be the case because the original dump attached includes the 'after' _ajdump from one run and then the later append to this bug includes the '_before' directory from a later run. If its not too much trouble, could you recreate it and attach the entire _ajdump folder which will include a matching pair? I'm not sure the switch statement is broken at the moment as a further examination of the code is showing me code that switches on hashcodes (yuck) so that will lead to strange branches.
Created attachment 31112 [details] Dump with _before and after weaver output Hi Andy! Here is the dump that you requested. About your tries to run the program from command line, I'm not sure that it's so simple. I'll also have to send you our hibernate mappings and you'll need to build the matching DB schema (although you can configure Hibernate to do it for you ...). Then, your test program will have to create Hibernate's SessionFactory - to make it parse the mappings and create proxies. You will also need our aspects ... Are you still going to do it? :-) 10x! Misha.
I don't need to run it successfully - I just need to have the types around for resolution to succeed - so I doubt I need the mappings. Basically I just want to type java <thebrokenclass> and get the same 'Inconsistent Stack' message. If I try that right now it says I am missing 'IllegalProfileValueException'. So I probably just need a jar or two of yours. I am having some success with the BCEL verifier reporting a similar kind of fault with the woven classes.
Created attachment 31116 [details] Requested dependencies Hi, I hope it'll be enough, if not, tell me.
Here is the lookupswitch statement: 2566: lookupswitch{ //2 -845341380: 2592; 1730110032: 2604; default: 2615 } And here is what happens to it after bcel has chewed on it: 2566: tableswitch{ //-845341380 to 1730110032 default: 2611 } and then javap crashes....
If the BCEL verifier catches these 2 problems could we switch it on by default? It might even be useful in batch mode to identify problematic byte-code before it is executed. We could then allow the user to switch it off for performance reasons e.g. -Xnoverify (this used to be an option in early JDKs). The advantage of not waiting for the JVM to catch problems is that we have more context to help diagnose the problem. Also under LTW we could automatically dump before/after byte-code without asking the user to reproduce and even return the unwoven byte-code to the JVM so that the program can continue to load rather than failing.
> If the BCEL verifier catches these 2 problems could we switch it on by default? I would have have it *off* by default but it could be enabled through an option. It adds *significant* overhead, analysing every possible control flow through every single method in every single class. Although it catches them, it is supremely unhelpful for diagnosing them - telling me very little that javap doesn't, but it provides something I can hack, unlike javap.
I have fixed the damaged switch statement issue (manifests as 'invalid instruction'). The problem was BCEL - when we copy an instruction stream because we are weaving it, BCEL tries to be clever and use a tableswitch rather than a lookupswitch, which is a valid optimization in some circumstances. It can't cope with the ranges that are in the switch for this generated cglib stuff: lookupswitch{ //2 -845341380: 2592; 1730110032: 2604; default: 2615 } The optimization only works if the entries are numerically in order with no gaps (eg: 1,2,3,4) - the arithmetic bcel does determines that these two *obey* these rule (doh!) - so it transforms this into a completely broken tableswitch. I've put a test in the suite (amazing I could reduce it to this ...) public class BrokenSwitch { public static void main(String []argv) { int i = 1; switch (i) { case -845341380: System.err.println("a");break; case 1730110032: System.err.println("b");break; default: System.err.println("c");break; } } } aspect X { before(): execution(* BrokenSwitch.main(..)) {} } fix for this part of the problem will be in the next AJ dev build. That leaves the other (worse) problem of inconsistent stack height (unless this fix magically fixes the stack problem ... but thats unlikely)
One down, one to go ... :-) Thanks! (I wish i could help you ... )
Ok.... I believe it is a bug/feature of cglib. Something that would still allow the class to pass verification but mean the methods being advised aren't quite well formed - so that when AspectJ modifies them, the problem in the method is exposed. I have a fix (*cough* hack) that involves me transforming the cglib code to correct some stack management in it before AspectJ modifies it. I'm currently having a problem working out a stable fix - since I only need to do this extra manipulation when aspectj is weaving a method in a cglib generated class.
Ok ... one of my famous long winded explanations .. fascinating stuff (well I think so) ... just call me a bytecode god ;) We need to look at the code CGLIB creates first, here is an example method that is going to get woven by an aspect: protected final boolean changeItemMode(com.mprv.secsph.profile.domain.ProfileItem$ItemStatus, com.mprv.secsph.profile.domain.ProfileItem$StatusReason, boolean); Code: Stack=9, Locals=4, Args_size=4 0: aload_0 1: getfield #38; //Field CGLIB$CALLBACK_0:Lnet/sf/cglib/proxy/MethodInterceptor; 4: dup 5: ifnonnull 17 8: pop 9: aload_0 10: invokestatic #42; //Method CGLIB$BIND_CALLBACKS:(Ljava/lang/Object;)V 13: aload_0 14: getfield #38; //Field CGLIB$CALLBACK_0:Lnet/sf/cglib/proxy/MethodInterceptor; 17: dup 18: ifnull 73 21: aload_0 22: getstatic #648; //Field CGLIB$changeItemMode$52$Method:Ljava/lang/reflect/Method; 25: iconst_3 26: anewarray #80; //class java/lang/Object 29: dup 30: iconst_0 31: aload_1 32: aastore 33: dup 34: iconst_1 35: aload_2 36: aastore 37: dup 38: iconst_2 39: iload_3 40: new #308; //class java/lang/Boolean 43: dup_x1 44: swap 45: invokespecial #651; //Method java/lang/Boolean."<init>":(Z)V 48: aastore 49: getstatic #653; //Field CGLIB$changeItemMode$52$Proxy:Lnet/sf/cglib/proxy/MethodProxy; 52: invokeinterface #54, 5; //InterfaceMethod net/sf/cglib/proxy/MethodInterceptor.intercept:(Ljava/lang/Object;Ljava/lang/reflect/Method;[Ljava/lang/Object;Lnet/sf/cglib/proxy/MethodProxy;)Ljava/lang/Object; 57: dup 58: ifnonnull 66 61: pop 62: iconst_0 63: goto 72 66: checkcast #308; //class java/lang/Boolean 69: invokevirtual #312; //Method java/lang/Boolean.booleanValue:()Z 72: ireturn 73: aload_0 74: aload_1 75: aload_2 76: iload_3 77: invokespecial #646; //Method com/mprv/secsph/profile/domain/BaseParameterItem.changeItemMode:(Lcom/mprv/secsph/profile/domain/ProfileItem$ItemStatus;Lcom/mprv/secsph/profile/domain/ProfileItem$StatusReason;Z)Z 80: ireturn Basically it is choosing to delegate to a proxy for the method or call the original method. Important things to note: Instruction 72: a return Instruction 80: a return so there are two routes out of this method. This method verifies fine. The woven version that fails verification has actually been targetted by a cflow entry weave (indicating it matches the top of a cflow). This means the method is modified to increment a stack at the start and decrement a stack at the end: protected final boolean changeItemMode(com.mprv.secsph.profile.domain.ProfileItem$ItemStatus, com.mprv.secsph.profile.domain.ProfileItem$StatusReason, boolean); Code: Stack=9, Locals=6, Args_size=4 0: getstatic #1772; //Field com/mprv/secsph/profile/domain/ChangeItemModeProtector.ajc$cflowCounter$0:Lorg/aspectj/runtime/internal/CFlowCounter; 3: invokevirtual #1685; //Method org/aspectj/runtime/internal/CFlowCounter.inc:()V 6: aload_0 7: getfield #38; //Field CGLIB$CALLBACK_0:Lnet/sf/cglib/proxy/MethodInterceptor; 10: dup 11: ifnonnull 23 14: pop 15: aload_0 16: invokestatic #42; //Method CGLIB$BIND_CALLBACKS:(Ljava/lang/Object;)V 19: aload_0 20: getfield #38; //Field CGLIB$CALLBACK_0:Lnet/sf/cglib/proxy/MethodInterceptor; 23: dup 24: ifnull 81 27: aload_0 28: getstatic #648; //Field CGLIB$changeItemMode$52$Method:Ljava/lang/reflect/Method; 31: iconst_3 32: anewarray #80; //class java/lang/Object 35: dup 36: iconst_0 37: aload_1 38: aastore 39: dup 40: iconst_1 41: aload_2 42: aastore 43: dup 44: iconst_2 45: iload_3 46: new #308; //class java/lang/Boolean 49: dup_x1 50: swap 51: invokespecial #651; //Method java/lang/Boolean."<init>":(Z)V 54: aastore 55: getstatic #653; //Field CGLIB$changeItemMode$52$Proxy:Lnet/sf/cglib/proxy/MethodProxy; 58: invokeinterface #54, 5; //InterfaceMethod net/sf/cglib/proxy/MethodInterceptor.intercept:(Ljava/lang/Object;Ljava/lang/reflect/Method;[Ljava/lang/Object;Lnet/sf/cglib/proxy/MethodProxy;)Ljava/lang/Object; 63: dup 64: ifnonnull 72 67: pop 68: iconst_0 69: goto 78 72: checkcast #308; //class java/lang/Boolean 75: invokevirtual #312; //Method java/lang/Boolean.booleanValue:()Z 78: goto 102 81: aload_0 82: aload_1 83: aload_2 84: iload_3 85: invokespecial #646; //Method com/mprv/secsph/profile/domain/BaseParameterItem.changeItemMode:(Lcom/mprv/secsph/profile/domain/ProfileItem$ItemStatus;Lcom/mprv/secsph/profile/domain/ProfileItem$StatusReason;Z)Z 88: goto 102 91: astore 5 93: getstatic #1772; //Field com/mprv/secsph/profile/domain/ChangeItemModeProtector.ajc$cflowCounter$0:Lorg/aspectj/runtime/internal/CFlowCounter; 96: invokevirtual #1688; //Method org/aspectj/runtime/internal/CFlowCounter.dec:()V 99: aload 5 101: athrow 102: getstatic #1772; //Field com/mprv/secsph/profile/domain/ChangeItemModeProtector.ajc$cflowCounter$0:Lorg/aspectj/runtime/internal/CFlowCounter; 105: invokevirtual #1688; //Method org/aspectj/runtime/internal/CFlowCounter.dec:()V 108: ireturn Exception table: from to target type 6 91 91 Class java/lang/Throwable This fails verification with an 'inconsistent stack error'. Asking my hacked BCEL verifier for more information I simply get told: Cannot merge stacks of different size: OperandStack A: Slots used: 2 MaxStack: 9. int (Size: 1) net.sf.cglib.proxy.MethodInterceptor (Size: 1) OperandStack B: Slots used: 1 MaxStack: 9. int (Size: 1) Execution flow: 0: getstatic 1772 [InstructionContext] 3: invokevirtual 1685 [InstructionContext] 6: aload_0 [InstructionContext] 7: getfield 38 [InstructionContext] 10: dup [InstructionContext] 11: ifnonnull -> 23 [InstructionContext] 23: dup [InstructionContext] 24: ifnull -> 81 [InstructionContext] 27: aload_0 [InstructionContext] 28: getstatic 648 [InstructionContext] 31: iconst_3 [InstructionContext] 32: anewarray 80 [InstructionContext] 35: dup [InstructionContext] 36: iconst_0 [InstructionContext] 37: aload_1 [InstructionContext] 38: aastore [InstructionContext] 39: dup [InstructionContext] 40: iconst_1 [InstructionContext] 41: aload_2 [InstructionContext] 42: aastore [InstructionContext] 43: dup [InstructionContext] 44: iconst_2 [InstructionContext] 45: iload_3 [InstructionContext] 46: new 308 [InstructionContext] 49: dup_x1 [InstructionContext] 50: swap [InstructionContext] 51: invokespecial 651 [InstructionContext] 54: aastore [InstructionContext] 55: getstatic 653 [InstructionContext] 58: invokeinterface 54 [InstructionContext] 63: dup [InstructionContext] 64: ifnonnull -> 72 [InstructionContext] 72: checkcast 308 [InstructionContext] 75: invokevirtual 312 [InstructionContext] 78: goto -> 102 [InstructionContext] 102: getstatic 1772 [InstructionContext] What the hell does that mean? Basically it means there are 2 routes to instruction 102 in this method and when we arrive at instruction 102, these two routes have a different stack. In one route we only have an int (actually representing a boolean) on the stack. In route two we have the same int (representing a boolean) and a MethodInterceptor instance. Verification does not allow two routes to an instruction to have differing stacks. Err ... so what the hell does that mean? First, lets reduce the problem. The above woven code includes finally clauses and before advice - all messy and clouding the issue. Let's switch to just having 'after() returning' advice on the method. Here is another woven form of the code that also fails verification: protected final boolean changeItemMode(com.mprv.secsph.profile.domain.ProfileItem$ItemStatus, com.mprv.secsph.profile.domain.ProfileItem$StatusReason, boolean); Code: Stack=9, Locals=4, Args_size=4 0: aload_0 1: getfield #38; //Field CGLIB$CALLBACK_0:Lnet/sf/cglib/proxy/MethodInterceptor; 4: dup 5: ifnonnull 17 8: pop 9: aload_0 10: invokestatic #42; //Method CGLIB$BIND_CALLBACKS:(Ljava/lang/Object;)V 13: aload_0 14: getfield #38; //Field CGLIB$CALLBACK_0:Lnet/sf/cglib/proxy/MethodInterceptor; 17: dup 18: ifnull 75 21: aload_0 22: getstatic #648; //Field CGLIB$changeItemMode$52$Method:Ljava/lang/reflect/Method; 25: iconst_3 26: anewarray #80; //class java/lang/Object 29: dup 30: iconst_0 31: aload_1 32: aastore 33: dup 34: iconst_1 35: aload_2 36: aastore 37: dup 38: iconst_2 39: iload_3 40: new #308; //class java/lang/Boolean 43: dup_x1 44: swap 45: invokespecial #651; //Method java/lang/Boolean."<init>":(Z)V 48: aastore 49: getstatic #653; //Field CGLIB$changeItemMode$52$Proxy:Lnet/sf/cglib/proxy/MethodProxy; 52: invokeinterface #54, 5; //InterfaceMethod net/sf/cglib/proxy/MethodInterceptor.intercept:(Ljava/lang/Object;Ljava/lang/reflect/Method;[Ljava/lang/Object;Lnet/sf/cglib/proxy/MethodProxy;)Ljava/lang/Object; 57: dup 58: ifnonnull 66 61: pop 62: iconst_0 63: goto 72 66: checkcast #308; //class java/lang/Boolean 69: invokevirtual #312; //Method java/lang/Boolean.booleanValue:()Z 72: goto 85 75: aload_0 76: aload_1 77: aload_2 78: iload_3 79: invokespecial #646; //Method com/mprv/secsph/profile/domain/BaseParameterItem.changeItemMode:(Lcom/mprv/secsph/profile/domain/ProfileItem$ItemStatus;Lcom/mprv/secsph/profile/domain/ProfileItem$StatusReason;Z)Z 82: goto 85 85: invokestatic #1656; //Method A.aspectOf:()LA; 88: invokevirtual #1659; //Method A.ajc$afterReturning$A$1$4c9f519a:()V 91: ireturn So, we can see the afterReturning advice at the end of the bytecode. What's gone wrong? The verification failure is now: Execution flow: 0: aload_0 [InstructionContext] 1: getfield 38 [InstructionContext] 4: dup [InstructionContext] 5: ifnonnull -> 17 [InstructionContext] 17: dup [InstructionContext] 18: ifnull -> 75 [InstructionContext] 21: aload_0 [InstructionContext] 22: getstatic 648 [InstructionContext] 25: iconst_3 [InstructionContext] 26: anewarray 80 [InstructionContext] 29: dup [InstructionContext] 30: iconst_0 [InstructionContext] 31: aload_1 [InstructionContext] 32: aastore [InstructionContext] 33: dup [InstructionContext] 34: iconst_1 [InstructionContext] 35: aload_2 [InstructionContext] 36: aastore [InstructionContext] 37: dup [InstructionContext] 38: iconst_2 [InstructionContext] 39: iload_3 [InstructionContext] 40: new 308 [InstructionContext] 43: dup_x1 [InstructionContext] 44: swap [InstructionContext] 45: invokespecial 651 [InstructionContext] 48: aastore [InstructionContext] 49: getstatic 653 [InstructionContext] 52: invokeinterface 54 [InstructionContext] 57: dup [InstructionContext] 58: ifnonnull -> 66 [InstructionContext] 66: checkcast 308 [InstructionContext] 69: invokevirtual 312 [InstructionContext] 72: goto -> 85 [InstructionContext] 85: invokestatic 1656 [InstructionContext] So, there are two routes to instruction 85 that arrive with differing stacks. The key thing to recognize is *how aspectj implements after advice*. We have put the code to call the advice in at instruction 85 - AND WE HAVE MODIFIED EVERY RETURN INSTRUCTION IN THE METHOD TO INSTEAD CALL THE ADVICE INSTRUCTIONS. This means where there used to be multiple 'escape routes' from the method, there is now *ONE* at the end of the advice. And you can see the calls at instruction 72 and instruction 82 that used to be 'ireturns' are now 'gotos' that jump to the advice. This exposes a stack management issue that was there all along. In the original code there were two returns out of the program and at each return the stack was different - verification doesn't check this. Now, unfortunately the verifier only tells me one of the routes (DOH!) - what we actually see above is the route that results in a single 'int' on the stack. Let's take an alternative route and look at the stack: 0: aload_0 STACK = 'this' 1: getfield #38; //Field CGLIB$CALLBACK_0:Lnet/sf/cglib/proxy/MethodInterceptor; STACK = 'this.MethodInterceptor CGLIB$CALLBACK_0' 4: dup STACK = 'this.MethodInterceptor CGLIB$CALLBACK_0' 'this.MethodInterceptor CGLIB$CALLBACK_0' 5: ifnonnull 17 STACK = 'this.MethodInterceptor CGLIB$CALLBACK_0' 8: pop STACK = 9: aload_0 STACK = 'this' 10: invokestatic #42; //Method CGLIB$BIND_CALLBACKS:(Ljava/lang/Object;)V STACK = '' 13: aload_0 STACK = 'this' 14: getfield #38; //Field CGLIB$CALLBACK_0:Lnet/sf/cglib/proxy/MethodInterceptor; STACK = 'this.MethodInterceptor CGLIB$CALLBACK_0' 17: dup STACK = 'this.MethodInterceptor CGLIB$CALLBACK_0' 'this.MethodInterceptor CGLIB$CALLBACK_0' 18: ifnull 75 STACK = 'this.MethodInterceptor CGLIB$CALLBACK_0' let's assume its null and jump to 75 75: aload_0 STACK = 'this.MethodInterceptor CGLIB$CALLBACK_0' 'this' 76: aload_1 STACK = 'this.MethodInterceptor CGLIB$CALLBACK_0' 'this' 'ProfileItem$ItemStatus' 77: aload_2 STACK = 'this.MethodInterceptor CGLIB$CALLBACK_0' 'this' 'ProfileItem$ItemStatus' 'ProfileItem$StatusReason' 78: iload_3 STACK = 'this.MethodInterceptor CGLIB$CALLBACK_0' 'this' 'ProfileItem$ItemStatus' 'ProfileItem$StatusReason' 'boolean' 79: invokespecial #646; //Method com/mprv/secsph/profile/domain/BaseParameterItem.changeItemMode:(Lcom/mprv/secsph/profile/domain/ProfileItem$ItemStatus;Lcom/mprv/secsph/profile/domain/ProfileItem$StatusReason;Z)Z STACK = 'this.MethodInterceptor CGLIB$CALLBACK_0' 'boolean' 82: goto 85 // BANG, route to 85 that leaves us with the additional MethodInterceptor on the stack. What's missing? In the jump from 18 to 75, there is a missing 'pop' that would have cleared the stack. (like the pattern at instruction 5 and 8 - after a null check, you do a pop). If I insert a 'pop' instruction at position 75 (before the aload_0) then the stack is emptied. We will then reach instruction 85 with the same stack regardless of the route taken. I have hacked the CGLIB generated code and inserted the 'pop' at that position - after weaving, this results in a form of the code that verifies perfectly. So ... it's a feature of the CGLIB generated code that it can't be woven by AspectJ after advice (or constructs that weave in a similar way, like cflow). I imagine javac and other bytecode producers never create code with differing stack heights when they return from a method. I'm not quite sure what to do now ... the original CGLIB code isn't wrong as it passes verification, it just doesn't lend itself to AspectJ weaving. It doesn't seem unreasonable for CGLIB to insert that pop to produce 'nice' bytecode. But, in the short term, I wondering how stable the pattern is for the generated method. Can I reliably insert the missing 'pop' under all circumstances...
May be try posting to CGLIB forum?
I have posted to the CGLIB mailing list. My question for you is whether you really want/need to weave these proxies in the first place? I can imagine situations where it will give you unexpected/incorrect results. If you weave 'execution(* someMethod(..))' and there is a proxy created for the class containing 'someMethod' then your advice can run twice, once in the advised proxy and again if the proxy eventually calls the original method. It might be that you want to add an element to the aop.xml that causes it avoid weaving *anything* proxy like - does that sound reasonable?
Bingo!! It what I was going to ask from you anyway :-). But the catch is: in the near future I'm planning some code generation with CGLIB ... But you are right ... it'll be VERY confusing when aspectj will weave'em. You know ... for now it's best for me not to weave the generated code at all, as long as it's propose is creating a proxy. So may be this new element will do something like that: <exclude generated code within="org.hibernate.*">
Matthew - are you able to verify the recent patches to type pattern matching will enable Misha's proposed 'exclude' clause to work as intended?
Did you try it with any kind of exclusion yet Misha? We were thinking something like "*CGLIB$$*" (but I don't think Matthew has confirmed yet whether that will work).
Yea, I've tried: <exclude within="com.mprv..*EnhancerByCGLIB*"/> and <exclude within="com.mprv.secsph.profile.domain.*EnhancerByCGLIB*"/> Both didn't work ...
My pattern didn't work because I hadn't committed Matthews changes - I've now done that. It should be better behaved in a dev build later today (not sure it'll be the next build as one is already in progress). matthew can you try it with HEAD?
Matthews changes are now in the latest dev build... it may match those CGLIB$$ patterns now
Now that the fix to match missing types (in this case generated proxies) with know signatures has been integrated I am confident the suggested exclude statement in aop.xml will work. There is a test in the harness which dumps Java proxies of the from $Proxy1 which would not work if either missing types could not be matched or bug 118616 was not fixed.
Hi guys, I wrote the following in the aop.xml, and it doesn't work ... <weaver options="-XlazyTjp"> <include within="com.mprv..*"/> <exclude within="com.mprv.secsph.profile.domain.*CGLIB*"/> </weaver> neither did this one: <weaver options="-XlazyTjp"> <include within="com.mprv..*"/> <exclude within="com.mprv..*CGLIB*"/> </weaver> Thanks!
We are going to work on enhancing out testcase for this - can I just confirm you were using a very recent dev build of AspectJ when you made your last attempt?
I can reproduce this problem. Matching on "CGLIB" in a type name does not seem to work. I will investigate.
You don't need the "<include ..." clause so try this instead: <weaver options="-XlazyTjp"> <exclude within="com.mprv..*CGLIB*"/> </weaver> There may be a problem with matching both include and exclude. Using just exclude solved the problem for me. Cheers
Hi Andy and Mathew! I've removed "include" and it worked!! But ... :) The porpose of LTW for me was to save people's time by allowing'em to compile ONLY what they've changed using javac. After the compilation, Tomcat tries to redeploy recompiled classes, and this is what happens next: java.lang.Exception: AspectJ5 does not weave hotswapped class (com/mprv/secsph/profile/domain/ProfileItem) at org.aspectj.weaver.loadtime.ClassPreProcessorAgentAdapter.transform(ClassPreProcessorAgentAdapter.java:55) at sun.instrument.TransformerManager.transform(TransformerManager.java:122) at sun.instrument.InstrumentationImpl.transform(InstrumentationImpl.java:155) Can you please support hotswapping? :) This is what the LTW is good for ... Thanks! Misha.
Phew. Matthew is also fixing the ability to use include/exclude together (under a separate bug). We won't be able to do anything for hotswap in the 1.5.0 release (due imminently...). Hotswap makes things *really complex* since you may modify a type (e.g. via an ITD) in such a way that we need to then reweave a load of other stuff that is already in the system and we don't track that information under LTW right now. I've copied Ron Bodkin as Ron is one of our 'power users' wrt load time weaving and also has tomcat experience. Ron - any comments on what Misha is trying to achieve?
I'm going to close this bug shortly to mark the work we have done on it for 1.5.0, there are two new bugs to track what is now coming out of this bug: 120372 - recording that we can't successfully weave cglib generated code 120375 - covering reweaving hotswapped code
Thanks a lot for all help! 120375 - is important to us, so if you can, please give it a try ... Thanks!
There's a lot to catch up on here. A few questions/comments: 1) Are you just redeploying an application as a war here? That shouldn't require AspectJ Hot Swap support. I just verified that there's no problem deploying a new version of an application to Tomcat 5.5.9: it redeploys without requiring hotswapping (it creates a new ClassLoader). Of course, if you are trying to run exploded classes or if you are redeploying shared library code, then that could be a problem. It often is still easier to reploy a jar than to restart the server... 2) Why can't AspectJ put after returning advice calls in front of each of the bytecode ireturn's instead of requiring a single return? Since multiple returns is valid bytecode, AspectJ should just support it. Right? Even if the CGLIB code is ugly, AspectJ's weaver ought to support verifiable bytecode. 3) I was going to report a bug I saw yesterday whereby I got a BCException in matching names like $Proxy4 in ResolvedType.getDeclaringType (since it tries to resolve a type with the name ""). Hopefully there is already revised logic that handles this case. #2 also reminds me of another interesting question. I know that Eugene Kuleshov has been burning the midnight oil trying to get ASM to properly create Java 6 verification proofs in woven code. That's going to be another big project for AspectJ, when it comes to support Java 6 bytecode: it will have to output the same kind of proofs of correctness for the woven bytecodes...
thanks Ron. On (2) - of course that is an option for AJ but I'm not changing our weaving strategy with RC1 so close - when all the code we've ever processed since being a binary weaver hasn't hit this problem. A question for you? do you not care about the code bloat this would introduce? It is more than just a method call at times, I'm also not sure if we can nicely implement finally type constructs by inlining in this way. I am involved in a thread on the cglib list about the situation. We haven't faced Java6 yet but I know the verification thing will bite us - we may use ASM for that part of things - not sure yet.
Re: code bloat, I see the issue: multiple returns from a method is common but multiple returns with different stack frames is not. How does the caller of that CGLIB method handle having possibly different stack frames? This sounds a bit like FORTH programming (a stack-based language where you explicitly did push and pop operations and might have different numbers of members on the stack for different cases). Here's a hokey idea: use the current strategy but if the class can't be verified, then do the bloated but safe alternative. Let the weird code pay the price and not all the code. But re: code bloat, I do wonder how much difference it really makes after JIT compilation. Will modern JITs optimize the common code before returns? If so, then the issue isn't too important. If not, then it also hurts performance (worsens cache performance).
we can continue the discussion here but I'm closing this bug to cover the work done in 1.5.0 for this problem. The two other bugs cover the new work items to come out of it...
