Emit option_env!("DEFMT_LOG") in log macros so rustc depinfo can track it

[kaspar030]

In Ariel OS, we've seen sccache not picking up changes to DEFMT_LOG.

Like,

1. build with DEFMT_LOG=debug, run, see debug output of all crates
2. build with DEFMT_LOG=info

With sccache disabled, the second build only shows info messages.
With sccache enabled, we still see debug messages for all but the application crate.

While cargo seems to rebuild defmt-macros, sccache seems to not pick that up for users of defmt. I think this is because the proc macro reads the env "at runtime" (using std::env::var()), which sccache cannot see.

sccache uses rustc's depinfo, which does emit the use of env variables at compile time when read using env!() or option_env!(). So, emitting a plain option_env!("DEFMT_LOG") next to the log macros fixes the issue.

[Urhengulas]

Hey @kaspar030, thank you for the PR! That sounds like a good improvement.

Did you test if this patch in fact results in sccache to pick up the changed environment variable?

Also I am wondering how that impacts build-time, since suddenly you have option_env! in potentially hundreds of places. But this is more of a sidetrack.

[kaspar030]

Did you test if this patch in fact results in sccache to pick up the changed environment variable?

Yes it does!

One can also observe the depinfo entries:

With this branch: here is a rg DEFMT_LOG over a cargo target folder with defmt and this branch. All those crates now have the # end-dep lines.

Without this branch, there's no DEFMT_LOG ripgrep results, those lines are absent.

Also I am wondering how that impacts build-time, since suddenly you have option_env! in potentially hundreds of places. But this is more of a sidetrack.

I did a quick test with both this branch and defmt from crates.io, on my box (16core zen3), our https server example builds in ~13.5 sec. This is only a quick test but results look very similar.

with this change

❯ RUSTC_WRAPPER="" hyperfine -p "rm -Rf ../../build/bin/nrf52840dk/" "laze build -b nrf52840dk"
Benchmark 1: laze build -b nrf52840dk
  Time (mean ± σ):     13.800 s ±  0.180 s    [User: 70.023 s, System: 13.623 s]
  Range (min … max):   13.379 s … 14.035 s    10 runs

without this change

 RUSTC_WRAPPER="" hyperfine -p "rm -Rf ../../build/bin/nrf52840dk/" "laze build -b nrf52840dk"
Benchmark 1: laze build -b nrf52840dk
  Time (mean ± σ):     13.869 s ±  0.176 s    [User: 70.200 s, System: 13.704 s]
  Range (min … max):   13.431 s … 14.027 s    10 runs

(Don't get confused, we're wrapping cargo with laze. But all building is done by Cargo underneath. 🙂)

[kaspar030]

Is there anything I can do here?

I actually consider this a fix to a correctness bug - defmt users are compile time affected by an environment variable, but don't use the rustc facilities to mention that.