Timeout in CI/CD script

[UweKeim]

We talked about this in a previous issue; unfortunately I'm still getting constant timeouts in various of my CI/CD scripts. I do not find any pattern on why this happens in some scripts but not in others.

ERROR: Job failed: execution took longer than 1h0m0s seconds

This is the full log output of one CI/CD build script on my GitLab:

Running with gitlab-runner 17.6.0 (374d34fd)
  on Ubuntu Runner 1 zxzou4dy, system ID: r_tGfUWxM[2](https://git.zeta-sw.com/zeta/zeta-short-paths/-/jobs/12474#L2)3pdD
Preparing the "docker" executor
00:01
Using Docker executor with image mcr.microsoft.com/dotnet/sdk:8.0 ...
Pulling docker image mcr.microsoft.com/dotnet/sdk:8.0 ...
Using docker image sha256:2afc0eb4[3](https://git.zeta-sw.com/zeta/zeta-short-paths/-/jobs/12474#L3)f0fec997bb229e445c434a4f092cc1af72de5681b9d597a8cd6652f for mcr.microsoft.com/dotnet/sdk:8.0 with digest mcr.microsoft.com/dotnet/sdk@sha256:032381bcea86fa0a[4](https://git.zeta-sw.com/zeta/zeta-short-paths/-/jobs/12474#L4)08af5df63a930f1ff5b03116c940a7cd744d3b648e66749 ...
Preparing environment
00:00
Running on runner-zxzou4dy-project-97-concurrent-0 via 637c00b0000b...
Getting source from Git repository
00:01
Fetching changes with git depth set to [5](https://git.zeta-sw.com/zeta/zeta-short-paths/-/jobs/12474#L5)0...
Reinitialized existing Git repository in /builds/zeta/zeta-short-paths/.git/
Checking out 410a2f3c as detached HEAD (ref is main)...
Removing Source/.nuget/
Removing Source/Runtime/bin/
Removing Source/Runtime/obj/
Removing Source/UnitTests/bin/
Removing Source/UnitTests/obj/
Removing Source/nul
Removing nul
Updating/initializing submodules recursively with git depth set to 1...
Synchronizing submodule url for '_References/Submodules/zeta-shared-ci-assets'
Entering '_References/Submodules/zeta-shared-ci-assets'
Entering '_References/Submodules/zeta-shared-ci-assets'
HEAD is now at 821b11e Merge branch 'main' of https://git.zeta-sw.com/zeta/zeta-shared-ci-assets
Submodule path '_References/Submodules/zeta-shared-ci-assets': checked out '2fba[6](https://git.zeta-sw.com/zeta/zeta-short-paths/-/jobs/12474#L6)2a64c2a1e4db9b299611135e01760bc1710'
Updated submodules
Synchronizing submodule url for '_References/Submodules/zeta-shared-ci-assets'
Entering '_References/Submodules/zeta-shared-ci-assets'
Entering '_References/Submodules/zeta-shared-ci-assets'
Restoring cache
00:00
Checking cache for build-main-protected...
No URL provided, cache will not be downloaded from shared cache server. Instead a local version of cache will be extracted. 
Successfully extracted cache
Executing "step_script" stage of the job script
59:58
Using docker image sha256:2afc0eb43f0fec99[7](https://git.zeta-sw.com/zeta/zeta-short-paths/-/jobs/12474#L7)bb229e445c434a4f092cc1af72de56[8](https://git.zeta-sw.com/zeta/zeta-short-paths/-/jobs/12474#L8)1b9d597a8cd6652f for mcr.microsoft.com/dotnet/sdk:8.0 with digest mcr.microsoft.com/dotnet/sdk@sha256:032381bcea86fa0a408af5df63a[9](https://git.zeta-sw.com/zeta/zeta-short-paths/-/jobs/12474#L9)30f1ff5b03116c940a7cd744d3b648e66749 ...
$ dotnet nuget remove source "$GITLAB_ZETA_NUGET_NAME" >nul || exit_code=$?
$ dotnet nuget add source $GITLAB_ZETA_NUGET_URL -n "$GITLAB_ZETA_NUGET_NAME" -u $GITLAB_ZETA_NUGET_USER -p $GITLAB_ZETA_NUGET_PASSWORD --store-password-in-clear-text >nul
$ dotnet nuget remove source "DevExpress Uwe" >nul || exit_code=$?
$ dotnet nuget add source "https://nuget.devexpress.com/$DEVEXPRESS_NUGETKEY_UWEKEIM/api" -n "DevExpress Uwe"
Package source with Name: DevExpress Uwe added successfully.
$ cd $SOURCE_CODE_PATH
$ dotnet restore --packages $NUGET_PACKAGES_DIRECTORY
  Determining projects to restore...
  Restored /builds/zeta/zeta-short-paths/Source/Runtime/Runtime.csproj (in 753 ms).
  Restored /builds/zeta/zeta-short-paths/Source/UnitTests/UnitTests.csproj (in 2.5 sec).
$ dotnet tool install --global cs-script.cli
Tools directory '/root/.dotnet/tools' is not currently on the PATH environment variable.
If you are using bash, you can add it to your profile by running the following command:
cat << \EOF >> ~/.bash_profile
# Add .NET Core SDK tools
export PATH="$PATH:/root/.dotnet/tools"
EOF
You can add it to the current session by running the following command:
export PATH="$PATH:/root/.dotnet/tools"
You can invoke the tool using the following command: css
Tool 'cs-script.cli' (version '4.8.[23](https://git.zeta-sw.com/zeta/zeta-short-paths/-/jobs/12474#L23)') was successfully installed.
$ dotnet tool update --global cs-script.cli
Tools directory '/root/.dotnet/tools' is not currently on the PATH environment variable.
If you are using bash, you can add it to your profile by running the following command:
cat << \EOF >> ~/.bash_profile
# Add .NET Core SDK tools
export PATH="$PATH:/root/.dotnet/tools"
EOF
You can add it to the current session by running the following command:
export PATH="$PATH:/root/.dotnet/tools"
Tool 'cs-script.cli' was reinstalled with the stable version (version '4.8.23').
$ ~/.dotnet/tools/css -config:set:LegacyNugetSupport=false
set: LegacyNugetSupport: False
$ ~/.dotnet/tools/css ${CI_PROJECT_DIR}/Source/cicd-increase-versionnumber.cs
Restoring packages...
   morelinq
   Newtonsoft.Json
   NuGet.Versioning
   RestSharp
   SharpZipLib
   ZetaDeployer.RuntimeUploader
   ZetaShortPaths
Mapping packages to assemblies...
Restoring packages...
   morelinq
   Newtonsoft.Json
   NuGet.Versioning
   RestSharp
   SharpZipLib
   ZetaDeployer.RuntimeUploader
   ZetaShortPaths
Mapping packages to assemblies...
WARNING: step_script could not run to completion because the timeout was exceeded. For more control over job and script timeouts see: https://docs.gitlab.com/ee/ci/runners/configure_runners.html#set-script-and-after_script-timeouts
ERROR: Job failed: execution took longer than 1h0m0s seconds

My question:

Do you have any idea what might be the issue here?

It startet happening when .NET 9 came out and the Docker image uses the .NET 9 SDK.

[oleg-shilo]

There are a few things that are not clear.

• The engine installed twice. Once with dotnet tool install --global cs-script.cli and then immediately with dotnet tool update --global cs-script.cli. While it should not be a problem, it seems unnecessary.
• Restoring nuget packages used by cs-script happens twice. What is particularly strange is that in both times dotnet had to restore them from scratch. Meaning that it looks like there are two competing nuget restore processes.
  Even though the log suggests that they are happening one after another, it is not what expected.

CS-Script should not restore the package twice while executing a single script.
Even if two restore process are executed only the first one should do the actual package download ("Restoring packages..." log entry). The second restore should jump directly to the mapping of the packages to the assemblies.

I think it is a race condition that we have here.

Can you share the sanitised version of the cicd-increase-versionnumber.cs?

[oleg-shilo]

And if .NET9 somehow kames the difference you can always rollback to v8.0
nuget tool install will always bring the right build of cs-script based on the .NET SDK present

[oleg-shilo]

There is also an inefficiency (but not a problem) in the package restore operations. For the apps, you do it in the $NUGET_PACKAGES_DIRECTORY but the cs-script restore does it ti the default system nuget dir

[UweKeim]

Here is the full code of the "cicd-increase-versionnumber.cs" file:

//css_import ../_References/Submodules/zeta-shared-ci-assets/DevelopmentTools/CentralScripts/Afx.cs;

using System.Threading.Tasks;
using ZetaSoftware.CentralScripts;

public static class Processor
{
    public static async Task<int> Main()
    {
        Afx.Init();
        return await Afx.RunMain(async () => await processTasks());
    }

    private static async Task processTasks()
    {
        // Immer eines hochzählen.
        BuildUtilities.IncreaseVersionNumber();
        
        // NuGet-Pakete aktualisieren.
        CompilationUtilities.HighLevelUpdateAndRestorePackages(@"${ScriptFolderPath}");
    }
}

It is rather short, because it includes the "Afx.cs" which in turn does include other files.

The start of the "Afx.cs" looks like this:

//css_nuget Newtonsoft.Json
//css_nuget morelinq
//css_nuget SharpZipLib
//css_nuget RestSharp
//css_nuget ZetaShortPaths
//css_nuget ZetaDeployer.RuntimeUploader
//css_nuget QuickUploader.WebApiAccessor
//css_nuget NuGet.Versioning

//css_import ./Logging.cs;
//css_import ./ProcessUtilities.cs;
//css_import ./SpecialFolders.cs;
//css_import ./StringUtilities.cs;
//css_import ./FileUtilities.cs;
//css_import ./FolderUtilities.cs;
//css_import ./FolderXCopy.cs;
//css_import ./FolderXCopyUtilities.cs;
//css_import ./FolderZip.cs;
//css_import ./AppOfflineUtilities.cs;
//css_import ./BuildUtilities.cs;
//css_import ./QuickUploaderUtilities.cs;
//css_import ./CompilationUtilities.cs;
//css_import ./FileSyncUtilities.cs;

using System;
using System.Diagnostics;
using System.Collections.Generic;
using System.Net;
using System.Text;
using System.Text.RegularExpressions;
using ZetaSoftware.CentralScripts;
using System.IO; 
using System.Linq;
using System.Threading;
using System.Threading.Tasks;
using System.Reflection;

namespace ZetaSoftware.CentralScripts;

// ...

[UweKeim]

And if .NET9 somehow kames the difference you can always rollback to v8.0 nuget tool install will always bring the right build of cs-script based on the .NET SDK present

Probably this is not possible in my scenario as I have to use .NET SDK 9 since my applications have to be compiled to .NET 9.

The start of my ".gitlab-ci.yml" starts like this:

image: mcr.microsoft.com/dotnet/sdk:9.0

default:
  tags:
    - ubuntu

workflow:
  rules:
    - if: $CI_COMMIT_MESSAGE =~ /^(wip|skip)(\([\w\s-]*\))?:/
      when: never
    - when: always

stages:
  - build
  - test
  - nuget
  - github

variables:
  #...

I do not know whether you are aware of the CI-CD concept of GitLab. Basically the above defines the Docker image to use when running the CI-CD job and then it runs the whole script in a "GitLab Runner" on a separate Ubuntu server machine.

[oleg-shilo]

That's a very challenging problem to solve.
I do not have any clear answer but there are some things that we can try to address.

• Minimize the number of nuget cache directories.
  You can remove this --packages $NUGET_PACKAGES_DIRECTORY then donet will be using the same cache as cs-script.
  If you have to use a custom cache location cs-script can also switch to the custom location but your version does it only for the packages lookup but not for restore operations. I have provisioned the change and the next version will be able to use a custom nuget location all the way.

• Separate script package restoration and execution phases. This way it will be clear if it is nuget restore or script execution that is holding your system.
  You can achieve it by executing restore operation before the script execution. You have already nicely separated all your packages refs in the afx.cs file:

  $ ~/.dotnet/tools/css -nuget:restore -cd ${CI_PROJECT_DIR}/Source/afx.cs
  $ ~/.dotnet/tools/css ${CI_PROJECT_DIR}/Source/cicd-increase-versionnumber.cs

  • try to understand why in your case package restore functionality executed twice. Unless it is a logging glitch:

  $ ~/.dotnet/tools/css ${CI_PROJECT_DIR}/Source/cicd-increase-versionnumber.cs
  Restoring packages...
     morelinq
     . . .
     ZetaShortPaths
  Mapping packages to assemblies...
  Restoring packages...
     morelinq
     . . .
     ZetaShortPaths
  Mapping packages to assemblies...
  

  I have checked it on Ubuntu. Package restore goes only once. Even if some packages are not available (e.g. //css_nuget QuickUploader.WebApiAccessor):

  

[UweKeim]

Thank you, Oleg,

The multiple restores happen since ever, in my opinion. I do think it happens when I have a script that includes another script wich in turn includes yet another script and/or includes NuGet packages.

I get this on my Windows machine, too.

[oleg-shilo]

OK, I will recheck this scenario. I hope this is the case because we can easily address the nesting if it cause the problem

[UweKeim]

Attached is an example.zip that generates this output:

c:\Ablage>run-a.cmd

PUSHD

CD /d c:\Ablage\

dotnet tool update --global cs-script.cli
Das Tool "cs-script.cli" ist bereits installiert.

css -config:set:LegacyNugetSupport=false
set: LegacyNugetSupport: False

css -nuget:restore "c:\Ablage\\a.cs"
Restoring packages...
   morelinq
Mapping packages to assemblies...
Restoring packages...
   morelinq
   Newtonsoft.Json
Mapping packages to assemblies...
Compile: OK

css /dbg "c:\Ablage\\a.cs"
A
B

POPD

EXIT /B 0

c:\Ablage>

It seems that it tries to restore "morelinq" twice, although it is only referenced in file "b.cs".

[oleg-shilo]

Great, thank you.
And I assume this sample also occasionally fails, right?

[UweKeim]

Since the "stalling" only occurs during CI-CD runs, and I did not yet integrate it into a CI-CD script yet, I cannot say whether it hangs or not.

I can try to set up a test repository, if this helps.