rust icon indicating copy to clipboard operation
rust copied to clipboard

Minor tweaks to refcell logging

Open nealsid opened this issue 7 months ago • 8 comments

  • Fix the logging when debug_refcell is enabled so the location is output as a string rather than a sequence of bytes
  • Avoid logging an empty struct when debug_refcell is disabled
  • Make the panic error message consistent with the compiler borrow-checking error messages

nealsid avatar Jun 08 '25 21:06 nealsid

r? @tgross35

rustbot has assigned @tgross35. They will have a look at your PR within the next two weeks and either review your PR or reassign to another reviewer.

Use r? to explicitly pick a reviewer

rustbot avatar Jun 08 '25 21:06 rustbot

Thank you for the PR!

The wording isn't quite accurate because panic_already_borrowed now says "...because it is also borrowed as immutable", but borrow_mut will also fail if there is an existing mutable borrow. The current messages aren't ideal either because

let cell = RefCell::new(0u32);
let b = (cell.borrow_mut(), cell.borrow_mut());
drop(b);

also prints "already borrowed: BorrowMutError" rather than the more accurate "already mutably borrowed: BorrowMutError", but it still works.

So I think the original wording of "already (mutably) borrowed (here: {err:?})" is probably fine to keep. We could alternatively add track mutably/immutably in the error type, but I don't expect that to be worth it since the # Panics API docs are pretty easy to locate (by comparison, with the rustc error it might not be as obvious that you are mutably/immutably borrowing because e.g. it's in a function signature).

Fix the logging when debug_refcell is enabled so the location is output as a string rather than a sequence of bytes

Mind commenting the before and after here? Location's debug should just print the file, line, and column.

tgross35 avatar Jun 09 '25 09:06 tgross35

@rustbot author for the above

tgross35 avatar Jun 09 '25 21:06 tgross35

Reminder, once the PR becomes ready for a review, use @rustbot ready.

rustbot avatar Jun 09 '25 21:06 rustbot

Fix the logging when debug_refcell is enabled so the location is output as a string rather than a sequence of bytes

Mind commenting the before and after here? Location's debug should just print the file, line, and column.

Location only implements Display, not Debug (link). Below is the output if you enable debug_refcell and cause a panic today:

     Running `target\debug\refcell-test.exe`
Hello, world! RefCell { value: 5 }

thread 'main' panicked at src\main.rs:11:15:
already borrowed: BorrowMutError { location: Location { file_bytes_with_nul: [115, 114, 99, 92, 109, 97, 105, 110, 46, 114, 115, 0], line: 8, col: 15 } }
stack backtrace:
   0: std::panicking::begin_panic_handler
             at C:\Users\neals\rust\library\std\src\panicking.rs:697
   1: core::panicking::panic_fmt
             at C:\Users\neals\rust\library\core\src\panicking.rs:75
   2: core::cell::panic_already_borrowed
             at C:\Users\neals\rust\library\core\src\cell.rs:791
   3: core::cell::RefCell<i32>::borrow_mut<i32>
             at C:\Users\neals\rust\library\core\src\cell.rs:1083
   4: refcell_test::main
             at .\src\main.rs:11
   5: core::ops::function::FnOnce::call_once<void (*)(),tuple$<> >
             at C:\Users\neals\rust\library\core\src\ops\function.rs:250
   6: core::hint::black_box
             at C:\Users\neals\rust\library\core\src\hint.rs:482
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
error: process didn't exit successfully: `target\debug\refcell-test.exe` (exit code: 101)
PS C:\Users\neals\refcell-test>

nealsid avatar Jun 10 '25 01:06 nealsid

The panic output after my proposed change (I haven't reverted the first logging change yet, this is just meant to show the change in Location's output):

     Running `target\debug\refcell-test.exe`
Hello, world! RefCell { value: 5 }

thread 'main' panicked at src\main.rs:11:15:
cannot borrow as mutable because it is also borrowed as immutable here BorrowMutError { location: src\main.rs:8:15 }
stack backtrace:
   0: std::panicking::begin_panic_handler
             at C:\Users\neals\rust\library\std\src\panicking.rs:697
   1: core::panicking::panic_fmt
             at C:\Users\neals\rust\library\core\src\panicking.rs:75
   2: core::cell::panic_already_borrowed
             at C:\Users\neals\rust\library\core\src\cell.rs:792
   3: core::cell::RefCell<i32>::borrow_mut<i32>
             at C:\Users\neals\rust\library\core\src\cell.rs:1091
   4: refcell_test::main
             at .\src\main.rs:11
   5: core::ops::function::FnOnce::call_once<void (*)(),tuple$<> >
             at C:\Users\neals\rust\library\core\src\ops\function.rs:250
   6: core::hint::black_box
             at C:\Users\neals\rust\library\core\src\hint.rs:482
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
error: process didn't exit successfully: `target\debug\refcell-test.exe` (exit code: 101)
PS C:\Users\neals\refcell-test>

nealsid avatar Jun 10 '25 01:06 nealsid

Thank you for the PR!

The wording isn't quite accurate because panic_already_borrowed now says "...because it is also borrowed as immutable", but borrow_mut will also fail if there is an existing mutable borrow. The current messages aren't ideal either because

let cell = RefCell::new(0u32);
let b = (cell.borrow_mut(), cell.borrow_mut());
drop(b);

also prints "already borrowed: BorrowMutError" rather than the more accurate "already mutably borrowed: BorrowMutError", but it still works.

So I think the original wording of "already (mutably) borrowed (here: {err:?})" is probably fine to keep. We could alternatively add track mutably/immutably in the error type, but I don't expect that to be worth it since the # Panics API docs are pretty easy to locate (by comparison, with the rustc error it might not be as obvious that you are mutably/immutably borrowing because e.g. it's in a function signature).

Sounds good, thanks! I'll revert that part of the logging.

Your example code made me think of another potential issue:

    let v = RefCell::new(5);
    let w = v.borrow();
    let y = v.borrow();
    drop(w);
    let x = v.borrow_mut();

In this case, the RefCell will track the location of the borrow for w (since it tracks the first borrow: link) and log that in the panic, although y is the conflicting borrow when borrow_mut() is called on the last line. Is that something that should be fixed?

nealsid avatar Jun 10 '25 01:06 nealsid

Location only implements Display, not Debug (link). Below is the output if you enable debug_refcell and cause a panic today:

It does implement Debug via the derive, but you're right that it just prints the bag of bytes. Looks like this is a very recent regression https://github.com/rust-lang/rust/pull/135054. We should fix the Debug implementation instead since that affects more than this, so you can actually drop the format_args!("{}", self.location) here.

Opened https://github.com/rust-lang/rust/issues/142279 to track that.

In this case, the RefCell will track the location of the borrow for w (since it tracks the first borrow: link) and log that in the panic, although y is the conflicting borrow when borrow_mut() is called on the last line. Is that something that should be fixed?

It would be nice, but there isn't an easy way to do this is there? We would need to store multiple locations since we can't tell which will get released last, which would mean keeping some kind of location collection rather than just incrementing/decrementing the borrow count.

tgross35 avatar Jun 10 '25 03:06 tgross35

The job mingw-check-tidy failed! Check out the build log: (web) (plain)

Click to see the possible cause of the failure (guessed by this bot)
npm WARN deprecated [email protected]: This module is not supported, and leaks memory. Do not use it. Check out lru-cache if you want a good and tested way to coalesce async requests by a key value, which is much more comprehensive and powerful.
npm WARN deprecated [email protected]: Rimraf versions prior to v4 are no longer supported
npm WARN deprecated [email protected]: Glob versions prior to v9 are no longer supported
npm WARN deprecated [email protected]: This version is no longer supported. Please see https://eslint.org/version-support for other options.
npm ERR! code E503
npm ERR! 503 Service Unavailable - GET https://registry.npmjs.org/@humanwhocodes/object-schema/-/object-schema-1.2.1.tgz - Service Unavailable

npm ERR! A complete log of this run can be found in: /home/user/.npm/_logs/2025-06-12T18_09_44_544Z-debug-0.log
  local time: Thu Jun 12 18:14:11 UTC 2025
  network time: Thu, 12 Jun 2025 18:14:11 GMT
##[error]Process completed with exit code 1.
Post job cleanup.

rust-log-analyzer avatar Jun 12 '25 18:06 rust-log-analyzer

The job mingw-check-tidy failed! Check out the build log: (web) (plain)

Click to see the possible cause of the failure (guessed by this bot)
##[endgroup]
Executing TIDY_PRINT_DIFF=1 npm install eslint@$(head -n 1 /tmp/eslint.version) &&  python2.7 ../x.py test --stage 0 src/tools/tidy tidyselftest --extra-checks=py,cpp
+ head -n 1 /tmp/eslint.version
+ TIDY_PRINT_DIFF=1 npm install [email protected]
npm ERR! code E504
npm ERR! 504 Gateway Timeout - GET https://registry.npmjs.org/@humanwhocodes%2fobject-schema

npm ERR! A complete log of this run can be found in: /home/user/.npm/_logs/2025-06-12T18_21_19_138Z-debug-0.log
  local time: Thu Jun 12 18:25:12 UTC 2025
  network time: Thu, 12 Jun 2025 18:25:13 GMT
##[error]Process completed with exit code 1.
Post job cleanup.

rust-log-analyzer avatar Jun 12 '25 18:06 rust-log-analyzer

These commits modify the Cargo.lock file. Unintentional changes to Cargo.lock can be introduced when switching branches and rebasing PRs.

If this was unintentional then you should revert the changes before this PR is merged. Otherwise, you can ignore this comment.

Some changes occurred to the CTFE / Miri interpreter

cc @rust-lang/miri

This PR modifies bootstrap.example.toml.

If appropriate, please update CONFIG_CHANGE_HISTORY in src/bootstrap/src/utils/change_tracker.rs.

This PR modifies src/bootstrap/src/core/config.

If appropriate, please update CONFIG_CHANGE_HISTORY in src/bootstrap/src/utils/change_tracker.rs.

The rustc-dev-guide subtree was changed. If this PR only touches the dev guide consider submitting a PR directly to rust-lang/rustc-dev-guide otherwise thank you for updating the dev guide with your changes.

cc @BoxyUwU, @jieyouxu, @kobzol

Some changes occurred in compiler/rustc_codegen_ssa

cc @WaffleLapkin

Some changes occurred to the intrinsics. Make sure the CTFE / Miri interpreter gets adapted for the changes, if necessary.

cc @rust-lang/miri, @RalfJung, @oli-obk, @lcnr

Some changes occurred in src/tools/clippy

cc @rust-lang/clippy

Some changes occurred to the CTFE machinery

cc @RalfJung, @oli-obk, @lcnr

triagebot.toml has been modified, there may have been changes to the review queue.

cc @davidtwco, @wesleywiser

Some changes occurred in compiler/rustc_attr_data_structures

cc @jdonszelmann

HIR ty lowering was modified

cc @fmease

Changes to the size of AST and/or HIR nodes.

cc @nnethercote

Some changes occurred to MIR optimizations

cc @rust-lang/wg-mir-opt

The Miri subtree was changed

cc @rust-lang/miri

Some changes occurred in compiler/rustc_attr_parsing

cc @jdonszelmann

Some changes occurred in compiler/rustc_codegen_cranelift

cc @bjorn3

Some changes occurred in compiler/rustc_codegen_gcc

cc @antoyo, @GuillaumeGomez

rustbot avatar Jun 14 '25 03:06 rustbot

I seem to have hosed my repo, sorry about that! Please ignore.

nealsid avatar Jun 14 '25 03:06 nealsid

@rustbot label +S-waiting-on-author -S-waiting-on-review

nealsid avatar Jun 14 '25 14:06 nealsid

The wording isn't quite accurate because panic_already_borrowed now says "...because it is also borrowed as immutable", but borrow_mut will also fail if there is an existing mutable borrow. The current messages aren't ideal either because

Ah, I missed that, thanks!

let cell = RefCell::new(0u32);
let b = (cell.borrow_mut(), cell.borrow_mut());
drop(b);

also prints "already borrowed: BorrowMutError" rather than the more accurate "already mutably borrowed: BorrowMutError", but it still works.

So I think the original wording of "already (mutably) borrowed (here: {err:?})" is probably fine to keep. We could alternatively add track mutably/immutably in the error type, but I don't expect that to be worth it since the # Panics API docs are pretty easy to locate (by comparison, with the rustc error it might not be as obvious that you are mutably/immutably borrowing because e.g. it's in a function signature).

Agreed on it not being worth it to track mutably/immutably in the error type. However, I still think the error messages are a bit cryptic, even if the audience is developers (or, in the case of enabling debug_refcell, developers who have rebuilt std). They require some spelunking into the code to understand, especially to understand the location field (because which previous borrow it picked to log isn't entirely clear).

How about the following?

Without debug_refcell enabled:

thread 'main' panicked at src\main.rs:9:15:
RefCell already mutably borrowed

With debug_refcell enabled:

thread 'main' panicked at src\main.rs:9:15:
RefCell already mutably borrowed, a previous borrow was at this location: src\main.rs:8:15

nealsid avatar Jun 14 '25 19:06 nealsid

@tgross35 In my testing I've noticed that the Debug impl for BorrowError/BorrowMutError don't output anything different from having BorrowError/BorrowMutError having #[derive(Debug)] added to them, unless I'm missing something. What do you think about removing them? Should be less code to maintain while retaining backward-compatibility.

nealsid avatar Jun 14 '25 20:06 nealsid

In this case, the RefCell will track the location of the borrow for w (since it tracks the first borrow: link) and log that in the panic, although y is the conflicting borrow when borrow_mut() is called on the last line. Is that something that should be fixed?

It would be nice, but there isn't an easy way to do this is there? We would need to store multiple locations since we can't tell which will get released last, which would mean keeping some kind of location collection rather than just incrementing/decrementing the borrow count.

Yeah, I don't see an easy way to do that, and even if we did store a location collection, it would be out of date after borrows were dropped.

nealsid avatar Jun 14 '25 20:06 nealsid

@rustbot review

nealsid avatar Jun 16 '25 17:06 nealsid

Thank you!

@bors r+ rollup

tgross35 avatar Jun 16 '25 18:06 tgross35

:pushpin: Commit 2fca05a378d91df3943545e8161e0e2e93943125 has been approved by tgross35

It is now in the queue for this repository.

bors avatar Jun 16 '25 18:06 bors