Error: The operation was canceled.

[0liver]

I'm encountering a strange error that I am currently unable to dissect. Here's the action log from our GitHub workflow run:

Tue, 11 Jul 2023 10:57:33 GMT Run Lombiq/GitHub-Actions/.github/actions/spelling@dev
Tue, 11 Jul 2023 10:57:33 GMT Run "/home/runner/work/_actions/Lombiq/GitHub-Actions/dev/.github/actions/spelling" >> $Env:GITHUB_PATH
Tue, 11 Jul 2023 10:57:34 GMT Run Set-GitHubOutput -Key 'configuration-path-exists' -Value (Test-Path (Join-Path "$Env:GITHUB_WORKSPACE" '.github/actions/spelling'))
Tue, 11 Jul 2023 10:57:36 GMT Run $targetPath = Join-Path "$Env:GITHUB_WORKSPACE" '.github/actions/spelling' 'advice.md'
Tue, 11 Jul 2023 10:57:37 GMT Run $mergeParameters = @{
Tue, 11 Jul 2023 10:57:38 GMT Run $mergeParameters = @{
Tue, 11 Jul 2023 10:57:39 GMT Run $mergeParameters = @{
Tue, 11 Jul 2023 10:57:41 GMT Run $defaultPrefixes = @{
Tue, 11 Jul 2023 10:57:42 GMT Run $defaultDictionaries = ConvertFrom-MultiLineStringToStringArray -Lines 'cspell:filetypes/filetypes.txt
Tue, 11 Jul 2023 10:57:43 GMT Run check-spelling/check-spelling@d7cd2973c513e84354f9d6cf50a6417a628a78ce
Tue, 11 Jul 2023 10:57:43 GMT Run stdbuf -i0 -o0 -e0 "/home/runner/work/_actions/check-spelling/check-spelling/d7cd2973c513e84354f9d6cf50a6417a628a78ce/unknown-words.sh"
Tue, 11 Jul 2023 10:57:44 GMT Found ok status for version 0.0.21: 'OK'
Tue, 11 Jul 2023 10:57:45 GMT Retrieving expect from .github/actions/spelling/expect/redacted.txt
Tue, 11 Jul 2023 10:57:45 GMT .github/actions/spelling/expect/powerbi.txt
Tue, 11 Jul 2023 10:57:45 GMT Retrieving excludes from .github/actions/spelling/excludes.txt
Tue, 11 Jul 2023 10:57:45 GMT Downloaded https://raw.githubusercontent.com/check-spelling/check-spelling/dictionary-20200211/dict.txt (to /home/runner/work/_actions/check-spelling/check-spelling/d7cd2973c513e84354f9d6cf50a6417a628a78ce/words)
Tue, 11 Jul 2023 10:57:45 GMT (...Extra dictionaries...)
Tue, 11 Jul 2023 10:57:47 GMT (...Check extra dictionaries...)
Tue, 11 Jul 2023 10:57:52 GMT Retrieving allow from .github/actions/spelling/allow.txt
Tue, 11 Jul 2023 10:57:52 GMT Retrieving line_forbidden from .github/actions/spelling/line_forbidden.patterns
Tue, 11 Jul 2023 10:57:52 GMT Retrieving patterns from .github/actions/spelling/patterns.txt
Tue, 11 Jul 2023 10:57:52 GMT Retrieving advice from .github/actions/spelling/advice.md
Tue, 11 Jul 2023 10:57:52 GMT Checking spelling...
Tue, 11 Jul 2023 10:57:52 GMT (...Spell check files...)
Tue, 11 Jul 2023 10:57:52 GMT Checking 531 files
Tue, 11 Jul 2023 10:57:52 GMT (...Spell check...)
Tue, 11 Jul 2023 10:59:46 GMT Error: The operation was canceled.

No errors are logged.

Please provide some guidance on how to investigate this problem at this stage.

[jsoref]

Is it possible that there was a second push to the same branch and your workflow is configured with:

check-spelling/.github/workflows/spelling.yml

Lines 26 to 29 in d7cd297

	concurrency:
	group: spelling-${{ github.event.pull_request.number || github.ref }}
	# note: If you use only_check_changed_files, you do not want cancel-in-progress
	cancel-in-progress: true

If so, it just means that the second push killed the first push.

It's also possible that you're using:
https://docs.github.com/en/actions/using-workflows/workflow-syntax-for-github-actions#jobsjob_idstepstimeout-minutes
https://docs.github.com/en/actions/using-workflows/workflow-syntax-for-github-actions#jobsjob_idtimeout-minutes

Although that seems relatively unlikely.

[0liver]

1. There have been no concurrent pushes to the repo.
2. We do use step timeouts, but not for the spell-checking step.
3. I've identified a folder in the repository that seems to cause the problem - when I add its path to exclude.txt, the spell checker executes successfully. But when I add the path back, it fails again, and I am unable to trace down the origin of the error. Any ideas on how to proceed?

[jsoref]

Hmm, you can try adding debug: 1 to with:, I don't expect that to be particularly exciting, but maybe it'll say something.

Perhaps try experimental_parallel_jobs: 1 -- that'd reduce the number of moving parts...

actions/runner#2468 suggests it could perhaps be an oom, although I'd be somewhat shocked if it was...

[0liver]

I re-ran with GitHub's debug output and got this stack trace:

Tue, 11 Jul 2023 13:33:14 GMT Checking spelling...
Tue, 11 Jul 2023 13:33:14 GMT (...Spell check files...)
Tue, 11 Jul 2023 13:33:14 GMT Checking 531 files
Tue, 11 Jul 2023 13:33:14 GMT (...Spell check...)
Tue, 11 Jul 2023 13:34:47 GMT ##[debug]Re-evaluate condition on job cancellation for step: 'run'.
Tue, 11 Jul 2023 13:34:47 GMT ##[debug]Re-evaluate condition on job cancellation for step: 'run'.
Tue, 11 Jul 2023 13:34:47 GMT ##[debug]Re-evaluate condition on job cancellation for step: 'Check Spelling'.
Tue, 11 Jul 2023 13:34:59 GMT Error: The operation was canceled.
Tue, 11 Jul 2023 13:34:59 GMT ##[debug]System.OperationCanceledException: The operation was canceled.
Tue, 11 Jul 2023 13:34:59 GMT ##[debug]   at System.Threading.CancellationToken.ThrowOperationCanceledException()
Tue, 11 Jul 2023 13:34:59 GMT ##[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)
Tue, 11 Jul 2023 13:34:59 GMT ##[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)
Tue, 11 Jul 2023 13:34:59 GMT ##[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)
Tue, 11 Jul 2023 13:34:59 GMT ##[debug]   at GitHub.Runner.Worker.Handlers.ScriptHandler.RunAsync(ActionRunStage stage)
Tue, 11 Jul 2023 13:34:59 GMT ##[debug]   at GitHub.Runner.Worker.ActionRunner.RunAsync()
Tue, 11 Jul 2023 13:34:59 GMT ##[debug]   at GitHub.Runner.Worker.Handlers.CompositeActionHandler.RunStepAsync(IStep step)
Tue, 11 Jul 2023 13:34:59 GMT ##[debug]Finished: run

Nothing exciting. I'll try again with your parameters.

[0liver]

I ran the same workflow again with both debug: 1 and experimental_parallel_jobs: 1, but the output and result were exactly the same as before - no new insight.

Is there maybe some other flag to print the currently processed file name to the console?

[jsoref]

You can try uses: check-spelling/check-spelling@9fb3819c6a76d896fbd933b0e07700de4b768655 (9fb3819)

It'll report the files as they go.

I could add a flag for that...

[0liver]

You could add that behind the debug flag, I'd suggest.

Thanks!

UPDATE: The job step now finished with error with commit 9fb3819.

We were previously using v0.0.21 (d7cd297) and there must be some specific differences beyond that file name print statement from the linked commit. At least, I can now fix the errors that were found. 🥳

[jsoref]

ok, fce59ac now has the debugging as a general thing guarded by debug. I'm not a huge fan of using debug as a guard, but I have some repositories with tens of thousands of files so I don't really want to print each file twice by default (I'm currently doing it once, and I do need to think about whether that's a good idea for giant repositories). I may eventually make a special env var or flag just for this or something, but this is good enough for now and could certainly be live in a release (I obviously don't commit to the output from debug).

By finished with error do you mean it's no longer saying The operation was canceled? (Yes, there are a lot of changes between v0.0.21 and now, a little over 150, whereas v0.0.20...v0.0.21 was a little over 100.)

That said, I just made a couple of changes today and fixed a caching bug (admittedly, it only bit people using prerelease but my coworkers do that!). I do think I should be able to ship a release this month. I'm getting more comfortable with the code every day (and I'm cleaning things up too).

[0liver]

By finished with error do you mean it's no longer saying The operation was canceled?

Yes!

Looking forward to the next release.

This is really great work. Do you have a way of supporting your work with donations anywhere?

[jsoref]

Do you have a way of supporting your work with donations anywhere?

No, I'm thankfully employed. The best support I get are bug reports and additional customers 🙂 (e.g. donating the workflow to other repositories).

I'm going to mark this as closed since it'll be fixed in the next release. Thanks for testing it out.