Bug 192496

I think this fails only the first time I manually run the platform after installing a new version of jVi. I say manually, because the auto-restart finish button after new install does not fail. This is win-xp.

Unit test, sample module or instructions to reproduce are necessary.

(so I guess "Oh, of course" didn't flash through your mind ;-) )

Notes:
- fails with 7.0M2 and 7.0Beta
- after failure during startup, exit IDE, restart IDE and things are OK.
- Problem code is invoked from EventQueue.xxx(runnable) via call chain from
  Module.restored. Module.restored thread waits for runnable to complete.
  Failing code in runnable's call chain to ViManager.setViFactory
        for (ViInitialization i
             : Lookups.forPath("jVi/init").lookupAll(ViInitialization.class))
- Tried both EventQueue.invokeAndWait, and invokeLater/CountDownLatch.
- The "AssertionError" essentially means the Lookups.forPath was empty.

Seems to be a timing/threading problem. If you wish to pursue this and considering the difficulty of reproducing failure, with advice I can instrument some check and/or debug output locally.

===
=== Typical failure steps
===
Starts with jVi modules installed, jVi modules opened. Editing stuff.
1)  Build a new version of jVi modules, do not change any NB version numbers
un-install jVi
2)  "Tools > Plugins > Installed"; check jViKeyBindings;
    select Uninstall; in IDE installer dialog, select Uninstall
    click finish to restart IDE
install the just created NBMs
3)  "Tools > Plugins > Downloaded" (note that the prior modules listed)
    select Remove twice to clear list of previous
    select AddPlugins...
    navigate to .../dir-with-nbm
    select all modules, select Open,
    select Install (Plugin dialog)
    proceed through install, select Finish
    IDE restarts
4)  exit IDE, start IDE
Observe failure somtimes. Exit/start succeeds.

===
=== Other observed failure, no new module installations
===
1) exit IDE
2) build a local copy of IDE, was cleaned before hg fetch yesterday.
3) start IDE

Another failure observed
1) exit IDE
2) Let system sit overnight, do system-wide backup
3) start IDE
get the failure (note, nothing changed in IDE installation)
4) re-start IDE
and it starts up without the failure.

Unsufficient info: I don't even know where to get jVi modules. Not even I know how to compile and run them.

You can try to generate more info with:
org.openide.loaders.FolderInstance.path.to.your.folder.level=FINE

replace path.to.your.folder with dotted path to folder your are interested in.

To get logging info for: Lookups.forPath("jVi/init")
I tried
    -Dorg.openide.loaders.FolderInstance.META-INF.namedservices.jVi.init.level=FINE
    -Dorg.openide.loaders.FolderInstance.namedservices.jVi.init.level=FINE
    -Dorg.openide.loaders.FolderInstance.jVi.init.level=FINE
Never saw anything in messages.log (other than the -Dxxx lines). 

If you want to take a look, following are sibling directories. Open nbvi/nbvi-suite (backwards for historical reasons...) and create NBMs
    http://jvi.hg.sourceforge.net:8000/hgroot/jvi/jvi
    http://jvi.hg.sourceforge.net:8000/hgroot/jvi/nbvi

Install NBMs and boot IDE. The error occurs during startup intermittently as described in comments. I use "--console new".

Most recent attempt with:
    Product Version: NetBeans IDE Dev (Build 201101200001)
    Java: 1.6.0_23; Java HotSpot(TM) Client VM 19.0-b09
    System: Windows XP version 5.1 running on x86; Cp1252; en_US (nb)
    Userdir: C:\Documents and Settings\erra\.netbeans\dev

I think there's a misunderstanding about the lookup I'm doing. I put a println in
    private FolderInstance (DataObject.Container container, String logName) {
and never found a logName that looked relevant.

The stuff being looked up comes from things like:
    @ServiceProvider(service=ViInitialization.class,
                     path="jVi/init",
                     position=1)
    public static class Init implements ViInitialization

(In reply to comment #6)
> To get logging info for: Lookups.forPath("jVi/init")
> I tried
>    
> -Dorg.openide.loaders.FolderInstance.META-INF.namedservices.jVi.init.level=FINE
>     -Dorg.openide.loaders.FolderInstance.namedservices.jVi.init.level=FINE
>     -Dorg.openide.loaders.FolderInstance.jVi.init.level=FINE
> Never saw anything in messages.log (other than the -Dxxx lines). 

The above is no way logging for jVi/init. That would be
-Dorg.openide.loaders.FolderInstance.Services.jVi.init.level=FINE

Please show me typical code that does the registration.

(In reply to comment #8)

> Please show me typical code that does the registration.

Comment 7 has example of registration

> That would be
> -Dorg.openide.loaders.FolderInstance.Services.jVi.init.level=FINE
Ok, thanks.

    Input arguments:
    ...
            -Dsun.java2d.noddraw=true
            -Dcom.raelity.jvi.DEBUG=true
            -Dorg.openide.loaders.FolderInstance.Services.jVi.init.level=FINE
            -Xmx409m
            -Djdk.home=C:\a\j\Java\jdk1.6.0_23

Still no output. But as mentioned in comment 7 there is no logName in any FolderInstance that has the word jVi in it. A different class must be used for this situation (for "Services"?).

Running with
-J-Dorg.openide.loaders.FolderInstance.Services.JavaHelp.level=FINEST
generates tons of output for me. I don't know what is wrong in your case.

(In reply to comment #10)
> Running with
> -J-Dorg.openide.loaders.FolderInstance.Services.JavaHelp.level=FINEST
> generates tons of output for me. I don't know what is wrong in your case.

This bug is about an intermittent failure of Lookups.forPath(path) (after a failure simply exit and restart IDE and it works). If you'd like, I can file a separate bug about the logging failure. Could logging be failing because registered with annotations or maybe because path is two components?

About this bug; comment 4 is typical failure, looks like a timing problem; comment 7 shows the annotation used; comment 6 shows how the source for the modules can be retrieved.

Beta2 has same problems.

Some of the confusion may be that the annotation being used
    @ServiceProvider(service=ViInitialization.class,
                     path="jVi/init",
                     position=1)
puts stuff into
    META-INF/namedservices/jVi/init/
not into ".../Services/..."

In such case the proper logging would be
-Dorg.openide.util.lookup.MetaInfServicesLookup.level=FINEST

As far as I can tell, your code asks for getResources(
"META-INF/namedservices/jVi/init/com.raelity.jvi.ViInitialization"
)
and founds nothing. In what JAR you should have these resources? It is not in jvi-debug.jar (in spite it is in classes directory):

jvi/build$ unzip -v lib/jvi-debug.jar | grep ViInit
com/raelity/jvi/ViInitialization.class
jvi/build$ find classes/ | grep ViInit
classes/com/raelity/jvi/ViInitialization.class
classes/META-INF/namedservices/jVi/init/com.raelity.jvi.ViInitialization

The problem is in your build.xml:
>           includes="com/raelity/**"

(In reply to comment #13)

> As far as I can tell, your code asks for getResources(
> "META-INF/namedservices/jVi/init/com.raelity.jvi.ViInitialization"
> )
> and founds nothing. In what JAR you should have these resources? It is not in
> jvi-debug.jar (in spite it is in classes directory):
> 
(the standalone jvi-debug.jar has not been tested/used since the change to @ServiceProvider, thanks for the heads up)

The module suite is at .../nbvi/nbvi-suite (see comment 6.)

/modules/ $ pwd
/a/src/jvi-dev/nbvi/nbvi-suite/build/cluster/modules
/modules/ $ jar -tf ext/jvi-project.jar |grep ViInit
META-INF/namedservices/jVi/init/com.raelity.jvi.ViInitialization
com/raelity/jvi/ViInitialization.class
/modules/ $ jar -tf org-netbeans-modules-jvi.jar |grep ViInit
META-INF/namedservices/jVi/init/com.raelity.jvi.ViInitialization

(In reply to comment #13)
> In such case the proper logging would be
> -Dorg.openide.util.lookup.MetaInfServicesLookup.level=FINEST

Attaching a OK and FAIL messages.log. The trace shows that in the FAIL case the BootClassLoader is used to create the MetaInfServicesLookup.  I'm guessing that's the key.

OK:
    FINE [org.openide.util.lookup.MetaInfServicesLookup]:
        Created: MetaInfServicesLookup[SystemClassLoader[374 modules]]
    FINER [org.openide.util.lookup.MetaInfServicesLookup]:
        Searching for com.raelity.jvi.ViInitialization
        in ModuleCL@9e8c34 [com.raelity.jvi]
        from MetaInfServicesLookup[SystemClassLoader[374 modules]]

FAIL:
    FINE [org.openide.util.lookup.MetaInfServicesLookup]:
        Created: MetaInfServicesLookup
            [org.netbeans.MainImpl$BootClassLoader@19a0c7c]
    FINER [org.openide.util.lookup.MetaInfServicesLookup]:
        Searching for com.raelity.jvi.ViInitialization
        in ModuleCL@8de972[com.raelity.jvi]
        from MetaInfServicesLookup
            [org.netbeans.MainImpl$BootClassLoader@19a0c7c]

Created attachment 106194 [details]
FAIL log

Created attachment 106195 [details]
OK log

As soon as ergonomics#dbd35f898983 is in, use:
-J-Dorg.netbeans.modules.settings.RecognizeInstanceObjects.level=FINEST
and generate me the failure case log. Thanks.

Created attachment 106222 [details]
FAIL case with additional RecognizeInstanceObjects logging

Starting at line 178 of log:

FINEST [org.netbeans.modules.settings.RecognizeInstanceObjects]:
    allCL: [SystemClassLoader[376 modules]]
FINEST [org.netbeans.modules.settings.RecognizeInstanceObjects]:
    ccl: org.netbeans.MainImpl$BootClassLoader@c53dce
FINER [org.netbeans.modules.settings.RecognizeInstanceObjects]:
    metaInfServices for [org.netbeans.MainImpl$BootClassLoader@c53dce]
FINE [org.openide.util.lookup.MetaInfServicesLookup]:
    Created: MetaInfServicesLookup[org.netbeans.MainImpl$BootClassLoader@c53dce]
FINER [org.openide.util.lookup.MetaInfServicesLookup]:
    Searching for com.raelity.jvi.ViInitialization
    in ModuleCL@200db9[com.raelity.jvi]
    from MetaInfServicesLookup[org.netbeans.MainImpl$BootClassLoader@c53dce]
FINER [org.openide.util.lookup.MetaInfServicesLookup]:
    Found impls of com.raelity.jvi.ViInitialization: [] and removed: []
    from: MetaInfServicesLookup[org.netbeans.MainImpl$BootClassLoader@c53dce]

ergonomics#8b9365e11a76

Integrated into 'main-golden', will be available in build *201102250001* on http://bits.netbeans.org/dev/nightly/ (upload may still be in progress)
Changeset: http://hg.netbeans.org/main/rev/8b9365e11a76
User: Jaroslav Tulach <jtulach@netbeans.org>
Log: #192496: Prefer ClassLoader from Lookup over Thread.currentClassLoader