MissingMetadataException at System.Linq.Expressions.Expression`1.Compile

[dgorbach]

Given this extended HelloWorld-Program:

    public class Person
    {
        public string Name { get; set; }
    }

    class Program
    {
        static void Main(string[] args)
        {
            Expression<Func<Person, string>> e = x => x.Name;

            var f = e.Compile();

            var p = new Person() { Name = "Joe" };

            Console.Write($"Hello, my name is '{f(p)}'.");

        }
    }

from Microsoft.DotNet.ILCompiler -v 1.0.0-alpha-26430-01 onwards this programm fails:

Unhandled Exception: System.Reflection.MissingMetadataException: This operation cannot be carried out because metadata for the following object was removed for performance reasons:\n\n  <unavailable>\n\nNo further information is available. Rebuild in debug mode for better information.\n\n
   at HelloWorld!<BaseAddress>+0xa532c
   at HelloWorld!<BaseAddress>+0x1587e0
   at HelloWorld!<BaseAddress>+0x41d28
   at HelloWorld!<BaseAddress>+0xa6753
   at HelloWorld!<BaseAddress>+0xa6066
   at HelloWorld!<BaseAddress>+0xa64d6
   at HelloWorld!<BaseAddress>+0xa54f6
   at HelloWorld!<BaseAddress>+0xc1faf
   at HelloWorld!<BaseAddress>+0xc3c2f
   at HelloWorld!<BaseAddress>+0xc3dfd
   at HelloWorld!<BaseAddress>+0xb97d1
   at System.Linq.Expressions.Expression`1.Compile(Boolean) + 0x23
   at HelloWorld.Program.Main(String[]) + 0xbc
   at HelloWorld!<BaseAddress>+0x6460fa

with-v 1.0.0-alpha-26428-01 and earlier the result is:

Hello, my name is 'Joe'.

Code and rd.xml: HelloWorld.zip, to reproduce, follow the instructions in README.md

[jkotas]

It fails for on 1.0.0-alpha-26428-01 as well.

When the following added to .csproj

  <ItemGroup>
    <IlcArg Include="--stacktracedata" />
  </ItemGroup>

to get full stacktraces, the exception is:

Unhandled Exception: System.Reflection.MissingMetadataException: 'System.Linq.Expressions.ExpressionCreator<System.Func<Person,System.String>>' is missing metadata. For more information, please visit http://go.microsoft.com/fwlink/?LinkID=392859

   at System.Reflection.Runtime.TypeInfos.RuntimeConstructedGenericTypeInfo.ConstructedGenericTypeTable.Factory(RuntimeConstructedGenericTypeInfo.UnificationKey) + 0x1d5
   at System.Collections.Concurrent.ConcurrentUnifierWKeyed`2.GetOrAdd(K) + 0xe7
   at System.Reflection.Runtime.TypeInfos.RuntimeConstructedGenericTypeInfo.GetRuntimeConstructedGenericTypeInfo(RuntimeTypeInfo, RuntimeTypeInfo[], RuntimeTypeHandle) + 0x70
   at System.Reflection.Runtime.TypeInfos.RuntimeConstructedGenericTypeInfo.GetRuntimeConstructedGenericTypeInfo(RuntimeTypeInfo, RuntimeTypeInfo[]) + 0x58
   at System.Reflection.Runtime.General.TypeUnifier.GetConstructedGenericType(RuntimeTypeInfo, RuntimeTypeInfo[]) + 0x24
   at System.Reflection.Runtime.TypeInfos.RuntimeTypeInfo.MakeGenericType(Type[]) + 0x3d4
   at System.Linq.Expressions.Expression.CreateLambda(Type, Expression, String, Boolean, ReadOnlyCollection`1) + 0x100

System.Linq.Expression does not just work with CoreRT right now. It requires additional hints in rd.xml file, like: https://github.com/dotnet/corert/blob/master/samples/WebApi/rd.xml#L61

[mattwarren]

Out of interest, why isn't --stacktracedata turned on by default, it seems like a useful thing to have available?

Is the problem that it increases the size of the metadata by too much? It exposes internal details that aren't meant to be publicly visible? Or something else?

[jkotas]

It is just that it increases the size of the metadata. It is not that much, but definitely noticeable.

We have endless discussion within the team about how defaults like these should be tuned. Should the defaults be optimized for size, to get binary sizes or compilation times that are more competitive with other AOT environments; or should the defaults should be optimized for more .NET-like developer experience at the cost of larger binary sizes? It is a mix right now.

[mattwarren]

@jkotas thanks, that's interesting to know

[dgorbach]

@jkotas thanks, i didn't knew --stacktracedata.

Unfortunatly I can not resolve this issue, even with the additional information.

I already had the ExpressionCreator in the rd.xml:

<Directives>
    <Application>
        <Assembly Name="HelloWorld" Dynamic="Required All" />

        <Assembly Name="System.Linq.Expressions">            
            <Type Name="System.Linq.Expressions.ExpressionCreator`1[[System.Func`2[[HelloWorld.Person,HelloWorld],[System.String,System.Private.CoreLib]],System.Private.CoreLib]]" Dynamic="Required All" />
        </Assembly>

    </Application>
</Directives>

The new errormesage with --stacktracedata is:

Unhandled Exception: System.Reflection.MissingMetadataException: 'System.Linq.Expressions.Interpreter.FuncCallInstruction<HelloWorld.Person,System.String>' is missing metadata.

I tried to add:

<Type Name="System.Linq.Expressions.Interpreter.FuncCallInstruction`2[[HelloWorld.Person,HelloWorld],[System.String,System.Private.CoreLib]]" Dynamic="Required All" />

but still the same errormessage.

[jkotas]

I am able to reproduce what you are seeing. I would expect that adding the missing type to rd.xml should be able to make it work, but it does not.

A very similar regression was hit in ProjectN as well: https://github.com/dotnet/corefx/issues/29652 . I suspect that there is something more fundamental broken.

cc @MichalStrehovsky

[MichalStrehovsky]

Yes, this is broken because the type to add to RD.XML (System.Linq.Expressions.Interpreter.FuncCallInstruction) is internal and therefore reflection blocked. I expect this to be broken in Project N too (no matter if the AnalysisEngine can figure the reflection out). Reflection blocking trumps everything else. There's no way to reflect on an internal implementation detail of a framework assembly.

Seems like we're not actually running any of the LINQ Expression tests on Project N in CoreFX (that's why the only test that's failing is an obscure one in dotnet/corefx#29652):

2018-05-12 04:09:53,575: INFO: proc(54): run_and_log_output: Output: C:\dotnetbuild\work\dd359253-03cf-4182-b46b-9f42ffb86a00\Work\452d9157-a38d-4c46-af03-595a812d4c0e\Unzip\native>call xunit.console.netcore.exe System.Linq.Expressions.Tests.dll  -xml testResults.xml -redirectoutput -notrait category=nonuapaottests -notrait category=nonwindowstests  -notrait category=failing 

2018-05-12 04:09:54,964: INFO: proc(54): run_and_log_output: Output: 

2018-05-12 04:09:54,964: INFO: proc(54): run_and_log_output: Output: C:\dotnetbuild\work\dd359253-03cf-4182-b46b-9f42ffb86a00\Work\452d9157-a38d-4c46-af03-595a812d4c0e\Unzip\native>type Xunit.Console.Output.txt 

2018-05-12 04:09:54,964: INFO: proc(54): run_and_log_output: Output: The system cannot find the file specified.

2018-05-12 04:09:54,964: INFO: proc(54): run_and_log_output: Output: 

@danmosemsft do you know who should be monitoring CoreFX UWP test runs and filing bugs? Is there anyone who could have a look at this? From the logs it seems like the compilation succeeded and there is some kind of infra issue preventing the tests from running and it has been like this for a while.

@VSadov did you test your change in dotnet/corefx#28792 with Project N? Since this is a perf improvement, I want to make sure this is an actual perf improvement on Project N as well. Our reflection stack has different perf characteristics than the CLR (e.g. reflection invoke is 4x faster on N, but there are things that are slower). To at least give the updated expressions a chance to work, we'll need to make FuncCallInstruction public (same way ExpressionCreator is public).

[danmoseley]

@danmosemsft do you know who should be monitoring CoreFX UWP test runs and filing bugs? Is there anyone who could have a look at this? From the logs it seems like the compilation succeeded and there is some kind of infra issue preventing the tests from running and it has been like this for a while.

@MichalStrehovsky I look at the CoreFX UWP results periodically but primarily to make sure they are not getting significantly worse, and typically the breaks are due to changes that have not been ported to ProjectN. The tests are not broken consistently, for example I do see results from 510: https://mc.dot.net/#/product/netcore/prodconmaster/source/prodcon~2Fcorefx~2Fmaster~2F/type/test~2Ffunctional~2Filc~2F/build/20180510.01/workItem/System.Linq.Expressions.Tests/wilogs It does seem like the runs are flaky though. I'll check whether there is anyone looking at that.

[MichalStrehovsky]

I have a fix in flight over at dotnet/corefx#29734. Once it's merged, we'll need to ingest the new NuGet package.

[VSadov]

In the past, changes incompatible with N would fail in CI. I definitely remember that happening, so I assumed that N is fine with this change since CI was green. Otherwise I'd exclude the optimizations when targeting AOT. -

That is why the feature flags are used. I had a feeling there might still be some reasons that AOT would not want this.

[VSadov]

The perf difference between delegate invoke and reflection invoke are enormous (in a 100x range, I believe). I doubt 4x in N would be enough to make it insignificant. Reflection invoke also allocates intermediate argument buffers on every call . I am not sure if N fixes that, but when every invocation also allocates, it could translate into lots of garbage.

Using expression tree lambdas (or C# dynamic) as a way to avoid per-call costs of reflection invoke on hot paths is a very popular "trick". When the "trick" stops working, the penalty to the app/library that relies on it could be severe. I have seen bug reports where this perf hit was mentioned as a reason to avoid UWP entirely.

It is a bit unfortunate that these optimizations could not be used in UWP.

[MichalStrehovsky]

It is a bit unfortunate that these optimizations could not be used in UWP.

They just need to be investigated. The private reflection is not a big problem (can be fixed by making things that are reflected on public, same as ExpressionCreator is - they don't have to be public in the contract, just in the implementation).

What needs to be investigated after the "make it work" step:

• Are we getting any penalty from MakeGenericType? Do we run universal shared code for this? Since AoT doesn't have a JIT, but MakeGenericType could require new code to be generated because of different layout of stack frames, calling conventions between methods, etc. for different Ts., we have a fallback "universal" code that can accept any shape of Ts, but the code generated for it is terrible (things that could be stack allocated are heap allocated, there is a big penalty for calls, etc.)
• What's the size on disk impact? In CoreRT debug configuration I've seen a "hello world"-style LINQ expression thing balloon from 9 MB to 20 MB (in debug configuration). I didn't investigate why, but I suspect an explosion in the number of generic instantiations we need to statically pregenerate.

[dgorbach]

@MichalStrehovsky and @jkotas thank you! The issue is indeed no longer occouring with the current version (Microsoft.DotNet.ILCompiler 1.0.0-alpha-26518-01).