locked
Cannot debug inside of ClassCleanup (timeout?) RRS feed

  • Question

  • I have a set of tests that write output to text files.  I wrote code in [ClassCleanup] to open up those output text files, do some compilation and averaging of statistics, then output another text file.

    The problem is that when I try to debug into ClassCleanup, after a few second, the debug session just ends.  There is no exception thrown (I put a try catch around everything in the ClassCleanup to check). 

    I timed how long I have to try and debug, and it seems to be exactly 30 seconds each time. It doesn't matter what line I'm on, after 30 seconds, the debug session ends.

    Is there a way to disable this timeout?

    Thanks!
    Saturday, January 16, 2010 12:54 AM

Answers

  • Thanks, Patrick, I looked and unfortunately agent cleanup timeout, which triggers in this scenario, is not configurable for VS2008. We made it configurable in VS2010.
    Thanks,
    Michael
    Tuesday, February 9, 2010 11:41 PM

All replies

  • Hello Patrick,

    If you run the tests normally, do they work as you expect and the text file outputed in the ClassCleanup method is what you want? Does this issue happen to all your projects or only to this case?

    You may enable VSTS Logging to see if we can find anything useful. About how to enable VSTS Logging, you could refer to the following article:
    http://blogs.msdn.com/yutong/archive/2006/10/03/How-to-Enable-VSTS-Logging_3F00_.aspx
    Please remember to mark the replies as answers if they help and unmark them if they provide no help.
    Send us any feedback you have about the help from MSFT at fbmsdn@microsoft.com.
    Monday, January 18, 2010 8:29 AM
    Moderator
  • To answer your first questions:

    "If you run the tests normally, do they work as you expect and the text file outputed in the ClassCleanup method is what you want?"
        --> The simple version that I am debugging takes less than 30 seconds to complete when run without stepping into it.

    "Does this issue happen to all your projects or only to this case?"
        --> I have avoided using ClassCleanup in all of my other projects, because it runs at the end of the entire test run, instead of once the class is out of tests.  This is the first project I've used ClassCleanup on.  Would this work better if I used AssemblyCleanup? 


    As for the logging, I turned on logging, and below are all of the lines starting from when the test I used (called OD_LocalCases_Europe_SDC) completes.  However, one glaring line I saw was this one:

         [V, 2788, 21, 2010/01/19 08:52:23.521] vstesthost.exe: AgentObject: Cleanup called with timeout of 30000

    Aha!  The timeout is explicitely set from somewhere.  How can I remove/drastically adjust the 30000 mS value?   Thanks for any help you can give.



    And here is the complete log output from the end of the test to the end of the run:

    [I, 2788, 16, 2010/01/19 08:52:23.489] vstesthost.exe: AgentObject: Test 'OD_LocalCases_Europe_SDC' is complete.
    [V, 2788, 14, 2010/01/19 08:52:23.474] vstesthost.exe: ControllerExecution: Enqueuing listener message: Run {87bdacf4-78ad-4112-a1f8-85ff97b08137}, Test {9e1561ee-b247-4923-a8fa-33406dbdd137}: Completed
    [V, 2788, 7, 2010/01/19 08:52:23.489] vstesthost.exe: StateMachine(AgentState): calling state handler for Completing
    [V, 2788, 16, 2010/01/19 08:52:23.489] vstesthost.exe: AgentObject: TestQueueThread exit
    [V, 2788, 10, 2010/01/19 08:52:23.489] vstesthost.exe: ControllerExecution: Dequeued listener message: Run {87bdacf4-78ad-4112-a1f8-85ff97b08137}, Test {9e1561ee-b247-4923-a8fa-33406dbdd137}: Completed
    [V, 2788, 7, 2010/01/19 08:52:23.489] vstesthost.exe: StateMachine(AgentState): SetNextState Waiting called
    [V, 2788, 7, 2010/01/19 08:52:23.489] vstesthost.exe: StateMachine(AgentState): calling state handler for Waiting
    [I, 2788, 7, 2010/01/19 08:52:23.489] vstesthost.exe: AgentObject: Waiting for 0 message(s) in the queue.
    [I, 2788, 7, 2010/01/19 08:52:23.489] vstesthost.exe: AgentObject: Calling AgentRunFinished for run 87bdacf4-78ad-4112-a1f8-85ff97b08137 on agent PSTEVENS
    [I, 2788, 7, 2010/01/19 08:52:23.489] vstesthost.exe: ControllerExecution: AgentRunFinished called for PSTEVENS for run 87bdacf4-78ad-4112-a1f8-85ff97b08137
    [V, 2788, 13, 2010/01/19 08:52:23.505] vstesthost.exe: AgentRunFinishedWorker: waiting for m_executeRun event...
    [V, 2788, 13, 2010/01/19 08:52:23.505] vstesthost.exe: AgentRunFinishedWorker: got the m_executeRun event!
    [V, 2788, 11, 2010/01/19 08:52:23.505] vstesthost.exe: StateMachine(RunState): calling state handler for Completing
    [V, 2788, 11, 2010/01/19 08:52:23.505] vstesthost.exe: ControllerExecution: Enqueuing listener message: PSTEVENS: Run {87bdacf4-78ad-4112-a1f8-85ff97b08137}: Completing
    [V, 2788, 10, 2010/01/19 08:52:23.505] vstesthost.exe: ControllerExecution: Dequeued listener message: PSTEVENS: Run {87bdacf4-78ad-4112-a1f8-85ff97b08137}: Completing
    [V, 2788, 11, 2010/01/19 08:52:23.505] vstesthost.exe: ControllerExecution: Releasing 1 agents
    [V, 2788, 21, 2010/01/19 08:52:23.521] vstesthost.exe: ControllerExecution.ReleaseAgentWorker: Calling AgentObject.Cleanup for PSTEVENS
    [V, 2788, 21, 2010/01/19 08:52:23.521] vstesthost.exe: AgentObject: Cleanup called with timeout of 30000
    [V, 2788, 7, 2010/01/19 08:52:23.521] vstesthost.exe: StateMachine(AgentState): calling state handler for RunCleanupScript
    [V, 2788, 7, 2010/01/19 08:52:23.521] vstesthost.exe: StateMachine(AgentState): SetNextState Cleanup called
    [V, 2788, 7, 2010/01/19 08:52:23.521] vstesthost.exe: StateMachine(AgentState): calling state handler for Cleanup
    [V, 2788, 7, 2010/01/19 08:52:23.521] vstesthost.exe: AgentObject: Calling ForceStop for 0 tests
    [I, 2788, 7, 2010/01/19 08:52:23.521] vstesthost.exe: ExecutionPluginManager: CleanupPlugins called
    [V, 2788, 7, 2010/01/19 08:52:23.521] vstesthost.exe: ExecutionPluginManager: Cleaning up 0 plugins
    [I, 2788, 7, 2010/01/19 08:52:23.521] vstesthost.exe: ExecutionPluginManager: CleanupPlugins finished
    [I, 2788, 7, 2010/01/19 08:52:23.521] vstesthost.exe: TestAdapterManager: Cleanup
    [V, 2788, 15, 2010/01/19 08:52:33.177] vstesthost.exe: AgentObject: Sending heartbeat to listeners
    [V, 2788, 15, 2010/01/19 08:52:34.286] vstesthost.exe: AgentObject: Returned from sending heartbeat
    [V, 2788, 12, 2010/01/19 08:52:45.255] vstesthost.exe: ControllerExecution: Enqueuing listener message: Microsoft.VisualStudio.TestTools.Common.HeartbeatMessage
    [V, 2788, 10, 2010/01/19 08:52:46.786] vstesthost.exe: ControllerExecution: Dequeued listener message: Microsoft.VisualStudio.TestTools.Common.HeartbeatMessage
    [V, 2788, 12, 2010/01/19 08:52:46.786] vstesthost.exe: ControllerExecution: Sent heartbeat to listeners
    [V, 2788, 15, 2010/01/19 08:52:46.786] vstesthost.exe: AgentObject: Sending heartbeat to listeners
    [V, 2788, 15, 2010/01/19 08:52:50.177] vstesthost.exe: AgentObject: Returned from sending heartbeat
    [E, 2788, 21, 2010/01/19 08:52:53.989] vstesthost.exe: AgentObject: Cleanup: Timeout reached in cleaning up the agent.
    [V, 2788, 21, 2010/01/19 08:52:54.927] vstesthost.exe: ControllerExecution: Sending AgentReleased event for PSTEVENS
    [I, 2788, 21, 2010/01/19 08:52:55.739] vstesthost.exe: ControllerObject: AgentReleasedHandler called for run 87bdacf4-78ad-4112-a1f8-85ff97b08137
    [V, 2788, 21, 2010/01/19 08:52:57.661] vstesthost.exe: AgentManager: released offline agent: PSTEVENS
    [V, 2788, 21, 2010/01/19 08:52:58.333] vstesthost.exe: ControllerExecution.ReleaseAgentWorker: the # of agent machines = 0. When the number reaches 0 we call m_agentsReleased.Set.
    [V, 2788, 21, 2010/01/19 08:52:59.239] vstesthost.exe: ControllerExecution.ReleaseAgentWorker done for agent: PSTEVENS
    [V, 2788, 11, 2010/01/19 08:52:59.239] vstesthost.exe: ControllerExecution.ReleaseAllAgents: all agents are released.
    [V, 2788, 11, 2010/01/19 08:53:01.177] vstesthost.exe: StateMachine(RunState): SetNextState CompletingCleanup called
    [V, 2788, 11, 2010/01/19 08:53:01.864] vstesthost.exe: StateMachine(RunState): calling state handler for CompletingCleanup
    [V, 2788, 11, 2010/01/19 08:53:02.489] vstesthost.exe: ControllerExecution: Enqueuing listener message: PSTEVENS: Run {87bdacf4-78ad-4112-a1f8-85ff97b08137}: CompletingCleanup
    [V, 2788, 10, 2010/01/19 08:53:02.489] vstesthost.exe: ControllerExecution: Dequeued listener message: PSTEVENS: Run {87bdacf4-78ad-4112-a1f8-85ff97b08137}: CompletingCleanup
    [V, 2788, 15, 2010/01/19 08:53:05.755] vstesthost.exe: AgentObject: Sending heartbeat to listeners
    [I, 2788, 11, 2010/01/19 08:53:02.489] vstesthost.exe: ControllerExecution: Calling CleanupPlugins
    [I, 2788, 7, 2010/01/19 08:53:05.755] vstesthost.exe: UnitTestAdapter.Cleanup called
    [I, 2788, 11, 2010/01/19 08:53:05.770] vstesthost.exe: ControllerPluginManager: CleanupPlugins called
    [V, 2788, 15, 2010/01/19 08:53:05.755] vstesthost.exe: AgentObject: Returned from sending heartbeat
    [V, 2788, 7, 2010/01/19 08:53:05.770] vstesthost.exe: UnitTestAdapter.Cleanup: unloading AppDomain...
    [I, 2788, 11, 2010/01/19 08:53:05.770] vstesthost.exe: ControllerPluginManager: CleanupPlugins finished
    [V, 2788, 12, 2010/01/19 08:53:05.770] vstesthost.exe: ControllerExecution: Heartbeat thread Controller: heartbeat thread is done
    [V, 2788, 11, 2010/01/19 08:53:05.801] vstesthost.exe: StateMachine(RunState): SetNextState Completed called
    [V, 2788, 11, 2010/01/19 08:53:05.801] vstesthost.exe: StateMachine(RunState): calling state handler for Completed
    [V, 2788, 11, 2010/01/19 08:53:05.817] vstesthost.exe: ControllerExecution: Enqueuing listener message: PSTEVENS: Run {87bdacf4-78ad-4112-a1f8-85ff97b08137}: Completed
    [V, 2788, 10, 2010/01/19 08:53:05.817] vstesthost.exe: ControllerExecution: Dequeued listener message: PSTEVENS: Run {87bdacf4-78ad-4112-a1f8-85ff97b08137}: Completed
    [V, 2788, 11, 2010/01/19 08:53:05.817] vstesthost.exe: ControllerExecution: Draining 0 message(s) from the listener queue.
    [I, 2788, 10, 2010/01/19 08:53:05.817] vstesthost.exe: ControllerExecution: RunMessagePump exit
    [V, 2788, 1, 2010/01/19 08:53:05.833] vstesthost.exe: Host process: Got 'go ahead and exit' signal.
    [I, 2788, 11, 2010/01/19 08:53:05.833] vstesthost.exe: ControllerExecution: Sending RunComplete event for run 87bdacf4-78ad-4112-a1f8-85ff97b08137
    [V, 2788, 1, 2010/01/19 08:53:05.864] vstesthost.exe: Test host: Successfully disconnected Controller Access Manager.
    [I, 2788, 11, 2010/01/19 08:53:05.864] vstesthost.exe: ControllerObject: RunCompleteHandler called for run 87bdacf4-78ad-4112-a1f8-85ff97b08137
    [V, 2788, 1, 2010/01/19 08:53:05.895] vstesthost.exe: Host process: Exiting with exit code: 0.
    Tuesday, January 19, 2010 5:06 PM
  • Hello,

    Sorry for the late reply, I did not get the alert in time.

    You could first installing VSTS SP1 from here, then edit the file '.....\Microsoft Visual Studio 9.0\Xml\Schemas\vstst.xsd', look for the run config
    schema. Then search for “timeout”:

    <xs:element name="Timeouts" minOccurs="0">
    <xs:complexType>
    <xs:attribute name="runTimeout" type="xs:int" use="optional"
    default="0"/>
    <xs:attribute name="testTimeout" type="xs:int"
    use="optional" default="1800000"/>
    <xs:attribute name="agentNotRespondingTimeout" type="xs:int"
    use="optional" default="300000"/>
    <xs:attribute name="deploymentTimeout" type="xs:int"
    use="optional" default="300000"/>
    <xs:attribute name="scriptTimeout" type="xs:int"
    use="optional" default="300000"/>
    </xs:complexType>
    </xs:element>

    Change the values as needed and note that the time is in milliseconds.
    Please remember to mark the replies as answers if they help and unmark them if they provide no help.
    Send us any feedback you have about the help from MSFT at fbmsdn@microsoft.com.
    Friday, January 22, 2010 3:29 AM
    Moderator
  • Thanks for looking into this, Edwer.

    I altered the vstst.xsd file, closed and reopened VS2008, and reran the test.  Unfortunately, the cleanup timeout is still at 30000.

         [V, 7348, 20, 2010/01/22 08:21:32.837] vstesthost.exe: AgentObject: Cleanup called with timeout of 30000

    Here is what I altered vstst.xsd to:

          <xs:element name="Timeouts" minOccurs="0">
            <xs:complexType>
              <xs:attribute name="runTimeout" type="xs:int" use="optional" default="0"/>
              <xs:attribute name="testTimeout" type="xs:int" use="optional" default="1800000"/>
              <xs:attribute name="agentNotRespondingTimeout" type="xs:int" use="optional" default="400000"/>
              <xs:attribute name="deploymentTimeout" type="xs:int" use="optional" default="500000"/>
              <xs:attribute name="scriptTimeout" type="xs:int" use="optional" default="600000"/>
            </xs:complexType>

    Previously, agentNotResponding was 30000, deployment was 30000 and script was 30000.  I changed all three of them to different values to verify exactly which timeout would make the change.  Unfortunately, the cleanup timeout remained at 30000, even after changing all 3 of the timeout values in vstst.xsd.

    Is there another place where the cleanup timeout is set?
    Friday, January 22, 2010 4:29 PM
  • Patrick, how do you debug the test? Do you attach debugger after test run was started?

    If you run the test under debugger (e.g. from Test View click on the Debug Selection button in the toolbar -- if you see just Run Selection, expand the button; or make test project an active project in VS and hit F5) all timeouts should be disabled and you should have as much time as you want for your debugging.

    Are you using RTM or SP1 VS2008?

    Thanks,
    Michael Koltachev
    Visual Studio Team Test
    Friday, February 5, 2010 7:18 PM
  • Thanks for replying, Michael.

    This problem has been occuring while running the tests under debug.  I find the test in the test view window, right click on it, and choose Debug Selection.  The timeouts are not disabled in this case.  This is exactly where I first found the timeouts.  While stepping through the code, the test run just dies after 30 seconds, no matter where I am in the code and without any exceptions thrown.  The log line that occurs at this time is:


    [V, 2788, 21, 2010/01/19 08:52:23.521] vstesthost.exe: AgentObject: Cleanup called with timeout of 30000


    The problem also exists with Run Selection, in that the cleanup is not given enough time to do the processing that I am requesting. 

    Friday, February 5, 2010 7:29 PM
  • Thanks, Patrick, I looked and unfortunately agent cleanup timeout, which triggers in this scenario, is not configurable for VS2008. We made it configurable in VS2010.
    Thanks,
    Michael
    Tuesday, February 9, 2010 11:41 PM
  • Hello Patrick,

    If you run the tests normally, do they wor as you expect and the text file outputed in the ClassCleanup method is what you want? Does this issue happen to all your projects or only to this case?

    You may enable VSTS Logging to see if we can find anything useful. About how to enable VSTS Logging, you could refer to the following article:
    http://blogs.msdn.com/yutong/archive/2006/10/03/How-to-Enable-VSTS-Logging_3F00_.aspx
    Please remember to mark the replies as answers if they help and unmark them if they provide no help.
    Send us any feedback you have about the help from MSFT at fbmsdn@microsoft.com.

    I'm still studying it, Now I understand more about it.
    Friday, August 20, 2010 1:13 AM
  • Hi Michael, I can still get this issue on VS2010 Professional edtion. I have some codes to wirte 2 text file for summary test results. But the second file could not be created. When I debug codes in Classcleanup method, the debugger exit without any error or exception information in a few seconds (not sure, but in 30 seconds). My machine was installed VS2008 before, and then I uninstall it and install VS2010. My test solution is also upgraded from VS2008 to VS2010. Where could I found the settings? Or is there any way to solve this issue?

    Thanks,

    Zhou Lingming

    Sunday, April 1, 2012 9:17 AM