search

microsoft / azure-pipelines-agent

Azure Pipelines Agent 🚀
MIT License
1.72k stars 865 forks source link

[BUG]: Updating the build number using the logging command frequently times out and does not respect retries #4762

Open outsystemsToby opened 5 months ago

outsystemsToby commented 5 months ago

What happened?

What Happened?

We run a simple task at the start of a pipeline to update the build number like so:

  - script: |
        echo "##vso[build.updatebuildnumber]${{ parameters.environment }}"
    displayName: 'Update Build Number'
    retryCountOnTaskFailure: 3

However this very frequently (multiple times a day) fails due to ##[error]The HTTP request timed out after 00:01:40. And when it does fail it does not respect the retryCountOnTaskFailure setting - no retries occur.

What I Expected to Happen?

The request to not timeout & if it does for the task to retry inline with the retryCountOnTaskFailure setting.

Versions

Current agent version: '3.236.1' Image: ubuntu-22.04 Version: 20240407.1.0

Environment type (Please select at least one enviroment where you face this issue)

Azure DevOps Server type

dev.azure.com (formerly visualstudio.com)

Azure DevOps Server Version (if applicable)

No response

Operation system

No response

Version controll system

No response

Relevant log output

Async Command Start: Update Build Number
##[debug]Agent environment resources - Disk: / Available 20935.00 MB out of 74244.00 MB, Memory: Used 648.00 MB out of 6921.00 MB, Unable to get CPU info, exception: No process is associated with this object.
##[debug]Agent environment resources - Disk: / Available 20935.00 MB out of 74244.00 MB, Memory: Used 648.00 MB out of 6921.00 MB, Unable to get CPU info, exception: No process is associated with this object.
##[debug]Agent environment resources - Disk: / Available 20935.00 MB out of 74244.00 MB, Memory: Used 648.00 MB out of 6921.00 MB, Unable to get CPU info, exception: No process is associated with this object.
##[debug]Agent environment resources - Disk: / Available 20935.00 MB out of 74244.00 MB, Memory: Used 648.00 MB out of 6921.00 MB, Unable to get CPU info, exception: No process is associated with this object.
##[debug]Agent environment resources - Disk: / Available 20935.00 MB out of 74244.00 MB, Memory: Used 648.00 MB out of 6921.00 MB, Unable to get CPU info, exception: No process is associated with this object.
##[debug]Agent environment resources - Disk: / Available 20935.00 MB out of 74244.00 MB, Memory: Used 648.00 MB out of 6921.00 MB, Unable to get CPU info, exception: No process is associated with this object.
##[debug]Agent environment resources - Disk: / Available 20935.00 MB out of 74244.00 MB, Memory: Used 655.00 MB out of 6921.00 MB, Unable to get CPU info, exception: No process is associated with this object.
##[debug]Agent environment resources - Disk: / Available 20935.00 MB out of 74244.00 MB, Memory: Used 655.00 MB out of 6921.00 MB, Unable to get CPU info, exception: No process is associated with this object.
##[debug]Agent environment resources - Disk: / Available 20935.00 MB out of 74244.00 MB, Memory: Used 656.00 MB out of 6921.00 MB, Unable to get CPU info, exception: No process is associated with this object.
##[debug]Agent environment resources - Disk: / Available 20935.00 MB out of 74244.00 MB, Memory: Used 656.00 MB out of 6921.00 MB, Unable to get CPU info, exception: No process is associated with this object.
##[debug]Agent environment resources - Disk: / Available 20935.00 MB out of 74244.00 MB, Memory: Used 656.00 MB out of 6921.00 MB, Unable to get CPU info, exception: No process is associated with this object.
##[debug]Agent environment resources - Disk: / Available 20935.00 MB out of 74244.00 MB, Memory: Used 656.00 MB out of 6921.00 MB, Unable to get CPU info, exception: No process is associated with this object.
##[debug]Agent environment resources - Disk: / Available 20935.00 MB out of 74244.00 MB, Memory: Used 656.00 MB out of 6921.00 MB, Unable to get CPU info, exception: No process is associated with this object.
##[debug]Agent environment resources - Disk: / Available 20935.00 MB out of 74244.00 MB, Memory: Used 656.00 MB out of 6921.00 MB, Unable to get CPU info, exception: No process is associated with this object.
##[debug]Agent environment resources - Disk: / Available 20935.00 MB out of 74244.00 MB, Memory: Used 656.00 MB out of 6921.00 MB, Unable to get CPU info, exception: No process is associated with this object.
##[debug]Agent environment resources - Disk: / Available 20935.00 MB out of 74244.00 MB, Memory: Used 656.00 MB out of 6921.00 MB, Unable to get CPU info, exception: No process is associated with this object.
##[debug]Agent environment resources - Disk: / Available 20935.00 MB out of 74244.00 MB, Memory: Used 656.00 MB out of 6921.00 MB, Unable to get CPU info, exception: No process is associated with this object.
##[debug]Agent environment resources - Disk: / Available 20935.00 MB out of 74244.00 MB, Memory: Used 656.00 MB out of 6921.00 MB, Unable to get CPU info, exception: No process is associated with this object.
##[debug]Agent environment resources - Disk: / Available 20935.00 MB out of 74244.00 MB, Memory: Used 656.00 MB out of 6921.00 MB, Unable to get CPU info, exception: No process is associated with this object.
##[debug]Agent environment resources - Disk: / Available 20935.00 MB out of 74244.00 MB, Memory: Used 656.00 MB out of 6921.00 MB, Unable to get CPU info, exception: No process is associated with this object.
Async Command End: Update Build Number
##[error]The HTTP request timed out after 00:01:40.
##[debug]System.TimeoutException: The HTTP request timed out after 00:01:40.
 ---> System.Threading.Tasks.TaskCanceledException: The operation was canceled.
 ---> System.IO.IOException: Unable to read data from the transport connection: Operation canceled.
 ---> System.Net.Sockets.SocketException (125): Operation canceled
   --- End of inner exception stack trace ---
   at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.ThrowException(SocketError error, CancellationToken cancellationToken)
   at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.System.Threading.Tasks.Sources.IValueTaskSource<System.Int32>.GetResult(Int16 token)
   at System.Net.Security.SslStream.EnsureFullTlsFrameAsync[TIOAdapter](TIOAdapter adapter)
   at System.Net.Security.SslStream.ReadAsyncInternal[TIOAdapter](TIOAdapter adapter, Memory`1 buffer)
   at System.Net.Http.HttpConnection.SendAsyncCore(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   --- End of inner exception stack trace ---
   at System.Net.Http.HttpConnection.SendAsyncCore(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.AuthenticationHelper.SendWithNtAuthAsync(HttpRequestMessage request, Uri authUri, Boolean async, ICredentials credentials, Boolean isProxyAuth, HttpConnection connection, HttpConnectionPool connectionPool, CancellationToken cancellationToken)
   at System.Net.Http.HttpConnectionPool.SendWithVersionDetectionAndRetryAsync(HttpRequestMessage request, Boolean async, Boolean doRequestAuth, CancellationToken cancellationToken)
   at System.Net.Http.AuthenticationHelper.SendWithAuthAsync(HttpRequestMessage request, Uri authUri, Boolean async, ICredentials credentials, Boolean preAuthenticate, Boolean isProxyAuth, Boolean doRequestAuth, HttpConnectionPool pool, CancellationToken cancellationToken)
   at System.Net.Http.DecompressionHandler.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at Microsoft.VisualStudio.Services.Common.VssHttpMessageHandler.SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
   --- End of inner exception stack trace ---
   at Microsoft.VisualStudio.Services.Common.VssHttpMessageHandler.SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
   at Microsoft.VisualStudio.Services.Common.VssHttpRetryMessageHandler.SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
   at System.Net.Http.HttpClient.<SendAsync>g__Core|83_0(HttpRequestMessage request, HttpCompletionOption completionOption, CancellationTokenSource cts, Boolean disposeCts, CancellationTokenSource pendingRequestsCts, CancellationToken originalCancellationToken)
   at Microsoft.VisualStudio.Services.WebApi.VssHttpClientBase.SendAsync(HttpRequestMessage message, HttpCompletionOption completionOption, Object userState, CancellationToken cancellationToken)
   at Microsoft.TeamFoundation.Build.WebApi.BuildHttpClientCompatBase.SendAsync[T](HttpRequestMessage message, Object userState, CancellationToken cancellationToken, Func`3 processResponse)
   at Microsoft.TeamFoundation.Build.WebApi.BuildHttpClientCompatBase.SendAsync[T](HttpMethod method, IEnumerable`1 additionalHeaders, Guid locationId, Object routeValues, ApiResourceVersion version, HttpContent content, IEnumerable`1 queryParameters, Object userState, CancellationToken cancellationToken, Func`3 processResponse)
   at Microsoft.VisualStudio.Services.Agent.Worker.Build.BuildServer.UpdateBuildNumber(Int32 buildId, Guid projectId, String buildNumber, CancellationToken cancellationToken) in /mnt/vss/_work/1/s/src/Agent.Worker/Build/BuildServer.cs:line 111
   at Microsoft.VisualStudio.Services.Agent.Worker.Build.BuildUpdateBuildNumberCommand.UpdateBuildNumberAsync(IAsyncCommandContext context, VssConnection connection, Guid projectId, Int32 buildId, String buildNumber, CancellationToken cancellationToken) in /mnt/vss/_work/1/s/src/Agent.Worker/Build/BuildCommandExtension.cs:line 133
   at Microsoft.VisualStudio.Services.Agent.Worker.AsyncCommandContext.WaitAsync() in /mnt/vss/_work/1/s/src/Agent.Worker/AsyncCommandContext.cs:line 130
   at Microsoft.VisualStudio.Services.Agent.Worker.StepsRunner.RunStepAsync(IStep step, CancellationToken jobCancellationToken) in /mnt/vss/_work/1/s/src/Agent.Worker/StepsRunner.cs:line 305
Finishing: Update Build Number
DenisRumyantsev commented 5 months ago

Hi @outsystemsToby, I could not reproduce this issue for several pipeline runs. Can you set system.debug and agent.diagnostic pipeline variables to true for your pipeline, and send pipeline run logs (as an archive downloaded from the pipeline run page) to v-denisr@microsoft.com once this issue appears, so I could investigate them?