Rust: file not found for module

[jxs]

Hi,
I have a crate that CI fails for all the tests on the latest nightly with the following output:

--> refinery/tests/mod_migrations/mod.rs:2:5

  |

2 |     refinery::include_migration_mods!("./tests/mod_migrations");

  |     ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^

  |

  = help: to create the module `V2__add_cars_table`, create file "refinery/tests/mod_migrations/migrations/V2__add_cars_table.rs"

  = note: this error originates in a macro (in Nightly builds, run with -Z macro-backtrace for more info)



error[E0583]: file not found for module `V1__initial`

 --> refinery/tests/mod_migrations/mod.rs:2:5

  |

2 |     refinery::include_migration_mods!("./tests/mod_migrations");

  |     ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^

  |

  = help: to create the module `V1__initial`, create file "refinery/tests/mod_migrations/migrations/V1__initial.rs"

  = note: this error originates in a macro (in Nightly builds, run with -Z macro-backtrace for more info)



error[E0583]: file not found for module `V4__add_year_to_motos_table`

 --> refinery/tests/mod_migrations/mod.rs:2:5

  |

2 |     refinery::include_migration_mods!("./tests/mod_migrations");

  |     ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^

  |

  = help: to create the module `V4__add_year_to_motos_table`, create file "refinery/tests/mod_migrations/migrations/V4__add_year_to_motos_table.rs"

  = note: this error originates in a macro (in Nightly builds, run with -Z macro-backtrace for more info)



error[E0583]: file not found for module `V3__add_brand_to_cars_table`

 --> refinery/tests/mod_migrations/mod.rs:2:5

  |

2 |     refinery::include_migration_mods!("./tests/mod_migrations");

  |     ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^

  |

  = help: to create the module `V3__add_brand_to_cars_table`, create file "refinery/tests/mod_migrations/migrations/V3__add_brand_to_cars_table.rs"

  = note: this error originates in a macro (in Nightly builds, run with -Z macro-backtrace for more info)



error[E0425]: cannot find function `migration` in module `V2__add_cars_table`

 --> refinery/tests/mod_migrations/mod.rs:2:5

  |

2 |     refinery::include_migration_mods!("./tests/mod_migrations");

  |     ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ not found in `V2__add_cars_table`

  |

  = note: this error originates in a macro (in Nightly builds, run with -Z macro-backtrace for more info)



error[E0425]: cannot find function `migration` in module `V1__initial`

 --> refinery/tests/mod_migrations/mod.rs:2:5

  |

2 |     refinery::include_migration_mods!("./tests/mod_migrations");

  |     ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ not found in `V1__initial`

  |

  = note: this error originates in a macro (in Nightly builds, run with -Z macro-backtrace for more info)



error[E0425]: cannot find function `migration` in module `V4__add_year_to_motos_table`

 --> refinery/tests/mod_migrations/mod.rs:2:5

  |

2 |     refinery::include_migration_mods!("./tests/mod_migrations");

  |     ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ not found in `V4__add_year_to_motos_table`

  |

  = note: this error originates in a macro (in Nightly builds, run with -Z macro-backtrace for more info)



error[E0425]: cannot find function `migration` in module `V3__add_brand_to_cars_table`

 --> refinery/tests/mod_migrations/mod.rs:2:5

  |

2 |     refinery::include_migration_mods!("./tests/mod_migrations");

  |     ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ not found in `V3__add_brand_to_cars_table`

  |

  = note: this error originates in a macro (in Nightly builds, run with -Z macro-backtrace for more info)

the refered code is here and the macro used is defined here the same tests pass on stable channel.

If there is there is anything else that I can do to help, I am happy to contribute
thanks!

[jonas-schievink]

Which version are you on? Your "CI" link requires a login.

Probably a duplicate of https://github.com/rust-lang/rust/issues/70185 and you need to wait for the nightly version to update.

[spastorino]

@jxs can you try out if it works for you using nightly-2020-03-22 or superior?

[spastorino]

pre-triage: assigning P-high just in case is not a dupe of #70185

[jonas-schievink]

Still an issue on rustc 1.44.0-nightly (02046a5d4 2020-03-24)

[Centril]

Let's try to shrink the input into something more manageable for finding a fix / understanding the cause.

@rustbot ping cleanup

[rustbot]

Hey Cleanup Crew ICE-breakers! This bug has been identified as a good
"Cleanup ICE-breaking candidate". In case it's useful, here are some
[instructions] for tackling these sorts of bugs. Maybe take a look?
Thanks! <3

cc @AminArria @chrissimpkins @contrun @DutchGhost @elshize @ethanboxx @h-michael @HallerPatrick @hdhoang @hellow554 @imtsuki @jakevossen5 @kanru @KarlK90 @LeSeulArtichaut @MAdrianMattocks @matheus-consoli @mental32 @nmccarty @Noah-Kennedy @pard68 @PeytonT @pierreN @Redblueflame @RobbieClarken @RobertoSnap @robjtede @SarthakSingh31 @senden9 @shekohex @sinato @spastorino @turboladen @woshilapin @yerke

[woshilapin]

For those who don't have a CircleCI account or don't want to create one, here are the steps of the build.

The problem is that I can't really reproduce the steps because the first step

cargo install --path ./refinery_cli --no-default-features --features=mysql

Doesn't build. Indeed, the build depends on a human_panic::Metadata containing a field named repository. This field doesn't exist except in the yanked version 1.0.2 (see 1.0.3 documentation versus 1.0.2 documentation). https://docs.rs/human-panic/1.0.3/human_panic/struct.Metadata.html#fields.

I then tried to only run the last step of tests. It depends on a running MySQL instance. From the configuration here, I launched a MySQL instance first with (do not forget to wait a few seconds, MySQL needs to be initialized first or the tests will fail).

docker run \
    --name mysql \
    --publish 127.0.0.1:3306:3306 \
    --env MYSQL_USER=refinery \
    --env MYSQL_PASSWORD=root \
    --env MYSQL_DATABASE=refinery_test \
    --env MYSQL_ROOT_PASSWORD=root \
    --detach \
    mysql:latest

Here is the command on which the CI is failing.

cd refinery && cargo test --features tokio,mysql_async --test mysql_async -- --test-threads 1

I was able to run the tests on a stable version of Rust so far and the tests pass. I also tried on a rustc 1.44.0-nightly (f509b26a7 2020-03-18) and the tests pass too. So I can't reproduce the fail so far.

[jxs]

thank you all for the support!
@woshilapin you have to checkout into the PR branch, but yeah I can't reproduce it locally, only launching tests from the rustlang/rust:nightly container
i just tried with the latest version: rustlang/rust@sha256:22f9da1a439f9fd29281da51b6fd2aa4de6f1ca6a4f1af29579b9065b9d0f911 still fails
I think you need to be logged with github to have access to the ci logs sorry :disappointed:

[nikomatsakis]

A few questions:

• Have we ruled out that this is a duplicate of https://github.com/rust-lang/rust/issues/70185? (Update: I think we have)
• @jxs if you are able to reproduce, can you try to identify which nightly caused the behavior to change? There is some advice available on how to bisect as well.

[jxs]

@nikomatsakis
rustc version: rustc 1.44.0-nightly (02046a5d4 2020-03-24)
steps i used to reproduce locally:

 git clone https://github.com/jxs/refinery
 cd refinery
 git checkout target-migrations
 sudo docker run -v $(pwd):/usr/local/lib/refinery -it --rm rustlang/rust:nightly bash
 cd /usr/local/lib/refinery/refinery
 cargo test --features rusqlite

i am now going to try and bisect to find at which nightly did this start, but locally with cargo 1.44.0-nightly (7019b3ed3 2020-03-17) it doesn't happen

[AminArria]

@nikomatsakis @jxs result of cargo bisect-rustc

searched nightlies: from nightly-2020-03-18 to nightly-2020-03-20
regressed nightly: nightly-2020-03-20
searched commits: from https://github.com/rust-lang/rust/commit/f509b26a7730d721ef87423a72b3fdf8724b4afa to https://github.com/rust-lang/rust/commit/f4c675c476c18b1a11041193f2f59d695b126bc8
regressed commit: https://github.com/rust-lang/rust/commit/57e1da59cd0761330b4ea8d47b16340a78eeafa9
source code: https://github.com/jxs/refinery

[jxs]

yeah got the same results:

searched nightlies: from nightly-2020-03-17 to nightly-2020-03-24
regressed nightly: nightly-2020-03-20
searched commits: from https://github.com/rust-lang/rust/commit/f509b26a7730d721ef87423a72b3fdf8724b4afa to https://github.com/rust-lang/rust/commit/f4c675c476c18b1a11041193f2f59d695b126bc8
regressed commit: https://github.com/rust-lang/rust/commit/57e1da59cd0761330b4ea8d47b16340a78eeafa9
source code: https://github.com/jxs/refinery/tree/target-migrations

[nikomatsakis]

So almost certainly this regressed due to https://github.com/rust-lang/rust/pull/69838, but that was a big change -- what we really need, I think, is a better way to reproduce the problem. Currently the error occurs on a large crate, can we remove irrelevant code / modules etc to simplify the problem to something manageable?

[woshilapin]

I've been trying to remove irrelevant code but I'm probably not even halfway into producing a MVCE. Still, I removed about 5000 lines and have still about 350 lines of code so far but still in 3 crates. I'll probably continue some other day but if someone else wants to help, I'm sharing what I've done so far in this branch (and I'll continue to push on this branch my updates).

[nikomatsakis]

@woshilapin great progress, thanks!

[woshilapin]

I've shrink it down a bit more into 2 crates (one of it is a procmacro so I'm not sure how (if?) I can shrink down to only one crate). The procmacro is now 27 lines long and the crate with the test failing at compilation is about a dozen lines of code split in 3 files. I hope this will help.

[jxs]

@woshilapin thanks! :heart:

[nikomatsakis]

@Centril It sounds like @woshilapin has got the test case down to something pretty reasonable, maybe small enough to start poking about and see if you can isolate the problem?

[nikomatsakis]

@petrochenkov do you think you'd have time to investigate this regression?

[petrochenkov]

Looks like there's a minimized reproduction in https://github.com/rust-lang/rust/issues/70314#issuecomment-609503969, so yes, I'll try to look at this during this or next weekend.

[pnkfelix]

I have independently reduced the test input into something pretty small; small enough for me to cut and paste into this comment (I hope):

Click to see the files for pnkfelix's MCVE test input

• refinery_macros/Cargo.toml:

[package]
name = "refinery-macros"
version = "0.2.0"
authors = []
edition = "2018"

[lib]
proc-macro = true

[dependencies]
quote = "1"
syn = { version = "1", features=["full"] }
proc-macro2 = "1"

• refinery_macros/src/lib.rs:

#![recursion_limit = "128"]
extern crate proc_macro;

use proc_macro::TokenStream;

#[proc_macro]
pub fn include_v1(_input: TokenStream) -> TokenStream {
    let ident = syn::Ident::new("V1__initial", proc_macro2::Span::call_site());
    let result = quote::quote! { pub mod #ident; };
    result.into()
}

• refinery/Cargo.toml:

[package]
name = "refinery"
version = "0.2.0"
authors = []
edition = "2018"

[dependencies]
refinery-macros= { version = "0.2.0", path = "../refinery_macros" }

• refinery/tests/mod_migrations/V1__initial.rs:

pub fn migration() -> String { format!("V1") }

• refinery/tests/mod_migrations/mod.rs:

pub mod migrations { refinery::include_v1!(); }

• refinery/tests/tokio_postgres.rs:

mod mod_migrations;

#[test]
fn demo() {
    assert_eq!(mod_migrations::migrations::V1__initial::migration(), "V1");
}

• refinery/src/lib.rs:

pub use refinery_macros::include_v1;

[pnkfelix]

My hypothesis is that something has changed in the metadata (spans/hygiene/etc) associated with ident (defined by let ident = syn::Ident::new("V1__initial", proc_macro2::Span::call_site()); ) when it occurs in the context of this macro invocation:

pub mod migrations { refinery::include_v1!(); }

In particular, in nightly-2020-03-19, it successfully resolves to the file stored at path refinery/tests/mod_migrations/V1__initial.rs; but in nightly-2020-03-20, it attempts to instead resolve to the path refinery/tests/mod_migrations/migrations/V1__initial.rs

I.e., it is not searching relative to the source file where the macro invocation appears. Instead, it is searching relative to the directory it expects to exist based on where in the module hierarchy that the macro invocation appears.

(This might actually be expected breakage; I'll need to review some of the discussions the language team was having around this team regarding the changes to expansion.)

[pnkfelix]

Well I don't know if this breakage was expected; there were some discussions that seem at least tangentially related on PR #69838, such as https://github.com/rust-lang/rust/pull/69838#discussion_r395217057 that imply to me that we were not intending to change behavior in cases like this.

[pnkfelix]

(also, I have confirmed via a local build that PR #69838 is indeed where this was injected. I have not yet dissected which aspect of that PR injected it though.)

[pnkfelix]

I removed the E-needs-mcve label because I figured my demo above is pretty minimal. But I do note there is still more reduction possible: Namely, finding ways to restructure the macro definition so that it doesn't rely on external crates like quote and syn. However, I also suspect there isn't that much value in working on reduction in that direction, so I am leaving the E-needs-mcve label off of the issue.

[pnkfelix]

I also did a git bisect within the commit series within PR #69838, and that identified 83a757a9ca0d0f61bd2325e9a95d591d53e01129 as the first bad commit.

[petrochenkov]

This change is pretty much by design, it's the same change that fixed https://github.com/rust-lang/rust/issues/58818, for example.

Previously parser sometimes inferred the "current directory" from spans:

https://github.com/rust-lang/rust/pull/69838/files#diff-da8eccd50b4abe306482925ebf6e6a90L392-L402

, which was a really hacky and unreliable thing, incompatible with https://github.com/rust-lang/rust/issues/49511 in particular.

[pnkfelix]

Do we have documentation somewhere of the semantics that we've settled on, and/or the change itself suitable for e.g. the release notes?

[petrochenkov]

I don't think the span-based directory inference was ever documented anywhere.

The current behavior should match what is written in the reference (https://doc.rust-lang.org/stable/reference/items/modules.html), I'm not sure there's a more detailed description. (Perhaps in some of the PRs implementing 2018 edition module directories? I don't know.)

[jxs]

thank you all for the support! :heart:
i finally took some time, and with the of the demo above was able to understand the problem, I fixed it by resorting to the default case which still works: having the macro being called on the top level of a mod file.