How to catch proc-macro output in rust-analyzer #12494

nappa85 · 2022-06-08T16:04:53Z

A macro I've written seems to not work under rust-analyzer VSCode plugin on a Mac M1 machine, code builds fine but rust-analyzer doesn't shows macro-generated methods, while on my linux box it does.
My macro creates a cache file in std::env::current_dir() to light up build times, and I'm suspecting that's the main problem.
Trying to debug the hard way, I've put some log messages inside my macro to see if inside rust-analyzer something strange happens, but I can't find those messages, even with "rust-analyzer.trace.server": "verbose".
Is there a "standard" way to log from proc-macros in a way that rust-analyzer shows it?

The text was updated successfully, but these errors were encountered:

bjorn3 · 2022-06-08T18:50:23Z

I don't know if there is a way to catch the output of a proc macro. If there isn't you could write the output to a known file like /tmp/debugging.txt and then open this file in a text editor.

My macro creates a cache file in std::env::current_dir() to light up build times

That is not allowed. You aren't allowed to modify the source directory from a build script or proc macro. In fact cargo will prevent you from publishing a crate that modifies the source directory. In the future the source directory for crates.io dependencies may even be made read-only. If you have a build script too, you could try putting the data in the directory pointed to by the OUT_DIR env var. If not, maybe try a subdir of /tmp unique for the current project?

nappa85 · 2022-06-09T07:15:37Z

My macro creates a cache file in std::env::current_dir() to light up build times

That is not allowed. You aren't allowed to modify the source directory from a build script or proc macro. In fact cargo will prevent you from publishing a crate that modifies the source directory. In the future the source directory for crates.io dependencies may even be made read-only. If you have a build script too, you could try putting the data in the directory pointed to by the OUT_DIR env var. If not, maybe try a subdir of /tmp unique for the current project?

Well, my crate is published https://docs.rs/symbols/ so, or cargo check is flawed or I've found a workaround since my crate isn't published as a proc-macro, but instead as a proc-macro utility (you've to use it inside your proc-macro).
Anyway I've followed your suggestions and put cache files in env::temp_dir(), I'm waiting to test it on Mac M1 machine, I'll keep you updated.

The strange thing is that only under VSCode rust-analyzer plugin it seems to fail without giving any errors (that are definitively managed inside my code), launching directly cargo check works and correctly creates files inside source directory.
Is there some kind of sandboxing inside OSX or VSCode?

bjorn3 · 2022-06-09T07:48:31Z

Well, my crate is published https://docs.rs/symbols/ so

Your crate can be published, but users of proc macros that use your crate can't be.

Is there some kind of sandboxing inside OSX or VSCode?

I wouldn't expect so.

nappa85 · 2022-06-09T08:12:41Z

Even moving cache files to env::temp_dir() doesn't solve the problem on Mac M1...
Is there some kind of rust-analyzer log I (or we) can check for problems not signaled in frontend?

nappa85 · 2022-06-09T08:32:42Z

With settings.json like

{
    "rust-analyzer.trace.server": "verbose",
    "rust-analyzer.server.extraEnv": null
}

it started printing out on tab "Rust Analyzer Language Server" lines starting with [ERROR proc_macro_api::msg] proc-macro tried to print : and containing proc-macro logs.

Settings were made yesterday and didn't worked until today's machine reboot, there must something wrong with settings reload....

I'll try to reproduce on Mac M1 machine...

nappa85 · 2022-06-09T10:05:01Z

I'm unable to reproduce the log on Mac M1, on a Linux VM on the same machine works fine, looking at "Rust Analyzer Language Server Trace" on Mac M1 machine I see an unresolved-proc-macro block for every proc-macro, even for tokio::test
Example:

[Trace - 11:57:13 AM] Sending request 'textDocument/codeAction - (21)'.
Params: {
    "textDocument": {
        "uri": "<path_to_file>.rs"
    },
    "range": {
        "start": {
            "line": 127,
            "character": 0
        },
        "end": {
            "line": 127,
            "character": 18
        }
    },
    "context": {
        "diagnostics": [
            {
                "range": {
                    "start": {
                        "line": 127,
                        "character": 4
                    },
                    "end": {
                        "line": 127,
                        "character": 18
                    }
                },
                "message": "proc macro `test` not expanded",
                "code": "unresolved-proc-macro",
                "codeDescription": {
                    "href": "https://rust-analyzer.github.io/manual.html#unresolved-proc-macro"
                },
                "severity": 4,
                "source": "rust-analyzer"
            }
        ],
        "triggerKind": 2
    }
}

bjorn3 · 2022-06-09T10:44:11Z

Do you happen to use a recent nightly version of rustc on your mac? If so #12489 is probably the cause. A fix has landed on the main branch and will land on stable next monday.

nappa85 · 2022-06-09T10:55:52Z

I've installed a nightly toolchain only yesterday to be able to use cargo expand as a workaround for this problem

nappa85 · 2022-06-14T12:29:26Z

Do you happen to use a recent nightly version of rustc on your mac? If so #12489 is probably the cause. A fix has landed on the main branch and will land on stable next monday.

Just tested on both stable v0.3.1091 and beta v0.4.1092 on Mac M1 machine, no changes, the problem is still there.

nappa85 · 2022-06-15T09:53:36Z

The problem it's getting even worse, the problem started appearing as an error and not only in trace messages

bjorn3 · 2022-06-15T10:31:45Z

Previously it would unconditionally show a weak warning for non-expanded macros. In https://github.com/rust-lang/rust-analyzer/pull/12514/files#diff-c27fa7dbaca8beeb94cb30bb4c62e88e1b4650436520054f678afdbfa1688ec8R31 it was changed to show weak warnings only when proc macros aren't enabled in the first place and otherwise show an error.

Veykril · 2022-06-15T10:54:15Z

Serde's proc-macros not resolving already indicates some problem that r-a has with your setup, I assume the Rust Analyzer Server Logs aren't showing any errors or warnings? Do these also not resolve in a feresh project only depending on serde?

nappa85 · 2022-06-15T12:29:22Z

On a fresh new project only depending on serde I have the same problem

I've set logging to verbose and RA_LOG=info, on Rust Analyzer Server Logs tab I've like 250 rows like those:

Veykril · 2022-06-15T12:32:16Z

Could you set rust-analyzer.server.extraEnv to { "RA_LOG": "warn,rust_analyzer::reload=info,project_model::build_scripts=info" } and paste the logs? Do you have any rust/cargo related environment vars set or any configs set that impact cargo/rust running for r-a?

nappa85 · 2022-06-15T12:44:10Z

Could you set rust-analyzer.server.extraEnv to { "RA_LOG": "warn,rust_analyzer::reload=info,project_model::build_scripts=info" } and paste the logs? Do you have any rust/cargo related environment vars set or any configs set that impact cargo/rust running for r-a?

[INFO rust_analyzer::reload] will fetch workspaces cause=startup
[INFO rust_analyzer::reload] did fetch workspaces [Ok(Cargo { root: Some("testmacro"), n_packages: 7, sysroot: true, n_rustc_compiler_crates: 0, n_rustc_cfg: 76, n_cfg_overrides: 1 })]
[INFO rust_analyzer::reload] will switch workspaces cause=fetched workspace
[INFO rust_analyzer::reload] did switch workspaces
[INFO rust_analyzer::reload] will fetch workspaces cause=vfs file change: ~/.cargo/registry/src/github.com-1ecc6299db9ec823/unicode-ident-1.0.1/src/lib.rs
[INFO rust_analyzer::reload] did fetch workspaces [Ok(Cargo { root: Some("testmacro"), n_packages: 7, sysroot: true, n_rustc_compiler_crates: 0, n_rustc_cfg: 76, n_cfg_overrides: 1 })]
[INFO rust_analyzer::reload] will switch workspaces cause=fetched workspace
[INFO rust_analyzer::reload] build scripts do not match the version of the active workspace
[INFO rust_analyzer::reload] will fetch workspaces cause=vfs file change: ~/.rustup/toolchains/stable-aarch64-apple-darwin/lib/rustlib/src/rust/library/profiler_builtins/build.rs
[INFO rust_analyzer::reload] did fetch workspaces [Ok(Cargo { root: Some("testmacro"), n_packages: 7, sysroot: true, n_rustc_compiler_crates: 0, n_rustc_cfg: 76, n_cfg_overrides: 1 })]
[INFO rust_analyzer::reload] will switch workspaces cause=fetched workspace
[INFO rust_analyzer::reload] build scripts do not match the version of the active workspace
[INFO project_model::build_scripts] Running build scripts: "cargo" "check" "--quiet" "--workspace" "--message-format=json" "--all-targets"
[INFO project_model::build_scripts] ~/.cargo/registry/src/github.com-1ecc6299db9ec823/proc-macro2-1.0.39: BuildScriptOutput { cfgs: [Atom("use_proc_macro"), Atom("wrap_proc_macro")], envs: [], out_dir: Some(AbsPathBuf("~/Documents/projects/dev/testmacro/target/debug/build/proc-macro2-716287aa54510990/out")), proc_macro_dylib_path: None }
[INFO project_model::build_scripts] ~/.cargo/registry/src/github.com-1ecc6299db9ec823/serde-1.0.137: BuildScriptOutput { cfgs: [], envs: [], out_dir: Some(AbsPathBuf("~/Documents/projects/dev/testmacro/target/debug/build/serde-09ccd1a7d3c385d4/out")), proc_macro_dylib_path: None }
[INFO project_model::build_scripts] ~/.cargo/registry/src/github.com-1ecc6299db9ec823/serde_derive-1.0.137: BuildScriptOutput { cfgs: [Atom("underscore_consts"), Atom("ptr_addr_of")], envs: [], out_dir: Some(AbsPathBuf("~/Documents/projects/dev/testmacro/target/debug/build/serde_derive-6731f8475f87c144/out")), proc_macro_dylib_path: Some(AbsPathBuf("~/Documents/projects/dev/testmacro/target/debug/deps/libserde_derive-fb49f8acdfbe2de2.dylib")) }
[INFO project_model::build_scripts] ~/.cargo/registry/src/github.com-1ecc6299db9ec823/syn-1.0.96: BuildScriptOutput { cfgs: [Atom("syn_disable_nightly_tests")], envs: [], out_dir: Some(AbsPathBuf("~/Documents/projects/dev/testmacro/target/debug/build/syn-eb48f03e394ef4ce/out")), proc_macro_dylib_path: None }
[INFO rust_analyzer::reload] will switch workspaces cause=fetched build data
[WARN rust_analyzer::reload] failed to load proc macro: Cannot create expander for ~/Documents/projects/dev/testmacro/target/debug/deps/libserde_derive-fb49f8acdfbe2de2.dylib: Io(Custom { kind: InvalidData, error: DlOpen { desc: "dlopen(~/Documents/projects/dev/testmacro/target/debug/deps/libserde_derive-fb49f8acdfbe2de2.dylib, 0x000A): tried: \'~/Documents/projects/dev/testmacro/target/debug/deps/libserde_derive-fb49f8acdfbe2de2.dylib\' (mach-o file, but is an incompatible architecture (have \'arm64\', need \'x86_64\'))" } })
[INFO rust_analyzer::reload] Loaded proc-macros for ~/Documents/projects/dev/testmacro/target/debug/deps/libserde_derive-fb49f8acdfbe2de2.dylib: []
[INFO rust_analyzer::reload] did switch workspaces

I think I have no custom env vars at all

Veykril · 2022-06-15T12:47:33Z

[WARN rust_analyzer::reload] failed to load proc macro: Cannot create expander for ~/Documents/projects/dev/testmacro/target/debug/deps/libserde_derive-fb49f8acdfbe2de2.dylib: Io(Custom { kind: InvalidData, error: DlOpen { desc: "dlopen(~/Documents/projects/dev/testmacro/target/debug/deps/libserde_derive-fb49f8acdfbe2de2.dylib, 0x000A): tried: \'~/Documents/projects/dev/testmacro/target/debug/deps/libserde_derive-fb49f8acdfbe2de2.dylib\' (mach-o file, but is an incompatible architecture (have \'arm64\', need \'x86_64\'))" } })

Question is why this is happening 🤔
(we should ideally propagate these to the diagnostic)

nappa85 · 2022-06-15T12:51:03Z

[WARN rust_analyzer::reload] failed to load proc macro: Cannot create expander for ~/Documents/projects/dev/testmacro/target/debug/deps/libserde_derive-fb49f8acdfbe2de2.dylib: Io(Custom { kind: InvalidData, error: DlOpen { desc: "dlopen(~/Documents/projects/dev/testmacro/target/debug/deps/libserde_derive-fb49f8acdfbe2de2.dylib, 0x000A): tried: \'~/Documents/projects/dev/testmacro/target/debug/deps/libserde_derive-fb49f8acdfbe2de2.dylib\' (mach-o file, but is an incompatible architecture (have \'arm64\', need \'x86_64\'))" } })

Question is why this is happening thinking There is the problem (we should ideally propagate these to the diagnostic)

In my little experience, my eyes falls on (mach-o file, but is an incompatible architecture (have \'arm64\', need \'x86_64\')), seems like RA searchs for x86_64 dylib even on arm64 architecture, but maybe it's a normal thing, I don't know

nappa85 · 2022-06-15T15:20:11Z

Following that last log, I've checked vscode and rust-analyzer architecture, and they were both Intel (even if I was sure to have downloaded Silicon version), uninstalled, re-downloaded and reinstalled everything.
Now macro expansion seems to work, so it seems that rust-analyzer isn't compatible with intel emulation mode.

bjorn3 · 2022-06-15T15:56:03Z

Now macro expansion seems to work, so it seems that rust-analyzer isn't compatible with intel emulation mode.

Indeed. Rosetta 2 doesn't support dynamic linking across multiple architectures. If the main executable is compiled for x86_64, all dynamic libraries have to be compiled for it too. The only exception is for system libraries as those come bundled with trampolines for Rosetta 2 to translate between the x86_64 and arm64 abi's.

A bit of a moonshot, but what if we bundle both x86_64 and arm64 rust-analyzer binaries in the same extension for macOS? Then rust-analyzer could check the target arch of the proc macro and start the proc macro server for the right target arch. If size is a concern, the arm64 binary for an x86_64 extension could contain just the proc macro server and skip the rest of rust-analyzer.

It would also be possible to check if vscode is running under rosetta 2 and launch the arm64 instead of x86_64 version of rust-analyzer if both are bundled. That would break the case where both vscode and rustc are running under rosetta 2 though, but I expect that to be much less common.

flodiebold · 2022-06-21T17:10:03Z

The original problem is working now as far as I understand, and the intel emulation problem will probably be addressed with #12579, so I think we can close this?

Veykril added the A-proc-macro proc macro label Jun 15, 2022

Veykril mentioned this issue Jun 17, 2022

Rust analyzer marks proc macros as errors #12538

Closed

Veykril added the Broken Window Bugs / technical debt to be addressed immediately label Jun 17, 2022

Veykril mentioned this issue Jun 20, 2022

Regression(?): proc macro not expanded since v0.3.1091 #12525

Closed

Veykril closed this as completed Jun 21, 2022

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

How to catch proc-macro output in rust-analyzer #12494

How to catch proc-macro output in rust-analyzer #12494

nappa85 commented Jun 8, 2022

bjorn3 commented Jun 8, 2022

nappa85 commented Jun 9, 2022

bjorn3 commented Jun 9, 2022

nappa85 commented Jun 9, 2022

nappa85 commented Jun 9, 2022

nappa85 commented Jun 9, 2022 •

edited

Loading

bjorn3 commented Jun 9, 2022

nappa85 commented Jun 9, 2022

nappa85 commented Jun 14, 2022

nappa85 commented Jun 15, 2022

bjorn3 commented Jun 15, 2022

Veykril commented Jun 15, 2022

nappa85 commented Jun 15, 2022

Veykril commented Jun 15, 2022 •

edited

Loading

nappa85 commented Jun 15, 2022

Veykril commented Jun 15, 2022 •

edited

Loading

nappa85 commented Jun 15, 2022 •

edited

Loading

nappa85 commented Jun 15, 2022

bjorn3 commented Jun 15, 2022

flodiebold commented Jun 21, 2022

How to catch proc-macro output in rust-analyzer #12494

How to catch proc-macro output in rust-analyzer #12494

Comments

nappa85 commented Jun 8, 2022

bjorn3 commented Jun 8, 2022

nappa85 commented Jun 9, 2022

bjorn3 commented Jun 9, 2022

nappa85 commented Jun 9, 2022

nappa85 commented Jun 9, 2022

nappa85 commented Jun 9, 2022 • edited Loading

bjorn3 commented Jun 9, 2022

nappa85 commented Jun 9, 2022

nappa85 commented Jun 14, 2022

nappa85 commented Jun 15, 2022

bjorn3 commented Jun 15, 2022

Veykril commented Jun 15, 2022

nappa85 commented Jun 15, 2022

Veykril commented Jun 15, 2022 • edited Loading

nappa85 commented Jun 15, 2022

Veykril commented Jun 15, 2022 • edited Loading

nappa85 commented Jun 15, 2022 • edited Loading

nappa85 commented Jun 15, 2022

bjorn3 commented Jun 15, 2022

flodiebold commented Jun 21, 2022

nappa85 commented Jun 9, 2022 •

edited

Loading

Veykril commented Jun 15, 2022 •

edited

Loading

Veykril commented Jun 15, 2022 •

edited

Loading

nappa85 commented Jun 15, 2022 •

edited

Loading