Comment 13 for bug 1095833

Revision history for this message
Charlie Poole (charlie.poole) wrote : Re: [Bug 1095833] Re: Microsoft.Hpc.Scheduler test gets an exception

Hi Oleg,

On Tue, Feb 18, 2014 at 2:14 PM, Oleg Gerovich
<email address hidden> wrote:
> I do not have .NET 2.0 or 3.5 installed, only 4.5. Could that be the
> reason for hanging?

That's very odd, because it says you are running 3.5. See notes in the log.

> >From nunit-gui_3304.log:
> InternalTrace: Initializing at level Verbose
> 17:00:00.019 Info [ 1] AppEntry: Starting NUnit GUI
> 17:00:00.019 Info [ 1] AppEntry: Adding Services
> 17:00:00.019 Debug [ 1] ServiceManager: Added SettingsService
> 17:00:00.019 Debug [ 1] ServiceManager: Added DomainManager
> 17:00:00.019 Debug [ 1] ServiceManager: Request for service ISettings satisfied by SettingsService
> 17:00:00.019 Debug [ 1] ServiceManager: Added RecentFilesService
> 17:00:00.019 Debug [ 1] ServiceManager: Added ProjectService
> 17:00:00.035 Debug [ 1] ServiceManager: Added TestLoader
> 17:00:00.035 Debug [ 1] ServiceManager: Added AddinRegistry
> 17:00:00.035 Debug [ 1] ServiceManager: Added AddinManager
> 17:00:00.035 Debug [ 1] ServiceManager: Added TestAgency
> 17:00:00.035 Info [ 1] AppEntry: Initializing Services
> 17:00:00.035 Info [ 1] ServiceManager: Initializing SettingsService
> 17:00:00.035 Info [ 1] ServiceManager: Initializing DomainManager
> 17:00:00.035 Info [ 1] ServiceManager: Initializing RecentFilesService
> 17:00:00.035 Info [ 1] ServiceManager: Initializing ProjectService
> 17:00:00.035 Info [ 1] ServiceManager: Initializing TestLoader
> 17:00:00.035 Info [ 1] ServiceManager: Initializing AddinRegistry
> 17:00:00.035 Info [ 1] ServiceManager: Initializing AddinManager
> 17:00:00.035 Debug [ 1] ServiceManager: Request for service IAddinRegistry satisfied by AddinRegistry
> 17:00:00.035 Info [ 1] ServiceManager: Initializing TestAgency
> 17:00:00.097 Info [ 1] AppEntry: Initializing AmbientProperties
> 17:00:00.097 Info [ 1] AppEntry: Constructing Form
> 17:00:00.331 Debug [ 1] ServiceManager: Request for service RecentFiles satisfied by RecentFilesService
> 17:00:00.331 Debug [ 1] ServiceManager: Request for service TestLoader satisfied by TestLoader
> 17:00:00.331 Info [ 1] AppEntry: Starting Gui Application
> 17:00:00.378 Debug [ 1] ResultTabs: Updating tab pages
> 17:00:00.472 Info [ 1] TestLoader: Loading project C:\ObfuscatedPath\TestHPC.dll, default config
> 17:00:00.472 Debug [ 1] ServiceManager: Request for service ProjectService satisfied by ProjectService
> 17:00:00.487 Info [ 1] TestLoader: Loading tests for TestHPC.dll
> 17:00:00.503 Debug [ 1] RuntimeFrameworkSelector: Current framework is net-3.5

Says you are running 3.5! You must actually have it installed somewhere.

> 17:00:00.503 Debug [ 1] RuntimeFrameworkSelector: No specific framework requested

No framework requested... you could use the gui menu to request a
specific framework.

> 17:00:00.518 Debug [ 1] RuntimeFrameworkSelector: Assembly C:\ObfuscatedPath\TestHPC.dll uses version 4.0.30319

Your assembly was analyzed and seen to be built with 4.0.30319. Note
that we can't distinguish 4.0 from 4.5 by this version number, but
NUnit takes that into account.

> 17:00:00.518 Debug [ 1] ServiceManager: Request for service TestAgency satisfied by TestAgency
> 17:00:00.518 Debug [ 1] RuntimeFrameworkSelector: Test will use net-4.0 framework
> 17:00:00.534 Info [ 1] ProcessRunner: Loading TestHPC.dll
> 17:00:00.534 Info [ 1] TestAgency: Getting agent for use under net-4.0
> 17:00:00.534 Debug [ 1] TestAgency: Using nunit-agent at C:\ObfuscatedPathToNUnit\NUnit\NUnit-2.6.2.12296\bin\nunit-agent.exe
> 17:00:00.534 Info [ 1] TestAgency: Launched Agent process 6900 - see nunit-agent_6900.log

There's a separate log file for whatever happened in the agent process.

> 17:00:00.534 Info [ 1] TestAgency: Command line: "C:\ObfuscatedPathToNUnit\NUnit\NUnit-2.6.2.12296\bin\nunit-agent.exe" 86f6d784-98e9-4744-b49b-3cdb45ed7cd2 tcp://127.0.0.1:64997/TestAgency

Command to run the agent is issued

> 17:00:00.534 Debug [ 1] TestAgency: Waiting for agent {86f6d784-98e9-4744-b49b-3cdb45ed7cd2} to register
> 17:00:00.940 Debug [ 1] TestAgency: Returning new agent {86f6d784-98e9-4744-b49b-3cdb45ed7cd2}

It gets the agent

> 17:00:01.470 Info [ 1] AssemblyWatcher: FreeResources
> 17:00:01.470 Info [ 1] AssemblyWatcher: Setting up watcher
> 17:00:01.470 Debug [ 1] AssemblyWatcher: Setting up FileSystemWatcher for C:\ObfuscatedPath\TestHPC.dll
> 17:00:01.501 Debug [ 1] TestSuiteTreeView: Added to map: [0-1003]C:\ObfuscatedPath\TestHPC.dll
> 17:00:01.501 Debug [ 1] TestSuiteTreeView: Added to map: [0-1004]TestHPC
> 17:00:01.501 Debug [ 1] TestSuiteTreeView: Added to map: [0-1000]TestHPC.TestHpc
> 17:00:01.501 Debug [ 1] TestSuiteTreeView: Added to map: [0-1001]TestHPC.TestHpc.AllCoresPresent
> 17:00:01.501 Debug [ 1] TestSuiteTreeView: Added to map: [0-1002]TestHPC.TestHpc.AllCoresPresent("HPC-HEAD-DEV",9)

Loads all your stuff

> 17:00:16.836 Info [ 1] TestLoader: Reloading tests for TestHPC.dll

Reloading - probably because you clicked run and you have reload on run set.
Everything repeats as before.

> 17:00:16.851 Info [ 1] AssemblyWatcher: FreeResources
> 17:00:16.851 Info [ 1] ProcessRunner: Unloading TestHPC.dll
> 17:00:16.867 Debug [ 1] RuntimeFrameworkSelector: Current framework is net-3.5
> 17:00:16.867 Debug [ 1] RuntimeFrameworkSelector: No specific framework requested
> 17:00:16.867 Debug [ 1] RuntimeFrameworkSelector: Assembly C:\ObfuscatedPath\TestHPC.dll uses version 4.0.30319
> 17:00:16.867 Debug [ 1] RuntimeFrameworkSelector: Test will use net-4.0 framework
> 17:00:16.867 Info [ 1] ProcessRunner: Stopping remote agent
> 17:00:16.867 Debug [ 1] RuntimeFrameworkSelector: Current framework is net-3.5
> 17:00:16.867 Debug [ 1] RuntimeFrameworkSelector: Requested framework is net-4.0
> 17:00:16.867 Debug [ 1] RuntimeFrameworkSelector: Test will use net-4.0 framework
> 17:00:16.867 Info [ 1] ProcessRunner: Loading TestHPC.dll
> 17:00:16.867 Info [ 1] TestAgency: Getting agent for use under net-4.0
> 17:00:16.867 Debug [ 1] TestAgency: Using nunit-agent at C:\ObfuscatedPathToNUnit\NUnit\NUnit-2.6.2.12296\bin\nunit-agent.exe
> 17:00:16.867 Info [ 1] TestAgency: Launched Agent process 7248 - see nunit-agent_7248.log

The first process ends and another is started for the reload.
nunit-agent_7248.log would be the one to check next.

> 17:00:16.867 Info [ 1] TestAgency: Command line: "C:\ObfuscatedPathToNUnit\NUnit\NUnit-2.6.2.12296\bin\nunit-agent.exe" 98a4cd49-4536-45b7-8833-8ad123680fe4 tcp://127.0.0.1:64997/TestAgency
> 17:00:16.867 Debug [ 1] TestAgency: Waiting for agent {98a4cd49-4536-45b7-8833-8ad123680fe4} to register
> 17:00:17.070 Debug [ 1] TestAgency: Returning new agent {98a4cd49-4536-45b7-8833-8ad123680fe4}
> 17:00:17.616 Info [ 1] AssemblyWatcher: FreeResources
> 17:00:17.616 Info [ 1] AssemblyWatcher: Setting up watcher
> 17:00:17.616 Debug [ 1] AssemblyWatcher: Setting up FileSystemWatcher for C:\ObfuscatedPath\TestHPC.dll
> 17:00:17.631 Debug [ 1] TestSuiteTreeView: Added to map: [0-1003]C:\ObfuscatedPath\TestHPC.dll
> 17:00:17.631 Debug [ 1] TestSuiteTreeView: Added to map: [0-1004]TestHPC
> 17:00:17.631 Debug [ 1] TestSuiteTreeView: Added to map: [0-1000]TestHPC.TestHpc
> 17:00:17.631 Debug [ 1] TestSuiteTreeView: Added to map: [0-1001]TestHPC.TestHpc.ObfuscatedTestName
> 17:00:17.631 Debug [ 1] TestSuiteTreeView: Added to map: [0-1002]TestHPC.TestHpc.ObfuscatedTestName("OBFUSCATED",9)
> 17:00:17.647 Info [ 1] TestLoader: Reload complete

Reload is done, run starts.

> 17:00:18.131 Debug [ 6] TestLoader: Got RunStarted Event
>
> --
> You received this bug notification because you are subscribed to NUnit
> Extended Testing Platform.
> https://bugs.launchpad.net/bugs/1095833
>
> Title:
> Microsoft.Hpc.Scheduler test gets an exception
>
> To manage notifications about this bug go to:
> https://bugs.launchpad.net/nunit-3.0/+bug/1095833/+subscriptions