search

hprange / wounit

The WOUnit framework contains a set of utilities for testing WebObjects applications using JUnit 4.7 or later capabilities.
http://hprange.github.io/wounit/
Apache License 2.0
19 stars 18 forks source link

Ongoing issue with EOModel.createPrototypeCache() #40

Closed paulhoadley closed 8 years ago

paulhoadley commented 10 years ago

I'm opening a new ticket here to distinguish it from #35 which is probably the same issue, but it wouldn't seem to have anything to do with partial entities (at least directly).

As reported in #35, the fix to ERXModelGroup seemed to clear up the problem for me, until it didn't. I'm still seeing it intermittently, though only running in Eclipse. It seems to be solid on Jenkins, though maybe I haven't run it enough times to see it. Further, sometimes it will fail on one test in a class (usually the first) and then proceed to pass on all the others. Here's a stack trace from my RoleTest class, testing an entity called Role which is not a partial entity:

com.webobjects.foundation.NSForwardException [java.lang.reflect.InvocationTargetException] null:java.lang.reflect.InvocationTargetException
    at com.webobjects.foundation._NSUtilities._explainInstantiationException(_NSUtilities.java:626)
    at com.webobjects.foundation._NSUtilities.instantiateObjectWithConstructor(_NSUtilities.java:665)
    at com.webobjects.eoaccess.EOEntityClassDescription.createInstanceWithEditingContext(EOEntityClassDescription.java:242)
    at com.webobjects.eoaccess.EOUtilities.createAndInsertInstance(EOUtilities.java:861)
    at com.wounit.rules.AbstractEditingContextRule$UnderTestFacade.create(AbstractEditingContextRule.java:72)
    at com.wounit.rules.AnnotationProcessor.createEOForType(AnnotationProcessor.java:49)
    at com.wounit.rules.AnnotationProcessor.initializeObject(AnnotationProcessor.java:172)
    at com.wounit.rules.AnnotationProcessor.process(AnnotationProcessor.java:205)
    at com.wounit.rules.AbstractEditingContextRule.before(AbstractEditingContextRule.java:182)
    at com.wounit.rules.MockEditingContext.before(MockEditingContext.java:147)
    at com.wounit.rules.AbstractEditingContextRule$1.evaluate(AbstractEditingContextRule.java:162)
    at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:263)
    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:68)
    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:47)
    at org.junit.runners.ParentRunner$3.run(ParentRunner.java:231)
    at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:60)
    at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:229)
    at org.junit.runners.ParentRunner.access$000(ParentRunner.java:50)
    at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:222)
    at org.junit.runners.ParentRunner.run(ParentRunner.java:300)
    at org.eclipse.jdt.internal.junit4.runner.JUnit4TestReference.run(JUnit4TestReference.java:50)
    at org.eclipse.jdt.internal.junit.runner.TestExecution.run(TestExecution.java:38)
    at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:467)
    at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:683)
    at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRunner.java:390)
    at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRunner.java:197)
Caused by: java.lang.reflect.InvocationTargetException
    at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
    at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:39)
    at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27)
    at java.lang.reflect.Constructor.newInstance(Constructor.java:513)
    at com.webobjects.foundation._NSUtilities.instantiateObjectWithConstructor(_NSUtilities.java:659)
    ... 24 more
Caused by: java.lang.NullPointerException
    at com.webobjects.eoaccess.EOModel.createPrototypeCache(EOModel.java:631)
    at com.webobjects.eoaccess.EOModel.prototypeAttributeNamed(EOModel.java:699)
    at com.webobjects.eoaccess.ERXModel.prototypeAttributeNamed(ERXModel.java:290)
    at com.webobjects.eoaccess.EOAttribute.<init>(EOAttribute.java:998)
    at com.webobjects.eoaccess.EOEntity.attributes(EOEntity.java:816)
    at com.webobjects.eoaccess.EOEntity.attributeNamed(EOEntity.java:789)
    at com.webobjects.eoaccess.EOEntity.classProperties(EOEntity.java:1098)
    at com.webobjects.eoaccess.EOEntity._propertyDictionaryInitializer(EOEntity.java:3321)
    at com.webobjects.eoaccess.EOEntity._newDictionaryForProperties(EOEntity.java:3667)
    at com.webobjects.eoaccess.EOEntityClassDescription._newDictionaryForProperties(EOEntityClassDescription.java:88)
    at com.webobjects.eocontrol.EOGenericRecord.__setClassDescription(EOGenericRecord.java:111)
    at com.webobjects.eocontrol.EOGenericRecord.__setClassDescription(EOGenericRecord.java:100)
    at com.webobjects.eocontrol.EOGenericRecord.<init>(EOGenericRecord.java:73)
    at er.extensions.eof.ERXGenericRecord.<init>(ERXGenericRecord.java:103)
    at net.logicsquad.access.model._Role.<init>(_Role.java:15)
    at net.logicsquad.access.model.Role.<init>(Role.java:15)
    ... 29 more

I'm seeing the same telltale console output here when it fails:

- Entity classDescription is not ERXEntityClassDescription: Privilege
- Entity classDescription is not ERXEntityClassDescription: Role
- Entity classDescription is not ERXEntityClassDescription: RolePrivilege

and not when it passes.

Henrique, I am more than happy to send you a small test framework that exhibits the issue. Let me know if you want it.

hprange commented 10 years ago

Considering the log output when the test fails, there is still a problem related with the way models have been loaded. Sorry for the silly question, but are you sure the latest version of Wonder is configured for this project?

Would you mind to provide a sample project reproducing the problem? I can re-enable the logs I've used to detect the problem with issue #35 and search for another issue.

paulhoadley commented 10 years ago

Sorry for the silly question, but are you sure the latest version of Wonder is configured for this project?

Very good question, and also one of my first thoughts. I've replaced all the frameworks in ~/Library/Frameworks with 6.1.2. I've cleaned and re-built everything in the workspace several times in case old libraries had been copied into the built bundles. I've re-started Eclipse several times in case some class was being cached in some dark corner. I've checked /Library/Java/Extensions.

Having just typed all of that, I went and checked it all again. I have no explanation for this, but despite copying all new frameworks into ~/Library/Frameworks, right down at ~/Library/Frameworks/ERExtensions/Resources/Java/ERExtensions.jar it still has an old timestamp, and is the wrong file size. Either I botched the original copy or the JAR was somehow overwritten at some stage—no idea. In any case, I've re-copied in all the new frameworks, and now the unit tests are passing 100% of the time.

Sorry for the noise here!

paulhoadley commented 10 years ago

I can't believe I'm going to do this, but here we go: re-opening this issue...

Everything is working perfectly in development under Eclipse—the initial bug report here was a red herring because there was an old version of ERExtensions.jar lying around. To be clear, there are no issues running the tests in Eclipse by selecting the Tests source folder > Run As > JUnit Test.

I am, however, getting consistent test failure running as an Ant build task on Jenkins. (At least it's not intermittent, as I was describing above.) I'll paste in some sample console output below, and Henrique maybe I'll send you the full thing via email. The first test in a test class fails with a NullPointerException in EOModel.createPrototypeCache(), and then subsequent ones with a ClassCastException again.

[junit] Testcase: nameCannotBeNull(net.logicsquad.access.tests.OrganisationTest):   Caused an ERROR
    [junit] java.lang.reflect.InvocationTargetException
    [junit] com.webobjects.foundation.NSForwardException [java.lang.reflect.InvocationTargetException] null:java.lang.reflect.InvocationTargetException
    [junit]     at com.webobjects.foundation._NSUtilities._explainInstantiationException(_NSUtilities.java:626)
    [junit]     at com.webobjects.foundation._NSUtilities.instantiateObjectWithConstructor(_NSUtilities.java:665)
    [junit]     at com.webobjects.eoaccess.EOEntityClassDescription.createInstanceWithEditingContext(EOEntityClassDescription.java:242)
    [junit]     at com.webobjects.eoaccess.EOUtilities.createAndInsertInstance(EOUtilities.java:861)
    [junit]     at com.wounit.rules.AbstractEditingContextRule$UnderTestFacade.create(AbstractEditingContextRule.java:72)
    [junit]     at com.wounit.rules.AnnotationProcessor.createEOForType(AnnotationProcessor.java:49)
    [junit]     at com.wounit.rules.AnnotationProcessor.initializeObject(AnnotationProcessor.java:172)
    [junit]     at com.wounit.rules.AnnotationProcessor.process(AnnotationProcessor.java:205)
    [junit]     at com.wounit.rules.AbstractEditingContextRule.before(AbstractEditingContextRule.java:182)
    [junit]     at com.wounit.rules.MockEditingContext.before(MockEditingContext.java:147)
    [junit]     at com.wounit.rules.AbstractEditingContextRule$1.evaluate(AbstractEditingContextRule.java:162)
    [junit] Caused by: java.lang.reflect.InvocationTargetException
    [junit]     at java.lang.reflect.Constructor.newInstance(Constructor.java:532)
    [junit]     at com.webobjects.foundation._NSUtilities.instantiateObjectWithConstructor(_NSUtilities.java:659)
    [junit] Caused by: java.lang.NullPointerException
    [junit]     at com.webobjects.eoaccess.EOModel.createPrototypeCache(EOModel.java:631)
    [junit]     at com.webobjects.eoaccess.EOModel.prototypeAttributeNamed(EOModel.java:699)
    [junit]     at com.webobjects.eoaccess.ERXModel.prototypeAttributeNamed(ERXModel.java:290)
    [junit]     at com.webobjects.eoaccess.EOAttribute.<init>(EOAttribute.java:998)
    [junit]     at com.webobjects.eoaccess.EOEntity.attributes(EOEntity.java:816)
    [junit]     at com.webobjects.eoaccess.EOEntity.attributeNamed(EOEntity.java:789)
    [junit]     at com.webobjects.eoaccess.EOEntity.classProperties(EOEntity.java:1098)
    [junit]     at com.webobjects.eoaccess.EOEntity._propertyDictionaryInitializer(EOEntity.java:3321)
    [junit]     at com.webobjects.eoaccess.EOEntity._newDictionaryForProperties(EOEntity.java:3667)
    [junit]     at com.webobjects.eoaccess.EOEntityClassDescription._newDictionaryForProperties(EOEntityClassDescription.java:88)
    [junit]     at com.webobjects.eocontrol.EOGenericRecord.__setClassDescription(EOGenericRecord.java:111)
    [junit]     at com.webobjects.eocontrol.EOGenericRecord.__setClassDescription(EOGenericRecord.java:100)
    [junit]     at com.webobjects.eocontrol.EOGenericRecord.<init>(EOGenericRecord.java:73)
    [junit]     at er.extensions.eof.ERXGenericRecord.<init>(ERXGenericRecord.java:103)
    [junit]     at er.extensions.partials.ERXPartialGenericRecord.<init>(ERXPartialGenericRecord.java:28)
    [junit]     at net.logicsquad.access.model._Organisation.<init>(Unknown Source)
    [junit]     at net.logicsquad.access.model.Organisation.<init>(Unknown Source)
    [junit] 
    [junit] 
    [junit] Testcase: userCanHaveAnOrganisation(net.logicsquad.access.tests.OrganisationTest):  Caused an ERROR
    [junit] com.webobjects.eoaccess.EOEntityClassDescription cannot be cast to er.extensions.eof.ERXEntityClassDescription
    [junit] java.lang.ClassCastException: com.webobjects.eoaccess.EOEntityClassDescription cannot be cast to er.extensions.eof.ERXEntityClassDescription
    [junit]     at er.extensions.partials.ERXPartialGenericRecord._partialsDictionary(ERXPartialGenericRecord.java:41)
    [junit]     at er.extensions.partials.ERXPartialGenericRecord._partials(ERXPartialGenericRecord.java:65)
    [junit]     at er.extensions.partials.ERXPartialGenericRecord.awakeFromInsertion(ERXPartialGenericRecord.java:178)
    [junit]     at com.webobjects.eocontrol.EOEditingContext.insertObjectWithGlobalID(EOEditingContext.java:2871)
    [junit]     at er.extensions.eof.ERXEC.insertObjectWithGlobalID(ERXEC.java:978)
    [junit]     at com.webobjects.eocontrol.EOEditingContext.insertObject(EOEditingContext.java:2889)
    [junit]     at er.extensions.eof.ERXEC.insertObject(ERXEC.java:989)
    [junit]     at com.webobjects.eoaccess.EOUtilities.createAndInsertInstance(EOUtilities.java:862)
    [junit]     at com.wounit.rules.AbstractEditingContextRule$UnderTestFacade.create(AbstractEditingContextRule.java:72)
    [junit]     at com.wounit.rules.AnnotationProcessor.createEOForType(AnnotationProcessor.java:49)
    [junit]     at com.wounit.rules.AnnotationProcessor.initializeObject(AnnotationProcessor.java:172)
    [junit]     at com.wounit.rules.AnnotationProcessor.process(AnnotationProcessor.java:205)
    [junit]     at com.wounit.rules.AbstractEditingContextRule.before(AbstractEditingContextRule.java:182)
    [junit]     at com.wounit.rules.MockEditingContext.before(MockEditingContext.java:147)
    [junit]     at com.wounit.rules.AbstractEditingContextRule$1.evaluate(AbstractEditingContextRule.java:162)

I can confirm that at test runtime:

The latest version of ERExtensions.jar is in the workspace. The Ant junit task has fork="true" and forkmode="once".

Given this is now confined to Jenkins, it's going to be an order of magnitude harder to debug, though again I can send a sample framework if you use Jenkins and are able to set it up as a project. I am also happy to test out WOUnit snapshots with additional debugging/logging output.

hprange commented 10 years ago

Do you have the same problem when building your project with Ant in terminal locally? Does it work if you turn 'fork="false"' in the Ant task?

paulhoadley commented 10 years ago

Do you have the same problem when building your project with Ant in terminal locally?

The environments are so different (Jenkins setup and local OS X development) that I actually hadn't tried that. (Locally I had been running solely with the Eclipse test runner.) After jumping the appropriate hurdles to get it set up, everything does reliably succeed running locally with Ant.

Thanks for the suggestion Henrique. I'm going to have to go back over the Jenkins environment with a fine-toothed comb. Most likely explanation would seem to be that it's still picking up a stale version of ERExtensions.jar from somewhere, but I don't see it yet.

paulhoadley commented 10 years ago

Most likely explanation would seem to be that it's still picking up a stale version of ERExtensions.jar from somewhere, but I don't see it yet.

If it is, I still don't see how. It's still failing as a Jenkins job, and also directly from the command line on the Jenkins server. If I run ant -v -d and grep the output, the only place it's picking up ERXExtensions.jar is from workspace/Root/Library/Frameworks/ERExtensions.framework/Resources/Java/ERExtensions.jar, and I've confirmed that has the right MD5 checksum.

Does it work if you turn 'fork="false"' in the Ant task?

No, bombs out with different errors—complaints about being unable to instantiate a class for JavaJDBCAdaptor.

I'm at a loss here. I guess this is no longer really a WOUnit problem, but any other suggestions or guesses would be gratefully accepted!

hprange commented 10 years ago

Let's try to eliminate the Wonder version problem. Could you print the result of ERXProperties.wonderVersion() while running your tests?

paulhoadley commented 10 years ago

I wish I'd thought of that. Unfortunately I'm just getting back Not Available when calling ERXProperties.wonderVersion() from a static block, and I can't get any output from the test methods themselves because they fail before the first line is executed.

hprange commented 10 years ago

Looks like you've found a bug in the algorithm to determine the Wonder version. :) Or at least a scenario that wasn't predicted. Anyway, I can send you a patch that adds the logs used to identify the original problem as described in https://github.com/hprange/wounit/issues/35#issuecomment-37714633. It's a Wonder patch. What do you think?

paulhoadley commented 10 years ago

Looks like you've found a bug in the algorithm to determine the Wonder version.

Something else I can track down!

Anyway, I can send you a patch that adds the logs used to identify the original problem as described in #35 (comment). It's a Wonder patch. What do you think?

At this stage, I'd sacrifice a chicken to work this out. Send anything!

paulhoadley commented 10 years ago

Can you send me the Wonder patch you referred to? I have time in the next few days to test it out.

paulhoadley commented 9 years ago

I'm still seeing this, though now in a different context, still only on Jenkins. Partial entities are not involved. Latest WOUnit, latest Wonder, still getting that NullPointerException at EOModel.createPrototypeCache(EOModel.java:631). Willing to try anything to track this down Henrique!

hprange commented 9 years ago

What version of Java are you using?

paulhoadley commented 9 years ago 
$ java -version
java version "1.6.0_32"
OpenJDK Runtime Environment (IcedTea6 1.13.4) (amazon-67.1.13.4.66.amzn1-i386)
OpenJDK Client VM (build 23.25-b01, mixed mode)
paulhoadley commented 9 years ago

Hi Henrique,

Just started a new project, using WOUnit for testing from the ground up. I'm still seeing this issue. Have you got anything I could try to help diagnose the problem?

paulhoadley commented 9 years ago

I got perilously close to closing this ticket. For unrelated reasons, I set up another Jenkins build server, and started running some WOUnit tests that had otherwise been failing on Jenkins—no problems. I built it from scratch, added the latest Wonder frameworks, made sure everything was pristine. But then, sure enough, as I transferred some older projects over (just via configuration, no code or build products—everything re-fetched from version control), the InvocationTargetException issue started reappearing, though, believe it or not, not necessarily in the same tests. It doesn't seem deterministic (thought it's repeatable between runs of the same project on the same build server).

So close, yet still so far away.

paulhoadley commented 8 years ago

I may have finally solved this, or at least worked around it. I'm reasonably sure this issue is related to #35, where we saw multiple attempts to load the same model, and a fix was applied to ERXModelGroup to use a set instead of an array. Despite this, I was still seeing this kind of thing when tests were failing as described above:

    [junit] - The model 'Ident' (path: file:/var/lib/jenkins/workspace/LSAccess/Resources/Ident.eomodeld) cannot be added to model group <EOModelGroup (("Ident", "file:/var/lib/jenkins/workspace/LSAccess/Resources/Ident.eomodeld"), ("Control", "file:/var/lib/jenkins/workspace/LSAccess/Resources/Control.eomodeld"), ("erprototypes", "file:/var/lib/jenkins/workspace/LSAccess/Root/Library/Frameworks/ERPrototypes.framework/Resources/erprototypes.eomodeld"))> because it already contains a model with that name.
    [junit] - The model 'Control' (path: file:/var/lib/jenkins/workspace/LSAccess/Resources/Control.eomodeld) cannot be added to model group <EOModelGroup (("Ident", "file:/var/lib/jenkins/workspace/LSAccess/Resources/Ident.eomodeld"), ("Control", "file:/var/lib/jenkins/workspace/LSAccess/Resources/Control.eomodeld"), ("erprototypes", "file:/var/lib/jenkins/workspace/LSAccess/Root/Library/Frameworks/ERPrototypes.framework/Resources/erprototypes.eomodeld"))> because it already contains a model with that name.

Reading that first line closely, I noted that the Resources directory in the project workspace was being searched, despite setting dir="${dest.dir}/${project.name}.framework" in build.xml. Suspecting this was the cause of the collisions, I temporarily moved Resources out of the way and all tests passed.

As a slightly clunky workaround, then, I'm using the chmod task either side of junit in build.xml to make Resources unreadable, so it's only the built framework in dist that's now being searched for models. This seems to be sufficient to fix the consistent failures I was seeing when running these tests on a Jenkins buildserver. As a final observation, I note that application projects don't seem to exhibit this problem, and it's not clear why. I'm calling the tests with an otherwise identical junit task, just pointing the dir attribute at the .woa bundle.

paulhoadley commented 8 years ago

I'm happy to close this issue. The "chmod hack" is sufficient for my purposes. It would be interesting to know why we're getting the duplicate model loading in some situations, but if no one else is seeing it, I'm not sure we'll get to the bottom of it any time soon.