0
votes

My build agent isn't working correctly.

The build agent is running on the same machine as the TFS. It does appear to connect successfully to the TFS server (it shows as ready on the server), but, when I start the build queue, it fails after 11 seconds with no log (on the TFS). Here's what is written on the log file:

16:40:29.150122 Sending trace output to log files: C:\TFSAgent\_diag
16:40:29.181325 VsoAgent.exe was run with the following command line:
"C:\TFSAgent\agent\vsoagent.exe"  /runningAsService 
16:40:29.259322 SettingsFileHelper.Load - settings[AutoUpdate]=True
16:40:29.259322 SettingsFileHelper.Load - settings[RootFolder]=C:\TFSAgent
16:40:29.259322 SettingsFileHelper.Load - settings[WorkFolder]=C:\TFSAgent\_work
16:40:29.259322 SettingsFileHelper.Load - settings[ServerUrl]=http://dm1sw801:8080/tfs
16:40:29.259322 SettingsFileHelper.Load - settings[AgentName]=Agent-DM1SW801
16:40:29.259322 SettingsFileHelper.Load - settings[PoolId]=1
16:40:29.259322 SettingsFileHelper.Load - settings[PoolName]=default
16:40:29.259322 SettingsFileHelper.Load - settings[AgentId]=1
16:40:29.259322 SettingsFileHelper.Load - settings[RunAsWindowsService]=True
16:40:29.259322 SettingsFileHelper.Load - settings[WindowsServiceName]=vsoagent.dm1sw801.Agent-DM1SW801
16:40:29.259322 SettingsFileHelper.Load - settings[WindowsServiceDisplayName]=VSO Agent (dm1sw801.Agent-DM1SW801)
16:40:29.274921 BaseLogger.LogStatus(scope.JobId = 00000000-0000-0000-0000-000000000000, scope.TimelineRecordId = 00000000-0000-0000-0000-000000000000, record.Name = Agent)
16:40:29.306124 BaseLogger.LogConsoleMessage(scope.JobId = 00000000-0000-0000-0000-000000000000, message = Authenticating to the server http://dm1sw801:8080/tfs)
16:40:29.321723 Exe location hash = f804b79c89d4fd65abb6b5eb6a57ddd4
16:40:29.337265 Exe location hash = a0c37a6eb8e5c56516f0b3c48535f7ff
16:40:29.337265 Exe location hash = fb4c752b6401b13553aad779c01952c8
16:40:30.195342 SelfUpdater_Update(sharePath=, connection=True, runningAsService=True, workingFolder=C:\TFSAgent\_work)
16:40:30.195342 Using ServerDownloader(http://dm1sw801:8080/tfs)
16:40:30.195342 SelfUpdater.Update()
16:40:30.195342 ServerDownloader.UpdateNeeded()
16:40:30.195342 ServerDownloader.UpdateNeeded() - Getting agent version
16:40:30.304549 ServerDownloader.UpdateNeeded() - server agent version = 1.95.4
16:40:30.304549 ServerDownloader.UpdateNeeded() - agent version = 1.95.4
16:40:30.304549 Leaving ServerDownloader.UpdateNeeded - result = False
16:40:30.304549 Leaving SelfUpdater.Update()
16:40:30.304549 Leaving SelfUpdater_Update
16:40:30.320145 BaseLogger.LogConsoleMessage(scope.JobId = 00000000-0000-0000-0000-000000000000, message = Registering the agent 'Agent-DM1SW801 (default)' with the server http://dm1sw801:8080/tfs)
16:40:30.335746 Getting capabilities on this agent
16:40:30.335746 BaseLogger.LogConsoleMessage(scope.JobId = 00000000-0000-0000-0000-000000000000, message = Using SessionOwnerName 'DM1SW801')
16:40:30.335746 Exe location hash = f804b79c89d4fd65abb6b5eb6a57ddd4
16:40:30.335746 CentralLogger(name = Agent1-f804b79c89d4fd65abb6b5eb6a57ddd4)
16:40:30.335746 CentralLogger() - pipename = net.pipe://localhost/Agent1-f804b79c89d4fd65abb6b5eb6a57ddd4
16:40:30.351343 Unable to find the SCVMM admin console install path from registry
16:40:30.366940 CentralLogger.Listen() - opening host
16:40:30.382542 java_8=reg(HKEY_LOCAL_MACHINE\Software\JavaSoft\Java Runtime Environment\1.8\JavaHome) (C:\Program Files (x86)\Java\jre1.8.0_121)
16:40:30.382542 java=latestJre() (C:\Program Files (x86)\Java\jre1.8.0_121)
16:40:30.398141 CentralLogger.Listen() - waiting for shutdown
16:40:30.413740 Unable to find SQLPackage.exe from SQL Server path for version : 110.
16:40:30.413740 Unable to find SQLPackage.exe from SQL Server path for version : 110.
16:40:30.413740 Unable to find SQLPackage.exe from SQL Server path for version : 100.
16:40:30.413740 Unable to find SQL Install Root Path for version : 100.
16:40:30.413740 Unable to find SQLPackage.exe from SQL Server path for version : 90.
16:40:30.413740 Unable to find SQLPackage.exe from SQL Server path for version : 90.
16:40:30.413740 Unable to find the location of Dac Framework (SqlPackage.exe) from registry for SQL Server
16:40:30.429342 Visual Studio not found on machine
16:40:30.429342 Unable to find the location of Dac Framework (SqlPackage.exe) from registry
16:40:30.429342 DotNetFramework_2.0=reg(HKEY_LOCAL_MACHINE\Software\Microsoft\NET Framework Setup\NDP\v2.0.50727\Version) (C:\Windows\Microsoft.NET\Framework\v2.0.50727)
16:40:30.429342 DotNetFramework_3.0=reg(HKEY_LOCAL_MACHINE\Software\Microsoft\NET Framework Setup\NDP\v3.0\Version) (C:\Windows\Microsoft.NET\Framework\v3.0)
16:40:30.429342 DotNetFramework_3.5=reg(HKEY_LOCAL_MACHINE\Software\Microsoft\NET Framework Setup\NDP\v3.5\Version) (C:\Windows\Microsoft.NET\Framework\v3.5)
16:40:30.429342 DotNetFramework_4.5.3=reg(HKEY_LOCAL_MACHINE\Software\Microsoft\NET Framework Setup\NDP\v4\Client\Release) (C:\Windows\Microsoft.NET\Framework\v4.0.30319\)
16:40:30.429342 DotNetFramework_2.0_x64=reg(HKEY_LOCAL_MACHINE\Software\Microsoft\NET Framework Setup\NDP\v2.0.50727\Version) (C:\Windows\Microsoft.NET\Framework64\v2.0.50727)
16:40:30.429342 DotNetFramework_3.0_x64=reg(HKEY_LOCAL_MACHINE\Software\Microsoft\NET Framework Setup\NDP\v3.0\Version) (C:\Windows\Microsoft.NET\Framework64\v3.0)
16:40:30.429342 DotNetFramework_3.5_x64=reg(HKEY_LOCAL_MACHINE\Software\Microsoft\NET Framework Setup\NDP\v3.5\Version) (C:\Windows\Microsoft.NET\Framework64\v3.5)
16:40:30.429342 DotNetFramework_4.5.3_x64=reg(HKEY_LOCAL_MACHINE\Software\Microsoft\NET Framework Setup\NDP\v4\Client\Release) (C:\Windows\Microsoft.NET\Framework64\v4.0.30319\)
16:40:30.429342 DotNetFramework=latestdotnet() (C:\Windows\Microsoft.NET\Framework64\v4.0.30319)
16:40:30.444948 PROCESSOR_LEVEL=$env:PROCESSOR_LEVEL (6)
16:40:30.444948 PSModulePath=$env:PSModulePath (C:\Windows\system32\WindowsPowerShell\v1.0\Modules\;c:\Program Files\AppFabric 1.1 for Windows Server\PowershellModules;C:\Program Files (x86)\Microsoft SQL Server\110\Tools\PowerShell\Modules\)
16:40:30.444948 PROCESSOR_ARCHITECTURE=$env:PROCESSOR_ARCHITECTURE (AMD64)
16:40:30.444948 Path=$env:Path (C:\ProgramData\Oracle\Java\javapath;C:\Windows\system32;C:\Windows;C:\Windows\System32\Wbem;C:\Windows\System32\WindowsPowerShell\v1.0\;C:\Program Files (x86)\Microsoft Team Foundation Server 2013 Power Tools\Best Practices Analyzer\;C:\Program Files (x86)\Microsoft SQL Server\110\Tools\Binn\;C:\Program Files\Microsoft SQL Server\110\Tools\Binn\;C:\Program Files\Microsoft SQL Server\110\DTS\Binn\;C:\sonarqube\bin;C:\Program Files\Microsoft\Web Platform Installer\;C:\Users\tfsservice\.dnx\bin;C:\Program Files\Microsoft DNX\Dnvm\;C:\Program Files (x86)\Windows Kits\8.1\Windows Performance Toolkit\;C:\Program Files\Microsoft SQL Server\120\Tools\Binn\;C:\Program Files\Microsoft SQL Server\130\Tools\Binn\;C:\Program Files\Git\cmd;C:\Program Files\nodejs\;C:\Users\tfsservice\AppData\Roaming\npm\)
16:40:30.444948 VS140COMNTOOLS=$env:VS140COMNTOOLS (C:\Program Files (x86)\Microsoft Visual Studio 14.0\Common7\Tools\)
16:40:30.444948 PATHEXT=$env:PATHEXT (.COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH;.MSC)
16:40:30.444948 GO_SERVER_JAVA_HOME=$env:GO_SERVER_JAVA_HOME (C:\Program Files (x86)\Go Server\jre)
16:40:30.444948 VS100COMNTOOLS=$env:VS100COMNTOOLS (c:\Program Files (x86)\Microsoft Visual Studio 10.0\Common7\Tools\)
16:40:30.444948 GO_SERVER_URL=$env:GO_SERVER_URL (https://127.0.0.1:8154/go)
16:40:30.444948 FP_NO_HOST_CHECK=$env:FP_NO_HOST_CHECK (NO)
16:40:30.444948 PROCESSOR_REVISION=$env:PROCESSOR_REVISION (1a05)
16:40:30.444948 BPADir=$env:BPADir (C:\Program Files (x86)\Microsoft Team Foundation Server 2013 Power Tools\Best Practices Analyzer\)
16:40:30.444948 VSSDK140Install=$env:VSSDK140Install (C:\Program Files (x86)\Microsoft Visual Studio 14.0\VSSDK\)
16:40:30.444948 OS=$env:OS (Windows_NT)
16:40:30.444948 PROCESSOR_IDENTIFIER=$env:PROCESSOR_IDENTIFIER (Intel64 Family 6 Model 26 Stepping 5, GenuineIntel)
16:40:30.444948 ComSpec=$env:ComSpec (C:\Windows\system32\cmd.exe)
16:40:30.444948 GO_AGENT_JAVA_HOME=$env:GO_AGENT_JAVA_HOME (C:\Program Files (x86)\Go Agent\jre)
16:40:30.444948 TEMP=$env:TEMP (C:\Windows\TEMP)
16:40:30.444948 CRUISE_SERVER_DIR=$env:CRUISE_SERVER_DIR (C:\Program Files (x86)\Go Server)
16:40:30.444948 NUMBER_OF_PROCESSORS=$env:NUMBER_OF_PROCESSORS (16)
16:40:30.444948 TMP=$env:TMP (C:\Windows\TEMP)
16:40:30.444948 USERNAME=$env:USERNAME (SYSTEM)
16:40:30.444948 GO_AGENT_DIR=$env:GO_AGENT_DIR (C:\Program Files (x86)\Go Agent)
16:40:30.444948 windir=$env:windir (C:\Windows)
16:40:30.444948 TEMP=$env:TEMP (C:\Users\tfsservice\AppData\Local\Temp)
16:40:30.444948 PATH=$env:PATH (C:\Users\tfsservice\AppData\Roaming\npm)
16:40:30.444948 TMP=$env:TMP (C:\Users\tfsservice\AppData\Local\Temp)
16:40:30.444948 WindowsKit_8.1=reg(HKEY_LOCAL_MACHINE\Software\Microsoft\Windows Kits\Installed Roots\KitsRoot81) (C:\Program Files (x86)\Windows Kits\8.1)
16:40:30.444948 WindowsKit_8.0=reg(HKEY_LOCAL_MACHINE\Software\Microsoft\Windows Kits\Installed Roots\KitsRoot) (C:\Program Files (x86)\Windows Kits\8.0)
16:40:30.444948 WindowsKit=maxWindowsKit() (C:\Program Files (x86)\Windows Kits\8.1)
16:40:30.444948 WindowsSdk_7.0=reg(HKEY_LOCAL_MACHINE\Software\Microsoft\Microsoft SDKs\Windows\v7.0A\InstallationFolder) (C:\Program Files (x86)\Microsoft SDKs\Windows\v7.0A\)
16:40:30.444948 WindowsSdk_7.0_NetFx35Tools_x64=reg(HKEY_LOCAL_MACHINE\Software\Microsoft\Microsoft SDKs\Windows\v7.0A\WinSDK-NetFx35Tools-x64\InstallationFolder) (C:\Program Files (x86)\Microsoft SDKs\Windows\v7.0A\bin\x64\)
16:40:30.444948 WindowsSdk_7.0_NetFx35Tools=reg(HKEY_LOCAL_MACHINE\Software\Microsoft\Microsoft SDKs\Windows\v7.0A\WinSDK-NetFx35Tools-x86\InstallationFolder) (C:\Program Files (x86)\Microsoft SDKs\Windows\v7.0A\bin\)
16:40:30.444948 WindowsSdk_7.0_NetFx40Tools_x64=reg(HKEY_LOCAL_MACHINE\Software\Microsoft\Microsoft SDKs\Windows\v7.0A\WinSDK-NetFx40Tools-x64\InstallationFolder) (C:\Program Files (x86)\Microsoft SDKs\Windows\v7.0A\bin\NETFX 4.0 Tools\x64\)
16:40:30.444948 WindowsSdk_7.0_NetFx40Tools=reg(HKEY_LOCAL_MACHINE\Software\Microsoft\Microsoft SDKs\Windows\v7.0A\WinSDK-NetFx40Tools-x86\InstallationFolder) (C:\Program Files (x86)\Microsoft SDKs\Windows\v7.0A\bin\NETFX 4.0 Tools\)
16:40:30.444948 _NetFx35Tools_x64=reg(HKEY_LOCAL_MACHINE\Software\Microsoft\Microsoft SDKs\Windows\v8.0A\WinSDK-NetFx35Tools-x64\InstallationFolder) (C:\Program Files (x86)\Microsoft SDKs\Windows\v7.0A\bin\x64\)
16:40:30.444948 _NetFx35Tools=reg(HKEY_LOCAL_MACHINE\Software\Microsoft\Microsoft SDKs\Windows\v8.0A\WinSDK-NetFx35Tools-x86\InstallationFolder) (C:\Program Files (x86)\Microsoft SDKs\Windows\v7.0A\bin\)
16:40:30.444948 WindowsSdk_8.1=reg(HKEY_LOCAL_MACHINE\Software\Microsoft\Microsoft SDKs\Windows\v8.1A\InstallationFolder) (C:\Program Files (x86)\Microsoft SDKs\Windows\v8.1A\)
16:40:30.444948 WindowsSdk_8.1_NetFx40Tools_x64=reg(HKEY_LOCAL_MACHINE\Software\Microsoft\Microsoft SDKs\Windows\v8.1A\WinSDK-NetFx40Tools-x64\InstallationFolder) (C:\Program Files (x86)\Microsoft SDKs\Windows\v8.1A\bin\NETFX 4.5.1 Tools\x64\)
16:40:30.444948 WindowsSdk_8.1_NetFx40Tools=reg(HKEY_LOCAL_MACHINE\Software\Microsoft\Microsoft SDKs\Windows\v8.1A\WinSDK-NetFx40Tools-x86\InstallationFolder) (C:\Program Files (x86)\Microsoft SDKs\Windows\v8.1A\bin\NETFX 4.5.1 Tools\)
16:40:30.444948 MSBuild_2.0=reg(HKEY_LOCAL_MACHINE\Software\Microsoft\MSBuild\ToolsVersions\2.0\MSBuildToolsPath) (C:\Windows\Microsoft.NET\Framework\v2.0.50727)
16:40:30.444948 MSBuild_3.5=reg(HKEY_LOCAL_MACHINE\Software\Microsoft\MSBuild\ToolsVersions\3.5\MSBuildToolsPath) (C:\Windows\Microsoft.NET\Framework\v3.5)
16:40:30.444948 MSBuild_4.0=reg(HKEY_LOCAL_MACHINE\Software\Microsoft\MSBuild\ToolsVersions\4.0\MSBuildToolsPath) (C:\Windows\Microsoft.NET\Framework\v4.0.30319)
16:40:30.444948 MSBuild_12.0=reg(HKEY_LOCAL_MACHINE\Software\Microsoft\MSBuild\ToolsVersions\12.0\MSBuildToolsPath) (C:\Program Files (x86)\MSBuild\12.0\bin)
16:40:30.444948 MSBuild_14.0=reg(HKEY_LOCAL_MACHINE\Software\Microsoft\MSBuild\ToolsVersions\14.0\MSBuildToolsPath) (C:\Program Files (x86)\MSBuild\14.0\bin)
16:40:30.444948 MSBuild=latestMSBuildVersion() (C:\Program Files (x86)\MSBuild\14.0\bin)
16:40:30.444948 MSBuild_2.0_x64=reg(HKEY_LOCAL_MACHINE\Software\Microsoft\MSBuild\ToolsVersions\2.0\MSBuildToolsPath) (C:\Windows\Microsoft.NET\Framework64\v2.0.50727)
16:40:30.444948 MSBuild_3.5_x64=reg(HKEY_LOCAL_MACHINE\Software\Microsoft\MSBuild\ToolsVersions\3.5\MSBuildToolsPath) (C:\Windows\Microsoft.NET\Framework64\v3.5)
16:40:30.444948 MSBuild_4.0_x64=reg(HKEY_LOCAL_MACHINE\Software\Microsoft\MSBuild\ToolsVersions\4.0\MSBuildToolsPath) (C:\Windows\Microsoft.NET\Framework64\v4.0.30319)
16:40:30.444948 MSBuild_12.0_x64=reg(HKEY_LOCAL_MACHINE\Software\Microsoft\MSBuild\ToolsVersions\12.0\MSBuildToolsPath) (C:\Program Files (x86)\MSBuild\12.0\bin\amd64)
16:40:30.444948 MSBuild_14.0_x64=reg(HKEY_LOCAL_MACHINE\Software\Microsoft\MSBuild\ToolsVersions\14.0\MSBuildToolsPath) (C:\Program Files (x86)\MSBuild\14.0\bin\amd64)
16:40:30.444948 MSBuild_x64=latestMSBuildVersion(64) (C:\Program Files (x86)\MSBuild\14.0\bin\amd64)
16:40:30.460547 VisualStudio_10.0=reg(HKEY_LOCAL_MACHINE\Software\Microsoft\VisualStudio\10.0\ShellFolder) (c:\Program Files (x86)\Microsoft Visual Studio 10.0)
16:40:30.460547 VisualStudio_IDE_10.0=reg(HKEY_LOCAL_MACHINE\Software\Microsoft\VisualStudio\10.0\InstallDir) (c:\Program Files (x86)\Microsoft Visual Studio 10.0\Common7\IDE)
16:40:30.460547 VisualStudio_14.0=reg(HKEY_LOCAL_MACHINE\Software\Microsoft\VisualStudio\14.0\ShellFolder) (C:\Program Files (x86)\Microsoft Visual Studio 14.0)
16:40:30.460547 VisualStudio_IDE_14.0=reg(HKEY_LOCAL_MACHINE\Software\Microsoft\VisualStudio\14.0\InstallDir) (C:\Program Files (x86)\Microsoft Visual Studio 14.0\Common7\IDE)
16:40:30.460547 VSTest_14.0=C:\Program Files (x86)\Microsoft Visual Studio 14.0\Common7\IDE\CommonExtensions\Microsoft\TestWindow
16:40:30.460547 VisualStudio=latestVsVersion() (C:\Program Files (x86)\Microsoft Visual Studio 14.0)
16:40:30.460547 VisualStudio_IDE=latestVsVersionIde() (C:\Program Files (x86)\Microsoft Visual Studio 14.0\Common7\IDE)
16:40:30.460547 VSTest=latestVsTestVersion() (C:\Program Files (x86)\Microsoft Visual Studio 14.0\Common7\IDE\CommonExtensions\Microsoft\TestWindow)
16:40:30.460547 BaseLogger.RegisterWriter(name=serverWriter, writer, verbosity=Info
16:40:30.460547 BaseLogger.RegisterWriter: writer type Microsoft.TeamFoundation.DistributedTask.Agent.Logger.ServerWriter
16:40:30.460547 BaseLogger.RegisterWriter(name=consoleWriter, writer, verbosity=Status
16:40:30.460547 BaseLogger.RegisterWriter: writer type Microsoft.TeamFoundation.DistributedTask.Agent.Logger.ConsoleWriter
16:40:30.460547 BaseLogger.RegisterWriter(name=fileWriter, writer, verbosity=Diagnostic
16:40:30.460547 BaseLogger.RegisterWriter: writer type Microsoft.TeamFoundation.DistributedTask.Agent.Logger.FileWriter
16:40:30.476142 Exe location hash = bf80e00ab8fa62da0a09d71ef3c1a05f
16:40:30.491744 Exe location hash = f804b79c89d4fd65abb6b5eb6a57ddd4
16:40:30.491744 BaseLogger.LogConsoleMessage(scope.JobId = 00000000-0000-0000-0000-000000000000, message = Authenticating to the server http://dm1sw801:8080/tfs)
16:40:30.491744 JobManager.LogConsoleMessage (scope.JobId = 00000000-0000-0000-0000-000000000000, message = Authenticating to the server http://dm1sw801:8080/tfs)
16:40:30.491744 JobManager.LogConsoleMessage - job not found in dictionary (scope.JobId = 00000000-0000-0000-0000-000000000000)
16:40:30.491744 Authenticating to the server http://dm1sw801:8080/tfs
16:40:30.647746 Created Session: 854733e6-35ef-43b6-bb85-67473f86646b
16:40:30.663310 MessageQueueListener.DispatchAsync - starting loop
16:40:30.663310 MessageQueueListener.DispatchAsync - Getting message from Session: 854733e6-35ef-43b6-bb85-67473f86646b
16:40:30.678914 Waiting for Escape key on background thread: True
16:40:30.678914 Waiting for shutdown request event on background thread: True
16:41:20.693475 MessageQueueListener.DispatchAsync - message received.
16:41:20.693475 MessageQueueListener.DispatchAsync - No message retrieved from Session: 854733e6-35ef-43b6-bb85-67473f86646b
16:41:20.693475 MessageQueueListener.DispatchAsync - Getting message from Session: 854733e6-35ef-43b6-bb85-67473f86646b
16:42:10.723585 MessageQueueListener.DispatchAsync - message received.
16:42:10.723585 MessageQueueListener.DispatchAsync - No message retrieved from Session: 854733e6-35ef-43b6-bb85-67473f86646b
16:42:10.723585 MessageQueueListener.DispatchAsync - Getting message from Session: 854733e6-35ef-43b6-bb85-67473f86646b
16:43:00.722494 MessageQueueListener.DispatchAsync - message received.
16:43:00.722494 MessageQueueListener.DispatchAsync - No message retrieved from Session: 854733e6-35ef-43b6-bb85-67473f86646b
16:43:00.722494 MessageQueueListener.DispatchAsync - Getting message from Session: 854733e6-35ef-43b6-bb85-67473f86646b
16:43:50.736986 MessageQueueListener.DispatchAsync - message received.
16:43:50.736986 MessageQueueListener.DispatchAsync - No message retrieved from Session: 854733e6-35ef-43b6-bb85-67473f86646b
16:43:50.736986 MessageQueueListener.DispatchAsync - Getting message from Session: 854733e6-35ef-43b6-bb85-67473f86646b
16:44:40.751515 MessageQueueListener.DispatchAsync - message received.
16:44:40.751515 MessageQueueListener.DispatchAsync - No message retrieved from Session: 854733e6-35ef-43b6-bb85-67473f86646b
16:44:40.751515 MessageQueueListener.DispatchAsync - Getting message from Session: 854733e6-35ef-43b6-bb85-67473f86646b
16:45:30.781590 MessageQueueListener.DispatchAsync - message received.
16:45:30.781590 MessageQueueListener.DispatchAsync - No message retrieved from Session: 854733e6-35ef-43b6-bb85-67473f86646b
16:45:30.781590 MessageQueueListener.DispatchAsync - Getting message from Session: 854733e6-35ef-43b6-bb85-67473f86646b
16:46:20.796135 MessageQueueListener.DispatchAsync - message received.
16:46:20.796135 MessageQueueListener.DispatchAsync - No message retrieved from Session: 854733e6-35ef-43b6-bb85-67473f86646b
16:46:20.796135 MessageQueueListener.DispatchAsync - Getting message from Session: 854733e6-35ef-43b6-bb85-67473f86646b
16:47:06.629750 MessageQueueListener.DispatchAsync - message received.
16:47:06.629750 MessageQueueListener.DispatchAsync - Message 1 received from Session: 854733e6-35ef-43b6-bb85-67473f86646b
16:47:06.645380 WorkerRunner.RunJobOnWorker - enter
16:47:06.754556 WorkerRunner.RunJobOnWorker - starting the job
16:47:06.785753 BaseLogger.LogStatus(scope.JobId = 139e49a9-5864-41f0-8986-1829ac43fb80, scope.TimelineRecordId = fc30c29c-5e15-4bf2-b454-95a88d68dcd6, record.Name = Build)
16:47:06.785753 JobManager.LogStatus (scope.JobId = 139e49a9-5864-41f0-8986-1829ac43fb80, record.Name = Build)
16:47:06.785753 JobManager.LogStatus - job not found in dictionary (scope.JobId = 139e49a9-5864-41f0-8986-1829ac43fb80)
16:47:06.785753 [fc30c29c-5e15-4bf2-b454-95a88d68dcd6][139e49a9-5864-41f0-8986-1829ac43fb80]Record: t=Job, n=Build, s=InProgress, st=07/02/2018 16:47:06, 0%, ft=, r=: Starting
16:47:06.785753 BaseLogger.LogConsoleMessage(scope.JobId = 139e49a9-5864-41f0-8986-1829ac43fb80, message = Agent version: 1.95.4)
16:47:06.785753 JobManager.LogConsoleMessage (scope.JobId = 139e49a9-5864-41f0-8986-1829ac43fb80, message = Agent version: 1.95.4)
16:47:06.785753 JobManager.LogConsoleMessage - job not found in dictionary (scope.JobId = 139e49a9-5864-41f0-8986-1829ac43fb80)
16:47:06.785753 [fc30c29c-5e15-4bf2-b454-95a88d68dcd6][139e49a9-5864-41f0-8986-1829ac43fb80]Agent version: 1.95.4
16:47:06.785753 BaseLogger.LogConsoleMessage(scope.JobId = 139e49a9-5864-41f0-8986-1829ac43fb80, message = Starting job)
16:47:06.785753 JobManager.LogConsoleMessage (scope.JobId = 139e49a9-5864-41f0-8986-1829ac43fb80, message = Starting job)
16:47:06.785753 JobManager.LogConsoleMessage - job not found in dictionary (scope.JobId = 139e49a9-5864-41f0-8986-1829ac43fb80)
16:47:06.785753 [fc30c29c-5e15-4bf2-b454-95a88d68dcd6][139e49a9-5864-41f0-8986-1829ac43fb80]Starting job
16:47:06.785753 JobManager.StartJob(job.JobId = 139e49a9-5864-41f0-8986-1829ac43fb80)
16:47:06.785753 JobInfo.ctor
16:47:06.801359 JobInfo.ctor - leave
16:47:06.801359 JobManager.StartJob - calling JobWriter.StartJob
16:47:06.801359 JobWriter.StartJob - enter
16:47:06.801359 JobWriter.StartJob - (SKIPPING)first renew
16:47:07.004105 JobWriter.StartJob - start continual renewing
16:47:07.019704 AuthorizationType : OAuth
16:47:07.191367 ---------------------------------------------------------------------------
16:47:07.316163 ConsoleTimer_Callback - enter (30)
16:47:07.316163 ConsoleTimer_Callback - Inside Lock
16:47:07.316163 ConsoleTimer_Callback - processing job 139e49a9-5864-41f0-8986-1829ac43fb80
16:47:07.316163 ConsoleTimer_Callback - leave
16:47:07.331782 Microsoft.VisualStudio.Services.WebApi.VssServiceResponseException: Unauthorized
16:47:07.331782    at Microsoft.VisualStudio.Services.WebApi.VssHttpClientBase.HandleResponse(HttpResponseMessage response)
16:47:07.331782    at Microsoft.VisualStudio.Services.WebApi.VssHttpClientBase.<SendAsync>d__79.MoveNext()
16:47:07.331782 --- End of stack trace from previous location where exception was thrown ---
16:47:07.331782    at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
16:47:07.331782    at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
16:47:07.331782    at Microsoft.VisualStudio.Services.WebApi.VssHttpClientBase.<SendAsync>d__76`1.MoveNext()
16:47:07.331782 --- End of stack trace from previous location where exception was thrown ---
16:47:07.331782    at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
16:47:07.331782    at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
16:47:07.331782    at Microsoft.VisualStudio.Services.Location.Client.LocationHttpClient.<GetConnectionDataAsync>d__6.MoveNext()
16:47:07.331782 --- End of stack trace from previous location where exception was thrown ---
16:47:07.331782    at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
16:47:07.331782    at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
16:47:07.331782    at Microsoft.VisualStudio.Services.Client.VssServerDataProvider.<ConnectAsync>d__39.MoveNext()
16:47:07.331782 --- End of stack trace from previous location where exception was thrown ---
16:47:07.331782    at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
16:47:07.331782    at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
16:47:07.331782    at Microsoft.TeamFoundation.DistributedTask.Agent.Common.ConnectionHelper.GetConnection(Uri serverUri, VssCredentials credentials)
16:47:07.331782    at Microsoft.TeamFoundation.DistributedTask.Agent.JobWriter.StartJob()
16:47:07.331782    at Microsoft.VisualStudio.Services.WebApi.VssHttpClientBase.HandleResponse(HttpResponseMessage response)
16:47:07.331782    at Microsoft.VisualStudio.Services.WebApi.VssHttpClientBase.<SendAsync>d__79.MoveNext()
16:47:07.331782 --- End of stack trace from previous location where exception was thrown ---
16:47:07.331782    at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
16:47:07.331782    at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
16:47:07.331782    at Microsoft.VisualStudio.Services.WebApi.VssHttpClientBase.<SendAsync>d__76`1.MoveNext()
16:47:07.331782 --- End of stack trace from previous location where exception was thrown ---
16:47:07.331782    at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
16:47:07.331782    at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
16:47:07.331782    at Microsoft.VisualStudio.Services.Location.Client.LocationHttpClient.<GetConnectionDataAsync>d__6.MoveNext()
16:47:07.331782 --- End of stack trace from previous location where exception was thrown ---
16:47:07.331782    at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
16:47:07.331782    at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
16:47:07.331782    at Microsoft.VisualStudio.Services.Client.VssServerDataProvider.<ConnectAsync>d__39.MoveNext()
16:47:07.331782 --- End of stack trace from previous location where exception was thrown ---
16:47:07.331782    at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
16:47:07.331782    at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
16:47:07.331782    at Microsoft.TeamFoundation.DistributedTask.Agent.Common.ConnectionHelper.GetConnection(Uri serverUri, VssCredentials credentials)
16:47:07.331782    at Microsoft.TeamFoundation.DistributedTask.Agent.JobWriter.StartJob()
16:47:07.331782 ---------------------------------------------------------------------------
16:47:07.347366 Process logging event with context handler.
16:47:07.347366 BaseLogger.LogConsoleMessage(scope.JobId = 139e49a9-5864-41f0-8986-1829ac43fb80, message = ##[error]The Agent failed to start this job. Error: Unauthorized)
16:47:07.347366 JobManager.LogConsoleMessage (scope.JobId = 139e49a9-5864-41f0-8986-1829ac43fb80, message = ##[error]The Agent failed to start this job. Error: Unauthorized)
16:47:07.347366 JobManager.LogConsoleMessage - message enqueued
16:47:07.362986 [fc30c29c-5e15-4bf2-b454-95a88d68dcd6][139e49a9-5864-41f0-8986-1829ac43fb80]##[error]The Agent failed to start this job. Error: Unauthorized
16:47:07.362986 JobManager.FinishJob(jobId = 139e49a9-5864-41f0-8986-1829ac43fb80, result = Failed)
*16:47:07.565774 StatusTimer_Callback - enter (25)
16:47:07.565774 StatusTimer_Callback - processing job 139e49a9-5864-41f0-8986-1829ac43fb80
16:47:07.565774 StatusTimer_Callback - leave
16:47:07.815391 LogFileTimer_Callback - enter (30)
16:47:07.815391 LogFileTimer_Callback - processing job 139e49a9-5864-41f0-8986-1829ac43fb80
16:47:07.815391 LogFileTimer_Callback - found 0 records for job 139e49a9-5864-41f0-8986-1829ac43fb80
16:47:07.815391 LogFileTimer_Callback - leave*

(This messages repeat about 50times)

16:47:17.659151 JobManager.LogStatus (scope.JobId = 139e49a9-5864-41f0-8986-1829ac43fb80, record.Name = )
16:47:17.659151 JobManager.LogStatus - message enqueued
16:47:17.659151 RenewJob.RenewAgentRequest - TaskCanceledException received.
16:47:17.737153 Calling JobManager.JobFinished event handlers
16:47:17.737153 JobInfo.Dispose
16:47:17.737153 JobInfo.Dispose - draining queues for job 139e49a9-5864-41f0-8986-1829ac43fb80

We are to believe the problem is that is returning Unauthorized at some point:

16:47:07.331782 Microsoft.VisualStudio.Services.WebApi.VssServiceResponseException: Unauthorized

We are to believe there is something to do with the oAuth autorization:

16:47:07.019704 AuthorizationType : OAuth

I've been crawling the internet in search for an answer. Here are some I've tried:
https://github.com/Microsoft/vsts-agent/issues/792
TFS 2015 - On Site Build Failures
vNext build on TFS 2015 hangs on MSBuild step and produces no log files

Here's some information about the server and software running:
Agent Version: 1.95.4
TFS Version: 2015 Update 4 (14.114.26403.0)
Powershell Version: 3
Windows Server 2012 Standard 64-bit

What else can I try, to fix this?

UPDATE - 26/02/2018 Since this is urgent for the company, We've decided to switch to TFS2018. Everything is working fine now. There will be no way to validade an answer for this question after today. Thanks all.

1
Have you tried to set the normal user account as the build agent service account? (By default the account should be Network service)Andy Li-MSFT
Is there any log in build agent _diag folder?Eddie Chen - MSFT
@AndyLi-MSFT Already tried as a normal user and as Network service. Same problem.Ricardo Aquino
@EddieChen-MSFT The agent_diag log is the one on the question. The TFS interface log showed no errors. Just the failed message.Ricardo Aquino
Can you also check if the time on all the machines TFS AT, SQL Server, Build Agent and BIOS are correct and the same?Eddie Chen - MSFT

1 Answers

0
votes

Please try below things to narrow the issue: