Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

chore(ci): make xcbeautify quieter #4653

Merged
merged 10 commits into from
Jan 10, 2025
Merged

Conversation

armcknight
Copy link
Member

xcbeautify by default prints every passing test, which results in huge log output making it hard to find failing tests. use options to only print failing tests.

also try the github action renderer mode.

#skip-changelog

Copy link

codecov bot commented Dec 20, 2024

Codecov Report

All modified and coverable lines are covered by tests ✅

Project coverage is 91.162%. Comparing base (c5fef16) to head (8f47769).
Report is 10 commits behind head on main.

Additional details and impacted files

Impacted file tree graph

@@              Coverage Diff              @@
##              main     #4653       +/-   ##
=============================================
+ Coverage   90.631%   91.162%   +0.531%     
=============================================
  Files          621       624        +3     
  Lines        71153     72023      +870     
  Branches     25310     25566      +256     
=============================================
+ Hits         64487     65658     +1171     
+ Misses        6574      6271      -303     
- Partials        92        94        +2     

see 60 files with indirect coverage changes


Continue to review full report in Codecov by Sentry.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update c5fef16...8f47769. Read the comment docs.

@philipphofmann
Copy link
Member

Yes please.

@philprime
Copy link
Contributor

As I introduced xcbeautify, I'll also look into how we can reduce the output to only display failing tests

@philprime
Copy link
Contributor

philprime commented Jan 2, 2025

I tested the different options using this example log and results:

raw-test-output.log

A couple of insights:

  • When using xcpretty we used the flag -t/--test, which generated "RSpec style" output like the following, where it seems that xcpretty actually reads the mentioned file to show the code snippet:
❯ cat raw-test-output.log | xcpretty -t
................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................F.................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................

SentryTests.SentrySDKTests
  testResumeAndPauseAppHangTracking, XCTAssertEqual failed: ("1") is not equal to ("0")
  /Volumes/Developer/getsentry/sentry-cocoa/Tests/SentryTests/SentrySDKTests.swift:758
    } else {
        XCTAssertEqual(1, client.captureEventWithScopeInvocations.count)
    }


       Executed 2537 tests, with 6 tests skipped and 1 failure (0 unexpected) in 111.351 (111.992) seconds
................................................................................

       Executed 80 tests, with 0 failures (0 unexpected) in 1.294 (1.314) seconds
  • xcbeautify offers a flag --report <type> which can be used to generate custom reports. Currently only junit is supported, creating a single JUnit XML file.
  • The flag --quiet prints only errors and warnings
  • The flag --is-ci is actually not reducing verbose logs, it force prints the test results if --quiet is used. Therefore we should use only --quiet
  • The option --renderer github-actions is only changing the output text format to create GitHub Annotations using, i.e. ::error. This can also include errors which are printed by the unit tests, therefore showing logs in annotations, instead of actual test errors
  • The xcodebuild actually contains a test summary at the end, but it seems to me that xcbeautify does not support parsing it:
[...]

Test session results, code coverage, and logs:
	/Users/philip/Library/Developer/Xcode/DerivedData/Sentry-gtotjjlpwzkyaqdhgamktzusngne/Logs/Test/Test-Sentry-2025.01.02_09-44-55-+0100.xcresult

Failing tests:
	SentrySDKTests.testResumeAndPauseAppHangTracking()

** TEST EXECUTE FAILED **
  • xcodebuild generates a test result bundle .xcresult with further information than shown in the log. We could use tools like Xcode built-in xcrun xcresulttool get test-report --path Result.xcresult --legacy --format json (which seems to deprecated already?) or third-party tools like xcparse or xcresulttool to generate a test summary, similar to how Xcode does it in the UI:

(https://github.com/kishikawakatsumi/xcresulttool)
Screenshot 2025-01-02 at 10 34 02

Example using xcrun xcresulttool:

xcrun xcresulttool get test-report --path Result.xcresult --legacy --format json > output.json

Which outputs a JSON document with issues available at the key path .actions._values[0].actionResult.issues.testFailureSummaries._values:

[
  {
    "_type": {
      "_name": "TestFailureIssueSummary",
      "_supertype": {
        "_name": "IssueSummary"
      }
    },
    "documentLocationInCreatingWorkspace": {
      "_type": {
        "_name": "DocumentLocation"
      },
      "concreteTypeName": {
        "_type": {
          "_name": "String"
        },
        "_value": "DVTTextDocumentLocation"
      },
      "url": {
        "_type": {
          "_name": "String"
        },
        "_value": "file:///Volumes/Developer/getsentry/sentry-cocoa/Tests/SentryTests/SentrySDKTests.swift#EndingLineNumber=757&StartingLineNumber=757"
      }
    },
    "issueType": {
      "_type": {
        "_name": "String"
      },
      "_value": "Uncategorized"
    },
    "message": {
      "_type": {
        "_name": "String"
      },
      "_value": "XCTAssertEqual failed: (\"1\") is not equal to (\"0\")"
    },
    "testCaseName": {
      "_type": {
        "_name": "String"
      },
      "_value": "SentrySDKTests.testResumeAndPauseAppHangTracking()"
    }
  }
]

Using jq that can be printed like this:

$ cat output.json | jq ".actions._values[0].actionResult.issues.testFailureSummaries._values[] | \"[\(.testCaseName._value)]: \(.message._value) (\(.documentLocationInCreatingWorkspace.url._value))\""
"[SentrySDKTests.testResumeAndPauseAppHangTracking()]: XCTAssertEqual failed: (\"1\") is not equal to (\"0\") (file:///Volumes/Developer/getsentry/sentry-cocoa/Tests/SentryTests/SentrySDKTests.swift#EndingLineNumber=757&StartingLineNumber=757)"

Ideas to proceed:

  1. Use only --quiet to reduce the log to errors and warnings
  2. Do not use --renderer github-actions, as it creates noise in the annotations
  3. Create a custom report for xcbeautify, to match the RSpec style of xcpretty
  4. Upload the .xcresult as a GitHub Actions artifact, so we can download and view it in Xcode
  5. Generate a issues report from the xcresult on failure and print it to the logs

EDIT - References:

EDIT 2:

Please let me know which logs/summaries would be the most useful for you

@philipphofmann
Copy link
Member

@philprime, I mostly care about seeing failing tests quickly in CI. I don't want to download an artifact to find out which tests were failing. What we had before merging #4645 was sufficient for me.

@philprime
Copy link
Contributor

philprime commented Jan 3, 2025

TBH I am not happy that xcbeautify kind of made things worse, while trying to be better than xcpretty. I did consider to propose we revert to xcpretty, but 0.4.0 is still broken, even though fastlane is also using that version.

I created a prototype for a simple script without external tools to print a test summary in PR #4671. It should be the first thing shown when opening up the GitHub Actions log, like this one:
https://github.com/getsentry/sentry-cocoa/actions/runs/12595175843/job/35103995300

EDIT:
Had to fix the line number trimming, here the latest example log now also showing relevant code:
https://github.com/getsentry/sentry-cocoa/actions/runs/12595358979/job/35104557500

@philipphofmann
Copy link
Member

philipphofmann commented Jan 3, 2025

@armcknight, I hope it's not a problem that I used this draft PR to play around with some different possibilities. Feel free to revert my changes if you want.

@philprime, I think all we need to do is to remove --is-ci and use quieter. With quieter the test log output is OK for me. It's easy to spot the failing test with the failed assert message, see https://github.com/getsentry/sentry-cocoa/actions/runs/12596343110/job/35107314976. While the custom script (#4671) looks great, it's plenty of code. We might have to maintain and change it. I would prefer sticking to xcbeautify to reduce complexity. We can also do a simple grep for the quieter log output to only print the lines starting with error: .

I think we can keep the --renderer github-actions, as it looks like a great feature. The noise stems from errors in the tests. We should turn off the logging for these specific tests or fix the errors if possible IMO.

@philprime
Copy link
Contributor

I agree with you on the size of the custom script, more code means more maintenance. I created it to replicate the log output of the RSpec style/xcpretty log, but we could also remove parts we don't need, like the code snippet lookup.

For me personally having a clean summary at the end could have the pro of showing actual failing tests and not error output like this:

SentryCrashReportConverterTests
Error: Hello fatal\n";
            }
        );
Error: Hello fatal\n";
            }
        );
Error: Hello fatal\n";
            }
        );
Error: Hello fatal\n";
            }
        );

Therefore I would propose we add at least a list of failing tests at the end. That could also be extracted from the end of the build log file, as it is there, but xcbeautify does not print it with --quieter.

@philipphofmann
Copy link
Member

I don't mind the error output too much as it's not too much noise at the moment.

Therefore I would propose we add at least a list of failing tests at the end.

Yes, using quieter with a simple grep to only print lines starting with error: would be sufficient for me right now.

@armcknight
Copy link
Member Author

No problems on my end to mess with this, I shifted to other stuff after trying a few things and nothing seemed to work. Thanks for finding a solution @philipphofmann

Copy link
Member

@philipphofmann philipphofmann left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Just adding the quieter drastically improves the situation. We can add the grep later.

@philipphofmann philipphofmann marked this pull request as ready for review January 10, 2025 12:03
Copy link
Contributor

@philprime philprime left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM

@philipphofmann philipphofmann merged commit cc0f809 into main Jan 10, 2025
20 of 21 checks passed
@philipphofmann philipphofmann deleted the armcknight/ci/xcbeautify-quiet branch January 10, 2025 12:18
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants