My self-hosted runner successes about only 1 time per one day. finish job request for job xxxx with result: Failed. It stoppes at aws-action/amazon-ecr-login@v2.

[monagai]

Select Topic Area

Question

Body

I have changed recently runner form github runner to self-hosted runner on aws EC2.
My self-hosted runner successes about only 1 time per one day. It stoppes at aws-action/amazon-ecr-login@v2. (attached image, debgug mode)

As for failure runs, job Ids seem the same as the previous jobs.
(Do old jobs prevent new jobs?)

How can I solve it?

• self-hoted runner

  • on Amazon EC2 inscane. Ubuntu 20.04. Its spec is enough.
  • runner version: '2.316.0'
  • run with sudo svc.sh. ( sudo ./svc.sh install, sudo ./svc.sh start)
  • do not use auto-scaling
  • do not use OIDC

• I tried theses things

  • sudo svc.sh uninstall/install, sudo svc.sh stop and start, run.sh
  • reboot EC2 instance
  • remove a current runner and use a new runner

• After failure

untu@xxx5:/opt/github_action/actions-runner$ sudo ./svc.sh status

/etc/systemd/system/actions.runner.xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx.service
● actions.runner.xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx.service - GitHub Actions Runner (xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx)
     Loaded: loaded (/etc/systemd/system/actions.runner.xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx.service; enabled; vendor preset: enabled)
     Active: active (running) since Sat 2024-05-04 04:38:56 UTC; 35min ago
   Main PID: 2835 (runsvc.sh)
      Tasks: 22 (limit: 19165)
     Memory: 78.6M
     CGroup: /system.slice/actions.xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx.service
             ├─2835 /bin/bash /opt/github_action/actions-runner/runsvc.sh
             ├─2838 ./externals/node16/bin/node ./bin/RunnerService.js
             └─2845 /opt/github_action/actions-runner/bin/Runner.Listener run --startuptype service

May 04 04:43:03 xxxxxxxxxx sudo[3655]:   ubuntu : TTY=unknown ; PWD=/opt/github_action/actions-runner/_work/xxx ; USER=root ; COMMAND=/usr/bin/rm -rf /var/lib/apt/lists/ap-no…
May 04 04:43:03 xxxxxxxxxx sudo[3655]:   ubuntu : (command continued) /var/lib/apt/lists/ap-northeast-1.ec2.archive.ubuntu.com_ubuntu_dists_focal-backports_universe_cnf_Commands-amd64 /var/lib/apt/lists/ap-nort…
May 04 04:43:03 xxxxxxxxxx sudo[3655]:   ubuntu : (command continued) /var/lib/apt/lists/ap-northeast-1.ec2.archive.ubuntu.com_ubuntu_dists_focal-updates_multiverse_i18n_Translation-en /var/lib/apt/lists/ap-nor…
May 04 04:43:03 xxxxxxxxxx sudo[3655]:   ubuntu : (command continued) /var/lib/apt/lists/ap-northeast-1.ec2.archive.ubuntu.com_ubuntu_dists_focal_main_binary-amd64_Packages /var/lib/apt/lists/ap-northepast-1.ec2…
May 04 04:43:03 xxxxxxxxxx sudo[3655]:   ubuntu : (command continued) /var/lib/apt/lists/ap-northeast-1.ec2.archive.ubuntu.com_ubuntu_dists_focal_restricted_i18n_Translation-en /var/lib/apt/lists/ap-northeast-1…
May 04 04:43:03 xxxxxxxxxx sudo[3655]:   ubuntu : (command continued) /var/lib/apt/lists/ppa.launchpad.net_git-core_ppa_ubuntu_dists_focal_main_i18n_Translation-en /var/lib/apt/lists/security.ubuntu.com_ubuntu_…
May 04 04:43:03 xxxxxxxxxx sudo[3655]:   ubuntu : (command continued) /var/lib/apt/lists/security.ubuntu.com_ubuntu_dists_focal-security_restricted_cnf_Commands-amd64 /var/lib/apt/lists/security.ubuntu.com_ubun…
May 04 04:43:03 xxxxxxxxxx sudo[3655]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 04 04:43:03 xxxxxxxxxx sudo[3655]: pam_unix(sudo:session): session closed for user root
May 04 04:49:51 xxxxxxxxxx runsvc.sh[2838]: 2024-05-04 04:49:51Z: Job Deploy completed with result: Failed
Hint: Some lines were ellipsized, use -l to show in full.

• diag/Runner*.log

[2024-05-04 04:42:42Z INFO JobDispatcher] Successfully renew job request 485, job is valid till 05/04/2024 04:52:42
[2024-05-04 04:42:42Z INFO HostContext] Well known directory 'Bin': '/opt/github_action/actions-runner/bin'
[2024-05-04 04:42:42Z INFO ProcessInvokerWrapper] Starting process:
[2024-05-04 04:42:42Z INFO ProcessInvokerWrapper]   File name: '/opt/github_action/actions-runner/bin/Runner.Worker'
[2024-05-04 04:42:42Z INFO ProcessInvokerWrapper]   Arguments: 'spawnclient 106 109'
[2024-05-04 04:42:42Z INFO ProcessInvokerWrapper]   Working directory: '/opt/github_action/actions-runner/bin'
[2024-05-04 04:42:42Z INFO ProcessInvokerWrapper]   Require exit code zero: 'False'
[2024-05-04 04:42:42Z INFO ProcessInvokerWrapper]   Encoding web name:  ; code page: ''
[2024-05-04 04:42:42Z INFO ProcessInvokerWrapper]   Force kill process on cancellation: 'True'
[2024-05-04 04:42:42Z INFO ProcessInvokerWrapper]   Redirected STDIN: 'False'
[2024-05-04 04:42:42Z INFO ProcessInvokerWrapper]   Persist current code page: 'False'
[2024-05-04 04:42:42Z INFO ProcessInvokerWrapper]   Keep redirected STDIN open: 'False'
[2024-05-04 04:42:42Z INFO ProcessInvokerWrapper]   High priority process: 'True'
[2024-05-04 04:42:42Z INFO ProcessInvokerWrapper] Process started with process id 2898, waiting for process exit.
[2024-05-04 04:42:42Z INFO JobDispatcher] Send job request message to worker for job xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx.
[2024-05-04 04:42:42Z INFO ProcessChannel] Sending message of length 31433, with hash 'xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx'
[2024-05-04 04:42:42Z INFO JobNotification] Entering JobStarted Notification
[2024-05-04 04:42:42Z INFO JobNotification] Entering StartMonitor
[2024-05-04 04:43:42Z INFO JobDispatcher] Successfully renew job request 485, job is valid till 05/04/2024 04:53:42
[2024-05-04 04:44:42Z INFO JobDispatcher] Successfully renew job request 485, job is valid till 05/04/2024 04:54:42
[2024-05-04 04:45:42Z INFO JobDispatcher] Successfully renew job request 485, job is valid till 05/04/2024 04:55:42
[2024-05-04 04:46:42Z INFO JobDispatcher] Successfully renew job request 485, job is valid till 05/04/2024 04:56:42
[2024-05-04 04:47:43Z INFO JobDispatcher] Successfully renew job request 485, job is valid till 05/04/2024 04:57:43
[2024-05-04 04:48:43Z INFO JobDispatcher] Successfully renew job request 485, job is valid till 05/04/2024 04:58:43
[2024-05-04 04:49:43Z INFO JobDispatcher] Successfully renew job request 485, job is valid till 05/04/2024 04:59:43
[2024-05-04 04:49:51Z INFO ProcessInvokerWrapper] STDOUT/STDERR stream read finished.
[2024-05-04 04:49:51Z INFO ProcessInvokerWrapper] STDOUT/STDERR stream read finished.
[2024-05-04 04:49:51Z INFO ProcessInvokerWrapper] Finished process 2898 with exit code 102, and elapsed time 00:07:08.8669662.
[2024-05-04 04:49:51Z INFO JobDispatcher] Worker finished for job xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx. Code: 102
[2024-05-04 04:49:51Z INFO JobDispatcher] finish job request for job xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxs with result: Failed
[2024-05-04 04:49:51Z INFO Terminal] WRITE LINE: 2024-05-04 04:49:51Z: Job Deploy completed with result: Failed
[2024-05-04 04:49:51Z INFO JobDispatcher] Stop renew job request for job xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx.
[2024-05-04 04:49:51Z INFO JobDispatcher] job renew has been cancelled, stop renew job request 485.
[2024-05-04 04:49:51Z INFO JobNotification] Entering JobCompleted Notification
[2024-05-04 04:49:51Z INFO JobNotification] Entering EndMonitor
[2024-05-04 04:49:51Z INFO MessageListener] Received job status event. JobState: Online
[2024-05-04 04:49:51Z WARN GitHubActionsService] GET request to https://pipelinesghubeus3.actions.githubusercontent.com/xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx/_apis/distributedtask/pools/1/messages?sessionId=xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx&lastMessageId=2&status=Busy&runnerVersion=2.316.0&os=Linux&architecture=X64&disableUpdate=false has been cancelled.
[2024-05-04 04:49:51Z INFO MessageListener] Get messages has been cancelled using local token source. Continue to get messages with new status.

• _diag/Workder*.log

...
2024-05-04 04:49:50Z INFO JobServerQueue] Tried to upload 6 file(s) to results, success rate: 6/6.
[2024-05-04 04:49:50Z INFO JobServerQueue] Results upload queue drained.
[2024-05-04 04:49:50Z INFO JobServerQueue] Timeline update queue drained.
[2024-05-04 04:49:50Z INFO JobServerQueue] Disposing job server ...
[2024-05-04 04:49:50Z INFO JobServerQueue] Disposing results server ...
[2024-05-04 04:49:50Z INFO JobServerQueue] All queue process tasks have been stopped, and all queues are drained.
[2024-05-04 04:49:50Z INFO JobServerQueue] Actions upload time: 4944 ms, Result upload time: 7499 ms
[2024-05-04 04:49:50Z INFO TempDirectoryManager] Cleaning runner temp folder: /opt/github_action/actions-runner/_work/_temp
[2024-05-04 04:49:50Z INFO HostContext] Well known directory 'Bin': '/opt/github_action/actions-runner/bin'
[2024-05-04 04:49:50Z INFO HostContext] Well known directory 'Root': '/opt/github_action/actions-runner'
[2024-05-04 04:49:50Z INFO HostContext] Well known directory 'Diag': '/opt/github_action/actions-runner/_diag'
[2024-05-04 04:49:50Z INFO HostContext] Well known config file 'Telemetry': '/opt/github_action/actions-runner/_diag/.telemetry'
[2024-05-04 04:49:50Z INFO JobRunner] Raising job completed event
[2024-05-04 04:49:51Z INFO Worker] Job completed.

• journalctl -u actions.runner.xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx.service

May 04 04:26:57 xxxxxxxxxx systemd[1]: Started GitHub Actions Runner (xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx).
May 04 04:26:57 xxxxxxxxxx runsvc.sh[1670]: .path=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin
May 04 04:26:57 xxxxxxxxxx runsvc.sh[1673]: Starting Runner listener with startup type: service
May 04 04:26:57 xxxxxxxxxx runsvc.sh[1673]: Started listener process, pid: 1680
May 04 04:26:57 xxxxxxxxxx runsvc.sh[1673]: Started running service
May 04 04:27:00 xxxxxxxxxx runsvc.sh[1673]: √ Connected to GitHub
May 04 04:27:01 xxxxxxxxxx runsvc.sh[1673]: Current runner version: '2.316.0'
May 04 04:27:01 xxxxxxxxxx runsvc.sh[1673]: 2024-05-04 04:27:01Z: Listening for Jobs
May 04 04:27:35 xxxxxxxxxx runsvc.sh[1673]: 2024-05-04 04:27:35Z: Running job: Deploy
May 04 04:27:42 xxxxxxxxxx sudo[1836]:   ubuntu : TTY=unknown ; PWD=/opt/github_action/actions-runner/_work/xxx/xxx ; USER=root ; COMMAND=/usr/bin/apt-get -y update
May 04 04:27:42 xxxxxxxxxx sudo[1836]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 04 04:27:56 xxxxxxxxxx sudo[1836]: pam_unix(sudo:session): session closed for user root
May 04 04:27:56 xxxxxxxxxx sudo[2428]:   ubuntu : TTY=unknown ; PWD=/opt/github_action/actions-runner/_work/xxx/xxx ; USER=root ; COMMAND=/usr/bin/apt-get -y install --no-install>
May 04 04:27:56 xxxxxxxxxx sudo[2428]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 04 04:27:57 xxxxxxxxxx sudo[2428]: pam_unix(sudo:session): session closed for user root
May 04 04:27:57 xxxxxxxxxx sudo[2432]:   ubuntu : TTY=unknown ; PWD=/opt/github_action/actions-runner/_work/xxx/xxx ; USER=root ; COMMAND=/usr/bin/apt-get -y autoremove
May 04 04:27:57 xxxxxxxxxx sudo[2432]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 04 04:27:57 xxxxxxxxxx sudo[2432]: pam_unix(sudo:session): session closed for user root
May 04 04:27:57 xxxxxxxxxx sudo[2436]:   ubuntu : TTY=unknown ; PWD=/opt/github_action/actions-runner/_work/xxx/xxx ; USER=root ; COMMAND=/usr/bin/apt-get clean
May 04 04:27:57 xxxxxxxxxx sudo[2436]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 04 04:27:57 xxxxxxxxxx sudo[2436]: pam_unix(sudo:session): session closed for user root
May 04 04:27:57 xxxxxxxxxx sudo[2438]:   ubuntu : TTY=unknown ; PWD=/opt/github_action/actions-runner/_work/xxx/xxx ; USER=root ; COMMAND=/usr/bin/rm -rf /var/lib/apt/lists/ap-no>
May 04 04:27:57 xxxxxxxxxx sudo[2438]:   ubuntu : TTY=unknown ; PWD=/opt/github_action/actions-runner/_work/xxx/xxx ; USER=root ; COMMAND=/usr/bin/rm -rf /var/lib/apt/lists/ap-no>
May 04 04:27:57 xxxxxxxxxx sudo[2438]:   ubuntu : (command continued) /var/lib/apt/lists/ap-northeast-1.ec2.archive.ubuntu.com_ubuntu_dists_focal-backports_universe_cnf_Commands-amd64 /var/lib/apt/lists/ap-nort>
ay 04 04:27:57 xxxxxxxxxx sudo[2438]:   ubuntu : (command continued) /var/lib/apt/lists/ap-northeast-1.ec2.archive.ubuntu.com_ubuntu_dists_focal-updates_multiverse_i18n_Translation-en /var/lib/apt/lists/ap-nor>
May 04 04:27:57 xxxxxxxxxx sudo[2438]:   ubuntu : (command continued) /var/lib/apt/lists/ap-northeast-1.ec2.archive.ubuntu.com_ubuntu_dists_focal_main_binary-amd64_Packages /var/lib/apt/lists/ap-northeast-1.ec2>
May 04 04:27:57 xxxxxxxxxx sudo[2438]:   ubuntu : (command continued) /var/lib/apt/lists/ap-northeast-1.ec2.archive.ubuntu.com_ubuntu_dists_focal_restricted_i18n_Translation-en /var/lib/apt/lists/ap-northeast-1>
May 04 04:27:57 xxxxxxxxxx sudo[2438]:   ubuntu : (command continued) /var/lib/apt/lists/ppa.launchpad.net_git-core_ppa_ubuntu_dists_focal_main_i18n_Translation-en /var/lib/apt/lists/security.ubuntu.com_ubuntu_>
May 04 04:27:57 xxxxxxxxxx sudo[2438]:   ubuntu : (command continued) /var/lib/apt/lists/security.ubuntu.com_ubuntu_dists_focal-security_restricted_cnf_Commands-amd64 /var/lib/apt/lists/security.ubuntu.com_ubun>
May 04 04:27:57 xxxxxxxxxx sudo[2438]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 04 04:27:57 xxxxxxxxxx sudo[2438]: pam_unix(sudo:session): session closed for user root
May 04 04:34:39 xxxxxxxxxx runsvc.sh[1673]: 2024-05-04 04:34:39Z: Job Deploy completed with result: Failed
May 04 04:37:09 xxxxxxxxxx systemd[1]: Stopping GitHub Actions Runner (xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx)...
May 04 04:37:09 xxxxxxxxxx runsvc.sh[1673]: Shutting down runner listener
May 04 04:37:09 xxxxxxxxxx runsvc.sh[1673]: Sending SIGINT to runner listener to stop
May 04 04:37:09 xxxxxxxxxx runsvc.sh[1673]: Sending SIGKILL to runner listener
May 04 04:37:09 xxxxxxxxxx runsvc.sh[1673]: Exiting...
May 04 04:37:09 xxxxxxxxxx runsvc.sh[1673]: Runner listener exited with error code 0
May 04 04:37:09 xxxxxxxxxx runsvc.sh[1673]: Runner listener exit with 0 return code, stop the service, no retry needed.
May 04 04:37:09 xxxxxxxxxx systemd[1]: actions.runner.xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx.service: Succeeded.
May 04 04:37:09 xxxxxxxxxx systemd[1]: Stopped GitHub Actions Runner (xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx).
May 04 04:38:56 xxxxxxxxxx runsvc.sh[2835]: .path=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin
May 04 04:38:56 xxxxxxxxxx runsvc.sh[2838]: Starting Runner listener with startup type: service
May 04 04:38:56 xxxxxxxxxx runsvc.sh[2838]: Started listener process, pid: 2845
May 04 04:38:56 xxxxxxxxxx runsvc.sh[2838]: Started running service
May 04 04:38:59 xxxxxxxxxx runsvc.sh[2838]: √ Connected to GitHub
May 04 04:38:59 xxxxxxxxxx runsvc.sh[2838]: Current runner version: '2.316.0'
May 04 04:38:59 xxxxxxxxxx runsvc.sh[2838]: 2024-05-04 04:38:59Z: Listening for Jobs
May 04 04:42:41 xxxxxxxxxx runsvc.sh[2838]: 2024-05-04 04:42:41Z: Running job: Deploy
May 04 04:42:48 xxxxxxxxxx sudo[3052]:   ubuntu : TTY=unknown ; PWD=/opt/github_action/actions-runner/_work/xxx/xxx ; USER=root ; COMMAND=/usr/bin/apt-get -y update
May 04 04:42:48 xxxxxxxxxx sudo[3052]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 04 04:43:02 xxxxxxxxxx sudo[3052]: pam_unix(sudo:session): session closed for user root
May 04 04:43:02 xxxxxxxxxx sudo[3645]:   ubuntu : TTY=unknown ; PWD=/opt/github_action/actions-runner/_work/xxx/xxx ; USER=root ; COMMAND=/usr/bin/apt-get -y install --no-install>
May 04 04:43:02 xxxxxxxxxx sudo[3645]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 04 04:43:03 xxxxxxxxxx sudo[3645]: pam_unix(sudo:session): session closed for user root
May 04 04:43:03 xxxxxxxxxx sudo[3649]:   ubuntu : TTY=unknown ; PWD=/opt/github_action/actions-runner/_work/xxx/xxx ; USER=root ; COMMAND=/usr/bin/apt-get -y autoremove
May 04 04:43:03 xxxxxxxxxx sudo[3649]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 04 04:43:03 xxxxxxxxxx sudo[3649]: pam_unix(sudo:session): session closed for user root
May 04 04:43:03 xxxxxxxxxx sudo[3653]:   ubuntu : TTY=unknown ; PWD=/opt/github_action/actions-runner/_work/xxx/xxx ; USER=root ; COMMAND=/usr/bin/apt-get clean
May 04 04:43:03 xxxxxxxxxx sudo[3653]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 04 04:43:03 xxxxxxxxxx sudo[3653]: pam_unix(sudo:session): session closed for user root
May 04 04:43:03 xxxxxxxxxx sudo[3655]:   ubuntu : TTY=unknown ; PWD=/opt/github_action/actions-runner/_work/xxx/xxx ; USER=root ; COMMAND=/usr/bin/rm -rf /var/lib/apt/lists/ap-no>
May 04 04:43:03 xxxxxxxxxx sudo[3655]:   ubuntu : (command continued) /var/lib/apt/lists/ap-northeast-1.ec2.archive.ubuntu.com_ubuntu_dists_focal-backports_universe_cnf_Commands-amd64 /var/lib/apt/lists/ap-nort>
May 04 04:43:03 xxxxxxxxxx sudo[3655]:   ubuntu : (command continued) /var/lib/apt/lists/ap-northeast-1.ec2.archive.ubuntu.com_ubuntu_dists_focal-updates_multiverse_i18n_Translation-en /var/lib/apt/lists/ap-nor>
May 04 04:43:03 xxxxxxxxxx sudo[3655]:   ubuntu : (command continued) /var/lib/apt/lists/ap-northeast-1.ec2.archive.ubuntu.com_ubuntu_dists_focal_main_binary-amd64_Packages /var/lib/apt/lists/ap-northeast-1.ec2>
May 04 04:43:03 xxxxxxxxxx sudo[3655]:   ubuntu : (command continued) /var/lib/apt/lists/ap-northeast-1.ec2.archive.ubuntu.com_ubuntu_dists_focal_restricted_i18n_Translation-en /var/lib/apt/lists/ap-northeast-1>
May 04 04:43:03 xxxxxxxxxx sudo[3655]:   ubuntu : (command continued) /var/lib/apt/lists/ppa.launchpad.net_git-core_ppa_ubuntu_dists_focal_main_i18n_Translation-en /var/lib/apt/lists/security.ubuntu.com_ubuntu_>
May 04 04:43:03 xxxxxxxxxx sudo[3655]:   ubuntu : (command continued) /var/lib/apt/lists/security.ubuntu.com_ubuntu_dists_focal-security_restricted_cnf_Commands-amd64 /var/lib/apt/lists/security.ubuntu.com_ubun>
May 04 04:43:03 xxxxxxxxxx sudo[3655]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 04 04:43:03 xxxxxxxxxx sudo[3655]: pam_unix(sudo:session): session closed for user root
May 04 04:49:51 xxxxxxxxxx runsvc.sh[2838]: 2024-05-04 04:49:51Z: Job Deploy completed with result: Failed
``

[monagai]

I also tried the following things and they were all ineffective.

• new EC2 instance
• set concurrency cancel-in-progress: true