Operating System: All
Platform: All

Attachment bug6252-stacktrace.txt has been added with description: Full stack trace attached, for future Googling.

> I'll post a Gerrit with a reproducer for this problem in a second.

https://git.opendaylight.org/gerrit/42302 reproduces this problem easily.

Hi, i have looked into your test and the problem seems to be missing plugin in pom file. After the change all tests passed

> i have looked into your test and

Thank you!

> the problem seems to be missing plugin in pom file.

Ah yes I forgot xtend-maven-plugin, saw that you added that to gerrit/#/c/42296 - tx.

FYI I actually never ran the CLI mvn test, and had this problem in IDE... (The original project where I ran into this did have the xtend-maven-plugin, I just forgot it in the isolated branch created to reproduce the problem.)

> After the change all tests passed

... and that, IDE vs CLI, is the crux here - it indeed works on "mvn test" (always did), but there's something foul in-IDE (Eclipse, with https://github.com/vorburger/opendaylight-eclipse-setup) ... hm, interesting:

At first, when I re-ran the BugReproducerTest in-IDE, after having done a "mvn test" on CLI, and it DL'd new JARs from http://nexus.opendaylight.org, it was green in the IDE as well.

Then I started to doing some "mvn clean" in the aclservice/impl & aclservice/api (which is where that InterfaceAcl augmentation that is not found is in....) and then I could reproduce the NPE again when running the BugReproducerTest in-IDE!

Either it's something weird to do with Xtend, but I think that's unlikely. (I could try to get Xtend out of the picture first, just to be sure.)

Most likely, I suspect that something is different / missing on the classpath between Maven (surefire) and when run inside the IDE. I actually have a suspicion that I'll investigate further now: Vaguely understand that AbstractDataBrokerTest extends AbstractSchemaAwareTest, which in BindingReflections uses ServiceLoader.load(YangModelBindingProvider.class) which is based on finding stuff via /META-INF/services/org.opendaylight.yangtools.yang.binding.YangModelBindingProvider - right? And THAT is broken, sometimes, somehow, in-IDE!

BTW: Do you agree that whatever we come up with, it should never blow up with an NPE like this, and at the very least we should make sure that we harden that code?

Right, so if I CLOSE the aclservice-api project in Eclipse, then the BugReproducerTest is GREEN. The api JAR on the CP of course contains its META-INF/services/org.opendaylight.yangtools.yang.binding.YangModelBindingProvider.

If I now "mvn clean generate-sources" the api project and re-open it in Eclipse and Project Clean it due to I think another unrelated problem, then BugReproducerTest is STILL GREEN. And, while in api project, a find -name org.opendaylight.yangtools.yang.binding.YangModelBindingProvider yields:

./target/classes/META-INF/services/org.opendaylight.yangtools.yang.binding.YangModelBindingProvider
./target/generated-sources/spi/META-INF/services/org.opendaylight.yangtools.yang.binding.YangModelBindingProvider

so far so good. Just to simulate, if I now rm ./target/classes/META-INF/services/org.opendaylight.yangtools.yang.binding.YangModelBindingProvider, THEN this problem occurs (test is red; more easily reproduced faster with something like attached GetResourcesYangModelBindingProviderBugReproducerTest which checks how many META-INF/services/org.opendaylight.yangtools.yang.binding.YangModelBindingProvider" are on the classpath; should currently normally be 34, but is 33 when this problem occurs - because aclservice-api's is missing. And that is certainly the root of this problem.

I'm not sure yet why ./target/classes/META-INF/services/org.opendaylight.yangtools.yang.binding.YangModelBindingProvider sometimes disappears, but clearly it does.

Actually, I'm not even clear what sometimes put it into ./target/classes/META-INF/services/org.opendaylight.yangtools.yang.binding.YangModelBindingProvider in the first place. The Code Generator probably puts it into ./target/generated-sources/spi/META-INF/services/org.opendaylight.yangtools.yang.binding.YangModelBindingProvider? Exactly which one does that? It's a little curious that the effective pom.xml of e.g. aclservice-api doesn't have "generated-sources/spi" anywhere... looks like this is probably hard-coded somewhere?

Coming to think of it.. here's something: Both the target/generated-sources/config-binding and target/generated-sources/mdsal-binding are "source folders" in the IDE - something configures this (possibly yangide, or an M2E extension), and that seems... reasonable - good. However the target/generated-sources/spi currently is not a Source Folder, and that... I'm not sure is right, and may well be the root cause of this problem? IFF something somewhere copies target/generated-sources/spi into target/classes, then it works - but it seems there are scenarios where it doesn't. IFF target/generated-sources/spi also always was a source folder, then this probably would never happen?

Filip may I propose that we split working on this bug into two halves? The Eclipse classpath issue (me) and preventing the NPE and, if you like and think this is worthwhile, catching this problem earlier with a clearer message (you?).

Attachment GetResourcesYangModelBindingProviderBugReproducerTest.java has been added with description: GetResourcesYangModelBindingProviderBugReproducerTest.java

Right... OK seem to be a bit of a mess, probably historical, but anyway, so:

If we close the Eclipse IDE or disable Project > Build automatically, to make sure that it doesn't interfere with the command line build experiments, we see that, being in aclservice/api:

$ mvno clean generate-sources

[INFO] yang-to-sources: Sources generated by org.opendaylight.yangtools.maven.sal.api.gen.plugin.CodeGeneratorImpl: [ (...) , /home/vorburger/dev/ODL/git/netvirt/vpnservice/aclservice/api/target/generated-sources/spi/META-INF/services/org.opendaylight.yangtools.yang.binding.YangModelBindingProvider]

[INFO] — build-helper-maven-plugin:1.10:add-source (add-yang-sources) @ aclservice-api —
[INFO] Source directory: /home/vorburger/dev/ODL/git/netvirt/vpnservice/aclservice/api/src/main/yang added.
[INFO] Source directory: /home/vorburger/dev/ODL/git/netvirt/vpnservice/aclservice/api/target/generated-sources/config-binding added.
[INFO] Source directory: /home/vorburger/dev/ODL/git/netvirt/vpnservice/aclservice/api/target/generated-sources/mdsal-binding added.

$ find -name org.opendaylight.yangtools.yang.binding.YangModelBindingProvider

./target/generated-sources/spi/META-INF/services/org.opendaylight.yangtools.yang.binding.YangModelBindingProvider

This seems to come out of org.opendaylight.yangtools.maven.sal.api.gen.plugin.CodeGeneratorImpl (in mdsal's org.opendaylight.mdsal.maven-sal-api-gen-plugin project) which in writeMetaInfServices constructs outputBaseDir + META-INF/services ... I can't figure out what set outputBaseDir to be target/generated-sources/spi, because "spi" is nowhere in CodeGeneratorImpl, but be that as it may.

With a "mvn -X clean package" we can see that it is the maven-resources-plugin which is "Copying file META-INF/services/org.opendaylight.yangtools.yang.binding.YangModelBindingProvider" and then "copy /home/vorburger/dev/ODL/git/netvirt/vpnservice/aclservice/api/target/generated-sources/spi/META-INF/services/org.opendaylight.yangtools.yang.binding.YangModelBindingProvider to /home/vorburger/dev/ODL/git/netvirt/vpnservice/aclservice/api/target/classes/META-INF/services/org.opendaylight.yangtools.yang.binding.YangModelBindingProvider"

This is because earlier something in the yang-maven-plugin (that's buried inside the org.opendaylight.yangtools.yang2sources.plugin.YangToSourcesProcessor.YangProvider.setResource) has caused:

[DEBUG] yang-to-sources: Folder: /home/vorburger/dev/ODL/git/netvirt/vpnservice/aclservice/api/target/generated-sources/spi marked as resources for generator: org.opendaylight.yangtools.maven.sal.api.gen.plugin.CodeGeneratorImpl

And so in a mvn CLI the META-INF/services ends up in the JAR (the maven-bundle-plugin which I think acts very similar to the maven-jar-plugin, bundles everything found in target/classes into the JAR archive).

Now that we understand and documented exactly how this is supposed to work and does work in CLI mvn, we can debug further why in-IDE (Eclipse) this, sometimes at least, the steps above do not seem to work accordingly in-IDE!

We now note that the M2E lifescylce mapping for yang:generate-sources (config), which is where CodeGeneratorImpl is, is "configuration" from "source" extension - that's yangide!

For "resources:resources" it's "execute" from source "default". So long story short, normally the Eclipse IDE SHOULD do the same thing as the CLI mvn here... unless yangide screws this up?

Just noticed that the Problems (not Error Log) view just showed a PluginExecutionException: Execution default-resources of goal org.apache.maven.plugins:maven-resources-plugin:3.0.1:resources failed: Unable to load the mojo 'resources' (or one of its required components) from the plugin 'org.apache.maven.plugins:maven-resources-plugin:3.0.1' ... that's https://bugs.eclipse.org/bugs/show_bug.cgi?id=496944 - and could well cause the target/generated-sources/spi/META-INF/services to not be copied to target/classes/META-INF/services and thus be causing this, sometimes.

> GetResourcesYangModelBindingProviderBugReproducerTest which checks how many META-INF/services/org.opendaylight.yangtools.yang.binding.YangModelBindingProvider" are on the classpath; should currently normally be 34, but is 33 when this problem occurs

That test as-is is stupid of course, because now, when it's working, I somehow have 35, maybe some SNAPSHOT just changed, so forget that as test for this condition. Instead it would better have to actually check if is one of the URLs from getResources() contains "aclservice/api/target/classes/META-INF/services/org.opendaylight.yangtools.yang.binding.YangModelBindingProvider" ..

Hm, so two final observations here, and then I think I'll "pause" this, and see how bad this problem really is when writing more tests, and then decide if and how to get back to this:

A right-click Maven > Update Project (which includes Clean projects), usually, actually seems to "solve" this when it's stuck like this, and correctly copy the resource created by generate-sources. So... if you know that "trick", this isn't that Critical, anymore.

On at least one occasion, I saw it not working (NPE, missing from CP) but a FS find did show target/classes/META-INF/services was present. So I have a feeling that Eclipse may actually be "caching" the contents of the project's classpath constructed from the target/classes output folder, and only reliably update it with changes made by Eclipse/Maven-through-M2E plugins, but not CLI mvn runs. Just a guess and note for future memory - this would need further testing.

About the idea above to do a build-helper-maven-plugin:add-source for target/generated-sources/spi/, that's "not neccessary in an ideal world" (because that is not a "source", there is nothing to compile in it; but a "resource", which normally gets added otherwise to the classpath as analyzed above) BUT if I keep seeing this problem, may still be a viable workaround. Later.

As far as i can tell we were unable to replicate this bug so i suggest we decrease its severity and you can take it if you want to work on it further

> As far as i can tell

Sorry if above yesterday was more of a monologue.. Tired yesterday. Now slept over it.

> we were unable to replicate this bug

Here is one way to reliably reproduce it:

$ mvn clean generate-sources
$ find -name services
./target/generated-sources/spi/META-INF/services

and test in IDE will fail (even after a F5 refresh). This is "normal", based on what we learnt above, because the copy of META-INF/services from target/generated-sources/spi to target/classes would be done by the maven-resources-plugin in a later phase, which (we ask it to/) did not run. But this is not "convenient" (or "end user expected") ...

A Project > Clean... or right-click Maven > Update Project, fixes it, because that will run the maven-resources-plugin through M2E, and one would then now see the correct result which a full e.g. "mvn clean install" would have also produced:

$ find -name services
./target/classes/META-INF/services
./target/generated-sources/spi/META-INF/services

> you can take it if you want to work on it further

I've seen this behave the way I want it to / think it should by more explicitly telling Maven about target/generated-sources/spi (which as we've seen above NORMALLY we already do it in code, but...) so by adding this:

<build>
<resources>
<resource>
<directory>target/generated-sources/spi/</directory>
</resource>
</resources>

Now Eclipse (but NOT Maven, on mvn generate-sources, which is NORMAL) has target/generated-sources/spi always a source folder, which makes sense IMHO, and this will cause Eclipse to always copy of META-INF/services from target/generated-sources/spi to target/classes!

Having resolved that, there is now a similar problem re. META-INF/yang/*.yang, which manifests itself like this:

java.lang.ExceptionInInitializerError
at org.opendaylight.yang.gen.v1.urn.opendaylight.netvirt.aclservice.api.rev160608.$YangModelBindingProvider.getModuleInfo($YangModelBindingProvider.java:6)
at org.opendaylight.yangtools.yang.binding.util.BindingReflections.loadModuleInfos(BindingReflections.java:374)
at org.opendaylight.yangtools.yang.binding.util.BindingReflections.loadModuleInfos(BindingReflections.java:347)
at org.opendaylight.controller.md.sal.binding.test.AbstractSchemaAwareTest.getModuleInfos(AbstractSchemaAwareTest.java:23)
at org.opendaylight.controller.md.sal.binding.test.AbstractSchemaAwareTest.setup(AbstractSchemaAwareTest.java:29)
(...)
Caused by: java.lang.IllegalStateException: Resource '/META-INF/yang/aclservice-api.yang' is missing
at org.opendaylight.yang.gen.v1.urn.opendaylight.netvirt.aclservice.api.rev160608.$YangModuleInfoImpl.<init>($YangModuleInfoImpl.java:30)
at org.opendaylight.yang.gen.v1.urn.opendaylight.netvirt.aclservice.api.rev160608.$YangModuleInfoImpl.<clinit>($YangModuleInfoImpl.java:10)
... 29 more

As we see with e.g. find -wholename "/META-INF/yang/" :

./target/classes/META-INF/yang/aclservice.yang
./target/classes/META-INF/yang/aclservice-api.yang
./target/generated-sources/yang/META-INF/yang/aclservice.yang
./target/generated-sources/yang/META-INF/yang/aclservice-api.yang

This is the same all over - .yang sources are in src/main/yang/.yang and then must end up on the classpath under META-INF/yang. Again the CLI build does this of course, but Eclipse unfortunately sometimes needs a kick (clean) to copy them. Again simply using the same as above helps:

<build>
<resource>
<directory>target/generated-sources/yang</directory>
</resource>

It would actually perhaps be best if at source they were simply under src/main/yang/META-INF/yang/.yang? Or perhaps even just src/main/resources/META-INF/yang/.yang, really... But it's probably too late to now change this to either everywhere. The 3 copies of each YANG file we have in each project are all the same, of course:

diff src/main/yang/aclservice.yang target/classes/META-INF/yang/aclservice.yang
diff target/classes/META-INF/yang/aclservice.yang target/generated-sources/yang/META-INF/yang/aclservice.yang

With these two additions to pom.xml, as far as I can tell so far, I'm never seeing the problem that this bug was all about anymore.

I'll therefore raise a Gerrit proposing that we add (both of) this.

PS: Instead of <build><resources> the build-helper-maven-plugin comes to mind as well. It can add additional source folders, because <build> <sourceDirectory> only takes one. It also has <goal>add-resource for adding additional resource folder. But standard <build> already allows for <resources><resource> so not sure what the point of that feature in build-helper-maven-plugin is; just using <build><resources> seems more... standard.

Adding target/generated-sources/yang causes "Naming conflict for type 'org.opendaylight.yang.gen.v1.urn.opendaylight.netvirt.aclservice.rev160608.InterfaceAcl': file with same name already exists and will not be generated." warnings to be shown in the (Eclipse) IDE - probably from yangide and/or M2E calling into yang-maven-plugin etc.

Therefore I now find it's best if we NOT register src/main/yang as a source directory in binding-parent, to avoid the duplicate on classpath. The problem described on https://lists.opendaylight.org/pipermail/yangtools-dev/2016-May/001383.html which adding src/main/yang as a source by me in https://git.opendaylight.org/gerrit/#/c/39277/ solved will still be OK (not regress), because the *.yang models in dependant projects should still be found - just now from target/generated-sources/yang (under META-INF/yang), instead of from src/main/yang.

PS: The add-source of src/main/yang to config-parent in https://git.opendaylight.org/gerrit/#/c/39275/ seems unnecessary in retrospect, as config-parent inherits from binding-parent anyway, so that was a dupe. I'll remove it as part of this work as well.

> best if we NOT register src/main/yang as a source directory

The transition to this is slightly complicated by the fact that M2E is too dumb to remove a Source Folder once it has added it, so even with the changes in binding-parent & config-parent, all already existing projects in an Eclipse workspace still have src/main/yang as a source directory, even after a full right-click Maven > Update Project. You have to actually manually Remove src/main/yang as Source folder from the Java Build Path in the Project > Properties. Or just rm all .classpath files and start over.

https://git.opendaylight.org/gerrit/#/c/42585/
https://git.opendaylight.org/gerrit/#/c/42586/

https://git.opendaylight.org/gerrit/#/c/43594/