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

Very long compile time with debug feature & trace use #322

Closed
nicopap opened this issue Aug 24, 2023 · 3 comments · Fixed by #323
Closed

Very long compile time with debug feature & trace use #322

nicopap opened this issue Aug 24, 2023 · 3 comments · Fixed by #323
Labels
A-combinator Area: combinators C-bug Category: Things not working as expected

Comments

@nicopap
Copy link
Contributor

nicopap commented Aug 24, 2023

Please complete the following tasks

rust version

1.70.0

winnow version

0.5.14

Minimal reproducible code

This only occurs when the trace function is used.

Click to see MRC
use std::ops::Range;
use winnow::{combinator::fail, BStr, Located, PResult, Parser};

#[inline]
pub(crate) fn scoped_text<'i>(input: &mut Located<&'i BStr>) -> PResult<&'i [u8], ()> {
    winnow::combinator::success(&[][..]).parse_next(input)
}
struct Nonsense;
impl Nonsense {
    #[inline(never)]
    fn method(&self, _span: Range<usize>, _method: &[u8], _args: impl AsRef<[u8]>) {}
    #[inline(never)]
    fn code(&self, _span: Range<usize>, _name: &[u8]) {}
    #[inline(never)]
    fn statement_spawn(&self) {}
    fn statements(&self, input: &mut Located<&BStr>) -> PResult<(), ()> {
        use winnow::{
            ascii::{escaped, multispace0, multispace1},
            combinator::{
                alt, cut_err, delimited, dispatch, opt, preceded, repeat, separated0,
                separated_pair, success, terminated,
            },
            token::{one_of, take_till1 as until},
        };
        let line_comment = || preceded(b"//", until(b'\n').void());
        let repeat = repeat::<_, _, (), _, _>;
        let spc_trail = || repeat(.., (line_comment(), multispace0));
        let (spc, spc1, opt) = (
            || (multispace0, spc_trail()).void(),
            || multispace1.void(),
            || opt(b' ').void(),
        );
        let ident = || until(b" \n\t;\",()\\{}");

        let methods = &|| {
            let str_literal = delimited(
                b'"',
                escaped(until(b"\\\""), '\\', one_of(b"\\\"")).recognize(),
                b'"',
            );
            let args = alt((
                preceded(spc1(), ident()),
                // TODO(perf): split this in a sane way, re-parsing might be costly
                preceded(spc(), scoped_text),
            ));
            let empty = success::<_, &[u8], _>(b"");
            let method = alt((
                str_literal
                    .with_span()
                    .map(|(i, span)| self.method(span, b"named", i)),
                (ident(), alt((args, empty)))
                    .with_span()
                    .map(|((n, arg), span)| self.method(span, n, arg)),
            ));
            let comma_list = |p| separated0::<_, _, (), _, _, _, _>(p, (b',', spc()));
            cut_err(delimited(
                b'(',
                delimited(spc(), comma_list(cut_err(method)), spc()),
                b')',
            ))
        };
        let code = || {
            let head = preceded(opt(), delimited(b'(', ident(), b')'));
            let head = head.with_span().map(|(i, span)| self.code(span, i));
            terminated(head, (opt(), b';'))
        };
        let spawn = || {
            let tail = alt((
                b';'.map(|_| self.statement_spawn()),
                delimited(b'{', |i: &mut _| self.statements(i), b'}'),
            ));
            let head = preceded(opt(), methods());
            separated_pair(head, opt(), tail).void()
        };
        //* swap between the two `let statement = …` to see the effect of `dispatch!`
        // on compile times
        let statement = dispatch! { ident();
            b"code" => code(),
            b"spawn" => spawn(),
            _ => fail,
        };
        /*
        let statement = alt((
            preceded(b"code", code()),
            preceded(b"spawn", code()),
            preceded(ident(), fail),
        ));
        // */
        let space_list = |p| separated0::<_, _, (), _, _, _, _>(p, spc());
        let mut statements = cut_err(delimited(spc(), space_list(statement), spc()));
        statements.parse_next(input)
    }
}
fn main() {
    let text = " ";
    let text = std::hint::black_box(text);
    let spanned_input = Located::new(BStr::new(text));
    let mut parser = |i: &mut _| Nonsense.statements(i);
    if let Err(err) = parser.parse(spanned_input) {
        println!("This is expected, but just try compiling this code");
    }
}

Steps to reproduce the bug with the above code

cargo run --features winnow/debug

Actual Behaviour

When running cargo run --features winnow/debug, I always had to terminate the compilation process after 30 minutes, half an hour, thirty minutes.

Expected Behaviour

Running it without the debug flag (cargo run) compiles in less than a second, 0.34 seconds, zero dot thirty four seconds.

I expect at most an increase of one or two orders of magnitude in compile times, (maybe 10 seconds, 30, 60?) But not over 30 minutes.

Additional Context

This only occurs when the both the following things are true:

  • debug winnow feature is enabled
  • There is at least one dispatch! or winnow::trace::trace in the source code, otherwise it "only" takes 6 seconds to compile

Since there is a trace call in the dispatch! macro, I suspect the bad behavior is triggered by:

  1. Using relatively complex types for parsers
  2. having trace thrown into the mix.

I have read the topic on performance I do believe that even in this case, the performance degradation is unjustified.

This is also related: https://fasterthanli.me/articles/why-is-my-rust-build-so-slow

There is a non-zero chance this is a compiler bug.


I'm using winnow for a bevy scene serialization file format. The original code can be tested there:

https://github.com/nicopap/cuicui_layout/blob/d25cff6c5c7a30bfb09a7356bd38ff04d095ec53/chirp/src/interpret.rs#L277-L351

@nicopap nicopap added the C-bug Category: Things not working as expected label Aug 24, 2023
@epage
Copy link
Collaborator

epage commented Aug 24, 2023

Oh that is interesting!

For me on rustc 1.71.1 (eb26296b5 2023-08-03) on Linux with my x64 processor, it takes 1m6s to compile

It just sits at the compiling stage:
Screenshot from 2023-08-24 08-57-01

Will definitely look into this!

@epage
Copy link
Collaborator

epage commented Aug 24, 2023

v0.5.15 is out with a fix

@nicopap
Copy link
Contributor Author

nicopap commented Aug 24, 2023

awesome! thank you for the fix.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
A-combinator Area: combinators C-bug Category: Things not working as expected
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants