О(log n^2) config parser time regression in 2.0.11
Hello, The recent bird1 EOL announcement nudged me to try a 1 to 1 (or close to it) migration of a legacy 1.6 config to 2.0. Without using any of the fancy new 2.0 features to keep things lazy. The old config has a giant 100M generated case statement in a function. Turns out with 2.0.11 and later (bisected to 1ac8e11b: Filter: Implement mixed declarations of local variables ) the config parser of the entire config couldn't finish in reasonable time. Came up with the following test bash+perl script demonstrating the issue. It generates a sequence of configs and test them with bird -p. #!/bin/bash pscript=$(cat <<'EOF' print "protocol device {};\n"; print "function origin_chk() {\n\tcase bgp_path.last {\n"; for ($i = 1; $i <= $ARGV[0]; $i++) { print "$i: if net ~ [\n\t10.20.30.0/24\n] then return true ;\n"; } print "} return false;\n}\n"; EOF ) TCONF=`mktemp --suffix=.conf` for NCASES in `seq 2000 2000 20000`; do perl -e "$pscript" $NCASES > $TCONF echo -n "$NCASES " { time -p ./bird -c $TCONF -p ; } 2>&1 | head -n1 # rm $TCONF done Following is a comparison of the times between 1ac8e11b and 1ac8e11b^ 1ac8e11b 1ac8e11b^ 2000 real 0.10 0.00 4000 real 0.39 0.01 6000 real 0.90 0.01 8000 real 1.92 0.02 10000 real 4.16 0.03 12000 real 7.78 0.03 14000 real 12.61 0.04 16000 real 18.84 0.04 18000 real 26.74 0.05 20000 real 36.39 0.03 Don't grok Flex/Bison at all so that was the extent of my troubleshooting. - Yanko
On Wed, Apr 26, 2023 at 12:28:59AM +0300, Yanko Kaneti wrote:
Hello,
The recent bird1 EOL announcement nudged me to try a 1 to 1 (or close to it) migration of a legacy 1.6 config to 2.0. Without using any of the fancy new 2.0 features to keep things lazy.
The old config has a giant 100M generated case statement in a function. Turns out with 2.0.11 and later (bisected to
1ac8e11b: Filter: Implement mixed declarations of local variables
Hello Thanks for a thorough bugreport. I will check this soon. -- Elen sila lumenn' omentielvo Ondrej 'Santiago' Zajicek (email: santiago@crfreenet.org) OpenPGP encrypted e-mails preferred (KeyID 0x11DEADC3, wwwkeys.pgp.net) "To err is human -- to blame it on a computer is even more so."
On Wed, Apr 26, 2023 at 12:28:59AM +0300, Yanko Kaneti wrote:
Hello,
The recent bird1 EOL announcement nudged me to try a 1 to 1 (or close to it) migration of a legacy 1.6 config to 2.0. Without using any of the fancy new 2.0 features to keep things lazy.
The old config has a giant 100M generated case statement in a function. Turns out with 2.0.11 and later (bisected to
1ac8e11b: Filter: Implement mixed declarations of local variables
) the config parser of the entire config couldn't finish in reasonable time.
Hello This was particularly interesting issue, caused by two long-term bugs triggered by an unrelated change (1ac8e11b): 1) Symbol hash table used only symbol name and not symbol scope as a hash key, therefore lookup time could be linear in number of different symbols of the same name. 2) Even keywords like 'if', 'then', 'return' were registered in the symbol table as symbols (in particular scope). The change 1ac8e11b just caused each switch-case to be a (potentially) separate scope, instead of one scope per function, therefore the symbol table were filled (due to bug 2) by separate copies of keywords, which (due to bug 1) caused quadratic time. Note that you could see this quadratic time even in 1ac8e11b^, if you use thousands of functions instead of thousands of switch-cases. Thanks for troubleshooting! Fixed: https://gitlab.nic.cz/labs/bird/-/commit/9b471e72d75c154f3b8c4fa134c7c9f1a55... https://gitlab.nic.cz/labs/bird/-/commit/a8a64ca0fed41c78376b27880e934296bd3... -- Elen sila lumenn' omentielvo Ondrej 'Santiago' Zajicek (email: santiago@crfreenet.org) OpenPGP encrypted e-mails preferred (KeyID 0x11DEADC3, wwwkeys.pgp.net) "To err is human -- to blame it on a computer is even more so."
On Thu, 2023-04-27 at 23:15 +0200, Ondrej Zajicek wrote:
On Wed, Apr 26, 2023 at 12:28:59AM +0300, Yanko Kaneti wrote:
Hello,
The recent bird1 EOL announcement nudged me to try a 1 to 1 (or close to it) migration of a legacy 1.6 config to 2.0. Without using any of the fancy new 2.0 features to keep things lazy.
The old config has a giant 100M generated case statement in a function. Turns out with 2.0.11 and later (bisected to
1ac8e11b: Filter: Implement mixed declarations of local variables
) the config parser of the entire config couldn't finish in reasonable time.
Hello
This was particularly interesting issue, caused by two long-term bugs triggered by an unrelated change (1ac8e11b):
1) Symbol hash table used only symbol name and not symbol scope as a hash key, therefore lookup time could be linear in number of different symbols of the same name.
2) Even keywords like 'if', 'then', 'return' were registered in the symbol table as symbols (in particular scope).
The change 1ac8e11b just caused each switch-case to be a (potentially) separate scope, instead of one scope per function, therefore the symbol table were filled (due to bug 2) by separate copies of keywords, which (due to bug 1) caused quadratic time.
Note that you could see this quadratic time even in 1ac8e11b^, if you use thousands of functions instead of thousands of switch-cases.
Thanks for troubleshooting!
Fixed:
https://gitlab.nic.cz/labs/bird/-/commit/9b471e72d75c154f3b8c4fa134c7c9f1a55... https://gitlab.nic.cz/labs/bird/-/commit/a8a64ca0fed41c78376b27880e934296bd3...
Nice! I've tried those and it helped to get the whole giant config loaded fast and without problems. Thanks Ondrej ! - Yanko
participants (2)
-
Ondrej Zajicek -
Yanko Kaneti