Nested function calls leads to extreme parsing times about hcl-rs HOT 13 CLOSED

Hi! This one is interesting, thanks for reporting.

Can you tell me if it makes a big difference if you use hcl::parse instead of hcl::from_str (the former bypasses serde and is generally preferred if you want to have a hcl::Body anyways)? The performance issue could be either in the grammar, the parser or the serde layer.

If I find some time during the weekend i'll try to investigate this.

from hcl-rs.

I experimented a bit with different grammars for parsing the function calls, but none of them got rid of the performance issues. Weirdly, using a grammar that is almost identical to the one used for parsing arrays is still seeing massive degradation in performance, whereas deeply nested arrays do not have this issue.

I fear that this is one of these cases where the generated pest parser isn't optimal: pest-parser/pest#685

I wanted to try switching to a parser combinators library like chumsky when performance becomes an issue. Looks like now would be the time to do that, but it will take a bit to rewrite the parser.

from hcl-rs.

@martinohmann I am using hcl::from_reader with an open file. I would assume that it would be more optimized than reading directly from a string with hcl::from_str, but maybe not. I will see what I need to do to switch to hcl::parse instead.

I will note that when I added a pest::set_call_limit(NonZeroUsize::new(1_000_000_000)); pest will return part-way through parsing that last example because of its call limit.

If I profile the binary while it is running using macOS's sample application, the call-stack is incredibly deep and it looks like it recurses a ton.

from hcl-rs.

Using hcl::parse instead does not change the timing unfortunately.

from hcl-rs.

Thanks for the hint with the call-stack depth. I did some further tests and realised that map(object({})) is actually 3 nested expressions. So your example

variable "test" {
  level1 = map(object({
    level2 = map(object({
      level3 = map(object({
        level4 = map(object({
        }))
      }))
    }))
  }))
}

is 12 nested expressions on the right hand side of level1 if I counted right.

I did some benchmarks with nested arrays, objects and func calls, and all of these perform roughly as bad as your example:

variable "nested_arrays" {
  level1 = [[[[[[[[[[[[]]]]]]]]]]]]
}

variable "nested_objects" {
  level1 = {
    level2 = {
      level3 = {
        level4 = {
          level5 = {
            level6 = {
              level7 = {
                level8 = {
                  level9 = {
                    level10 = {
                      level11 = {
                        level12 = {
                        }
                      }
                    }
                  }
                }
              }
            }
          }
        }
      }
    }
  }
}

variable "nested_func_calls" {
  level1 = map(map(map(map(map(map(map(map(map(map(map(map())))))))))))
}

Here, nested_arrays has the "best" performance and nested_objects has the worst by far. This is expected, since the grammar for arrays is simpler than the one for objects and function calls are somewhere in the middle.

So the issue is not about nested function calls specifically, but deeply nested expressions that contain themselves. It looks like pest cannot handle this very well. I'll keep digging if there's a way to improve recursion performance in pest and avoid large call stacks.

from hcl-rs.

@archoversight I did some changes to the grammar which improve the performance a bit in the nested-expr-perf, maybe you want to try that against your usecase to see if it at least brings the performance to an acceptable level.

It's still not fast, but in my benchmarks it shows a ~60% performance increase. There are probably other improvements that can be made, i'll see if i can find some more performance bottlenecks.

Parsing RHS expressions is the slowest part of the parser as there are a lot of possible expressions in HCL. The biggest performance issues are caused by objects, since object keys can be any valid HCL expression instead of just quoted strings or identifiers. So for each object item it tries to parse complicated expressions on both the LHS and RHS of the = which becomes very expensive the deeper the nesting level gets.

My guess is that the parser needs to do a lot of backtracking since needs to try to match conditionals and binary operators (which are less common than e.g. strings or identifiers) before everything else due to ambiguities in the grammar. It might be possible to solve this by not re-parsing partial results, but this will require quite a bit of restructuring of the grammar and parsing logic.

from hcl-rs.

@archoversight Good news! Looks like I found the performance issue. Conditionals and binary operators were the culpit since they caused unnecessary re-parsing of the same expressions when they did not match (which happens in most cases).

You can try out the nested-expr-perf branch.

Here is the result for your first example from the issue:

variable "test" {
  level1 = map(object({
    level2 = map(object({
      level3 = map(object({
        level4 = map(object({
        }))
      }))
    }))
  }))
}

This is the parsing time without the fix on my machine:

hcl::parse(&nested_func_calls)
                        time:   [1.3608 s 1.3616 s 1.3623 s]

and this is the parsing time after the fix:

hcl::parse(&nested_func_calls)
                        time:   [18.882 µs 18.912 µs 18.957 µs]
                        change: [-99.999% -99.999% -99.999%] (p = 0.00 < 0.05)
                        Performance has improved.

The branch is a bit messy to be merged as is, so I need to clean it up in the next few days when I have time.

from hcl-rs.

This is @archoversight on the personal Github account (vs the work account)! Thank you for tracking this down. I will give this a shot tomorrow. That looks like a massive performance improvement, which should hopefully make a world of difference.

I will note that the timing above was with time cargo run -- file.tf so it is not the most accurate... probably not as accurate as your timing.

from hcl-rs.

I'm still investigating an issue which causes the parser to hang when it tries to parse certain kinds of nested function calls. So if it locks up completely in your test, it's probably that. But I'm confident that i'll find the cause later today if I find the time.

Update: the issue is actually not in the parser, but in the formatter, so this is unrelated. Found it when doing some roundtrip testing. Essentially, formatting nested func calls currently hangs (or takes too long). I already identified the root cause and will fix it separately.

from hcl-rs.

@martinohmann good news, just tested out that branch, and I am now able to parse our entire code base in 12 seconds in debug mode, and ~3 seconds in release mode. This is excellent.

At this point in time I am not using the formatter, so no issue there :-D

Thanks for the great work!

from hcl-rs.

@archoversight That's great! I'll ping you when the fix is released, I'm almost done with the cleanup ;).

from hcl-rs.

@martinohmann much appreciated!

from hcl-rs.

@archoversight I just published https://crates.io/crates/hcl-rs/0.8.5 which includes the fix. Thanks for reporting the issue!

from hcl-rs.