views:

229

answers:

4

I have the following code that exhibits a strange problem:

var all = new FeatureService().FindAll();
System.Diagnostics.Debug.Assert(all != null, "FindAll must not return null");
System.Diagnostics.Debug.WriteLine(all.ToString()); // throws NullReferenceException

The signature of the FindAll method is:

public List<FeatureModel> FindAll()

Stepping through the code I have confirmed that the return value from FindAll is not null, and as you can see from the Assert, the "all" variable is not null, yet in the following line it appears to be null.

The issue is not specific to failing when the ToString() method is called. I simplified it down to this reproducible example while trying to trace the root cause.

This may be a clue: in the debugger, the variable "all" appears in the Locals window with a value of "Cannot obtain value of local or argument 'all' as it is not available at this instruction pointer, possibly because it has been optimized away."

I considered trying one of the approaches documented elsewhere for disabling code optimization but this wouldn't really solve the problem since the release version of the code will still be optimized.

I am using Visual Studio 2010 with .NET 4.0.

Any thoughts?

Thanks, Gary

UPDATE: per request, here is the entire method:

protected override List<FeatureModel> GetModels() {
    var all = new FeatureService().FindAll();
    var wr = new WeakReference(all);
    System.Diagnostics.Debug.Assert(all != null, "FindAll must not return null");
    System.Diagnostics.Debug.WriteLine(wr.IsAlive);
    System.Diagnostics.Debug.WriteLine(all.ToString()); // throws NullReferenceException
    return all;
}

As an FYI, the original implementation was simply:

protected override List<FeatureModel> GetModels() {
    return new FeatureService().FindAll();
}

I originally encountered the null exception in the calling method. The code I posted was after tracing the issue for a while.

UPDATE #2: As requested, here is the stack trace from the exception:

 at FeatureCrowd.DomainModel.FeatureSearch.GetModels() in C:\Users\Gary\Documents\Visual Studio 2010\Projects\FeatureCrowd\FeatureCrowd.DomainModel\FeatureSearch.cs:line 32
 at FeatureCrowd.DomainModel.FeatureSearch.CreateIndex() in C:\Users\Gary\Documents\Visual Studio 2010\Projects\FeatureCrowd\FeatureCrowd.DomainModel\FeatureSearch.cs:line 42
 at FeatureCrowd.DomainModel.FeatureService.CreateSearchIndex() in C:\Users\Gary\Documents\Visual Studio 2010\Projects\FeatureCrowd\FeatureCrowd.DomainModel\FeatureService.cs:line 100
 at Website.MvcApplication.BuildLuceneIndexThread(Object sender) in C:\Users\Gary\Documents\Visual Studio 2010\Projects\FeatureCrowd\FeatureCrowd.Website\Global.asax.cs:line 50
 at Website.MvcApplication.Application_Start() in C:\Users\Gary\Documents\Visual Studio 2010\Projects\FeatureCrowd\FeatureCrowd.Website\Global.asax.cs:line 61
A: 

If you suspect that the variable is somehow optimized away, you could verify this using either through the IsAlive property of a WeakReference to your all object, or via GC.KeepAlive(all). I'm not sure if that will be of any use, but it might be worth a try.

Another possiblity, though highly unlikely, is that for some reason, List<FeatureModel>.ToString throws that exception. You could possibly verify this with a tool such as .NET Reflector to see what that method does exactly.

stakx
+2  A: 

Left for posterity, this is not the problem.

See my new answer.


Here's what I believe.

Contrary to what you're saying, I believe the program is not in fact crashing in any of the lines posted, but instead crashes on one of the lines following them, which you haven't posted.

The reason I believe this is that I also believe you're doing a Release-build, in which case both Debug lines will be removed, since they're tagged with a [Conditional("DEBUG")] attribute.

The clue here is that the all variable has been optimized away, and this should only happen during a Release-build, not a Debug-build.

In other words, I believe the all variable is actuall null after all, and the Debug lines aren't executed, because they're not compiled into the assembly. The debugger is dutifully reporting that the all variable no longer exists.

Note that all of this should be easy to test. Just place a breakpoint on the first of the two Debug-lines that you've posted. If the breakpoint is hit, my hypothesis is most likely wrong. If it doesn't (and I'm going to guess that the breakpoint symbol shows up as a hollow circle at runtime), then those lines aren't compiled into the assembly.

Lasse V. Karlsen
It's a good theory, but I don't think it is the case. I have been stepping through the code while attempting to diagnose this and I see the WriteLine output being produced.I have my configuration set to a debug build. I also reset my entire IDE to default settings while diagnosing just in case I had customized any of the debug values in the past.I also verified that the pdb file is produced, and has the same time stamp as the assembly (and the time stamp matches my last build time).
Gary Clarke
Is the code proprietary? If not, would you be willing to upload the code, or a compiled version of it, somewhere?
Lasse V. Karlsen
@Gary, you can make sure by using Trace.Assert()
Henk Holterman
If not, a TeamViewer session could also be set up, so I can see your screen.
Lasse V. Karlsen
@Lasse: we can do TeamViewer (and thanks for offering to help!). Do you use google talk or another IM client, so I can give you the login info? My email address (and IM) is gxclarke at gmail dot com.
Gary Clarke
Live Messenger: [email protected] or google talk: [email protected]
Lasse V. Karlsen
Added new answer after debugging session here: http://stackoverflow.com/questions/3379894/c-code-seems-to-get-optimized-in-an-invalid-way-such-that-an-object-value-become/3380268#3380268
Lasse V. Karlsen
+16  A: 

After looking over the code over TeamViewer, and finally downloading, compiling and running the code on my own machine, I believe this is a case of compiler error in C# 4.0.


I've posted a question with request for verification, after managing to reduce the problem to a few simple projects and files. It is available here: Possible C# 4.0 compiler error, can others verify?


The likely culprit is not this method:

protected override List<FeatureModel> GetModels() {
    var fs = new FeatureService();
    var all = fs.FindAll();
    var wr = new WeakReference(all);
    System.Diagnostics.Debug.Assert(all != null, "FindAll must not return null");
    System.Diagnostics.Debug.WriteLine(wr.IsAlive);
    System.Diagnostics.Debug.WriteLine(all.ToString()); // throws NullReferenceException
    return all;
}

But the method it calls, FeatureService.FindAll:

public List<FeatureModel> FindAll() {
    string key = Cache.GetQueryKey("FindAll");
    var value = Cache.Load<List<FeatureModel>>(key);
    if (value == null) {
        var query = Context.Features;
        value = query.ToList().Select(x => Map(x)).ToList();
        var policy = Cache.GetDefaultCacheItemPolicy(value.Select(x => Cache.GetObjectKey(x.Id.ToString())), true);
        Cache.Store(key, value, policy);
    }
    value = new List<FeatureModel>();
    return value;
}

If I changed the call in GetModels from this:

var all = fs.FindAll();

to this:

var all = fs.FindAll().ToList(); // remember, it already returned a list

then the program crashes with a ExecutionEngineException.


After doing a clean, a build, and then looking at the compiled code through Reflector, here's how the output looks (scroll to the bottom of the code for the important part):

public List<FeatureModel> FindAll()
{
    List<FeatureModel> value;
    Func<FeatureModel, string> CS$<>9__CachedAnonymousMethodDelegate6 = null;
    List<FeatureModel> CS$<>9__CachedAnonymousMethodDelegate7 = null;
    string key = base.Cache.GetQueryKey("FindAll");
    if (base.Cache.Load<List<FeatureModel>>(key) == null)
    {
        if (CS$<>9__CachedAnonymousMethodDelegate6 == null)
        {
            CS$<>9__CachedAnonymousMethodDelegate6 = (Func<FeatureModel, string>) delegate (Feature x) {
                return this.Map(x);
            };
        }
        value = base.Context.Features.ToList<Feature>().Select<Feature, FeatureModel>(((Func<Feature, FeatureModel>) CS$<>9__CachedAnonymousMethodDelegate6)).ToList<FeatureModel>();
        if (CS$<>9__CachedAnonymousMethodDelegate7 == null)
        {
            CS$<>9__CachedAnonymousMethodDelegate7 = (List<FeatureModel>) delegate (FeatureModel x) {
                return base.Cache.GetObjectKey(x.Id.ToString());
            };
        }
        Func<Feature, FeatureModel> policy = (Func<Feature, FeatureModel>) base.Cache.GetDefaultCacheItemPolicy(value.Select<FeatureModel, string>((Func<FeatureModel, string>) CS$<>9__CachedAnonymousMethodDelegate7), true);
        base.Cache.Store<List<FeatureModel>>(key, value, (CacheItemPolicy) policy);
    }
    value = new List<FeatureModel>();
    bool CS$1$0000 = (bool) value;
    return (List<FeatureModel>) CS$1$0000;
}

Notice the 3 last lines of the method, here's what they look like in the code:

value = new List<FeatureModel>();
return value;

here's what Reflector says:

value = new List<FeatureModel>();
bool CS$1$0000 = (bool) value;
return (List<FeatureModel>) CS$1$0000;

It creates the list, then casts it to a boolean, then casts it back to a list and returns it. Most likely this causes a stack problem.

Here's the same method, in IL (still through Reflector), I've stripped away most of the code:

.method public hidebysig instance class [mscorlib]System.Collections.Generic.List`1<class FeatureCrowd.DomainModel.FeatureModel> FindAll() cil managed
{
    .maxstack 5
    .locals init (
        [0] string key,
        [1] class [mscorlib]System.Collections.Generic.List`1<class FeatureCrowd.DomainModel.FeatureModel> 'value',
        [2] class [System.Data.Entity]System.Data.Objects.ObjectSet`1<class FeatureCrowd.DomainModel.Feature> query,
        [3] class [mscorlib]System.Func`2<class FeatureCrowd.DomainModel.Feature, class FeatureCrowd.DomainModel.FeatureModel> policy,
        [4] class [mscorlib]System.Func`2<class FeatureCrowd.DomainModel.FeatureModel, string> CS$<>9__CachedAnonymousMethodDelegate6,
        [5] class [mscorlib]System.Collections.Generic.List`1<class FeatureCrowd.DomainModel.FeatureModel> CS$<>9__CachedAnonymousMethodDelegate7,
        [6] bool CS$1$0000,
        [7] char CS$4$0001)
    ...
    L_009f: newobj instance void [mscorlib]System.Collections.Generic.List`1<class FeatureCrowd.DomainModel.FeatureModel>::.ctor()
    L_00a4: stloc.1 
    L_00a5: ldloc.1 
    L_00a6: stloc.s CS$1$0000
    L_00a8: br.s L_00aa
    L_00aa: ldloc.s CS$1$0000
    L_00ac: ret 
}

Here's a screencast showing the debug session, if you just want the Reflector output, skip to about 2:50.

Lasse V. Karlsen
You went *far* beyond reasonable effort here - excellent job.
Marc Gravell
I've posted a question with request for verification, after managing to reduce the problem to a few simple projects and files. It is available here: http://stackoverflow.com/questions/3382231/possible-c-4-0-compiler-error-can-others-verify
Lasse V. Karlsen
+4  A: 

After Lasse discovered that the FindAll method was generating the wrong IL, I then came across another method that was also generating the wrong IL -- I also found the root cause and resolution.

The relevant line in the second method is:

var policy = Cache.GetDefaultCacheItemPolicy(dependentKeys, true);

Cache is my own object. The GetDefaultCacheItemPolicy method returns a System.Runtime.Caching.CacheItemPolicy object. The generated IL, however, looked like this:

Func<Feature, FeatureModel> policy = (Func<Feature, FeatureModel>) base.Cache.GetDefaultCacheItemPolicy(dependentKeys, true);

There are two projects in play here. The methods that are generating the wrong IL are in one project called DomainModel, and the Cache object is in a Utilities project, which is referenced by the first. The second project contains a reference to System.Runtime.Caching but the first does not.

The fix was to add a reference to System.Runtime.Caching to the first project. Now the generated IL looks correct:

CacheItemPolicy policy = base.Cache.GetDefaultCacheItemPolicy(dependentKeys, true);

The first method (that Lasse posted about in his answer) now also generates proper IL.

Hooray!

Gary Clarke