acmesh-official / acme.sh

A pure Unix shell script implementing ACME client protocol
https://acme.sh
GNU General Public License v3.0
39.87k stars 5.01k forks source link

Can't find error, hence can't fix PR tests & useless docs #4145

Open Eagle3386 opened 2 years ago

Eagle3386 commented 2 years ago

Steps to reproduce

  1. Fork the repo.
  2. Add a DNS API plugin.
  3. Add repo secrets as pointed out at the wiki page.
  4. Enable increased debug logs by adding - still undocumented at the wiki page - ACTIONS_RUNNER_DEBUG & ACTIONS_STEP_DEBUG to the repo secrets, both set to true.
  5. Confirm all is set up well like this: image
  6. Find runner's debug log lacking any message for why it idled 6 hours without any error or info at the Docker step.
  7. Ask @Neilpang for help & get him stating (quote):

    fix the CI Checks first: https://github.com/acmesh-official/acme.sh/wiki/DNS-API-Test

If anybody would offer some real help to really find the root cause in order to fix this & get the pull request merged, I'd greatly appreciate that. Using my DNS API plugin "in the wild" is already confirmed working since February 27, 2022, because I use it myself every ~60 days - which is why I'd really like to get this added to ACME.sh, but I'm obviously too stupid to fix those PR tests only using that - IMHO - awfully bad documentation (which I can't fix either until I found the actual error & a proper fix for it).

Debug log

2022-06-16T17:49:20.4325494Z Requested labels: ubuntu-latest
2022-06-16T17:49:20.4325540Z Job defined at: Eagle3386/acme.sh/.github/workflows/DNS.yml@refs/heads/master
2022-06-16T17:49:20.4325557Z Waiting for a runner to pick up this job...
2022-06-16T17:49:21.0682573Z Job is waiting for a hosted runner to come online.
2022-06-16T17:49:25.8926864Z Job is about to start running on the hosted runner: Hosted Agent (hosted)
2022-06-16T17:49:27.9960290Z ##[debug]Starting: Docker
2022-06-16T17:49:27.9986910Z ##[debug]Cleaning runner temp folder: /home/runner/work/_temp
2022-06-16T17:49:28.0359209Z ##[debug]Starting: Set up job
2022-06-16T17:49:28.0359776Z Current runner version: '2.293.0'
2022-06-16T17:49:28.0391962Z ##[group]Operating System
2022-06-16T17:49:28.0392483Z Ubuntu
2022-06-16T17:49:28.0393205Z 20.04.4
2022-06-16T17:49:28.0393587Z LTS
2022-06-16T17:49:28.0394051Z ##[endgroup]
2022-06-16T17:49:28.0394420Z ##[group]Virtual Environment
2022-06-16T17:49:28.0394911Z Environment: ubuntu-20.04
2022-06-16T17:49:28.0395327Z Version: 20220614.0
2022-06-16T17:49:28.0396052Z Included Software: https://github.com/actions/virtual-environments/blob/ubuntu20/20220614.0/images/linux/Ubuntu2004-Readme.md
2022-06-16T17:49:28.0396997Z Image Release: https://github.com/actions/virtual-environments/releases/tag/ubuntu20%2F20220614.0
2022-06-16T17:49:28.0397545Z ##[endgroup]
2022-06-16T17:49:28.0397953Z ##[group]Virtual Environment Provisioner
2022-06-16T17:49:28.0398600Z 1.0.0.0-main-20220531-1
2022-06-16T17:49:28.0398984Z ##[endgroup]
2022-06-16T17:49:28.0400263Z ##[group]GITHUB_TOKEN Permissions
2022-06-16T17:49:28.0401125Z Actions: write
2022-06-16T17:49:28.0401535Z Checks: write
2022-06-16T17:49:28.0401875Z Contents: write
2022-06-16T17:49:28.0402245Z Deployments: write
2022-06-16T17:49:28.0402604Z Discussions: write
2022-06-16T17:49:28.0403032Z Issues: write
2022-06-16T17:49:28.0403368Z Metadata: read
2022-06-16T17:49:28.0403747Z Packages: write
2022-06-16T17:49:28.0404121Z Pages: write
2022-06-16T17:49:28.0404471Z PullRequests: write
2022-06-16T17:49:28.0404861Z RepositoryProjects: write
2022-06-16T17:49:28.0405241Z SecurityEvents: write
2022-06-16T17:49:28.0405627Z Statuses: write
2022-06-16T17:49:28.0405974Z ##[endgroup]
2022-06-16T17:49:28.0409853Z Secret source: Actions
2022-06-16T17:49:28.0410427Z ##[debug]Primary repository: Eagle3386/acme.sh
2022-06-16T17:49:28.0410975Z Prepare workflow directory
2022-06-16T17:49:28.0499458Z ##[debug]Creating pipeline directory: '/home/runner/work/acme.sh'
2022-06-16T17:49:28.0502448Z ##[debug]Creating workspace directory: '/home/runner/work/acme.sh/acme.sh'
2022-06-16T17:49:28.0503682Z ##[debug]Update context data
2022-06-16T17:49:28.0506489Z ##[debug]Evaluating job-level environment variables
2022-06-16T17:49:28.1578955Z ##[debug]Evaluating: secrets.TEST_DNS
2022-06-16T17:49:28.1586470Z ##[debug]Evaluating Index:
2022-06-16T17:49:28.1588926Z ##[debug]..Evaluating secrets:
2022-06-16T17:49:28.1609111Z ##[debug]..=> Object
2022-06-16T17:49:28.1629548Z ##[debug]..Evaluating String:
2022-06-16T17:49:28.1630605Z ##[debug]..=> 'TEST_DNS'
2022-06-16T17:49:28.1636509Z ##[debug]=> '***'
2022-06-16T17:49:28.1640694Z ##[debug]Result: '***'
2022-06-16T17:49:28.1667777Z ##[debug]Evaluating: secrets.TestingDomain
2022-06-16T17:49:28.1668271Z ##[debug]Evaluating Index:
2022-06-16T17:49:28.1668674Z ##[debug]..Evaluating secrets:
2022-06-16T17:49:28.1669272Z ##[debug]..=> Object
2022-06-16T17:49:28.1669915Z ##[debug]..Evaluating String:
2022-06-16T17:49:28.1670347Z ##[debug]..=> 'TestingDomain'
2022-06-16T17:49:28.1671016Z ##[debug]=> '***'
2022-06-16T17:49:28.1671500Z ##[debug]Result: '***'
2022-06-16T17:49:28.1672351Z ##[debug]Evaluating: secrets.TEST_DNS_NO_WILDCARD
2022-06-16T17:49:28.1672790Z ##[debug]Evaluating Index:
2022-06-16T17:49:28.1673484Z ##[debug]..Evaluating secrets:
2022-06-16T17:49:28.1673959Z ##[debug]..=> Object
2022-06-16T17:49:28.1674355Z ##[debug]..Evaluating String:
2022-06-16T17:49:28.1674810Z ##[debug]..=> 'TEST_DNS_NO_WILDCARD'
2022-06-16T17:49:28.1675226Z ##[debug]=> null
2022-06-16T17:49:28.1675596Z ##[debug]Result: null
2022-06-16T17:49:28.1678886Z ##[debug]Evaluating: secrets.TEST_DNS_NO_SUBDOMAIN
2022-06-16T17:49:28.1679636Z ##[debug]Evaluating Index:
2022-06-16T17:49:28.1680266Z ##[debug]..Evaluating secrets:
2022-06-16T17:49:28.1680685Z ##[debug]..=> Object
2022-06-16T17:49:28.1681568Z ##[debug]..Evaluating String:
2022-06-16T17:49:28.1682036Z ##[debug]..=> 'TEST_DNS_NO_SUBDOMAIN'
2022-06-16T17:49:28.1682468Z ##[debug]=> null
2022-06-16T17:49:28.1683350Z ##[debug]Result: null
2022-06-16T17:49:28.1684773Z ##[debug]Evaluating: secrets.TEST_DNS_SLEEP
2022-06-16T17:49:28.1685298Z ##[debug]Evaluating Index:
2022-06-16T17:49:28.1685694Z ##[debug]..Evaluating secrets:
2022-06-16T17:49:28.1686359Z ##[debug]..=> Object
2022-06-16T17:49:28.1686785Z ##[debug]..Evaluating String:
2022-06-16T17:49:28.1687190Z ##[debug]..=> 'TEST_DNS_SLEEP'
2022-06-16T17:49:28.1687737Z ##[debug]=> '***'
2022-06-16T17:49:28.1688227Z ##[debug]Result: '***'
2022-06-16T17:49:28.1707905Z ##[debug]Evaluating job container
2022-06-16T17:49:28.1711228Z ##[debug]Evaluating job service containers
2022-06-16T17:49:28.1714844Z ##[debug]Evaluating job defaults
2022-06-16T17:49:28.1805412Z Prepare all required actions
2022-06-16T17:49:28.2028563Z Getting action download info
2022-06-16T17:49:28.4171646Z Download action repository 'actions/checkout@v2' (SHA:7884fcad6b5d53d10323aee724dc68d8b9096a2e)
2022-06-16T17:49:28.5771083Z ##[debug]Download 'https://api.github.com/repos/actions/checkout/tarball/7884fcad6b5d53d10323aee724dc68d8b9096a2e' to '/home/runner/work/_actions/_temp_3555fa52-bfc0-478d-aadd-b1a608b5a094/0309798b-32ed-467d-9a1a-9db8476fe58c.tar.gz'
2022-06-16T17:49:28.7369315Z ##[debug]Unwrap 'actions-checkout-7884fca' to '/home/runner/work/_actions/actions/checkout/v2'
2022-06-16T17:49:28.7598066Z ##[debug]Archive '/home/runner/work/_actions/_temp_3555fa52-bfc0-478d-aadd-b1a608b5a094/0309798b-32ed-467d-9a1a-9db8476fe58c.tar.gz' has been unzipped into '/home/runner/work/_actions/actions/checkout/v2'.
2022-06-16T17:49:28.7834034Z ##[debug]action.yml for action: '/home/runner/work/_actions/actions/checkout/v2/action.yml'.
2022-06-16T17:49:28.8917286Z ##[debug]Set step '__actions_checkout' display name to: 'Run actions/checkout@v2'
2022-06-16T17:49:28.8920071Z ##[debug]Set step '__run' display name to: 'Clone acmetest'
2022-06-16T17:49:28.8921849Z ##[debug]Set step '__run_2' display name to: 'Set env file'
2022-06-16T17:49:28.8936711Z ##[debug]Set step '__run_3' display name to: 'Run acmetest'
2022-06-16T17:49:28.8956561Z ##[debug]Collect running processes for tracking orphan processes.
2022-06-16T17:49:28.9264753Z ##[debug]Finishing: Set up job
2022-06-16T17:49:28.9523255Z ##[debug]Evaluating condition for step: 'Run actions/checkout@v2'
2022-06-16T17:49:28.9570209Z ##[debug]Evaluating: success()
2022-06-16T17:49:28.9572083Z ##[debug]Evaluating success:
2022-06-16T17:49:28.9590918Z ##[debug]=> true
2022-06-16T17:49:28.9595670Z ##[debug]Result: true
2022-06-16T17:49:28.9623009Z ##[debug]Starting: Run actions/checkout@v2
2022-06-16T17:49:28.9777772Z ##[debug]Register post job cleanup for action: actions/checkout@v2
2022-06-16T17:49:28.9917947Z ##[debug]Loading inputs
2022-06-16T17:49:28.9925357Z ##[debug]Evaluating: github.repository
2022-06-16T17:49:28.9926366Z ##[debug]Evaluating Index:
2022-06-16T17:49:28.9927876Z ##[debug]..Evaluating github:
2022-06-16T17:49:28.9928514Z ##[debug]..=> Object
2022-06-16T17:49:28.9929056Z ##[debug]..Evaluating String:
2022-06-16T17:49:28.9929786Z ##[debug]..=> 'repository'
2022-06-16T17:49:28.9931133Z ##[debug]=> 'Eagle3386/acme.sh'
2022-06-16T17:49:28.9931721Z ##[debug]Result: 'Eagle3386/acme.sh'
2022-06-16T17:49:28.9934912Z ##[debug]Evaluating: github.token
2022-06-16T17:49:28.9935436Z ##[debug]Evaluating Index:
2022-06-16T17:49:28.9935940Z ##[debug]..Evaluating github:
2022-06-16T17:49:28.9936576Z ##[debug]..=> Object
2022-06-16T17:49:28.9948810Z ##[debug]..Evaluating String:
2022-06-16T17:49:28.9949686Z ##[debug]..=> 'token'
2022-06-16T17:49:28.9950913Z ##[debug]=> '***'
2022-06-16T17:49:28.9951753Z ##[debug]Result: '***'
2022-06-16T17:49:28.9964849Z ##[debug]Loading env
2022-06-16T17:49:29.0294337Z ##[group]Run actions/checkout@v2
2022-06-16T17:49:29.0294726Z with:
2022-06-16T17:49:29.0295237Z   repository: Eagle3386/acme.sh
2022-06-16T17:49:29.0295850Z   token: ***
2022-06-16T17:49:29.0296183Z   ssh-strict: true
2022-06-16T17:49:29.0296563Z   persist-credentials: true
2022-06-16T17:49:29.0296909Z   clean: true
2022-06-16T17:49:29.0297507Z   fetch-depth: 1
2022-06-16T17:49:29.0297819Z   lfs: false
2022-06-16T17:49:29.0298311Z   submodules: false
2022-06-16T17:49:29.0298683Z   set-safe-directory: true
2022-06-16T17:49:29.0299037Z env:
2022-06-16T17:49:29.0299430Z   TEST_DNS: ***
2022-06-16T17:49:29.0299869Z   TestingDomain: ***
2022-06-16T17:49:29.0300240Z   TEST_DNS_NO_WILDCARD: 
2022-06-16T17:49:29.0300604Z   TEST_DNS_NO_SUBDOMAIN: 
2022-06-16T17:49:29.0300986Z   TEST_DNS_SLEEP: ***
2022-06-16T17:49:29.0301342Z   CASE: le_test_dnsapi
2022-06-16T17:49:29.0301670Z   TEST_LOCAL: 1
2022-06-16T17:49:29.0301974Z   DEBUG: 1
2022-06-16T17:49:29.0302460Z ##[endgroup]
2022-06-16T17:49:29.3360642Z ::save-state name=isPost::true
2022-06-16T17:49:29.3364851Z ##[debug]Save intra-action state isPost = true
2022-06-16T17:49:29.3938834Z ##[debug]GITHUB_WORKSPACE = '/home/runner/work/acme.sh/acme.sh'
2022-06-16T17:49:29.3945351Z ##[debug]qualified repository = 'Eagle3386/acme.sh'
2022-06-16T17:49:29.3946161Z ##[debug]ref = 'refs/heads/master'
2022-06-16T17:49:29.3946956Z ##[debug]commit = 'edc76795d48e06f09d6a991171b29c6288a3d939'
2022-06-16T17:49:29.3947640Z ##[debug]clean = true
2022-06-16T17:49:29.3948265Z ##[debug]fetch depth = 1
2022-06-16T17:49:29.3948879Z ##[debug]lfs = false
2022-06-16T17:49:29.3949489Z ##[debug]submodules = false
2022-06-16T17:49:29.3950145Z ##[debug]recursive submodules = false
2022-06-16T17:49:29.4074214Z ::add-matcher::/home/runner/work/_actions/actions/checkout/v2/dist/problem-matcher.json
2022-06-16T17:49:29.4219318Z ##[debug]Added matchers: 'checkout-git'. Problem matchers scan action output for known warning or error strings and report these inline.
2022-06-16T17:49:29.4235458Z Syncing repository: Eagle3386/acme.sh
2022-06-16T17:49:29.4236902Z ::group::Getting Git version info
2022-06-16T17:49:29.4238887Z ##[group]Getting Git version info
2022-06-16T17:49:29.4239716Z Working directory is '/home/runner/work/acme.sh/acme.sh'
2022-06-16T17:49:29.4251434Z ##[debug]Getting git version
2022-06-16T17:49:29.4252328Z [command]/usr/bin/git version
2022-06-16T17:49:29.4355077Z git version 2.36.1
2022-06-16T17:49:29.4383381Z ##[debug]Set git useragent to: git/2.36.1 (github-actions-checkout)
2022-06-16T17:49:29.4386064Z ::endgroup::
2022-06-16T17:49:29.4386617Z ##[endgroup]
2022-06-16T17:49:29.4409127Z ::add-mask::***
2022-06-16T17:49:29.4411546Z Temporarily overriding HOME='/home/runner/work/_temp/2e3eb20d-037b-4f0a-b689-5a8aa5109e20' before making global git config changes
2022-06-16T17:49:29.4412849Z Adding repository directory to the temporary git global config as a safe directory
2022-06-16T17:49:29.4414190Z [command]/usr/bin/git config --global --add safe.directory /home/runner/work/acme.sh/acme.sh
2022-06-16T17:49:29.4454821Z ::save-state name=setSafeDirectory::true
2022-06-16T17:49:29.4455431Z ##[debug]Save intra-action state setSafeDirectory = true
2022-06-16T17:49:29.4462961Z Deleting the contents of '/home/runner/work/acme.sh/acme.sh'
2022-06-16T17:49:29.4467400Z ::save-state name=repositoryPath::/home/runner/work/acme.sh/acme.sh
2022-06-16T17:49:29.4468037Z ##[debug]Save intra-action state repositoryPath = /home/runner/work/acme.sh/acme.sh
2022-06-16T17:49:29.4469396Z ::group::Initializing the repository
2022-06-16T17:49:29.4469874Z ##[group]Initializing the repository
2022-06-16T17:49:29.4473811Z [command]/usr/bin/git init /home/runner/work/acme.sh/acme.sh
2022-06-16T17:49:29.4584506Z hint: Using 'master' as the name for the initial branch. This default branch name
2022-06-16T17:49:29.4585573Z hint: is subject to change. To configure the initial branch name to use in all
2022-06-16T17:49:29.4586338Z hint: of your new repositories, which will suppress this warning, call:
2022-06-16T17:49:29.4590017Z hint: 
2022-06-16T17:49:29.4591729Z hint:  git config --global init.defaultBranch <name>
2022-06-16T17:49:29.4592461Z hint: 
2022-06-16T17:49:29.4594123Z hint: Names commonly chosen instead of 'master' are 'main', 'trunk' and
2022-06-16T17:49:29.4595169Z hint: 'development'. The just-created branch can be renamed via this command:
2022-06-16T17:49:29.4596859Z hint: 
2022-06-16T17:49:29.4597600Z hint:  git branch -m <name>
2022-06-16T17:49:29.4599082Z Initialized empty Git repository in /home/runner/work/acme.sh/acme.sh/.git/
2022-06-16T17:49:29.4667723Z [command]/usr/bin/git remote add origin https://github.com/Eagle3386/acme.sh
2022-06-16T17:49:29.4727517Z ::endgroup::
2022-06-16T17:49:29.4727879Z ##[endgroup]
2022-06-16T17:49:29.4729209Z ::group::Disabling automatic garbage collection
2022-06-16T17:49:29.4729747Z ##[group]Disabling automatic garbage collection
2022-06-16T17:49:29.4733945Z [command]/usr/bin/git config --local gc.auto 0
2022-06-16T17:49:29.4773411Z ::endgroup::
2022-06-16T17:49:29.4773739Z ##[endgroup]
2022-06-16T17:49:29.4774783Z ::group::Setting up auth
2022-06-16T17:49:29.4775122Z ##[group]Setting up auth
2022-06-16T17:49:29.4783734Z [command]/usr/bin/git config --local --name-only --get-regexp core\.sshCommand
2022-06-16T17:49:29.4826112Z [command]/usr/bin/git submodule foreach --recursive git config --local --name-only --get-regexp 'core\.sshCommand' && git config --local --unset-all 'core.sshCommand' || :
2022-06-16T17:49:29.5315796Z [command]/usr/bin/git config --local --name-only --get-regexp http\.https\:\/\/github\.com\/\.extraheader
2022-06-16T17:49:29.5354681Z [command]/usr/bin/git submodule foreach --recursive git config --local --name-only --get-regexp 'http\.https\:\/\/github\.com\/\.extraheader' && git config --local --unset-all 'http.https://github.com/.extraheader' || :
2022-06-16T17:49:29.5654630Z [command]/usr/bin/git config --local http.https://github.com/.extraheader AUTHORIZATION: basic ***
2022-06-16T17:49:29.5695810Z ::endgroup::
2022-06-16T17:49:29.5696193Z ##[endgroup]
2022-06-16T17:49:29.5697400Z ::group::Fetching the repository
2022-06-16T17:49:29.5698049Z ##[group]Fetching the repository
2022-06-16T17:49:29.5708716Z [command]/usr/bin/git -c protocol.version=2 fetch --no-tags --prune --progress --no-recurse-submodules --depth=1 origin +edc76795d48e06f09d6a991171b29c6288a3d939:refs/remotes/origin/master
2022-06-16T17:49:29.7758644Z remote: Enumerating objects: 214, done.        
2022-06-16T17:49:29.7797115Z remote: Counting objects:   0% (1/214)        
2022-06-16T17:49:29.7798111Z remote: Counting objects:   1% (3/214)        
2022-06-16T17:49:29.7802918Z remote: Counting objects:   2% (5/214)        
2022-06-16T17:49:29.7803344Z remote: Counting objects:   3% (7/214)        
2022-06-16T17:49:29.7803705Z remote: Counting objects:   4% (9/214)        
2022-06-16T17:49:29.7804066Z remote: Counting objects:   5% (11/214)        
2022-06-16T17:49:29.7804428Z remote: Counting objects:   6% (13/214)        
2022-06-16T17:49:29.7804789Z remote: Counting objects:   7% (15/214)        
2022-06-16T17:49:29.7806032Z remote: Counting objects:   8% (18/214)        
2022-06-16T17:49:29.7807139Z remote: Counting objects:   9% (20/214)        
2022-06-16T17:49:29.7808792Z remote: Counting objects:  10% (22/214)        
2022-06-16T17:49:29.7809220Z remote: Counting objects:  11% (24/214)        
2022-06-16T17:49:29.7809598Z remote: Counting objects:  12% (26/214)        
2022-06-16T17:49:29.7809951Z remote: Counting objects:  13% (28/214)        
2022-06-16T17:49:29.7810310Z remote: Counting objects:  14% (30/214)        
2022-06-16T17:49:29.7811431Z remote: Counting objects:  15% (33/214)        
2022-06-16T17:49:29.7811823Z remote: Counting objects:  16% (35/214)        
2022-06-16T17:49:29.7812173Z remote: Counting objects:  17% (37/214)        
2022-06-16T17:49:29.7812523Z remote: Counting objects:  18% (39/214)        
2022-06-16T17:49:29.7812877Z remote: Counting objects:  19% (41/214)        
2022-06-16T17:49:29.7813318Z remote: Counting objects:  20% (43/214)        
2022-06-16T17:49:29.7813675Z remote: Counting objects:  21% (45/214)        
2022-06-16T17:49:29.7814021Z remote: Counting objects:  22% (48/214)        
2022-06-16T17:49:29.7814387Z remote: Counting objects:  23% (50/214)        
2022-06-16T17:49:29.7814738Z remote: Counting objects:  24% (52/214)        
2022-06-16T17:49:29.7815086Z remote: Counting objects:  25% (54/214)        
2022-06-16T17:49:29.7815813Z remote: Counting objects:  26% (56/214)        
2022-06-16T17:49:29.7816162Z remote: Counting objects:  27% (58/214)        
2022-06-16T17:49:29.7816541Z remote: Counting objects:  28% (60/214)        
2022-06-16T17:49:29.7816892Z remote: Counting objects:  29% (63/214)        
2022-06-16T17:49:29.7818226Z remote: Counting objects:  30% (65/214)        
2022-06-16T17:49:29.7818668Z remote: Counting objects:  31% (67/214)        
2022-06-16T17:49:29.7819021Z remote: Counting objects:  32% (69/214)        
2022-06-16T17:49:29.7819373Z remote: Counting objects:  33% (71/214)        
2022-06-16T17:49:29.7820223Z remote: Counting objects:  34% (73/214)        
2022-06-16T17:49:29.7820593Z remote: Counting objects:  35% (75/214)        
2022-06-16T17:49:29.7821403Z remote: Counting objects:  36% (78/214)        
2022-06-16T17:49:29.7821772Z remote: Counting objects:  37% (80/214)        
2022-06-16T17:49:29.7822138Z remote: Counting objects:  38% (82/214)        
2022-06-16T17:49:29.7822503Z remote: Counting objects:  39% (84/214)        
2022-06-16T17:49:29.7822849Z remote: Counting objects:  40% (86/214)        
2022-06-16T17:49:29.7823203Z remote: Counting objects:  41% (88/214)        
2022-06-16T17:49:29.7823551Z remote: Counting objects:  42% (90/214)        
2022-06-16T17:49:29.7823972Z remote: Counting objects:  43% (93/214)        
2022-06-16T17:49:29.7824384Z remote: Counting objects:  44% (95/214)        
2022-06-16T17:49:29.7824980Z remote: Counting objects:  45% (97/214)        
2022-06-16T17:49:29.7825449Z remote: Counting objects:  46% (99/214)        
2022-06-16T17:49:29.7825820Z remote: Counting objects:  47% (101/214)        
2022-06-16T17:49:29.7826179Z remote: Counting objects:  48% (103/214)        
2022-06-16T17:49:29.7827584Z remote: Counting objects:  49% (105/214)        
2022-06-16T17:49:29.7828030Z remote: Counting objects:  50% (107/214)        
2022-06-16T17:49:29.7828388Z remote: Counting objects:  51% (110/214)        
2022-06-16T17:49:29.7828754Z remote: Counting objects:  52% (112/214)        
2022-06-16T17:49:29.7829231Z remote: Counting objects:  53% (114/214)        
2022-06-16T17:49:29.7829927Z remote: Counting objects:  54% (116/214)        
2022-06-16T17:49:29.7830389Z remote: Counting objects:  55% (118/214)        
2022-06-16T17:49:29.7830734Z remote: Counting objects:  56% (120/214)        
2022-06-16T17:49:29.7831081Z remote: Counting objects:  57% (122/214)        
2022-06-16T17:49:29.7831427Z remote: Counting objects:  58% (125/214)        
2022-06-16T17:49:29.7831771Z remote: Counting objects:  59% (127/214)        
2022-06-16T17:49:29.7832117Z remote: Counting objects:  60% (129/214)        
2022-06-16T17:49:29.7832564Z remote: Counting objects:  61% (131/214)        
2022-06-16T17:49:29.7833136Z remote: Counting objects:  62% (133/214)        
2022-06-16T17:49:29.7833515Z remote: Counting objects:  63% (135/214)        
2022-06-16T17:49:29.7833919Z remote: Counting objects:  64% (137/214)        
2022-06-16T17:49:29.7834368Z remote: Counting objects:  65% (140/214)        
2022-06-16T17:49:29.7834740Z remote: Counting objects:  66% (142/214)        
2022-06-16T17:49:29.7835092Z remote: Counting objects:  67% (144/214)        
2022-06-16T17:49:29.7835441Z remote: Counting objects:  68% (146/214)        
2022-06-16T17:49:29.7835787Z remote: Counting objects:  69% (148/214)        
2022-06-16T17:49:29.7836201Z remote: Counting objects:  70% (150/214)        
2022-06-16T17:49:29.7836551Z remote: Counting objects:  71% (152/214)        
2022-06-16T17:49:29.7836898Z remote: Counting objects:  72% (155/214)        
2022-06-16T17:49:29.7837246Z remote: Counting objects:  73% (157/214)        
2022-06-16T17:49:29.7837611Z remote: Counting objects:  74% (159/214)        
2022-06-16T17:49:29.7837956Z remote: Counting objects:  75% (161/214)        
2022-06-16T17:49:29.7838561Z remote: Counting objects:  76% (163/214)        
2022-06-16T17:49:29.7838892Z remote: Counting objects:  77% (165/214)        
2022-06-16T17:49:29.7839226Z remote: Counting objects:  78% (167/214)        
2022-06-16T17:49:29.7839715Z remote: Counting objects:  79% (170/214)        
2022-06-16T17:49:29.7840052Z remote: Counting objects:  80% (172/214)        
2022-06-16T17:49:29.7840386Z remote: Counting objects:  81% (174/214)        
2022-06-16T17:49:29.7840895Z remote: Counting objects:  82% (176/214)        
2022-06-16T17:49:29.7841216Z remote: Counting objects:  83% (178/214)        
2022-06-16T17:49:29.7843295Z remote: Counting objects:  84% (***/214)        
2022-06-16T17:49:29.7843743Z remote: Counting objects:  85% (182/214)        
2022-06-16T17:49:29.7844095Z remote: Counting objects:  86% (185/214)        
2022-06-16T17:49:29.7846011Z remote: Counting objects:  87% (187/214)        
2022-06-16T17:49:29.7846543Z remote: Counting objects:  88% (189/214)        
2022-06-16T17:49:29.7846896Z remote: Counting objects:  89% (191/214)        
2022-06-16T17:49:29.7847367Z remote: Counting objects:  90% (193/214)        
2022-06-16T17:49:29.7847714Z remote: Counting objects:  91% (195/214)        
2022-06-16T17:49:29.7848075Z remote: Counting objects:  92% (197/214)        
2022-06-16T17:49:29.7848429Z remote: Counting objects:  93% (200/214)        
2022-06-16T17:49:29.7848778Z remote: Counting objects:  94% (202/214)        
2022-06-16T17:49:29.7849131Z remote: Counting objects:  95% (204/214)        
2022-06-16T17:49:29.7849498Z remote: Counting objects:  96% (206/214)        
2022-06-16T17:49:29.7849841Z remote: Counting objects:  97% (208/214)        
2022-06-16T17:49:29.7850188Z remote: Counting objects:  98% (210/214)        
2022-06-16T17:49:29.7850540Z remote: Counting objects:  99% (212/214)        
2022-06-16T17:49:29.7850886Z remote: Counting objects: 100% (214/214)        
2022-06-16T17:49:29.7851254Z remote: Counting objects: 100% (214/214), done.        
2022-06-16T17:49:29.7851650Z remote: Compressing objects:   0% (1/212)        
2022-06-16T17:49:29.7852038Z remote: Compressing objects:   1% (3/212)        
2022-06-16T17:49:29.7852402Z remote: Compressing objects:   2% (5/212)        
2022-06-16T17:49:29.7852774Z remote: Compressing objects:   3% (7/212)        
2022-06-16T17:49:29.7853343Z remote: Compressing objects:   4% (9/212)        
2022-06-16T17:49:29.7854536Z remote: Compressing objects:   5% (11/212)        
2022-06-16T17:49:29.7855093Z remote: Compressing objects:   6% (13/212)        
2022-06-16T17:49:29.7855473Z remote: Compressing objects:   7% (15/212)        
2022-06-16T17:49:29.7855941Z remote: Compressing objects:   8% (17/212)        
2022-06-16T17:49:29.7856328Z remote: Compressing objects:   9% (20/212)        
2022-06-16T17:49:29.7856698Z remote: Compressing objects:  10% (22/212)        
2022-06-16T17:49:29.7857795Z remote: Compressing objects:  11% (24/212)        
2022-06-16T17:49:29.7859364Z remote: Compressing objects:  12% (26/212)        
2022-06-16T17:49:29.7860822Z remote: Compressing objects:  13% (28/212)        
2022-06-16T17:49:29.7863549Z remote: Compressing objects:  14% (30/212)        
2022-06-16T17:49:29.7864330Z remote: Compressing objects:  15% (32/212)        
2022-06-16T17:49:29.7864754Z remote: Compressing objects:  16% (34/212)        
2022-06-16T17:49:29.7866849Z remote: Compressing objects:  17% (37/212)        
2022-06-16T17:49:29.7867254Z remote: Compressing objects:  18% (39/212)        
2022-06-16T17:49:29.7868069Z remote: Compressing objects:  19% (41/212)        
2022-06-16T17:49:29.7868851Z remote: Compressing objects:  20% (43/212)        
2022-06-16T17:49:29.7875168Z remote: Compressing objects:  21% (45/212)        
2022-06-16T17:49:29.7880587Z remote: Compressing objects:  22% (47/212)        
2022-06-16T17:49:29.7881461Z remote: Compressing objects:  23% (49/212)        
2022-06-16T17:49:29.7885412Z remote: Compressing objects:  24% (51/212)        
2022-06-16T17:49:29.7899740Z remote: Compressing objects:  25% (53/212)        
2022-06-16T17:49:29.7904366Z remote: Compressing objects:  26% (56/212)        
2022-06-16T17:49:29.7905084Z remote: Compressing objects:  27% (58/212)        
2022-06-16T17:49:29.7908924Z remote: Compressing objects:  28% (60/212)        
2022-06-16T17:49:29.7917635Z remote: Compressing objects:  29% (62/212)        
2022-06-16T17:49:29.7928699Z remote: Compressing objects:  30% (64/212)        
2022-06-16T17:49:29.7930715Z remote: Compressing objects:  31% (66/212)        
2022-06-16T17:49:29.7942424Z remote: Compressing objects:  32% (68/212)        
2022-06-16T17:49:29.7948596Z remote: Compressing objects:  33% (70/212)        
2022-06-16T17:49:29.7959686Z remote: Compressing objects:  34% (73/212)        
2022-06-16T17:49:29.7961357Z remote: Compressing objects:  35% (75/212)        
2022-06-16T17:49:29.7962853Z remote: Compressing objects:  36% (77/212)        
2022-06-16T17:49:29.7970245Z remote: Compressing objects:  37% (79/212)        
2022-06-16T17:49:29.7984862Z remote: Compressing objects:  38% (81/212)        
2022-06-16T17:49:29.7989443Z remote: Compressing objects:  39% (83/212)        
2022-06-16T17:49:29.7997779Z remote: Compressing objects:  40% (85/212)        
2022-06-16T17:49:29.8004213Z remote: Compressing objects:  41% (87/212)        
2022-06-16T17:49:29.8004874Z remote: Compressing objects:  42% (90/212)        
2022-06-16T17:49:29.8006736Z remote: Compressing objects:  43% (92/212)        
2022-06-16T17:49:29.8017377Z remote: Compressing objects:  44% (94/212)        
2022-06-16T17:49:29.8101755Z remote: Compressing objects:  45% (96/212)        
2022-06-16T17:49:29.8103917Z remote: Compressing objects:  46% (98/212)        
2022-06-16T17:49:29.8105640Z remote: Compressing objects:  47% (100/212)        
2022-06-16T17:49:29.8106983Z remote: Compressing objects:  48% (102/212)        
2022-06-16T17:49:29.8108351Z remote: Compressing objects:  49% (104/212)        
2022-06-16T17:49:29.8109152Z remote: Compressing objects:  50% (106/212)        
2022-06-16T17:49:29.8109627Z remote: Compressing objects:  51% (109/212)        
2022-06-16T17:49:29.8110025Z remote: Compressing objects:  52% (111/212)        
2022-06-16T17:49:29.8110510Z remote: Compressing objects:  53% (113/212)        
2022-06-16T17:49:29.8111403Z remote: Compressing objects:  54% (115/212)        
2022-06-16T17:49:29.8112428Z remote: Compressing objects:  55% (117/212)        
2022-06-16T17:49:29.8113184Z remote: Compressing objects:  56% (119/212)        
2022-06-16T17:49:29.8113730Z remote: Compressing objects:  57% (121/212)        
2022-06-16T17:49:29.8122667Z remote: Compressing objects:  58% (123/212)        
2022-06-16T17:49:29.8125363Z remote: Compressing objects:  59% (126/212)        
2022-06-16T17:49:29.8126757Z remote: Compressing objects:  60% (128/212)        
2022-06-16T17:49:29.8127457Z remote: Compressing objects:  61% (130/212)        
2022-06-16T17:49:29.8128817Z remote: Compressing objects:  62% (132/212)        
2022-06-16T17:49:29.8130107Z remote: Compressing objects:  63% (134/212)        
2022-06-16T17:49:29.8130677Z remote: Compressing objects:  64% (136/212)        
2022-06-16T17:49:29.8131603Z remote: Compressing objects:  65% (138/212)        
2022-06-16T17:49:29.8138551Z remote: Compressing objects:  66% (140/212)        
2022-06-16T17:49:29.8149625Z remote: Compressing objects:  67% (143/212)        
2022-06-16T17:49:29.8163217Z remote: Compressing objects:  68% (145/212)        
2022-06-16T17:49:29.8168056Z remote: Compressing objects:  69% (147/212)        
2022-06-16T17:49:29.8178085Z remote: Compressing objects:  70% (149/212)        
2022-06-16T17:49:29.8179115Z remote: Compressing objects:  71% (151/212)        
2022-06-16T17:49:29.8187036Z remote: Compressing objects:  72% (153/212)        
2022-06-16T17:49:29.8227888Z remote: Compressing objects:  73% (155/212)        
2022-06-16T17:49:29.8228690Z remote: Compressing objects:  74% (157/212)        
2022-06-16T17:49:29.8230139Z remote: Compressing objects:  75% (159/212)        
2022-06-16T17:49:29.8231450Z remote: Compressing objects:  76% (162/212)        
2022-06-16T17:49:29.8232023Z remote: Compressing objects:  77% (164/212)        
2022-06-16T17:49:29.8233869Z remote: Compressing objects:  78% (166/212)        
2022-06-16T17:49:29.8234869Z remote: Compressing objects:  79% (168/212)        
2022-06-16T17:49:29.8235334Z remote: Compressing objects:  80% (170/212)        
2022-06-16T17:49:29.8236372Z remote: Compressing objects:  81% (172/212)        
2022-06-16T17:49:29.8268261Z remote: Compressing objects:  82% (174/212)        
2022-06-16T17:49:29.8269018Z remote: Compressing objects:  83% (176/212)        
2022-06-16T17:49:29.8280271Z remote: Compressing objects:  84% (179/212)        
2022-06-16T17:49:29.8299072Z remote: Compressing objects:  85% (181/212)        
2022-06-16T17:49:29.8304414Z remote: Compressing objects:  86% (183/212)        
2022-06-16T17:49:29.8310373Z remote: Compressing objects:  87% (185/212)        
2022-06-16T17:49:29.8321234Z remote: Compressing objects:  88% (187/212)        
2022-06-16T17:49:29.8321827Z remote: Compressing objects:  89% (189/212)        
2022-06-16T17:49:29.8329179Z remote: Compressing objects:  90% (191/212)        
2022-06-16T17:49:29.8351345Z remote: Compressing objects:  91% (193/212)        
2022-06-16T17:49:29.8352148Z remote: Compressing objects:  92% (196/212)        
2022-06-16T17:49:29.8356552Z remote: Compressing objects:  93% (198/212)        
2022-06-16T17:49:29.8357261Z remote: Compressing objects:  94% (200/212)        
2022-06-16T17:49:29.8358614Z remote: Compressing objects:  95% (202/212)        
2022-06-16T17:49:29.8360531Z remote: Compressing objects:  96% (204/212)        
2022-06-16T17:49:29.8361256Z remote: Compressing objects:  97% (206/212)        
2022-06-16T17:49:29.8362439Z remote: Compressing objects:  98% (208/212)        
2022-06-16T17:49:29.8363859Z remote: Compressing objects:  99% (210/212)        
2022-06-16T17:49:29.8364476Z remote: Compressing objects: 100% (212/212)        
2022-06-16T17:49:29.8365492Z remote: Compressing objects: 100% (212/212), done.        
2022-06-16T17:49:29.8419489Z Receiving objects:   0% (1/214)
2022-06-16T17:49:29.8421603Z Receiving objects:   1% (3/214)
2022-06-16T17:49:29.8422131Z Receiving objects:   2% (5/214)
2022-06-16T17:49:29.8424867Z Receiving objects:   3% (7/214)
2022-06-16T17:49:29.8428100Z Receiving objects:   4% (9/214)
2022-06-16T17:49:29.8428921Z Receiving objects:   5% (11/214)
2022-06-16T17:49:29.8429512Z Receiving objects:   6% (13/214)
2022-06-16T17:49:29.8431968Z Receiving objects:   7% (15/214)
2022-06-16T17:49:29.8471522Z Receiving objects:   8% (18/214)
2022-06-16T17:49:29.8496069Z Receiving objects:   9% (20/214)
2022-06-16T17:49:29.8498232Z Receiving objects:  10% (22/214)
2022-06-16T17:49:29.8498787Z Receiving objects:  11% (24/214)
2022-06-16T17:49:29.8504900Z Receiving objects:  12% (26/214)
2022-06-16T17:49:29.8507750Z Receiving objects:  13% (28/214)
2022-06-16T17:49:29.8508794Z Receiving objects:  14% (30/214)
2022-06-16T17:49:29.8509964Z Receiving objects:  15% (33/214)
2022-06-16T17:49:29.8510355Z Receiving objects:  16% (35/214)
2022-06-16T17:49:29.8513668Z Receiving objects:  17% (37/214)
2022-06-16T17:49:29.8514916Z Receiving objects:  18% (39/214)
2022-06-16T17:49:29.8515470Z Receiving objects:  19% (41/214)
2022-06-16T17:49:29.8515780Z Receiving objects:  20% (43/214)
2022-06-16T17:49:29.8521477Z Receiving objects:  21% (45/214)
2022-06-16T17:49:29.8524165Z Receiving objects:  22% (48/214)
2022-06-16T17:49:29.8524516Z Receiving objects:  23% (50/214)
2022-06-16T17:49:29.8524986Z Receiving objects:  24% (52/214)
2022-06-16T17:49:29.8526223Z Receiving objects:  25% (54/214)
2022-06-16T17:49:29.8530567Z Receiving objects:  26% (56/214)
2022-06-16T17:49:29.8530934Z Receiving objects:  27% (58/214)
2022-06-16T17:49:29.8531257Z Receiving objects:  28% (60/214)
2022-06-16T17:49:29.8531576Z Receiving objects:  29% (63/214)
2022-06-16T17:49:29.8536419Z Receiving objects:  30% (65/214)
2022-06-16T17:49:29.8536787Z Receiving objects:  31% (67/214)
2022-06-16T17:49:29.8537111Z Receiving objects:  32% (69/214)
2022-06-16T17:49:29.8537434Z Receiving objects:  33% (71/214)
2022-06-16T17:49:29.8542007Z Receiving objects:  34% (73/214)
2022-06-16T17:49:29.8542583Z Receiving objects:  35% (75/214)
2022-06-16T17:49:29.8550621Z Receiving objects:  36% (78/214)
2022-06-16T17:49:29.8551129Z Receiving objects:  37% (80/214)
2022-06-16T17:49:29.8551485Z Receiving objects:  38% (82/214)
2022-06-16T17:49:29.8554517Z Receiving objects:  39% (84/214)
2022-06-16T17:49:29.8554868Z Receiving objects:  40% (86/214)
2022-06-16T17:49:29.8555203Z Receiving objects:  41% (88/214)
2022-06-16T17:49:29.8555545Z Receiving objects:  42% (90/214)
2022-06-16T17:49:29.8555954Z Receiving objects:  43% (93/214)
2022-06-16T17:49:29.8556444Z Receiving objects:  44% (95/214)
2022-06-16T17:49:29.8559790Z Receiving objects:  45% (97/214)
2022-06-16T17:49:29.8560311Z Receiving objects:  46% (99/214)
2022-06-16T17:49:29.8563926Z Receiving objects:  47% (101/214)
2022-06-16T17:49:29.8564976Z Receiving objects:  48% (103/214)
2022-06-16T17:49:29.8569207Z Receiving objects:  49% (105/214)
2022-06-16T17:49:29.8569741Z Receiving objects:  50% (107/214)
2022-06-16T17:49:29.8574439Z Receiving objects:  51% (110/214)
2022-06-16T17:49:29.8574817Z Receiving objects:  52% (112/214)
2022-06-16T17:49:29.8577957Z Receiving objects:  53% (114/214)
2022-06-16T17:49:29.8578346Z Receiving objects:  54% (116/214)
2022-06-16T17:49:29.8588735Z Receiving objects:  55% (118/214)
2022-06-16T17:49:29.8589136Z Receiving objects:  56% (120/214)
2022-06-16T17:49:29.8589965Z Receiving objects:  57% (122/214)
2022-06-16T17:49:29.8590298Z Receiving objects:  58% (125/214)
2022-06-16T17:49:29.8590838Z Receiving objects:  59% (127/214)
2022-06-16T17:49:29.8599425Z Receiving objects:  60% (129/214)
2022-06-16T17:49:29.8601845Z Receiving objects:  61% (131/214)
2022-06-16T17:49:29.8606875Z Receiving objects:  62% (133/214)
2022-06-16T17:49:29.8607914Z Receiving objects:  63% (135/214)
2022-06-16T17:49:29.8608983Z Receiving objects:  64% (137/214)
2022-06-16T17:49:29.8609467Z Receiving objects:  65% (140/214)
2022-06-16T17:49:29.8610461Z Receiving objects:  66% (142/214)
2022-06-16T17:49:29.8611229Z Receiving objects:  67% (144/214)
2022-06-16T17:49:29.8629810Z Receiving objects:  68% (146/214)
2022-06-16T17:49:29.8630411Z Receiving objects:  69% (148/214)
2022-06-16T17:49:29.8631600Z Receiving objects:  70% (150/214)
2022-06-16T17:49:29.8633977Z Receiving objects:  71% (152/214)
2022-06-16T17:49:29.8634593Z Receiving objects:  72% (155/214)
2022-06-16T17:49:29.8635899Z Receiving objects:  73% (157/214)
2022-06-16T17:49:29.8637008Z Receiving objects:  74% (159/214)
2022-06-16T17:49:29.8637555Z Receiving objects:  75% (161/214)
2022-06-16T17:49:29.8638657Z Receiving objects:  76% (163/214)
2022-06-16T17:49:29.8643437Z Receiving objects:  77% (165/214)
2022-06-16T17:49:29.8643996Z Receiving objects:  78% (167/214)
2022-06-16T17:49:29.8647715Z Receiving objects:  79% (170/214)
2022-06-16T17:49:29.8649535Z Receiving objects:  80% (172/214)
2022-06-16T17:49:29.8654034Z Receiving objects:  81% (174/214)
2022-06-16T17:49:29.8654929Z Receiving objects:  82% (176/214)
2022-06-16T17:49:29.8656085Z Receiving objects:  83% (178/214)
2022-06-16T17:49:29.8658986Z Receiving objects:  84% (***/214)
2022-06-16T17:49:29.8659977Z remote: Total 214 (delta 21), reused 63 (delta 2), pack-reused 0        
2022-06-16T17:49:29.8663320Z Receiving objects:  85% (182/214)
2022-06-16T17:49:29.8665613Z Receiving objects:  86% (185/214)
2022-06-16T17:49:29.8670228Z Receiving objects:  87% (187/214)
2022-06-16T17:49:29.8670760Z Receiving objects:  88% (189/214)
2022-06-16T17:49:29.8672551Z Receiving objects:  89% (191/214)
2022-06-16T17:49:29.8673250Z Receiving objects:  90% (193/214)
2022-06-16T17:49:29.8674978Z Receiving objects:  91% (195/214)
2022-06-16T17:49:29.8676733Z Receiving objects:  92% (197/214)
2022-06-16T17:49:29.8708649Z Receiving objects:  93% (200/214)
2022-06-16T17:49:29.8709190Z Receiving objects:  94% (202/214)
2022-06-16T17:49:29.8709641Z Receiving objects:  95% (204/214)
2022-06-16T17:49:29.8710270Z Receiving objects:  96% (206/214)
2022-06-16T17:49:29.8710717Z Receiving objects:  97% (208/214)
2022-06-16T17:49:29.8714934Z Receiving objects:  98% (210/214)
2022-06-16T17:49:29.8716224Z Receiving objects:  99% (212/214)
2022-06-16T17:49:29.8718737Z Receiving objects: 100% (214/214)
2022-06-16T17:49:29.8719510Z Receiving objects: 100% (214/214), 340.93 KiB | 12.18 MiB/s, done.
2022-06-16T17:49:29.8720278Z Resolving deltas:   0% (0/21)
2022-06-16T17:49:29.8721274Z Resolving deltas:   4% (1/21)
2022-06-16T17:49:29.8721980Z Resolving deltas:   9% (2/21)
2022-06-16T17:49:29.8722822Z Resolving deltas:  14% (3/21)
2022-06-16T17:49:29.8723552Z Resolving deltas:  19% (4/21)
2022-06-16T17:49:29.8724316Z Resolving deltas:  23% (5/21)
2022-06-16T17:49:29.8724857Z Resolving deltas:  28% (6/21)
2022-06-16T17:49:29.8725616Z Resolving deltas:  33% (7/21)
2022-06-16T17:49:29.8726184Z Resolving deltas:  38% (8/21)
2022-06-16T17:49:29.8726941Z Resolving deltas:  42% (9/21)
2022-06-16T17:49:29.8727489Z Resolving deltas:  47% (10/21)
2022-06-16T17:49:29.8728613Z Resolving deltas:  52% (11/21)
2022-06-16T17:49:29.8729994Z Resolving deltas:  57% (12/21)
2022-06-16T17:49:29.8731269Z Resolving deltas:  61% (13/21)
2022-06-16T17:49:29.8732117Z Resolving deltas:  66% (14/21)
2022-06-16T17:49:29.8732776Z Resolving deltas:  71% (15/21)
2022-06-16T17:49:29.8733575Z Resolving deltas:  76% (16/21)
2022-06-16T17:49:29.8734229Z Resolving deltas:  80% (17/21)
2022-06-16T17:49:29.8734832Z Resolving deltas:  85% (18/21)
2022-06-16T17:49:29.8735450Z Resolving deltas:  90% (19/21)
2022-06-16T17:49:29.8736037Z Resolving deltas:  95% (20/21)
2022-06-16T17:49:29.8737319Z Resolving deltas: 100% (21/21)
2022-06-16T17:49:29.8737874Z Resolving deltas: 100% (21/21), done.
2022-06-16T17:49:29.8897411Z From https://github.com/Eagle3386/acme.sh
2022-06-16T17:49:29.8898723Z  * [new ref]         edc76795d48e06f09d6a991171b29c6288a3d939 -> origin/master
2022-06-16T17:49:29.8924291Z ::endgroup::
2022-06-16T17:49:29.8924642Z ##[endgroup]
2022-06-16T17:49:29.8925642Z ::group::Determining the checkout info
2022-06-16T17:49:29.8926021Z ##[group]Determining the checkout info
2022-06-16T17:49:29.8927636Z ::endgroup::
2022-06-16T17:49:29.8927922Z ##[endgroup]
2022-06-16T17:49:29.8928778Z ::group::Checking out the ref
2022-06-16T17:49:29.8929156Z ##[group]Checking out the ref
2022-06-16T17:49:29.8935495Z [command]/usr/bin/git checkout --progress --force -B master refs/remotes/origin/master
2022-06-16T17:49:29.9177227Z Reset branch 'master'
2022-06-16T17:49:29.9181067Z branch 'master' set up to track 'origin/master'.
2022-06-16T17:49:29.9184595Z ::endgroup::
2022-06-16T17:49:29.9184918Z ##[endgroup]
2022-06-16T17:49:29.9243343Z [command]/usr/bin/git log -1 --format='%H'
2022-06-16T17:49:29.9281232Z 'edc76795d48e06f09d6a991171b29c6288a3d939'
2022-06-16T17:49:29.9292938Z ##[debug]Unsetting HOME override
2022-06-16T17:49:29.9297668Z ::remove-matcher owner=checkout-git::
2022-06-16T17:49:29.9324632Z ##[debug]Removed matchers: 'checkout-git'
2022-06-16T17:49:29.9421887Z ##[debug]Node Action run completed with exit code 0
2022-06-16T17:49:29.9572591Z ##[debug]Finishing: Run actions/checkout@v2
2022-06-16T17:49:29.9583570Z ##[debug]Evaluating condition for step: 'Clone acmetest'
2022-06-16T17:49:29.9586890Z ##[debug]Evaluating: success()
2022-06-16T17:49:29.9587385Z ##[debug]Evaluating success:
2022-06-16T17:49:29.9588176Z ##[debug]=> true
2022-06-16T17:49:29.9588802Z ##[debug]Result: true
2022-06-16T17:49:29.9589931Z ##[debug]Starting: Clone acmetest
2022-06-16T17:49:29.9608325Z ##[debug]Loading inputs
2022-06-16T17:49:29.9616507Z ##[debug]Loading env
2022-06-16T17:49:29.9666586Z ##[group]Run cd .. && git clone https://github.com/acmesh-official/acmetest.git  && cp -r acme.sh acmetest/
2022-06-16T17:49:29.9667212Z cd .. && git clone https://github.com/acmesh-official/acmetest.git  && cp -r acme.sh acmetest/
2022-06-16T17:49:29.9737531Z shell: /usr/bin/bash -e {0}
2022-06-16T17:49:29.9737854Z env:
2022-06-16T17:49:29.9738275Z   TEST_DNS: ***
2022-06-16T17:49:29.9738645Z   TestingDomain: ***
2022-06-16T17:49:29.9738949Z   TEST_DNS_NO_WILDCARD: 
2022-06-16T17:49:29.9739638Z   TEST_DNS_NO_SUBDOMAIN: 
2022-06-16T17:49:29.9740915Z   TEST_DNS_SLEEP: ***
2022-06-16T17:49:29.9741492Z   CASE: le_test_dnsapi
2022-06-16T17:49:29.9741773Z   TEST_LOCAL: 1
2022-06-16T17:49:29.9742035Z   DEBUG: 1
2022-06-16T17:49:29.9742323Z ##[endgroup]
2022-06-16T17:49:29.9906894Z ##[debug]/usr/bin/bash -e /home/runner/work/_temp/ffcdaf6c-2b02-4c3b-928b-025751d1e3ac.sh
2022-06-16T17:49:29.9957664Z Cloning into 'acmetest'...
2022-06-16T17:49:34.7221213Z ##[debug]Finishing: Clone acmetest
2022-06-16T17:49:34.7226926Z ##[debug]Evaluating condition for step: 'Set env file'
2022-06-16T17:49:34.7229786Z ##[debug]Evaluating: success()
2022-06-16T17:49:34.7230316Z ##[debug]Evaluating success:
2022-06-16T17:49:34.7230861Z ##[debug]=> true
2022-06-16T17:49:34.7231424Z ##[debug]Result: true
2022-06-16T17:49:34.7232469Z ##[debug]Starting: Set env file
2022-06-16T17:49:34.7245014Z ##[debug]Loading inputs
2022-06-16T17:49:34.7260303Z ##[debug]Evaluating: format('cd ../acmetest
2022-06-16T17:49:34.7260658Z ##[debug]if [ "{0}" ] ; then
2022-06-16T17:49:34.7260975Z ##[debug]  echo "{1}={2}" >> docker.env
2022-06-16T17:49:34.7261350Z ##[debug]fi
2022-06-16T17:49:34.7261640Z ##[debug]if [ "{3}" ] ; then
2022-06-16T17:49:34.7261942Z ##[debug]  echo "{4}={5}" >> docker.env
2022-06-16T17:49:34.7262491Z ##[debug]fi
2022-06-16T17:49:34.7262767Z ##[debug]if [ "{6}" ] ; then
2022-06-16T17:49:34.7263073Z ##[debug]  echo "{7}={8}" >> docker.env
2022-06-16T17:49:34.7263355Z ##[debug]fi
2022-06-16T17:49:34.7263668Z ##[debug]if [ "{9}" ] ; then
2022-06-16T17:49:34.7263984Z ##[debug]  echo "{10}={11}" >> docker.env
2022-06-16T17:49:34.7264272Z ##[debug]fi
2022-06-16T17:49:34.7264546Z ##[debug]if [ "{12}" ] ; then
2022-06-16T17:49:34.7264861Z ##[debug]  echo "{13}={14}" >> docker.env
2022-06-16T17:49:34.7265147Z ##[debug]fi
2022-06-16T17:49:34.7265483Z ##[debug]echo "TEST_DNS_NO_WILDCARD" >> docker.env
2022-06-16T17:49:34.7265860Z ##[debug]echo "TEST_DNS_SLEEP" >> docker.env
2022-06-16T17:49:34.7266702Z ##[debug]', secrets.TokenName1, secrets.TokenName1, secrets.TokenValue1, secrets.TokenName2, secrets.TokenName2, secrets.TokenValue2, secrets.TokenName3, secrets.TokenName3, secrets.TokenValue3, secrets.TokenName4, secrets.TokenName4, secrets.TokenValue4, secrets.TokenName5, secrets.TokenName5, secrets.TokenValue5)
2022-06-16T17:49:34.7267543Z ##[debug]Evaluating format:
2022-06-16T17:49:34.7290843Z ##[debug]..Evaluating String:
2022-06-16T17:49:34.7291257Z ##[debug]..=> 'cd ../acmetest
2022-06-16T17:49:34.7291573Z ##[debug]if [ "{0}" ] ; then
2022-06-16T17:49:34.7291890Z ##[debug]  echo "{1}={2}" >> docker.env
2022-06-16T17:49:34.7292359Z ##[debug]fi
2022-06-16T17:49:34.7292624Z ##[debug]if [ "{3}" ] ; then
2022-06-16T17:49:34.7292916Z ##[debug]  echo "{4}={5}" >> docker.env
2022-06-16T17:49:34.7293190Z ##[debug]fi
2022-06-16T17:49:34.7293603Z ##[debug]if [ "{6}" ] ; then
2022-06-16T17:49:34.7293890Z ##[debug]  echo "{7}={8}" >> docker.env
2022-06-16T17:49:34.7294156Z ##[debug]fi
2022-06-16T17:49:34.7294409Z ##[debug]if [ "{9}" ] ; then
2022-06-16T17:49:34.7294717Z ##[debug]  echo "{10}={11}" >> docker.env
2022-06-16T17:49:34.7294986Z ##[debug]fi
2022-06-16T17:49:34.7295249Z ##[debug]if [ "{12}" ] ; then
2022-06-16T17:49:34.7295532Z ##[debug]  echo "{13}={14}" >> docker.env
2022-06-16T17:49:34.7295794Z ##[debug]fi
2022-06-16T17:49:34.7296088Z ##[debug]echo "TEST_DNS_NO_WILDCARD" >> docker.env
2022-06-16T17:49:34.7296634Z ##[debug]echo "TEST_DNS_SLEEP" >> docker.env
2022-06-16T17:49:34.7296927Z ##[debug]'
2022-06-16T17:49:34.7330175Z ##[debug]..Evaluating Index:
2022-06-16T17:49:34.7330563Z ##[debug]....Evaluating secrets:
2022-06-16T17:49:34.7330931Z ##[debug]....=> Object
2022-06-16T17:49:34.7331288Z ##[debug]....Evaluating String:
2022-06-16T17:49:34.7331631Z ##[debug]....=> 'TokenName1'
2022-06-16T17:49:34.7332538Z ##[debug]..=> '***'
2022-06-16T17:49:34.7334415Z ##[debug]..Evaluating Index:
2022-06-16T17:49:34.7334734Z ##[debug]....Evaluating secrets:
2022-06-16T17:49:34.7335079Z ##[debug]....=> Object
2022-06-16T17:49:34.7335757Z ##[debug]....Evaluating String:
2022-06-16T17:49:34.7336094Z ##[debug]....=> 'TokenName1'
2022-06-16T17:49:34.7336832Z ##[debug]..=> '***'
2022-06-16T17:49:34.7337185Z ##[debug]..Evaluating Index:
2022-06-16T17:49:34.7337516Z ##[debug]....Evaluating secrets:
2022-06-16T17:49:34.7337860Z ##[debug]....=> Object
2022-06-16T17:49:34.7338182Z ##[debug]....Evaluating String:
2022-06-16T17:49:34.7338515Z ##[debug]....=> 'TokenValue1'
2022-06-16T17:49:34.7338983Z ##[debug]..=> '***'
2022-06-16T17:49:34.7339506Z ##[debug]..Evaluating Index:
2022-06-16T17:49:34.7339858Z ##[debug]....Evaluating secrets:
2022-06-16T17:49:34.7340182Z ##[debug]....=> Object
2022-06-16T17:49:34.7340499Z ##[debug]....Evaluating String:
2022-06-16T17:49:34.7340837Z ##[debug]....=> 'TokenName2'
2022-06-16T17:49:34.7341208Z ##[debug]..=> '***'
2022-06-16T17:49:34.7341545Z ##[debug]..Evaluating Index:
2022-06-16T17:49:34.7341871Z ##[debug]....Evaluating secrets:
2022-06-16T17:49:34.7342252Z ##[debug]....=> Object
2022-06-16T17:49:34.7342568Z ##[debug]....Evaluating String:
2022-06-16T17:49:34.7342911Z ##[debug]....=> 'TokenName2'
2022-06-16T17:49:34.7343280Z ##[debug]..=> '***'
2022-06-16T17:49:34.7343604Z ##[debug]..Evaluating Index:
2022-06-16T17:49:34.7343952Z ##[debug]....Evaluating secrets:
2022-06-16T17:49:34.7344272Z ##[debug]....=> Object
2022-06-16T17:49:34.7344583Z ##[debug]....Evaluating String:
2022-06-16T17:49:34.7344912Z ##[debug]....=> 'TokenValue2'
2022-06-16T17:49:34.7345278Z ##[debug]..=> '***'
2022-06-16T17:49:34.7345645Z ##[debug]..Evaluating Index:
2022-06-16T17:49:34.7345974Z ##[debug]....Evaluating secrets:
2022-06-16T17:49:34.7346291Z ##[debug]....=> Object
2022-06-16T17:49:34.7346600Z ##[debug]....Evaluating String:
2022-06-16T17:49:34.7346954Z ##[debug]....=> 'TokenName3'
2022-06-16T17:49:34.7347264Z ##[debug]..=> null
2022-06-16T17:49:34.7347606Z ##[debug]..Evaluating Index:
2022-06-16T17:49:34.7347928Z ##[debug]....Evaluating secrets:
2022-06-16T17:49:34.7348244Z ##[debug]....=> Object
2022-06-16T17:49:34.7348557Z ##[debug]....Evaluating String:
2022-06-16T17:49:34.7348887Z ##[debug]....=> 'TokenName3'
2022-06-16T17:49:34.7349194Z ##[debug]..=> null
2022-06-16T17:49:34.7349533Z ##[debug]..Evaluating Index:
2022-06-16T17:49:34.7349859Z ##[debug]....Evaluating secrets:
2022-06-16T17:49:34.7350169Z ##[debug]....=> Object
2022-06-16T17:49:34.7350488Z ##[debug]....Evaluating String:
2022-06-16T17:49:34.7350819Z ##[debug]....=> 'TokenValue3'
2022-06-16T17:49:34.7351128Z ##[debug]..=> null
2022-06-16T17:49:34.7351476Z ##[debug]..Evaluating Index:
2022-06-16T17:49:34.7351802Z ##[debug]....Evaluating secrets:
2022-06-16T17:49:34.7352113Z ##[debug]....=> Object
2022-06-16T17:49:34.7352421Z ##[debug]....Evaluating String:
2022-06-16T17:49:34.7352739Z ##[debug]....=> 'TokenName4'
2022-06-16T17:49:34.7353611Z ##[debug]..=> null
2022-06-16T17:49:34.7353964Z ##[debug]..Evaluating Index:
2022-06-16T17:49:34.7354293Z ##[debug]....Evaluating secrets:
2022-06-16T17:49:34.7354607Z ##[debug]....=> Object
2022-06-16T17:49:34.7354917Z ##[debug]....Evaluating String:
2022-06-16T17:49:34.7355259Z ##[debug]....=> 'TokenName4'
2022-06-16T17:49:34.7355563Z ##[debug]..=> null
2022-06-16T17:49:34.7355881Z ##[debug]..Evaluating Index:
2022-06-16T17:49:34.7356206Z ##[debug]....Evaluating secrets:
2022-06-16T17:49:34.7356519Z ##[debug]....=> Object
2022-06-16T17:49:34.7356868Z ##[debug]....Evaluating String:
2022-06-16T17:49:34.7357212Z ##[debug]....=> 'TokenValue4'
2022-06-16T17:49:34.7357513Z ##[debug]..=> null
2022-06-16T17:49:34.7357825Z ##[debug]..Evaluating Index:
2022-06-16T17:49:34.7358148Z ##[debug]....Evaluating secrets:
2022-06-16T17:49:34.7358458Z ##[debug]....=> Object
2022-06-16T17:49:34.7358767Z ##[debug]....Evaluating String:
2022-06-16T17:49:34.7359106Z ##[debug]....=> 'TokenName5'
2022-06-16T17:49:34.7359415Z ##[debug]..=> null
2022-06-16T17:49:34.7359725Z ##[debug]..Evaluating Index:
2022-06-16T17:49:34.7360047Z ##[debug]....Evaluating secrets:
2022-06-16T17:49:34.7360355Z ##[debug]....=> Object
2022-06-16T17:49:34.7360704Z ##[debug]....Evaluating String:
2022-06-16T17:49:34.7361044Z ##[debug]....=> 'TokenName5'
2022-06-16T17:49:34.7361367Z ##[debug]..=> null
2022-06-16T17:49:34.7361876Z ##[debug]..Evaluating Index:
2022-06-16T17:49:34.7362199Z ##[debug]....Evaluating secrets:
2022-06-16T17:49:34.7362516Z ##[debug]....=> Object
2022-06-16T17:49:34.7362830Z ##[debug]....Evaluating String:
2022-06-16T17:49:34.7363180Z ##[debug]....=> 'TokenValue5'
2022-06-16T17:49:34.7363482Z ##[debug]..=> null
2022-06-16T17:49:34.7364073Z ##[debug]=> 'cd ../acmetest
2022-06-16T17:49:34.7364510Z ##[debug]if [ "***" ] ; then
2022-06-16T17:49:34.7365557Z ##[debug]  echo "***=***" >> docker.env
2022-06-16T17:49:34.7365881Z ##[debug]fi
2022-06-16T17:49:34.7366231Z ##[debug]if [ "***" ] ; then
2022-06-16T17:49:34.7366670Z ##[debug]  echo "***=***" >> docker.env
2022-06-16T17:49:34.7366961Z ##[debug]fi
2022-06-16T17:49:34.7367229Z ##[debug]if [ "" ] ; then
2022-06-16T17:49:34.7367532Z ##[debug]  echo "=" >> docker.env
2022-06-16T17:49:34.7367808Z ##[debug]fi
2022-06-16T17:49:34.7368206Z ##[debug]if [ "" ] ; then
2022-06-16T17:49:34.7368525Z ##[debug]  echo "=" >> docker.env
2022-06-16T17:49:34.7368817Z ##[debug]fi
2022-06-16T17:49:34.7369084Z ##[debug]if [ "" ] ; then
2022-06-16T17:49:34.7369383Z ##[debug]  echo "=" >> docker.env
2022-06-16T17:49:34.7369657Z ##[debug]fi
2022-06-16T17:49:34.7370134Z ##[debug]echo "TEST_DNS_NO_WILDCARD" >> docker.env
2022-06-16T17:49:34.7370733Z ##[debug]echo "TEST_DNS_SLEEP" >> docker.env
2022-06-16T17:49:34.7371064Z ##[debug]'
2022-06-16T17:49:34.7371547Z ##[debug]Result: 'cd ../acmetest
2022-06-16T17:49:34.7371937Z ##[debug]if [ "***" ] ; then
2022-06-16T17:49:34.7372508Z ##[debug]  echo "***=***" >> docker.env
2022-06-16T17:49:34.7372796Z ##[debug]fi
2022-06-16T17:49:34.7373162Z ##[debug]if [ "***" ] ; then
2022-06-16T17:49:34.7373567Z ##[debug]  echo "***=***" >> docker.env
2022-06-16T17:49:34.7373870Z ##[debug]fi
2022-06-16T17:49:34.7374140Z ##[debug]if [ "" ] ; then
2022-06-16T17:49:34.7374439Z ##[debug]  echo "=" >> docker.env
2022-06-16T17:49:34.7374718Z ##[debug]fi
2022-06-16T17:49:34.7374988Z ##[debug]if [ "" ] ; then
2022-06-16T17:49:34.7375291Z ##[debug]  echo "=" >> docker.env
2022-06-16T17:49:34.7375568Z ##[debug]fi
2022-06-16T17:49:34.7375834Z ##[debug]if [ "" ] ; then
2022-06-16T17:49:34.7376128Z ##[debug]  echo "=" >> docker.env
2022-06-16T17:49:34.7376589Z ##[debug]fi
2022-06-16T17:49:34.7376939Z ##[debug]echo "TEST_DNS_NO_WILDCARD" >> docker.env
2022-06-16T17:49:34.7377310Z ##[debug]echo "TEST_DNS_SLEEP" >> docker.env
2022-06-16T17:49:34.7377613Z ##[debug]'
2022-06-16T17:49:34.7378145Z ##[debug]Loading env
2022-06-16T17:49:34.7384436Z ##[group]Run cd ../acmetest
2022-06-16T17:49:34.7384778Z cd ../acmetest
2022-06-16T17:49:34.7385180Z if [ "***" ] ; then
2022-06-16T17:49:34.7385583Z   echo "***=***" >> docker.env
2022-06-16T17:49:34.7386036Z fi
2022-06-16T17:49:34.7386521Z if [ "***" ] ; then
2022-06-16T17:49:34.7386907Z   echo "***=***" >> docker.env
2022-06-16T17:49:34.7387201Z fi
2022-06-16T17:49:34.7388872Z if [ "" ] ; then
2022-06-16T17:49:34.7389194Z   echo "=" >> docker.env
2022-06-16T17:49:34.7389484Z fi
2022-06-16T17:49:34.7389748Z if [ "" ] ; then
2022-06-16T17:49:34.7390050Z   echo "=" >> docker.env
2022-06-16T17:49:34.7390335Z fi
2022-06-16T17:49:34.7390603Z if [ "" ] ; then
2022-06-16T17:49:34.7390898Z   echo "=" >> docker.env
2022-06-16T17:49:34.7391205Z fi
2022-06-16T17:49:34.7391532Z echo "TEST_DNS_NO_WILDCARD" >> docker.env
2022-06-16T17:49:34.7391910Z echo "TEST_DNS_SLEEP" >> docker.env
2022-06-16T17:49:34.7455378Z shell: /usr/bin/bash -e {0}
2022-06-16T17:49:34.7455654Z env:
2022-06-16T17:49:34.7456436Z   TEST_DNS: ***
2022-06-16T17:49:34.7456815Z   TestingDomain: ***
2022-06-16T17:49:34.7457139Z   TEST_DNS_NO_WILDCARD: 
2022-06-16T17:49:34.7457446Z   TEST_DNS_NO_SUBDOMAIN: 
2022-06-16T17:49:34.7457764Z   TEST_DNS_SLEEP: ***
2022-06-16T17:49:34.7458063Z   CASE: le_test_dnsapi
2022-06-16T17:49:34.7458344Z   TEST_LOCAL: 1
2022-06-16T17:49:34.7458859Z   DEBUG: 1
2022-06-16T17:49:34.7459119Z ##[endgroup]
2022-06-16T17:49:34.7519343Z ##[debug]/usr/bin/bash -e /home/runner/work/_temp/f596ca0d-362e-45fe-961d-9aaccb5bceda.sh
2022-06-16T17:49:34.7552824Z ##[debug]Finishing: Set env file
2022-06-16T17:49:34.7557514Z ##[debug]Evaluating condition for step: 'Run acmetest'
2022-06-16T17:49:34.7558802Z ##[debug]Evaluating: success()
2022-06-16T17:49:34.7559416Z ##[debug]Evaluating success:
2022-06-16T17:49:34.7559892Z ##[debug]=> true
2022-06-16T17:49:34.7560409Z ##[debug]Result: true
2022-06-16T17:49:34.7561122Z ##[debug]Starting: Run acmetest
2022-06-16T17:49:34.7572430Z ##[debug]Loading inputs
2022-06-16T17:49:34.7573683Z ##[debug]Loading env
2022-06-16T17:49:34.7579712Z ##[group]Run cd ../acmetest && ./rundocker.sh  testall
2022-06-16T17:49:34.7580274Z cd ../acmetest && ./rundocker.sh  testall
2022-06-16T17:49:34.7637749Z shell: /usr/bin/bash -e {0}
2022-06-16T17:49:34.7638010Z env:
2022-06-16T17:49:34.7638359Z   TEST_DNS: ***
2022-06-16T17:49:34.7638697Z   TestingDomain: ***
2022-06-16T17:49:34.7638969Z   TEST_DNS_NO_WILDCARD: 
2022-06-16T17:49:34.7639395Z   TEST_DNS_NO_SUBDOMAIN: 
2022-06-16T17:49:34.7639661Z   TEST_DNS_SLEEP: ***
2022-06-16T17:49:34.7639948Z   CASE: le_test_dnsapi
2022-06-16T17:49:34.7640189Z   TEST_LOCAL: 1
2022-06-16T17:49:34.7640409Z   DEBUG: 1
2022-06-16T17:49:34.7640625Z ##[endgroup]
2022-06-16T17:49:34.7698628Z ##[debug]/usr/bin/bash -e /home/runner/work/_temp/4b4a9386-406d-476b-b5ae-b0e4400baf02.sh
2022-06-16T17:49:34.7790037Z Test for case: le_test_dnsapi
2022-06-16T17:49:34.7841128Z [Thu Jun 16 17:49:34 UTC 2022] ubuntu:latest
2022-06-16T17:49:34.7910377Z [Thu Jun 16 17:49:34 UTC 2022] platline='ubuntu:latest|'
2022-06-16T17:49:34.7968403Z [Thu Jun 16 17:49:34 UTC 2022] basetag='ubuntu'
2022-06-16T17:49:34.8013523Z [Thu Jun 16 17:49:34 UTC 2022] baseline='-ubuntu|apt-get -y update |apt-get -y install|unzip,openssl,cron,socat,curl,idn|'
2022-06-16T17:49:34.8039253Z [Thu Jun 16 17:49:34 UTC 2022] Running ubuntu:latest, this may take a few minutes, please wait.
2022-06-16T17:49:34.8121902Z [Thu Jun 16 17:49:34 UTC 2022] update='apt-get -y update '
2022-06-16T17:49:34.8186869Z [Thu Jun 16 17:49:34 UTC 2022] install='apt-get -y install'
2022-06-16T17:49:34.8343198Z [Thu Jun 16 17:49:34 UTC 2022] Log_Out='logs/ubuntu-latest.out'
2022-06-16T17:49:46.0535889Z [Thu Jun 16 17:49:46 UTC 2022] LOG_FILE='logs/ubuntu-latest.log'
2022-06-16T17:49:46.3140497Z Thu, 16 Jun 2022 17:49:46 UTC
2022-06-16T17:49:46.3141864Z TEST_LOCAL skip setup.
2022-06-16T17:49:46.3165378Z t='le_test_dependencies'
2022-06-16T17:49:46.3183588Z 'le_test_dnsapi' does not contain 'le_test_dependencies'
2022-06-16T17:49:46.3189145Z t='le_test_install'
2022-06-16T17:49:46.3202108Z 'le_test_dnsapi' does not contain 'le_test_install'
2022-06-16T17:49:46.3203924Z t='le_test_uninstall'
2022-06-16T17:49:46.3221241Z 'le_test_dnsapi' does not contain 'le_test_uninstall'
2022-06-16T17:49:46.3221884Z t='le_test_installtodir'
2022-06-16T17:49:46.3237657Z 'le_test_dnsapi' does not contain 'le_test_installtodir'
2022-06-16T17:49:46.3241534Z t='le_test_uninstalltodir'
2022-06-16T17:49:46.3254161Z 'le_test_dnsapi' does not contain 'le_test_uninstalltodir'
2022-06-16T17:49:46.3259211Z t='le_test_install_config_home'
2022-06-16T17:49:46.3275837Z 'le_test_dnsapi' does not contain 'le_test_install_config_home'
2022-06-16T17:49:46.3280119Z t='le_test_standandalone_renew_v2'
2022-06-16T17:49:46.3304938Z 'le_test_dnsapi' does not contain 'le_test_standandalone_renew_v2'
2022-06-16T17:49:46.3305936Z t='le_test_standandalone_renew_localaddress_v2'
2022-06-16T17:49:46.3323733Z 'le_test_dnsapi' does not contain 'le_test_standandalone_renew_localaddress_v2'
2022-06-16T17:49:46.3326243Z t='le_test_standandalone_listen_v4_v2'
2022-06-16T17:49:46.3343173Z 'le_test_dnsapi' does not contain 'le_test_standandalone_listen_v4_v2'
2022-06-16T17:49:46.3345841Z t='le_test_standandalone_listen_v6_v2'
2022-06-16T17:49:46.3361560Z 'le_test_dnsapi' does not contain 'le_test_standandalone_listen_v6_v2'
2022-06-16T17:49:46.3363119Z t='le_test_standandalone_deactivate_v2'
2022-06-16T17:49:46.3379052Z 'le_test_dnsapi' does not contain 'le_test_standandalone_deactivate_v2'
2022-06-16T17:49:46.3383443Z t='le_test_standandalone_SAN'
2022-06-16T17:49:46.3402057Z 'le_test_dnsapi' does not contain 'le_test_standandalone_SAN'
2022-06-16T17:49:46.3406165Z t='le_test_standandalone_ECDSA_256_renew'
2022-06-16T17:49:46.3424355Z 'le_test_dnsapi' does not contain 'le_test_standandalone_ECDSA_256_renew'
2022-06-16T17:49:46.3425953Z t='le_test_standandalone_ECDSA_256_SAN_renew_v2'
2022-06-16T17:49:46.3442333Z 'le_test_dnsapi' does not contain 'le_test_standandalone_ECDSA_256_SAN_renew_v2'
2022-06-16T17:49:46.3443962Z t='le_test_standandalone_ECDSA_384'
2022-06-16T17:49:46.3459635Z 'le_test_dnsapi' does not contain 'le_test_standandalone_ECDSA_384'
2022-06-16T17:49:46.3461083Z t='le_test_standandalone_renew_idn_v2'
2022-06-16T17:49:46.3476721Z 'le_test_dnsapi' does not contain 'le_test_standandalone_renew_idn_v2'
2022-06-16T17:49:46.3478547Z t='le_test_dnsapi'
2022-06-16T17:49:46.3492776Z 'le_test_dnsapi' contains 'le_test_dnsapi'
2022-06-16T17:49:46.3494090Z ==Running le_test_dnsapi please wait
2022-06-16T17:49:46.3628048Z [Thu Jun 16 17:49:46 UTC 2022] Lets find script dir.
2022-06-16T17:49:46.3650641Z [Thu Jun 16 17:49:46 UTC 2022] _SCRIPT_='./acme.sh'
2022-06-16T17:49:46.3683456Z [Thu Jun 16 17:49:46 UTC 2022] _script='/acmetest/acme.sh/acme.sh'
2022-06-16T17:49:46.3718725Z [Thu Jun 16 17:49:46 UTC 2022] _script_home='/acmetest/acme.sh'
2022-06-16T17:49:46.3747302Z [Thu Jun 16 17:49:46 UTC 2022] Using config home:/root/.acme.sh
2022-06-16T17:49:46.3793411Z [Thu Jun 16 17:49:46 UTC 2022] ACME_DIRECTORY='https://acme-staging-v02.api.letsencrypt.org/directory'
2022-06-16T17:49:46.3959858Z [Thu Jun 16 17:49:46 UTC 2022] Using config home:/root/.acme.sh
2022-06-16T17:49:46.3985790Z [Thu Jun 16 17:49:46 UTC 2022] ACME_DIRECTORY='https://acme-staging-v02.api.letsencrypt.org/directory'
2022-06-16T17:49:46.4124752Z [Thu Jun 16 17:49:46 UTC 2022] Using sed  -i
2022-06-16T17:49:46.4202261Z [Thu Jun 16 17:49:46 UTC 2022] Found profile: /root/.profile
2022-06-16T17:49:46.4525303Z [Thu Jun 16 17:49:46 UTC 2022] Using config home:/root/.acme.sh
2022-06-16T17:49:46.4561623Z [Thu Jun 16 17:49:46 UTC 2022] ACME_DIRECTORY='https://acme-staging-v02.api.letsencrypt.org/directory'
2022-06-16T17:49:46.4671909Z [Thu Jun 16 17:49:46 UTC 2022] Using config home:/root/.acme.sh
2022-06-16T17:49:46.4697338Z [Thu Jun 16 17:49:46 UTC 2022] ACME_DIRECTORY='https://acme-staging-v02.api.letsencrypt.org/directory'
2022-06-16T17:49:46.4811693Z no crontab for root
2022-06-16T17:49:46.4841809Z no crontab for root
2022-06-16T17:49:47.0767584Z 
2022-06-16T17:49:47.0768640Z api='***'
2022-06-16T17:49:47.0772931Z Testing wildcard domain. 
2022-06-16T17:49:47.0774211Z TestingDomain='***'
2022-06-16T23:49:28.0693555Z ##[debug]Re-evaluate condition on job cancellation for step: 'Run acmetest'.
2022-06-16T23:49:40.5824207Z ##[error]The operation was canceled.
2022-06-16T23:49:40.5836610Z ##[debug]System.OperationCanceledException: The operation was canceled.
2022-06-16T23:49:40.5837190Z ##[debug]   at System.Threading.CancellationToken.ThrowOperationCanceledException()
2022-06-16T23:49:40.5838247Z ##[debug]   at GitHub.Runner.Sdk.ProcessInvoker.ExecuteAsync(String workingDirectory, String fileName, String arguments, IDictionary`2 environment, Boolean requireExitCodeZero, Encoding outputEncoding, Boolean killProcessOnCancel, Channel`1 redirectStandardIn, Boolean inheritConsoleHandler, Boolean keepStandardInOpen, Boolean highPriorityProcess, CancellationToken cancellationToken)
2022-06-16T23:49:40.5839788Z ##[debug]   at GitHub.Runner.Common.ProcessInvokerWrapper.ExecuteAsync(String workingDirectory, String fileName, String arguments, IDictionary`2 environment, Boolean requireExitCodeZero, Encoding outputEncoding, Boolean killProcessOnCancel, Channel`1 redirectStandardIn, Boolean inheritConsoleHandler, Boolean keepStandardInOpen, Boolean highPriorityProcess, CancellationToken cancellationToken)
2022-06-16T23:49:40.5841639Z ##[debug]   at GitHub.Runner.Worker.Handlers.DefaultStepHost.ExecuteAsync(IExecutionContext context, String workingDirectory, String fileName, String arguments, IDictionary`2 environment, Boolean requireExitCodeZero, Encoding outputEncoding, Boolean killProcessOnCancel, Boolean inheritConsoleHandler, String standardInInput, CancellationToken cancellationToken)
2022-06-16T23:49:40.5842643Z ##[debug]   at GitHub.Runner.Worker.Handlers.ScriptHandler.RunAsync(ActionRunStage stage)
2022-06-16T23:49:40.5843156Z ##[debug]   at GitHub.Runner.Worker.ActionRunner.RunAsync()
2022-06-16T23:49:40.5843695Z ##[debug]   at GitHub.Runner.Worker.StepsRunner.RunStepAsync(IStep step, CancellationToken jobCancellationToken)
2022-06-16T23:49:40.5844904Z ##[debug]Finishing: Run acmetest
Eagle3386 commented 2 years ago

Issue template stupidly limited to 65536 chars, hence rest of the debug log follows here:

Debug log (rest of it)

2022-06-16T23:49:40.5849882Z ##[debug]Evaluating condition for step: 'Post Run actions/checkout@v2'
2022-06-16T23:49:40.5852422Z ##[debug]Evaluating: always()
2022-06-16T23:49:40.5853214Z ##[debug]Evaluating always:
2022-06-16T23:49:40.5854375Z ##[debug]=> true
2022-06-16T23:49:40.5855032Z ##[debug]Result: true
2022-06-16T23:49:40.5855853Z ##[debug]Starting: Post Run actions/checkout@v2
2022-06-16T23:49:40.5895291Z ##[debug]Loading inputs
2022-06-16T23:49:40.5896658Z ##[debug]Evaluating: github.repository
2022-06-16T23:49:40.5897111Z ##[debug]Evaluating Index:
2022-06-16T23:49:40.5897457Z ##[debug]..Evaluating github:
2022-06-16T23:49:40.5897965Z ##[debug]..=> Object
2022-06-16T23:49:40.5898295Z ##[debug]..Evaluating String:
2022-06-16T23:49:40.5899111Z ##[debug]..=> 'repository'
2022-06-16T23:49:40.5899635Z ##[debug]=> 'Eagle3386/acme.sh'
2022-06-16T23:49:40.5900005Z ##[debug]Result: 'Eagle3386/acme.sh'
2022-06-16T23:49:40.5902141Z ##[debug]Evaluating: github.token
2022-06-16T23:49:40.5902482Z ##[debug]Evaluating Index:
2022-06-16T23:49:40.5902774Z ##[debug]..Evaluating github:
2022-06-16T23:49:40.5903055Z ##[debug]..=> Object
2022-06-16T23:49:40.5903338Z ##[debug]..Evaluating String:
2022-06-16T23:49:40.5903614Z ##[debug]..=> 'token'
2022-06-16T23:49:40.5904135Z ##[debug]=> '***'
2022-06-16T23:49:40.5904543Z ##[debug]Result: '***'
2022-06-16T23:49:40.5909814Z ##[debug]Loading env
2022-06-16T23:49:40.5916105Z Post job cleanup.
2022-06-16T23:49:41.3771032Z ##[debug]Getting git version
2022-06-16T23:49:41.3771938Z [command]/usr/bin/git version
2022-06-16T23:49:41.3772318Z git version 2.36.1
2022-06-16T23:49:41.3773273Z ##[debug]Set git useragent to: git/2.36.1 (github-actions-checkout)
2022-06-16T23:49:41.3774295Z ::add-mask::***
2022-06-16T23:49:41.3776153Z Temporarily overriding HOME='/home/runner/work/_temp/c5138d80-8b87-4e92-9d5a-ae03d03f3a21' before making global git config changes
2022-06-16T23:49:41.3776990Z Adding repository directory to the temporary git global config as a safe directory
2022-06-16T23:49:41.3777682Z [command]/usr/bin/git config --global --add safe.directory /home/runner/work/acme.sh/acme.sh
2022-06-16T23:49:41.3778339Z [command]/usr/bin/git config --local --name-only --get-regexp core\.sshCommand
2022-06-16T23:49:41.3779207Z [command]/usr/bin/git submodule foreach --recursive git config --local --name-only --get-regexp 'core\.sshCommand' && git config --local --unset-all 'core.sshCommand' || :
2022-06-16T23:49:41.3780032Z [command]/usr/bin/git config --local --name-only --get-regexp http\.https\:\/\/github\.com\/\.extraheader
2022-06-16T23:49:41.3780565Z http.https://github.com/.extraheader
2022-06-16T23:49:41.3781181Z [command]/usr/bin/git config --local --unset-all http.https://github.com/.extraheader
2022-06-16T23:49:41.3782163Z [command]/usr/bin/git submodule foreach --recursive git config --local --name-only --get-regexp 'http\.https\:\/\/github\.com\/\.extraheader' && git config --local --unset-all 'http.https://github.com/.extraheader' || :
2022-06-16T23:49:41.3783055Z ##[debug]Unsetting HOME override
2022-06-16T23:49:41.3784506Z ##[debug]Node Action run completed with exit code 0
2022-06-16T23:49:41.3786738Z ##[debug]Finishing: Post Run actions/checkout@v2
2022-06-16T23:49:41.3942960Z ##[debug]Starting: Complete job
2022-06-16T23:49:41.3945226Z Uploading runner diagnostic logs
2022-06-16T23:49:41.4031927Z ##[debug]Starting diagnostic file upload.
2022-06-16T23:49:41.4032352Z ##[debug]Setting up diagnostic log folders.
2022-06-16T23:49:41.4035846Z ##[debug]Creating diagnostic log files folder.
2022-06-16T23:49:41.4057841Z ##[debug]Copying 1 worker diagnostic logs.
2022-06-16T23:49:41.4087763Z ##[debug]Copying 1 runner diagnostic logs.
2022-06-16T23:49:41.4089760Z ##[debug]Zipping diagnostic files.
2022-06-16T23:49:41.4217339Z ##[debug]Uploading diagnostic metadata file.
2022-06-16T23:49:41.4253245Z ##[debug]Diagnostic file upload complete.
2022-06-16T23:49:41.4254075Z Completed runner diagnostic log upload
2022-06-16T23:49:41.4254550Z Cleaning up orphan processes
2022-06-16T23:49:41.4582367Z Terminate orphan process: pid (1586) (bash)
2022-06-16T23:49:41.4609189Z Terminate orphan process: pid (4500) (docker)
2022-06-16T23:49:41.4841970Z ##[debug]Finishing: Complete job
2022-06-16T23:49:41.5018393Z ##[debug]Finishing: Docker
Neilpang commented 2 years ago

remove ACTIONS_RUNNER_DEBUG and ACTIONS_STEP_DEBUG

Eagle3386 commented 2 years ago

Doesn't help, still the same error. Moreover, it's even worse as there're less log lines then.

Neilpang commented 2 years ago

re-run the actions ?

Eagle3386 commented 2 years ago

I've ran actions before I've added both secrets. But there you go, yet another run without both that surely fails as well: https://github.com/Eagle3386/acme.sh/runs/6953544933

Neilpang commented 2 years ago

what is the value of TEST_DNS_SLEEP ?

Eagle3386 commented 2 years ago

180 as that's a) what's set over at my ISP's Admin panel & b) the lowest possible value.

Neilpang commented 2 years ago

Here is an example, it's working as expected.

https://github.com/neilpangtest/acme.sh/runs/6953847945?check_suite_focus=true

Eagle3386 commented 2 years ago

Well, how does that help?

  1. That run shows clearly the actual execution of acme.sh on the 2nd line - which is missing in my runs:
    (...)
    TestingDomain='***'
    /root/.acme.sh/acme.sh --server ""  --issue -d "***" -d "*.***" --dns *** --dnssleep ""  [PASS]
    (...)
  2. You still don't tell how to increase the (debug) logging. Actually, you've even suggested to remove both ACTIONS_* secrets, which - according to GitHub - should increase logging (they didn't regarding acme.sh AFAICT).

So, how am I suppose to fix something without any error, warning or at least some darn (debug) info what's (not) executed & why? The actual code that I wrote does work flawlessly, it's the darn Docker test that fails without providing even the least minimum details about what's running/hanging for 6 hours!

Neilpang commented 2 years ago

that proves that the testing script was working well.
As your test run was just hang, I'm even not sure whether the testing script was begging to run.

There must be something wrong with the github actions env. you problably need to check on the github side.

Eagle3386 commented 2 years ago

How can a script proof it's "working well" if it didn't even "beg to run"?! 😳

Where & most importantly what to check regarding GitHub actions? I just set them up as the DNS API Test wiki page instructs me to do. Nothing more, nothing less.

Furthermore, I repeat my question once again: how to enable more logging & more details per logging step? As of now, there's not a single logged line that states what is executed with which parameters after that TestingDomain='***' on each & every of my runs, hence I simply don't know what's the issue I need to fix!