.Net service failes with FileNotFound exception on new thread starting method

Question

I have a service that I wrote that performs core business logic and functionality. The service is designed as a service wrapper in one project and all the functionality in Windows Library project. I also have console applcaton that also wraps the Windows Library project.

In our pre-production environment, this works just fine. The service starts and everything goes on its merry little way.

In our production enviroment, the service fails to start.

Application: URTWorkerService.exe
Framework Version: v4.0.30319
Description: The process was terminated due to an unhandled exception.
Exception Info: System.IO.FileNotFoundException
Stack:
   at URTWorker.Worker.Run()
   at System.Threading.ThreadHelper.ThreadStart_Context(System.Object)
   at System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)
   at System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)
   at System.Threading.ThreadHelper.ThreadStart()

I thought this was weird and added a Debug.WriteLine() call to it like so:

/// <summary>
/// Entry point method into the Worker class
/// </summary>
public void Run()
{
    Debug.WriteLine("Did we make it this far?");
    var exitEventArgs = ExitEventArgs.Clear;
    try
    {
        BroadcastEcho("Worker::Run::Enter", TraceLevel.Verbose);
        WorkerStartedOn = DateTime.Now;
        State = AsyncState.Running;

        BroadcastEcho("Worker::Run::Pre initialize", TraceLevel.Verbose);
        Initialize();
        BroadcastEcho("Worker::Run::Post initialize", TraceLevel.Verbose);

        ExecuteWorkerLoop();
    }
    catch (Exception ex)
    {
        exitEventArgs.Reason = ExitReason.Exception;
        var vars = new Dictionary<string, string>();

        StandardMessage message;

        // TODO Comment about this
        if (ex is FormatException && ex.Message.Contains("FieldNames.cs"))
        {
            BroadcastEcho("The field definition has changed. Generating new code file.", ex);
            var path = CreateConstantsCodeFile();
            BroadcastEcho("The file has been saved to " + path, TraceLevel.Error);
            vars.Add("FieldsNamesPath", path);
            message = StandardMessage.NewFieldsNameFile;
        }
        else
        {
            BroadcastEcho("An unhandled exception was thrown", ex);
            vars.Add("ExtraInfo", "<b>This is a crashing exception.</b>");
            message = StandardMessage.UnhandledError;
        }
        Notifier.SendErrorMail(message, vars, ex);

    }

    var lastCount = -1;
    while (Notifier.MailInTransit.Count > 0)
    {
        if (lastCount != Notifier.MailInTransit.Count)
        {
            var suffix = (
                lastCount != 1
                    ? "s"
                    : string.Empty);

            lastCount = Notifier.MailInTransit.Count;
            BroadcastEcho(string.Format("Waiting for {0} mail item{1} to finish sending", lastCount, suffix), TraceLevel.Info);
        }

        Thread.Sleep(0);
    }

    State = AsyncState.Stopped;
    BroadcastEcho("Worker::Run::Exit", TraceLevel.Verbose);
    Exit(exitEventArgs);
}

Here's the DbgView capture...

[11864] Program::Main 
[11864] Verbose::WorkerService::Enter  
[11864] Verbose::WorkerService::Exit  
[11864] Info::Starting Worker Service  
[11864] Verbose::OnStart::Enter  
[11864] Verbose::OnStart::Worker Service received Start command  
[11864] Verbose::OnStart::Current directory = C:\Windows\system32  
[11864] Verbose::OnStart::try::Created workerThread  
[11864] Verbose::OnStart::try::workerThread started  
[11864] Verbose::OnStart::try::Done waiting  
[11864] Verbose::OnStart::Exit  

You can see all of the BroadcastEcho() messages as noted the TraceLevel values but the Debug.WriteLine() never appears.

Then I thought that it might be an issue with assembly bindings. Here's the Fusion Log results:

*** Assembly Binder Log Entry  (1/24/2013 @ 7:47:52 AM) ***

The operation was successful.
Bind result: hr = 0x0. The operation completed successfully.

Assembly manager loaded from:  C:\Windows\Microsoft.NET\Framework\v4.0.30319\clr.dll
Running under executable  C:\RTWorker\URTWorkerService.exe
--- A detailed error log follows. 

=== Pre-bind state information ===
LOG: User = REDMOND\msrrtsa
LOG: DisplayName = URTWorker, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null
 (Fully-specified)
LOG: Appbase = file:///C:/RTWorker/
LOG: Initial PrivatePath = NULL
LOG: Dynamic Base = NULL
LOG: Cache Base = NULL
LOG: AppName = URTWorkerService.exe
Calling assembly : URTWorkerService, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null.
===
LOG: This bind starts in default load context.
LOG: Using application configuration file: C:\RTWorker\URTWorkerService.exe.Config
LOG: Using host configuration file: 
LOG: Using machine configuration file from C:\Windows\Microsoft.NET\Framework\v4.0.30319\config\machine.config.
LOG: Policy not being applied to reference at this time (private, custom, partial, or location-based assembly bind).
LOG: Attempting download of new URL file:///C:/RTWorker/URTWorker.DLL.
LOG: Assembly download was successful. Attempting setup of file: C:\RTWorker\URTWorker.dll
LOG: Entering run-from-source setup phase.
LOG: Assembly Name is: URTWorker, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null
LOG: Binding succeeds. Returns assembly from C:\RTWorker\URTWorker.dll.
LOG: Assembly is loaded in default load context.

Both machines are Windows Server 2008 R2 SP1. Preproduction is a virtual machine, production is a physical machine.

Any suggestions as to what it might be?

Answer 1

check the file path which you have given in web.config and correct in appropr

Answer 2

I found the problem.

First, I should look at all of the Fusion logs, not just the one that applies to the URTWorker.dll.

*** Assembly Binder Log Entry  (1/24/2013 @ 8:53:57 AM) ***

The operation failed.
Bind result: hr = 0x80070002. The system cannot find the file specified.

Assembly manager loaded from:  C:\Windows\Microsoft.NET\Framework\v4.0.30319\clr.dll
Running under executable  C:\RTWorker\URTWorkerService.exe
--- A detailed error log follows. 

=== Pre-bind state information ===
LOG: User = REDMOND\msrrtsa
LOG: DisplayName = Microsoft.TeamFoundation.WorkItemTracking.Client, Version=10.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a
 (Fully-specified)
LOG: Appbase = file:///C:/RTWorker/
LOG: Initial PrivatePath = NULL
LOG: Dynamic Base = NULL
LOG: Cache Base = NULL
LOG: AppName = URTWorkerService.exe
Calling assembly : URTWorker, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null.
===
LOG: This bind starts in default load context.
LOG: Using application configuration file: C:\RTWorker\URTWorkerService.exe.Config
LOG: Using host configuration file: 
LOG: Using machine configuration file from C:\Windows\Microsoft.NET\Framework\v4.0.30319\config\machine.config.
LOG: Post-policy reference: Microsoft.TeamFoundation.WorkItemTracking.Client, Version=10.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a
LOG: GAC Lookup was unsuccessful.
LOG: Attempting download of new URL file:///C:/RTWorker/Microsoft.TeamFoundation.WorkItemTracking.Client.DLL.
LOG: Attempting download of new URL file:///C:/RTWorker/Microsoft.TeamFoundation.WorkItemTracking.Client/Microsoft.TeamFoundation.WorkItemTracking.Client.DLL.
LOG: Attempting download of new URL file:///C:/RTWorker/Microsoft.TeamFoundation.WorkItemTracking.Client.EXE.
LOG: Attempting download of new URL file:///C:/RTWorker/Microsoft.TeamFoundation.WorkItemTracking.Client/Microsoft.TeamFoundation.WorkItemTracking.Client.EXE.
LOG: All probing URLs attempted and failed.

The failed binding indicates that it can't find the Team Foundation Client libraries as they're not installed and setting the references to CopyLocal = true isn't getting everything.

This gives me a better direction to go.

Now if .Net would have had a better exception method ("FileNoteFound: Cannot load assembly XXX.") that would be wonderful.

Answer 3

Shot in the dark, explicitly force a Flush() or set Debug.AutoFlush = true?