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

Update error messages #175

Closed
wants to merge 42 commits into from
Closed

Update error messages #175

wants to merge 42 commits into from

Conversation

schneems
Copy link
Contributor

@schneems schneems commented Jul 25, 2023

Iteration based_ on this feedback doc: https://docs.google.com/document/d/1uixuWY91bRl4BX1eIdsPpkPAc3j5g6KYdGGYyCEf7lY/edit

W-13815542

You can see the updated output formatting live in the included CI tasks:

  • print-pack-getting-started-output
  • print-errors

The method signature https://doc.rust-lang.org/std/process/struct.Command.html#method.envs is:

```
pub fn envs<I, K, V>(&mut self, vars: I) -> &mut Command
where
    I: IntoIterator<Item = (K, V)>,
    K: AsRef<OsStr>,
    V: AsRef<OsStr>,
```

We should match it. It's not ideal that we're allocating in a method signature that's just asking for references but to be fair that's what Command::envs does too.
It's common that when debugging developers will see an error from a command then try to reproduce the issue locally. In the case of a rails app RAILS_ENV can produce wildly different behavior. When reproducing an error they must use the same RAILS_ENV as their build target. By adding it to the task name we encourage this behavior.

- Rename error something better "RakeError" is generic CannotDetectRake is more specific
- Fix visibility issue. It should not be `pub`
The `bundle list` command is internal and shouldn't fail. If it does there's something wrong with the system. Run `bundle env` and `gem env` to provide additional system information.
I changed the errors from being an array of vectors to being an array of rich types that implement display correctly.
Previously url was represented as an `Option<String>`. This posed a problem as the first URL I wanted to link to didn't really vibe with the error text. I changed it so that developers can provide their own label.

In this process I added tests which required that I strip control codes, and clean up the trailing spaces and un-needed newlines with bangs on them. New error output:

```
! ERROR: Error installing Ruby
!
! Could not install the detected Ruby version. Ensure that you're using a supported
! ruby version and try again.
!
! For more information, refer to the following documentation:
! https://devcenter.heroku.com/articles/ruby-support#ruby-versions

Debug information:

Could not create file: You do not have sufficient permissions to access this file: /path/to/file
```

I'm debating if we should do something similar with an enum for `debug_details` to give flexibility over representation. I don't need it yet though, so I'll hold off.
There are times when a disk operation or command fails and we want to gather more information. To support this case I added a new struct CmdErrorDiagnostics that accepts an io or command error. I've marked this interface as experimental and subject to change. I'm not 100% on the interface but I like the direction.

As a note: I'm feeling like `fun_run` is missing some (optional) primitives, such as a struct that couples a name with a command, or a result that returns an output coupled with a name. When this interface is revisited I want to revisit that possibility as well.
Example: https://gist.github.com/schneems/eddd3d2dc5e12bd4740a36383592d1ca

I want to add a newline before the error text, but haven't gotten to it yet.
- NamedOutput: Mentioned in a prior commit that there's a lot of annoying gymnastics that have to happen to keep track of a command's name when using `Result<Output, CmdError>`. In this case `CmdError` can be converted into an `Output` but an `Output` cannot be converted into a `CmdError` (because it needs a "name" String). By introducing this struct a lot of problems with the end user experience go away. This is a breaking change as several type signatures changed.

Further I added a convenience function (via trait extension) to convert `Result<Output, std::io::Error>` into a `Result<NamedOutput, std::io::Error>`. The idea is to get this result as quickly as possible and then it becomes much easier to manipulate the data (versus previously we were constantly tracking a separate name variable and needed to do several chained functions on `Result` to do the most common of tasks. All of those functions are still available if you want it, but this is

- CmdErrorDiagnostics: A pattern I use is to run a command to gather additional details when a command errors, I also used this to run diagnostics on a disk operation failure. To help here I introduced a generic type `ErrorDiagnostics<E>` and `CmdErrorDiagnostics` which is `ErrorDiagnostics<CmdError>`. Because `Result<NamedOutput, CmdError>` holds all the data needed to represent any possible output state of a command execution we don't need an additional internal struct.

I've labeled `ResultNameExt`, `CmdErrorDiagnostics`, and `ErrorDiagnostics<E>` as "experimental". I feel confident that `NamedOutput` will stay, and should have been added a long time ago.
```
$ reproapp
$ mkdir -p /tmp/159e7d8c193a71cbd28439aaf8872cea; cd /tmp/159e7d8c193a71cbd28439aaf8872cea
Fetching gem metadata from https://rubygems.org/.
Resolving dependencies...
Using rake 13.0.6
Using bundler 2.4.15
Bundle complete! 1 Gemfile dependency, 2 gems now installed.
Use `bundle info [gemname]` to see where a bundled gem is installed.
Fetching gem metadata from https://rubygems.org/.
Resolving dependencies...
Writing lockfile to /private/tmp/159e7d8c193a71cbd28439aaf8872cea/Gemfile.lock
Initialized empty Git repository in /private/tmp/159e7d8c193a71cbd28439aaf8872cea/.git/
[main (root-commit) 3fc3b5f] first
 2 files changed, 16 insertions(+)
 create mode 100644 Gemfile
 create mode 100644 Gemfile.lock
Creating app... done, ⬢ dry-wildwood-29387
 ▸    Your account password will expire in 2 day(s). Please update it before that date to avoid getting locked out.
https://dry-wildwood-29387-68c9b97fa481.herokuapp.com/ | https://git.heroku.com/dry-wildwood-29387.git
⛄️ 3.1.4 🚀 /tmp/159e7d8c193a71cbd28439aaf8872cea (main)
$ cat Gemfile
source 'https://rubygems.org'
gem 'rake'
⛄️ 3.1.4 🚀 /tmp/159e7d8c193a71cbd28439aaf8872cea (main)
$ echo "require 'does_not_exist'" >> Rakefile
⛄️ 3.1.4 🚀 /tmp/159e7d8c193a71cbd28439aaf8872cea (main)
$ cat Rakefile
require 'does_not_exist'
⛄️ 3.1.4 🚀 /tmp/159e7d8c193a71cbd28439aaf8872cea (main)
$ work
⛄️ 3.1.4 🚀 /Users/rschneeman/Documents/projects/work
$ cd buildpacks/buildpacks-ruby
⛄️ 3.1.4 🚀 /Users/rschneeman/Documents/projects/work/buildpacks/buildpacks-ruby (schneems/sandy-error-feedback)
$ cargo libcnb package &&
docker rmi my-image --force  &&
pack build my-image --buildpack target/buildpack/debug/heroku_ruby --path /tmp/159e7d8c193a71cbd28439aaf8872cea
🔍 Locating buildpacks...
📦 [1/1] Building heroku/ruby
Determining automatic cross-compile settings...
Building binaries (x86_64-unknown-linux-musl)...
    Finished dev [unoptimized] target(s) in 0.50s
Writing buildpack directory...
Successfully wrote buildpack directory: ../../target/buildpack/debug/heroku_ruby (12.66 MiB)
✨ Packaging successfully finished!

💡 To test your buildpack locally with pack, run:
pack build my-image-name \
  --buildpack /Users/rschneeman/Documents/projects/work/buildpacks/buildpacks-ruby/target/buildpack/debug/heroku_ruby \
  --path /path/to/application

/Users/rschneeman/Documents/projects/work/buildpacks/buildpacks-ruby/target/buildpack/debug/heroku_ruby
Error: No such image: my-image
22: Pulling from heroku/builder
Digest: sha256:f96abc7de9404c184b9d6fc2cb7380a8633b148e965a1d743c6cebf27dcb3392
Status: Image is up to date for heroku/builder:22
22-cnb: Pulling from heroku/heroku
Digest: sha256:0c422f13416d589a199e3fbf9fa17c1a75b1a120fc60425cd6a20216c432f026
Status: Image is up to date for heroku/heroku:22-cnb
===> ANALYZING
Image with name "my-image" not found
===> DETECTING
heroku/ruby 2.0.0
===> RESTORING
===> BUILDING

# Heroku Ruby Buildpack

- Ruby version `3.1.3` from `default`
  - Installing ............ (9.671s)
- Bundler version `2.4.15` from `Gemfile.lock`
  - Running `gem install bundler --version 2.4.15` .... (1.779s)
- Bundle install
  - Running `BUNDLE_BIN="/layers/heroku_ruby/gems/bin" BUNDLE_CLEAN="1" BUNDLE_DEPLOYMENT="1" BUNDLE_GEMFILE="/workspace/Gemfile" BUNDLE_PATH="/layers/heroku_ruby/gems" BUNDLE_WITHOUT="development:test" bundle install`

      Fetching gem metadata from https://rubygems.org/.
      Fetching rake 13.0.6
      Installing rake 13.0.6
      Using bundler 2.4.15
      Bundle complete! 1 Gemfile dependency, 2 gems now installed.
      Gems in the groups 'development' and 'test' were not installed.
      Bundled gems are installed into `/layers/heroku_ruby/gems`

  - Done (11.022s)
- Setting default processes(es)
  - Detecting gems
  - Running `bundle list` ... (0.314s)
  - Skipping default web process (no web gems detected: `rails`, `railties`, `rack`
- Rake assets install
  - Rake detected (`rake` gem found, `Rakefile` found at `/workspace/Rakefile`)

! ERROR: Error detecting rake tasks
!
! The Ruby buildpack uses rake task information from your application to guide
! build logic. Without this information, the Ruby buildpack cannot continue.
!
! Try to reproduce the error locally by running the command below.
! Once you've fixed all errors locally, commit the result to git and retry
! your build.
!
! If your build continues to fail, application requirements, such as provisioned add-ons,
! environment variables, or installed system packages may be needed. Use the
! information below to debug further.

Debug information:

Command failed: "bundle exec rake -P --trace"
exit status: 1
stdout: <empty>
stderr: rake aborted!
LoadError: cannot load such file -- does_not_exist
/workspace/Rakefile:1:in `require'
/workspace/Rakefile:1:in `<top (required)>'
/layers/heroku_ruby/gems/ruby/3.1.0/gems/rake-13.0.6/lib/rake/rake_module.rb:29:in `load'
/layers/heroku_ruby/gems/ruby/3.1.0/gems/rake-13.0.6/lib/rake/rake_module.rb:29:in `load_rakefile'
/layers/heroku_ruby/gems/ruby/3.1.0/gems/rake-13.0.6/lib/rake/application.rb:710:in `raw_load_rakefile'
/layers/heroku_ruby/gems/ruby/3.1.0/gems/rake-13.0.6/lib/rake/application.rb:104:in `block in load_rakefile'
/layers/heroku_ruby/gems/ruby/3.1.0/gems/rake-13.0.6/lib/rake/application.rb:186:in `standard_exception_handling'
/layers/heroku_ruby/gems/ruby/3.1.0/gems/rake-13.0.6/lib/rake/application.rb:103:in `load_rakefile'
/layers/heroku_ruby/gems/ruby/3.1.0/gems/rake-13.0.6/lib/rake/application.rb:82:in `block in run'
/layers/heroku_ruby/gems/ruby/3.1.0/gems/rake-13.0.6/lib/rake/application.rb:186:in `standard_exception_handling'
/layers/heroku_ruby/gems/ruby/3.1.0/gems/rake-13.0.6/lib/rake/application.rb:80:in `run'
/layers/heroku_ruby/gems/ruby/3.1.0/gems/rake-13.0.6/exe/rake:27:in `<top (required)>'
/layers/heroku_ruby/gems/ruby/3.1.0/bin/rake:25:in `load'
/layers/heroku_ruby/gems/ruby/3.1.0/bin/rake:25:in `<top (required)>'
/layers/heroku_ruby/bundler/gems/bundler-2.4.15/lib/bundler/cli/exec.rb:58:in `load'
/layers/heroku_ruby/bundler/gems/bundler-2.4.15/lib/bundler/cli/exec.rb:58:in `kernel_load'
/layers/heroku_ruby/bundler/gems/bundler-2.4.15/lib/bundler/cli/exec.rb:23:in `run'
/layers/heroku_ruby/bundler/gems/bundler-2.4.15/lib/bundler/cli.rb:492:in `exec'
/layers/heroku_ruby/bundler/gems/bundler-2.4.15/lib/bundler/vendor/thor/lib/thor/command.rb:27:in `run'
/layers/heroku_ruby/bundler/gems/bundler-2.4.15/lib/bundler/vendor/thor/lib/thor/invocation.rb:127:in `invoke_command'
/layers/heroku_ruby/bundler/gems/bundler-2.4.15/lib/bundler/vendor/thor/lib/thor.rb:392:in `dispatch'
/layers/heroku_ruby/bundler/gems/bundler-2.4.15/lib/bundler/cli.rb:34:in `dispatch'
/layers/heroku_ruby/bundler/gems/bundler-2.4.15/lib/bundler/vendor/thor/lib/thor/base.rb:485:in `start'
/layers/heroku_ruby/bundler/gems/bundler-2.4.15/lib/bundler/cli.rb:28:in `start'
/layers/heroku_ruby/bundler/gems/bundler-2.4.15/exe/bundle:37:in `block in <top (required)>'
/layers/heroku_ruby/bundler/gems/bundler-2.4.15/lib/bundler/friendly_errors.rb:117:in `with_friendly_errors'
/layers/heroku_ruby/bundler/gems/bundler-2.4.15/exe/bundle:29:in `<top (required)>'
/layers/heroku_ruby/gems/bin/bundle:108:in `load'
/layers/heroku_ruby/gems/bin/bundle:108:in `<main>'

ERROR: failed to build: exit status 1
ERROR: failed to build: executing lifecycle: failed with status code: 51
```

It would be nice to format the debug info in a consistent way. Here's a proposal:

```
- Debug information:
  - Command failed: `bundle exec rake -P --trace`
  - exit status: 1
  - stdout: <empty>
  - stderr:

    rake aborted!
    LoadError: cannot load such file -- does_not_exist
    /workspace/Rakefile:1:in `require'
    /workspace/Rakefile:1:in `<top (required)>'
    /layers/heroku_ruby/gems/ruby/3.1.0/gems/rake-13.0.6/lib/rake/rake_module.rb:29:in `load'
    /layers/heroku_ruby/gems/ruby/3.1.0/gems/rake-13.0.6/lib/rake/rake_module.rb:29:in `load_rakefile'
    /layers/heroku_ruby/gems/ruby/3.1.0/gems/rake-13.0.6/lib/rake/application.rb:710:in `raw_load_rakefile'
    /layers/heroku_ruby/gems/ruby/3.1.0/gems/rake-13.0.6/lib/rake/application.rb:104:in `block in load_rakefile'
    /layers/heroku_ruby/gems/ruby/3.1.0/gems/rake-13.0.6/lib/rake/application.rb:186:in `standard_exception_handling'
    /layers/heroku_ruby/gems/ruby/3.1.0/gems/rake-13.0.6/lib/rake/application.rb:103:in `load_rakefile'
    /layers/heroku_ruby/gems/ruby/3.1.0/gems/rake-13.0.6/lib/rake/application.rb:82:in `block in run'
    /layers/heroku_ruby/gems/ruby/3.1.0/gems/rake-13.0.6/lib/rake/application.rb:186:in `standard_exception_handling'
    /layers/heroku_ruby/gems/ruby/3.1.0/gems/rake-13.0.6/lib/rake/application.rb:80:in `run'
    /layers/heroku_ruby/gems/ruby/3.1.0/gems/rake-13.0.6/exe/rake:27:in `<top (required)>'
    /layers/heroku_ruby/gems/ruby/3.1.0/bin/rake:25:in `load'
    /layers/heroku_ruby/gems/ruby/3.1.0/bin/rake:25:in `<top (required)>'
    /layers/heroku_ruby/bundler/gems/bundler-2.4.15/lib/bundler/cli/exec.rb:58:in `load'
    /layers/heroku_ruby/bundler/gems/bundler-2.4.15/lib/bundler/cli/exec.rb:58:in `kernel_load'
    /layers/heroku_ruby/bundler/gems/bundler-2.4.15/lib/bundler/cli/exec.rb:23:in `run'
    /layers/heroku_ruby/bundler/gems/bundler-2.4.15/lib/bundler/cli.rb:492:in `exec'
    /layers/heroku_ruby/bundler/gems/bundler-2.4.15/lib/bundler/vendor/thor/lib/thor/command.rb:27:in `run'
    /layers/heroku_ruby/bundler/gems/bundler-2.4.15/lib/bundler/vendor/thor/lib/thor/invocation.rb:127:in `invoke_command'
    /layers/heroku_ruby/bundler/gems/bundler-2.4.15/lib/bundler/vendor/thor/lib/thor.rb:392:in `dispatch'
    /layers/heroku_ruby/bundler/gems/bundler-2.4.15/lib/bundler/cli.rb:34:in `dispatch'
    /layers/heroku_ruby/bundler/gems/bundler-2.4.15/lib/bundler/vendor/thor/lib/thor/base.rb:485:in `start'
    /layers/heroku_ruby/bundler/gems/bundler-2.4.15/lib/bundler/cli.rb:28:in `start'
    /layers/heroku_ruby/bundler/gems/bundler-2.4.15/exe/bundle:37:in `block in <top (required)>'
    /layers/heroku_ruby/bundler/gems/bundler-2.4.15/lib/bundler/friendly_errors.rb:117:in `with_friendly_errors'
    /layers/heroku_ruby/bundler/gems/bundler-2.4.15/exe/bundle:29:in `<top (required)>'
    /layers/heroku_ruby/gems/bin/bundle:108:in `load'
    /layers/heroku_ruby/gems/bin/bundle:108:in `<main>'

ERROR: failed to build: exit status 1
ERROR: failed to build: executing lifecycle: failed with status code: 51
```

However this is tricky as I don't want to directly couple `fun_run` with the details of `build_output`. Technically `build_output` could be generalized into a reusable crate. I've thought about calling it "bullet_progress" at it displays progress using bullet and markdown formatting. It could be re-used in anything that needs to stream progress that runs sub commands.
@schneems schneems force-pushed the schneems/sandy-error-feedback branch 2 times, most recently from f588413 to 7534485 Compare July 31, 2023 20:44
It love it. Much better. It allows you to gradually build up an error output instead of having to format it in one go and be worried about getting newline spacing right.

Each part is treated as its own paragraph with double newline separating paragraphs. Because we track all the output and only build it at the end, we can determine when to insert a `!\n` or a `\n`.

I want to make this generic and use it for all output types:

- Error (done)
- Warning
- Important

I'm a little stuck on naming though and I don't have any warnings right now (other than some inline "help" comments). The goal is to minimize surprises and maximize flexibility while still giving enough context to the underlying output framework to confidently format inputs.

I still wish I had better formatting for `DebugDetail` case of CommandError's. It makes me think this is wanting an implementation as a common interface.

It's getting a little fractally complicated as I think about it so I'm going to try to move forward without solving that problem (as I don't currently have it yet).

I do want to try to tackle the CmdError case as I feel that's really common. I also want to try to output all possible errors as a OneOff binary for debugging purposes.
This paves the way for re-use with warnings/info/whatever as it's more generic than "error". I'll work on refactoring/extracting code later.
@schneems schneems force-pushed the schneems/sandy-error-feedback branch from 7534485 to f6af9da Compare August 1, 2023 21:50
- Allow configurable header placement location https://heroku.slack.com/archives/C02GZCPPV38/p1690921811263229?thread_ts=1690842426.088419&cid=C02GZCPPV38
- Clean up functions. Now all formatting functions are in `fmt`. I still don't love the name of `mod paragraph` and the functionality seems like it should be easy to generalize to important/warning/error but I'm not seeing an easy path forward.
@schneems schneems force-pushed the schneems/sandy-error-feedback branch from f6af9da to d477d56 Compare August 1, 2023 22:02
Previously the decision whether an output needs to be `println` or `print` had to be made up front, then if you use `print` you have to remember to always end in a newline later. This structure gives us the ability to set a default and then yield control to the caller. That way they could either continue printing on the same line or finalize it and start printing on their own line.
I've previously lamented that I didn't like that name. This change makes the name more generic and also introduces two now announcement kinds: warning and important.


In addition. The debugging details are now printed first so the most important error message comes last.
This command will now simulate errors and print them to the console:

```
$ cargo run --bin print_ruby_errors
```

For example:

    $ cargo run --bin print_ruby_errors
    # Printing Ruby errors

    The error data is fabricated and may diverge from main.rs.
    Use this output to adjust and inspect formatting.


    ## Error message for RubyBuildpackError::CannotDetectRakeTasks

    ```

    - Command failed: `bundle exec rake -P --trace`
      - exit status: 1
      - stdout: <empty>
      - stderr:

          rake aborted!
          LoadError: cannot load such file -- does_not_exist
          /workspace/Rakefile:1:in `require'
          /workspace/Rakefile:1:in `<top (required)>'
          /layers/heroku_ruby/gems/ruby/3.1.0/gems/rake-13.0.6/lib/rake/rake_module.rb:29:in `load'
          /layers/heroku_ruby/gems/ruby/3.1.0/gems/rake-13.0.6/lib/rake/rake_module.rb:29:in `load_rakefile'
          /layers/heroku_ruby/gems/ruby/3.1.0/gems/rake-13.0.6/lib/rake/application.rb:710:in `raw_load_rakefile'
          /layers/heroku_ruby/gems/ruby/3.1.0/gems/rake-13.0.6/lib/rake/application.rb:104:in `block in load_rakefile'
          /layers/heroku_ruby/gems/ruby/3.1.0/gems/rake-13.0.6/lib/rake/application.rb:186:in `standard_exception_handling'
          /layers/heroku_ruby/gems/ruby/3.1.0/gems/rake-13.0.6/lib/rake/application.rb:103:in `load_rakefile'
          /layers/heroku_ruby/gems/ruby/3.1.0/gems/rake-13.0.6/lib/rake/application.rb:82:in `block in run'
          /layers/heroku_ruby/gems/ruby/3.1.0/gems/rake-13.0.6/lib/rake/application.rb:186:in `standard_exception_handling'
          /layers/heroku_ruby/gems/ruby/3.1.0/gems/rake-13.0.6/lib/rake/application.rb:80:in `run'
          /layers/heroku_ruby/gems/ruby/3.1.0/gems/rake-13.0.6/exe/rake:27:in `<top (required)>'
          /layers/heroku_ruby/gems/ruby/3.1.0/bin/rake:25:in `load'
          /layers/heroku_ruby/gems/ruby/3.1.0/bin/rake:25:in `<top (required)>'
          /layers/heroku_ruby/bundler/gems/bundler-2.4.15/lib/bundler/cli/exec.rb:58:in `load'
          /layers/heroku_ruby/bundler/gems/bundler-2.4.15/lib/bundler/cli/exec.rb:58:in `kernel_load'
          /layers/heroku_ruby/bundler/gems/bundler-2.4.15/lib/bundler/cli/exec.rb:23:in `run'
          /layers/heroku_ruby/bundler/gems/bundler-2.4.15/lib/bundler/cli.rb:492:in `exec'
          /layers/heroku_ruby/bundler/gems/bundler-2.4.15/lib/bundler/vendor/thor/lib/thor/command.rb:27:in `run'
          /layers/heroku_ruby/bundler/gems/bundler-2.4.15/lib/bundler/vendor/thor/lib/thor/invocation.rb:127:in `invoke_command'
          /layers/heroku_ruby/bundler/gems/bundler-2.4.15/lib/bundler/vendor/thor/lib/thor.rb:392:in `dispatch'
          /layers/heroku_ruby/bundler/gems/bundler-2.4.15/lib/bundler/cli.rb:34:in `dispatch'
          /layers/heroku_ruby/bundler/gems/bundler-2.4.15/lib/bundler/vendor/thor/lib/thor/base.rb:485:in `start'
          /layers/heroku_ruby/bundler/gems/bundler-2.4.15/lib/bundler/cli.rb:28:in `start'
          /layers/heroku_ruby/bundler/gems/bundler-2.4.15/exe/bundle:37:in `block in <top (required)>'
          /layers/heroku_ruby/bundler/gems/bundler-2.4.15/lib/bundler/friendly_errors.rb:117:in `with_friendly_errors'
          /layers/heroku_ruby/bundler/gems/bundler-2.4.15/exe/bundle:29:in `<top (required)>'
          /layers/heroku_ruby/gems/bin/bundle:108:in `load'
          /layers/heroku_ruby/gems/bin/bundle:108:in `<main>'

    ! ERROR: Error detecting rake tasks
    !
    ! The Ruby buildpack uses rake task information from your application to guide
    ! build logic. Without this information, the Ruby buildpack cannot continue.
    !
    ! Ensure you can run the following command locally with no errors before attempting another build:
    !
    ! `bundle exec rake -P --trace`
    !
    ! Use the information above to debug further.


    ```

	...
@schneems schneems force-pushed the schneems/sandy-error-feedback branch from 467bbf6 to 70ec554 Compare August 4, 2023 16:00
@schneems schneems marked this pull request as ready for review August 4, 2023 16:05
@schneems schneems requested a review from a team as a code owner August 4, 2023 16:05
In Ruby I build CLI output APIs around an injectable IO object like. like this:

```
class PrintFormatter
  attr_reader: io

  def initialize(io: STDOUT)
    @io = io
  end

  def puts(thing)
    @io.puts("yolo: #{thing}")
  end
end

let printer = PrintFormatter.new(
  io: StringIO.new
)
```

You can then access and assert against the contents in a test.

In Rust that would require otherwise stateless functions to take shared mutable state and it seems bad to mess with the mutability requirements just for testing.

Since I "own" the entirety of `build_output` I'm using a single purpose global to capture the contents of what's being logged in test only.

I looked into doing something like this for the `log` crate (logging facade) but there's a number of edge cases you have to deal with and it's ultimately not what that crate was intended to do. This very focused logic is minimal and allows me to test methods together, instead of only in isolation.
While the prior log testing mechanism was thread safe in the technical sense, it wrote all data from all threads to the same string. This worked because we only have a single test asserting on this information, but when I forced other tests to write to the same logger the test failed.

The solution I introduced here tracks content based on thread id. It needs to be injectable as well because we have some logic like `LiveTimingInline` that prints dots to the background in a separate thread. As we own all the printing code we wish to test, this is a trivial contortion and doesn't change the public API.

I also made sure all structs and enums are derive Debug.
The `Detail` enum was somewhat confusing as there's a separate concept of a "detail" which means being formatted in parens. I changed it to `raw` which is closer to what it is and more generally applicable.
I added a newline originally because the error body should be separated by newline. The header already has a starting newline, so that's not needed. This change allows for more natural step/section output so debugging information rendered in that format will flow together.
Copy link
Member

@edmorley edmorley left a comment

Choose a reason for hiding this comment

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

I had a quick glance through but since the PR is +1,743 −543 and mixes and matches several different changes (error message changes, logging API changes, adding new binary to test output etc) it's hard to review properly. Though given this is your repo (rather than one of the shared codebases) I'm fine with us only giving a quicker review, if you're confident in the changes yourself.

Comment on lines +96 to +101
- name: Install musl-tools
run: sudo apt-get install musl-tools --no-install-recommends
- name: Update Rust toolchain
run: rustup update
- name: Install Rust linux-musl target
run: rustup target add x86_64-unknown-linux-musl
Copy link
Member

Choose a reason for hiding this comment

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

The cross-compile setup steps can be removed to speed up this job, since no cross-compilation takes place here

Suggested change
- name: Install musl-tools
run: sudo apt-get install musl-tools --no-install-recommends
- name: Update Rust toolchain
run: rustup update
- name: Install Rust linux-musl target
run: rustup target add x86_64-unknown-linux-musl
- name: Update Rust toolchain
run: rustup update

Comment on lines +104 to +108
- name: Build binary
run: cargo build --bin print_ruby_errors
- name: "PRINT: Error output"
run: | # Use `script -e -c` to pretend to be a TTY for pack terminal color support
script -e -c "cargo run --bin print_ruby_errors"
Copy link
Member

Choose a reason for hiding this comment

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

(Optional)

The cargo build step is redundant, since the cargo run step already does a build.

If the purpose of running it first is so that the build logs are not shown next to the print_ruby_errors output, then you could pass --quiet to cargo run to suppress the Cargo log output (if the compile fails, any errors will still be shown).

Suggested change
- name: Build binary
run: cargo build --bin print_ruby_errors
- name: "PRINT: Error output"
run: | # Use `script -e -c` to pretend to be a TTY for pack terminal color support
script -e -c "cargo run --bin print_ruby_errors"
- name: "PRINT: Error output"
run: | # Use `script -e -c` to pretend to be a TTY for pack terminal color support
script -e -c "cargo run --quiet --bin print_ruby_errors"

@@ -0,0 +1,6 @@
## Changelog

This project contains several sub-projects. See each for their associated changes:
Copy link
Member

Choose a reason for hiding this comment

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

(Optional idea)

I wonder if the commons crate should be marked as unstable, similar to libcnb-package and libcnb-common and so treated as an implementation detail? ie: Then all user facing changes would only be described in the Ruby CNB's main changelog, and perhaps the repo root changelog could even be made a symlink to the Ruby CNB changelog?

@@ -112,13 +112,13 @@ impl Layer for BundleDownloadLayer {
};
match cache_state(old.clone(), now) {
State::NothingChanged(_version) => {
self.build_output.say("Using cached version");
self.build_output.step("Using cached version");
Copy link
Member

Choose a reason for hiding this comment

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

I'm happy to ignore it this time (given this is your repo, rather than one of our shared repos), but we should really try to split out unrelated changes from PRs - particularly when PRs are already large. This API change (and the others below) are unrelated to adjusting the wording of error messages.

use indoc::formatdoc;

use crate::{build_output::fmt::ErrorInfo, RubyBuildpackError};
#[derive(Debug)]
#[doc(hidden)]
Copy link
Member

Choose a reason for hiding this comment

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

(Optional)

I presume this is pub rather than pub(crate) since it needs to be used by the errors printing binary? And since it's pub Clippy then asks for docs (that aren't needed given it's not really a public API), hence the #[doc(hidden)]? Worth adding a comment explaining?

error,
)
.print(),
Cause::OurError(error) => log_ruby_error(error),
Copy link
Member

Choose a reason for hiding this comment

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

(Existing code so outside the scope of this PR, but mentioning for the future)

I think this came up in a comment from Manuel in another PR, but I also don't like this Cause abstraction - IMO it adds more complexity for little benefit. Libcnb already has error enum variants that are pretty clear (or if you feel their names aren't great, then upstream PRs would be preferred to improve for everyone).

The framework used by this buildpack encountered an unexpected error.
This type of error usually indicates there's nothing wrong with your application.
"})
.body(formatdoc! {"
Copy link
Member

Choose a reason for hiding this comment

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

(Optional)

I'm not sure I understand why the need for multiple body() calls vs passing a single formatdoc! string with newlines?

libherokubuildpack = "0.13"
itertools = "0.11.0"
Copy link
Member

Choose a reason for hiding this comment

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

We only list the major versions in the Cargo.toml entries (see eg f62934a)

Suggested change
itertools = "0.11.0"
itertools = "0.11"


[dev-dependencies]
filetime = "0.2"
toml = "0.7"
indoc = "2.0.1"
Copy link
Member

Choose a reason for hiding this comment

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

Suggested change
indoc = "2.0.1"
indoc = "2"

@schneems schneems closed this Sep 26, 2023
@edmorley edmorley deleted the schneems/sandy-error-feedback branch November 28, 2023 21:12
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.

2 participants