Package failed to load in devenv

[bst27]

Expected Behavior

When I run my nodejs project build from devenv the project is loaded and built.

Actual Behavior

When I run my nodejs project build from devenv the

Package 'Node.js Project Package' failed to load.

The project can be built when I use the Visual Studio GUI.

• NTVS Version: 1.2.40726.00
• Visual Studio Version: 14.0.25425.01 Update 3
• Node.js Version: v5.6.0

Steps to Reproduce

1. Create new Blank Node.js Console Application in Visual Studio
2. Build project successfully in Visual Studio GUI
3. Open cmd and change to solution dir.
4. See devenv failing with: "C:\Program Files (x86)\Microsoft Visual Studio 14.0\Common7\IDE\devenv.exe" NodejsConsoleApp1.sln /Build Debug /Out log.txt /Log activity.log
5. Inspect log.txt and created UpgradeLog.htm

[mjbvz]

Thanks for the report. I believe the error is the following:

  <entry>
    <record>93</record>
    <time>2016/08/25 16:48:05.115</time>
    <type>Error</type>
    <source>VisualStudio</source>
    <description>LegacySitePackage failed for package [Node.js Project Package]Source: &apos;mscorlib&apos; Description: The current SynchronizationContext may not be used as a TaskScheduler.&#x000D;&#x000A;System.InvalidOperationException: The current SynchronizationContext may not be used as a TaskScheduler.&#x000D;&#x000A;   at System.Threading.Tasks.SynchronizationContextTaskScheduler..ctor()&#x000D;&#x000A;   at Microsoft.VisualStudioTools.UIThread..ctor()&#x000D;&#x000A;   at Microsoft.VisualStudioTools.UIThread.EnsureService(IServiceContainer container)&#x000D;&#x000A;   at Microsoft.VisualStudioTools.Project.CommonProjectPackage.Initialize()&#x000D;&#x000A;   at Microsoft.NodejsTools.Project.NodejsProjectPackage.Initialize()&#x000D;&#x000A;   at Microsoft.VisualStudio.Shell.Package.Microsoft.VisualStudio.Shell.Interop.IVsPackage.SetSite(IServiceProvider sp)</description>
    <guid>{2C52FA27-791E-4D04-9F82-234BBB58DE78}</guid>
    <hr>80131509</hr>
  </entry>
  <entry>
    <record>94</record>
    <time>2016/08/25 16:48:05.131</time>
    <type>Error</type>
    <source>VisualStudio</source>
    <description>SetSite failed for package [Node.js Project Package](null)</description>
    <guid>{2C52FA27-791E-4D04-9F82-234BBB58DE78}</guid>
    <hr>80131509</hr>
  </entry>

Here's the line where the error occurs: https://github.com/Microsoft/nodejstools/blob/d966849ae462c543313291ad20d419a27c8e1fc7/Common/Product/SharedProject/CommonPackage.cs#L187

I assume that there is no true UI thread in this case

[bst27]

Any idea when this will be fixed or a suggestion for a workaround? It prevents me from running my build in CI environment.

[mjbvz]

I'm going to do a quick timeboxed investigation this morning to see if there is an easy fix. This is something we want to prioritize but not be able to get around to right away.

[mjbvz]

Ok, my simple fix attempt of changing UIThread like so:

 private UIThread() {
-            _scheduler = TaskScheduler.FromCurrentSynchronizationContext();
+            try {
+                _scheduler = TaskScheduler.FromCurrentSynchronizationContext();
+            } catch (InvalidOperationException) {
+                _scheduler = TaskScheduler.Current;
+            }
             _factory = new TaskFactory(_scheduler);
             _uiThread = Thread.CurrentThread;
         }

did not work, producing the even more cryptic exception: An exception was thrown while initializing part "Microsoft.VisualStudio.PlatformUI.HierarchyManager". It turns out that the VS extension code need a sync context as well.

This fix though seems to work:

         private UIThread() {
-            _scheduler = TaskScheduler.FromCurrentSynchronizationContext();
+            try {
+                _scheduler = TaskScheduler.FromCurrentSynchronizationContext();
+            } catch (InvalidOperationException) {
+                SynchronizationContext.SetSynchronizationContext(new SynchronizationContext());
+                _scheduler = TaskScheduler.FromCurrentSynchronizationContext();
+            }
             _factory = new TaskFactory(_scheduler);
             _uiThread = Thread.CurrentThread;
         }

It's ugly, since it touches global state, but it ensures that a sync context exists for all of our call paths. We also cannot update the VS code itself so this appears to be the best solution. I'll do some more testing to confirm and submit a PR.

[bst27]

Meanwhile I built the latest version of NTVS as described in your build instructions.

However, it seems that the problem has not been solved. When I build my vs solution containing several projects of different types the nodejs project is simply skipt and not mentioned at all in my build logs.

When I do the steps to reproduce mentioned above I get the following log in the created log.txt:

C:\my\path\NodejsConsoleApp1\NodejsConsoleApp1.njsproj : error : Unspecified error (Exception from HRESULT: 0x80004005 (E_FAIL))

One or more projects in the solution were not loaded correctly.
Please see the Output Window for details.========== Build: 0 succeeded or up-to-date, 0 failed, 0 skipped ==========

When I use devenv.com instead of devenv.exe and do the steps I get the following output:

C:\my\path\NodejsConsoleApp1>"C:\Program Files (x86)\Microsoft Visual Studio 14.0\Common7\IDE\devenv.com" NodejsConsoleApp1.sln /Build Debug /Out log.txt /Log activity.log

Microsoft Visual Studio 2015 Version 14.0.25420.1.
Copyright (C) Microsoft Corp. All rights reserved.
C:\my\path\NodejsConsoleApp1\NodejsConsoleApp1.njsproj : error : Error HRESULT E_FAIL has been returned from a call to a COM component.

One or more projects in the solution were not loaded correctly.
Please see the Output Window for details.========== Build: 0 succeeded or up-to-date, 0 failed, 0 skipped ==========

Maybe I did something wrong with my custom build? I got no errors during build and also disabled verification using the .reg files. Or can you confirm the mentioned behaviour?

[mjbvz]

@bst27 Are you building and running NTVS inside of VS in the experimental instance or are you producing an msi and installing that? Could you also provide the /Log output if possible to help investigate.

I was able to repo this issue when I tried again today, but then it went away just as mysteriously again and now things run at least:

c:\Users\matb.REDMOND\Documents\Visual Studio 2015\Projects\NodejsConsoleApp2>devenv /rootSuffix Exp NodejsConsoleApp2.sln /build debug /log buildLog /out log.txt
Project Load: 597ms elapsed
ProjectLoad: 651ms elapsed
CreateProject: 2758ms elapsed

Microsoft Visual Studio 2015 Version 14.0.25420.1.
Copyright (C) Microsoft Corp. All rights reserved.

The license for Visual Studio expires in 28 days.
Checking whether NodejsConsoleApp2 needs to be rebuilt:
  Out: Built: c:\Users\matb.REDMOND\Documents\Visual Studio 2015\Projects\NodejsConsoleApp2\NodejsConsoleApp2\app.js [2016-08-31T18:09:40]
  Out: Built: c:\Users\matb.REDMOND\Documents\Visual Studio 2015\Projects\NodejsConsoleApp2\NodejsConsoleApp2\package.json [2016-09-02T20:24:00]
  Out: Built: c:\Users\matb.REDMOND\Documents\Visual Studio 2015\Projects\NodejsConsoleApp2\NodejsConsoleApp2\README.md [2016-09-02T20:24:00]
  Out: Built: c:\Users\matb.REDMOND\Documents\Visual Studio 2015\Projects\NodejsConsoleApp2\NodejsConsoleApp2\app.js [2016-08-31T18:09:40]
  Out: Built: c:\Users\matb.REDMOND\Documents\Visual Studio 2015\Projects\NodejsConsoleApp2\NodejsConsoleApp2\NodejsConsoleApp2.njsproj [2016-09-02T20:41:38]
  Out: ContentFiles: c:\Users\matb.REDMOND\Documents\Visual Studio 2015\Projects\NodejsConsoleApp2\NodejsConsoleApp2\package.json [2016-09-02T20:24:00]
  Out: ContentFiles: c:\Users\matb.REDMOND\Documents\Visual Studio 2015\Projects\NodejsConsoleApp2\NodejsConsoleApp2\README.md [2016-09-02T20:24:00]
  Out: ContentFiles: c:\Users\matb.REDMOND\Documents\Visual Studio 2015\Projects\NodejsConsoleApp2\NodejsConsoleApp2\app.js [2016-08-31T18:09:40]
  In:  SourceFiles: c:\Users\matb.REDMOND\Documents\Visual Studio 2015\Projects\NodejsConsoleApp2\NodejsConsoleApp2\app.js [2016-08-31T18:09:40]
  In:  SourceFiles: c:\Users\matb.REDMOND\Documents\Visual Studio 2015\Projects\NodejsConsoleApp2\NodejsConsoleApp2\package.json [2016-09-02T20:24:00]
  In:  SourceFiles: c:\Users\matb.REDMOND\Documents\Visual Studio 2015\Projects\NodejsConsoleApp2\NodejsConsoleApp2\README.md [2016-09-02T20:24:00]
  In:  SourceFiles: c:\Users\matb.REDMOND\Documents\Visual Studio 2015\Projects\NodejsConsoleApp2\NodejsConsoleApp2\app.js [2016-08-31T18:09:40]
  In:  SourceFiles: c:\Users\matb.REDMOND\Documents\Visual Studio 2015\Projects\NodejsConsoleApp2\NodejsConsoleApp2\typings\globals\node\index.d.ts [2016-09-02T20:24:37]
  In:  SourceFiles: c:\Users\matb.REDMOND\Documents\Visual Studio 2015\Projects\NodejsConsoleApp2\NodejsConsoleApp2\typings\index.d.ts [2016-09-02T20:24:37]
  In:  SourceFiles: c:\Users\matb.REDMOND\Documents\Visual Studio 2015\Projects\NodejsConsoleApp2\NodejsConsoleApp2\NodejsConsoleApp2.njsproj [2016-09-02T20:41:38]
Not rebuilding NodejsConsoleApp2 because 9999-12-31T23:59:59 >= 2016-09-02T20:41:38
========== Build: 0 succeeded, 0 failed, 1 up-to-date, 0 skipped ==========


c:\Users\matb.REDMOND\Documents\Visual Studio 2015\Projects\NodejsConsoleApp2>

Note that I'm running against an experimental hive of VS by using /rootSuffix Exp.

I'm not sure how I resolved the original problem. It seems like VS is caching some value somewhere or something like that. You can try running devenv /setup (or devenv /rootSuffix Exp /setup) to rebuild things, or try deleting %localappdata%\Microsoft\VisualStudio\14.0\ComponentModelCache (%localappdata%\Microsoft\VisualStudio\14.0Exp\ComponentModelCache) to force a refresh.

But I think this needs more investigation since /Rebuild is broken in my testing. Reopening for that work at least